What callstack can tell you in Microsoft SQL Server

In previous article Slow TRUNCATE: Diagnosing SQL Server Spinlock Contention – SQL Peak Performance call stack analysis was one of key point to troubleshoot the issue. But what exactly is a call stack, where we can get it and what tools to use?

Call Stack in ms SQL Server

When a function in a program is called, its address (which is like a specific location or marker in the program) gets added to call stack list. This list keeps track of all the functions that are being called, one on top of another. The function that’s currently running is at the top of this list. When this function calls another function, the new one goes on top, and the original one moves down. This list, with all the functions and their addresses, is known as the call stack. It shows the order of function calls. As the program runs, functions call other functions, creating a trail of activity. By looking at the call stack, you can see this trail and get clues about what the program is doing at any moment.

Where to Find Call Stacks in SQL Server

In SQL Server, call stacks can be encountered in several places, each providing different insights into the internal workings and processes of the SQL Server instance. Here are a few key locations where you might come across call stacks:

  1. Error Logs: SQL Server error logs can contain call stacks, especially when the server encounters a critical error that leads to a crash or other issues.
  2. Extended Events (XE): Extended events sessions can be configured to capture call stack information for specific events. This feature is particularly useful for detailed performance analysis and troubleshooting.
  3. Dump Files: When SQL Server crashes or is manually triggered to produce a dump (DBCC STACKDUMP/DBCC DUMPTRIGGER etc), the resulting dump files contain the call stack at the time of the crash or trigger. Analyzing these files requires specialized tools like WinDbg and symbols to translate memory addresses into readable function calls.

SQLCallStackResolver: A Tool for Insight

Working as a SQL Server support engineer at Microsoft, I had the opportunity to use an invaluable tool that has become publicly available: SQLCallStackResolver. Hosted on GitHub (SQLCallStackResolver), this tool is a game-changer for anyone looking to decode SQL Server call stacks. It aids in resolving the addresses seen in a call stack to their corresponding function names, making the process of diagnosing and understanding performance issues, crashes, or any abnormal behavior in SQL Server significantly more manageable.

Understanding call stacks in SQL Server can significantly enhance your ability to diagnose and resolve complex issues, optimize performance, and gain deeper insights into the inner workings of SQL Server instances.

Please feel free to ask questions in comments.

Unlocking Spinlocks: Long-Term Monitoring in SQL Server

In this post

In this post, I’m going to talk about spinlocks in SQL Server, starting with an easy-to-understand explanation of what spinlocks are. I’ll also provide practical advice on how to monitor and capture spinlock information over the long term, ensuring your SQL Server environment remains efficient and responsive.

What is spinlock.

Spinlocks are simple locks used in SQL Server to manage access to data when multiple processes try to use it simultaneously. Think of them as quick checks: if a process wants to use a resource that’s already in use, it “spins” in place, checking repeatedly and quickly until the resource becomes available, using CPU cycles during this process. This ensures quick access control but can lead to high CPU usage if many processes are spinning frequently. This method is efficient for short operations to avoid the overhead of more complex locking mechanisms, ensuring that the system can handle many operations smoothly without significant delays.

SQL Server uses spinlocks to protect various low-level, critical data structures from concurrent access. This includes structures like caches (e.g., buffer pool), internal lists, and other metadata that require fast, efficient access control to ensure the database’s integrity and performance during high levels of concurrency.

Why do I need to monitor spinlocks in long term.

Monitoring spinlocks in the long term is essential for maintaining SQL Server performance. High contention on spinlocks can lead to significant CPU usage, impacting overall system responsiveness. It’s important to note that starting spinlock monitoring can be almost impossible when you’re already facing an issue with 100% CPU utilization. By proactively monitoring spinlock behavior, you can identify and address potential problems before they escalate, ensuring that your database environment remains efficient, responsive, and capable of handling high concurrency levels without degradation in performance.

How to setup long term spinlock monitoring.


To effectively monitor spinlocks, we’ll set up two tables: one for storing raw data from sys.dm_os_spinlock_stats and another for holding the calculated differences between two snapshots. Additionally, two stored procedures will be introduced—one for capturing the current state and another for calculating the differences between snapshots. This approach allows for a comprehensive analysis of spinlock activity over time. Please check the code below:

--Create tables
IF NOT EXISTS (SELECT * FROM sys.objects WHERE object_id = OBJECT_ID(N'[dbo].[spinlock_monitor]') AND type in (N'U'))
BEGIN
CREATE TABLE [dbo].[spinlock_monitor](
	[runtime] [datetime] NOT NULL,
	[name] [nvarchar](256) NOT NULL,
	[collisions] [bigint] NULL,
	[spins] [bigint] NULL,
	[spins_per_collision] [real] NULL,
	[sleep_time] [bigint] NULL,
	[backoffs] [bigint] NULL
) ON [PRIMARY]
WITH
(
DATA_COMPRESSION = PAGE
)
END
GO

