Sql-server – Sql_text Data Missing When Querying Extended Event File Target Using TSQL

The original Extended Event script from that article has some filters on it ( DBCC_CHECK, INDEX_CREATE and SE_REPL_PARTITION_BY_KEY ) which means they won't fire for just any old spinlocks. I have adapted the script to remove the filters and have successfully captured the callstacks. This demo script makes a number of assumptions:

• you are not trying to do this on your production server
• you know how to use SQLCMD mode ( SSMS > Query > SQLCMD Mode )
• you know how to use ostress and have it installed
• I'm working with a named instance called sql2012 - you can configure that
• I'm using c:\temp\temp.sql as a scratch file - you can configure that

Demo script. WARNING!! Do not run on production server

-- Spinlock simulation and callstack tracking with Extended Events
:on error exit
USE tempdb
GO

SET NOCOUNT ON
GO

CREATE TABLE spinlock_sim ( id INT PRIMARY KEY )
GO
INSERT INTO spinlock_sim VALUES( 1 )
GO

-- Create the sql file to run
!!bcp "SELECT N'SELECT id FROM spinlock_sim'" queryout c:\temp\temp.sql -S.\sql2012 -T -c

-- Reset spinlock stats (SQL 2012 only)
DBCC SQLPERF( 'sys.dm_os_spinlock_stats', CLEAR );
GO

-- Create the event session
CREATE EVENT SESSION [spin_lock_backoff] ON SERVER 
ADD EVENT sqlos.spinlock_backoff( ACTION(package0.callstack) )
ADD TARGET package0.histogram(SET filtering_event_name=N'sqlos.spinlock_backoff',
    source=N'package0.callstack',source_type=(1))
WITH (MAX_MEMORY=51200 KB,EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,MAX_DISPATCH_LATENCY=30 SECONDS,MAX_EVENT_SIZE=0 KB,MEMORY_PARTITION_MODE=PER_NODE,TRACK_CAUSALITY=OFF,STARTUP_STATE=OFF)
GO

-- Start the session
ALTER EVENT SESSION spin_lock_backoff ON SERVER STATE=START
GO

-- Attempt to create the spinlock contention with ostress
-- REM Parameters -E Windows Authentication -S server -Q query -o output directory -n number of connections -r iterations
-- REM eg 50 connections 200 times
!!"C:\Program Files\Microsoft Corporation\RMLUtils\ostress.exe" -E -S.\sql2012 -dtempdb -ic:\temp\temp.sql -q -oc:\temp\ostress.log -n50 -r200 -mstress
GO



--To view the data
--1. Ensure the sqlservr.pdb is in the same directory as the sqlservr.exe
--2. Enable this trace flag to turn on symbol resolution
DBCC TRACEON (3656, -1)
GO

--Get the callstacks from the bucketize target
select event_session_address, target_name, execution_count, cast (target_data as XML)
from sys.dm_xe_session_targets xst
inner join sys.dm_xe_sessions xs on (xst.event_session_address = xs.address)
where xs.name = 'spin_lock_backoff'
go

-- Look at spinlocks
SELECT * FROM sys.dm_os_spinlock_stats
ORDER BY backoffs DESC
GO

-- Cleanup
DROP TABLE spinlock_sim
GO
DBCC TRACEOFF (3656, -1)
GO
ALTER EVENT SESSION spin_lock_backoff ON SERVER STATE = STOP
GO
DROP EVENT SESSION spin_lock_backoff ON SERVER
GO

If your pdb is not in the right place you will only see hex values instead of method names (like mine), but you get the idea. Here's what I captured:

HTH

I couldn't find a definitive answer about how the offset is generated, only one unreliable reference that they're a block number. A little disappointing, I guess the engineers don't use stack exchange.

However I was listening to the SQL Down Under podcast this week and they were discussing the issues with doing ETL based on timestamps which are a little unreliable and result in skipped records.

The advice was that it's a good practice to read 30s back from where you left off and then eliminate duplicates.

So unless someone comes up with something better you can at least address your missed record concerns by starting your reads one block prior to the last block you received, and then eliminating duplicates.