IF NOT EXISTS (SELECT * FROM sys.indexes WHERE object_id = OBJECT_ID(N'[dbo].[spinlock_monitor]') AND name = N'Ci')
CREATE CLUSTERED INDEX [Ci] ON [dbo].[spinlock_monitor]
(
	[runtime] ASC
)WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, SORT_IN_TEMPDB = OFF, DROP_EXISTING = OFF, ONLINE = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON, DATA_COMPRESSION = PAGE) ON [PRIMARY]
GO

IF NOT EXISTS (SELECT * FROM sys.objects WHERE object_id = OBJECT_ID(N'[dbo].[spinlock_monitor_timeseries]') AND type IN (N'U'))
BEGIN
CREATE TABLE [dbo].[spinlock_monitor_timeseries](
	[runtime] [DATETIME] NOT NULL,
	[name] [NVARCHAR](256) NOT NULL,
	[collisions] [BIGINT] NULL,
	[spins] [BIGINT] NULL,
	[spins_per_collision] [REAL] NULL,
	[sleep_time] [BIGINT] NULL,
	[backoffs] [BIGINT] NULL
) ON [PRIMARY]
WITH
(
DATA_COMPRESSION = PAGE
)
END
GO


IF NOT EXISTS (SELECT * FROM sys.indexes WHERE object_id = OBJECT_ID(N'[dbo].[spinlock_monitor_timeseries]') AND name = N'CiSpinlock_monitor_timeseries')
CREATE CLUSTERED INDEX [CiSpinlock_monitor_timeseries] ON [dbo].[spinlock_monitor_timeseries]
(
	[runtime] ASC
)WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, SORT_IN_TEMPDB = OFF, DROP_EXISTING = OFF, ONLINE = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON, DATA_COMPRESSION = PAGE) ON [PRIMARY]
GO

IF NOT EXISTS (SELECT * FROM sys.indexes WHERE object_id = OBJECT_ID(N'[dbo].[spinlock_monitor_timeseries]') AND name = N'Unique_TimeAndName')
CREATE UNIQUE NONCLUSTERED INDEX [Unique_TimeAndName] ON [dbo].[spinlock_monitor_timeseries]
(
	[runtime] ASC,
	[name] ASC
)WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, SORT_IN_TEMPDB = OFF, IGNORE_DUP_KEY = OFF, DROP_EXISTING = OFF, ONLINE = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON, DATA_COMPRESSION = PAGE) ON [PRIMARY]
GO

--collect_spinlock_monitor

IF  EXISTS (SELECT * FROM sys.objects WHERE object_id = OBJECT_ID(N'[dbo].[collect_spinlock_monitor]') AND type in (N'P', N'PC'))
DROP PROCEDURE [dbo].[collect_spinlock_monitor]

GO

CREATE PROCEDURE [dbo].[collect_spinlock_monitor]
AS
BEGIN
SET NOCOUNT ON
SET LANGUAGE english;
INSERT INTO spinlock_monitor
SELECT GETDATE() [runtime], *
FROM
sys.dm_os_spinlock_stats WHERE collisions <>0
ORDER BY spins DESC

DELETE spinlock_monitor WHERE [runtime] < DATEADD(dd, 0, DATEDIFF(dd, 0, GETDATE()-14))

END
GO

--calculation_spinlock_monitor
IF  EXISTS (SELECT * FROM sys.objects WHERE object_id = OBJECT_ID(N'[dbo].[calculation_spinlock_monitor]') AND type in (N'P', N'PC'))
DROP PROCEDURE [dbo].[calculation_spinlock_monitor]
go

CREATE PROCEDURE [dbo].[calculation_spinlock_monitor] @StartTime DATETIME = NULL
	,@EndTime DATETIME = NULL
AS
BEGIN

	SET NOCOUNT ON;
	SET LANGUAGE english;

	DECLARE @RowCount INT;

-- Count the number of rows returned by the query
SELECT @RowCount = COUNT(*)
FROM (
    SELECT DISTINCT TOP 2 runtime
    FROM [dbo].[spinlock_monitor]
    ORDER BY runtime ASC
) AS Subquery;

-- Check the row count and run code accordingly
IF @RowCount = 2
BEGIN

	IF @StartTime IS NULL
		AND @EndTime IS NULL
	BEGIN
		SELECT @StartTime = MAX(runtime)
			,@EndTime = MIN(runtime)
		FROM (
			SELECT DISTINCT TOP 2 runtime
			FROM [dbo].[spinlock_monitor]
			ORDER BY runtime ASC
			) AS LatestDates;
	END;

	-- Declare temporary tables for initial and subsequent snapshots
	DECLARE @InitialSnapshot TABLE (
		[runtime] DATETIME
		,[name] VARCHAR(255)
		,[collisions] BIGINT
		,[spins] BIGINT
		,[spins_per_collision] REAL
		,[sleep_time] BIGINT
		,[backoffs] BIGINT
		);
	DECLARE @SubsequentSnapshot TABLE (
		[runtime] DATETIME
		,[name] VARCHAR(255)
		,[collisions] BIGINT
		,[spins] BIGINT
		,[spins_per_collision] REAL
		,[sleep_time] BIGINT
		,[backoffs] BIGINT
		);
	DECLARE @ExactStartTime DATETIME;
	DECLARE @ExactEndTime DATETIME;

	-- Populate initial and subsequent snapshots
	SELECT TOP 1 @ExactStartTime = [runtime]
	FROM [dbo].[spinlock_monitor]
	WHERE [runtime] >= @StartTime
	ORDER BY [runtime] ASC;

	INSERT INTO @InitialSnapshot
	SELECT *
	FROM [dbo].[spinlock_monitor]
	WHERE [runtime] = @ExactStartTime

	SELECT TOP 1 @ExactEndTime = [runtime]
	FROM [dbo].[spinlock_monitor]
	WHERE [runtime] <= @EndTime
	ORDER BY [runtime] DESC;

	INSERT INTO @SubsequentSnapshot
	SELECT *
	FROM [dbo].[spinlock_monitor]
	WHERE [runtime] = @ExactEndTime

	INSERT INTO spinlock_monitor_timeseries ([runtime], [name], [collisions], [spins], [spins_per_collision], [sleep_time], [backoffs])
	SELECT [ts2].runtime AS runtime
		,[ts2].[name] AS [Spinlock]
		,[ts2].[collisions] AS [DiffCollisions]
		,[ts2].[spins] AS [DiffSpins]
		,[ts2].[spins_per_collision] AS [SpinsPerCollision]
		,[ts2].[sleep_time] AS [DiffSleepTime]
		,[ts2].[backoffs] AS [DiffBackoffs]
	FROM @InitialSnapshot [ts2]
	LEFT OUTER JOIN @SubsequentSnapshot [ts1] ON [ts2].[name] = [ts1].[name]
	WHERE [ts1].[name] IS NULL
	UNION
	SELECT [ts2].runtime AS runtime
		,[ts2].[name] AS [Spinlock]
		,[ts2].[collisions] - [ts1].[collisions] AS [DiffCollisions]
		,[ts2].[spins] - [ts1].[spins] AS [DiffSpins]
		,CASE ([ts2].[spins] - [ts1].[spins])
			WHEN 0
				THEN 0
			ELSE ([ts2].[spins] - [ts1].[spins]) / ([ts2].[collisions] - [ts1].[collisions])
			END AS [SpinsPerCollision]
		,[ts2].[sleep_time] - [ts1].[sleep_time] AS [DiffSleepTime]
		,[ts2].[backoffs] - [ts1].[backoffs] AS [DiffBackoffs]
	FROM @InitialSnapshot [ts2]
	LEFT OUTER JOIN @SubsequentSnapshot [ts1] ON [ts2].[name] = [ts1].[name]
	WHERE [ts1].[name] IS NOT NULL
		AND [ts2].[collisions] - [ts1].[collisions] > 0
	ORDER BY [DiffSpins] DESC;
--delete processed data
	DELETE [spinlock_monitor] WHERE [runtime] = @ExactEndTime
END
ELSE
PRINT 'No data in spinlock_monitor';
END


Once the necessary objects are in place, we can proceed to set up a long-term monitoring for spinlocks. We will utilize SQL Server Agent to automate the data capture process, ensuring consistent and timely collection of spinlock activity for analysis.

Code example for SQL Server agent job:

--exec in user database context where objects created
WHILE 1 = 1
BEGIN
	SET @CurrentTime = GETDATE();
	IF @CurrentTime  >= '06:59:00' AND @CurrentTime < '07:00:00'
	BEGIN
		BREAK;-- Exit the loop
	END
	EXEC [dbo].[collect_spinlock_monitor]
	WAITFOR DELAY '00:00:15'

END


The provided code uses a while loop to continuously capture spinlock data at a set interval of 15 seconds, with a specific condition to exit the loop if the current time is within a defined range. This design allows the data capture process at a predetermined time. Following this interruption, a new cycle of the loop can be scheduled to begin via SQL Server Agent, ensuring continuous monitoring without overlapping executions. This approach is preferred in scenarios of high CPU utilization, as it ensures data capture can continue without the need to establish new connections, which may be difficult or impossible due to system resource constraints. This method allows for consistent monitoring even under significant load, providing valuable insights into system performance and spinlock activity.

Now that we’re capturing spinlock snapshots every 15 seconds, the next step is to analyze the data. Calculating the differences between snapshots outside of peak hours helps us track performance trends over time. This approach allows for less strain on the server during high-traffic periods and provides a clearer view of the data changes when the system is not under heavy load. For the actual calculation, you can use a scheduled job or a manual process, depending on your preference and system requirements.

SET NOCOUNT ON;
SET LANGUAGE english;

EXEC calculation_spinlock_monitor;

Ready to dive into the data you’ve collected? Just run this simple query:

select * from spinlock_monitor_timeseries

This command fetches all the data from the spinlock_monitor_timeseries table. To bring this data to life, why not try a visualization tool? It can make spotting trends and patterns much more intuitive. If you’re looking for recommendations or have any questions, drop a comment below—I might just explore that in a future post!

For those hungry for more details on spinlocks, I recommend reading the comprehensive whitepaper available at Microsoft Learn: Diagnose & Resolve Spinlock Contention in SQL Server. It’s a great resource for deepening your understanding.