In a previous post, I presented a solution for monitoring and logging long running queries in SQL Server. In this post I’ll show an extended version of that solution that also sends an email when a request has been blocked for more than 20 seconds.
Blocked Queries
Be sure to read the the original post about long running queries before implementing the solution outlined here.
To a DBA, notifications on blocked queries in a database can be a very useful tool in a proactive work trying to enhance the user experience. In the blog post mentioned above, I showed how to capture and store T-SQL queries that run for longer than 20 seconds.
That solution can be extended to also send an email whenever a long running query is caused by a lock. Most locks are resolved automatically after a while, but in some cases DBA intervention can be necessary. It is also very valuable troubleshooting information for the DBA. This extended solution will send the email when the total blocked_wait_time exceeds 20 seconds.
Note that the goal with this solution, and the one for long running queries, is to catch blocks that affect the user experience. Therefore, there is a rather long list of wait types that are not monitored, meaning not all blocks will be reported. Naturally, the list of excluded wait types can be changed as you see fit.
To use the solution you need to change the @profile_name and @recipients parameters for the sp_send_dbmail procedure:
EXEC msdb.dbo.sp_send_dbmail @profile_name = <YourEmailProfile>, @recipients = <Recipients>, @subject = 'Blocked queries detected!', @body = @MAIL_BODY, @body_format='HTML'
Follow the instructions in the long running queries post, but use this T-SQL instead (remember to change parameters on sp_send_dbmail):
SET QUOTED_IDENTIFIER ON
SET NOCOUNT ON
DECLARE @StartMonitoringAfterSeconds INT = 20, @MAIL_BODY NVARCHAR(4000)
IF (SELECT OBJECT_ID('#TLind_IGNORED_WAIT_TYPES')) IS NULL BEGIN
CREATE TABLE #TLind_IGNORED_WAIT_TYPES
(
WaitType NVARCHAR(60) NOT NULL
)
--http://www.sqlskills.com/blogs/paul/wait-statistics-or-please-tell-me-where-it-hurts/
INSERT #TLind_IGNORED_WAIT_TYPES (WaitType)
VALUES
('BROKER_EVENTHANDLER'),
('BROKER_RECEIVE_WAITFOR'),
('BROKER_TASK_STOP'),
('BROKER_TO_FLUSH'),
('BROKER_TRANSMITTER'),
('CHECKPOINT_QUEUE'),
('CHKPT'),
('CLR_AUTO_EVENT'),
('CLR_MANUAL_EVENT'),
('CLR_SEMAPHORE'),
('DBMIRROR_DBM_EVENT'),
('DBMIRROR_EVENTS_QUEUE'),
('DBMIRROR_WORKER_QUEUE'),
('DBMIRRORING_CMD'),
('DIRTY_PAGE_POLL'),
('DISPATCHER_QUEUE_SEMAPHORE'),
('EXECSYNC'),
('FSAGENT'),
('FT_IFTS_SCHEDULER_IDLE_WAIT'),
('FT_IFTSHC_MUTEX'),
('HADR_CLUSAPI_CALL'),
('HADR_FILESTREAM_IOMGR_IOCOMPLETION'),
('HADR_LOGCAPTURE_WAIT'),
('HADR_NOTIFICATION_DEQUEUE'),
('HADR_TIMER_TASK'),
('HADR_WORK_QUEUE'),
('KSOURCE_WAKEUP'),
('LAZYWRITER_SLEEP'),
('LOGMGR_QUEUE'),
('ONDEMAND_TASK_QUEUE'),
('PWAIT_ALL_COMPONENTS_INITIALIZED'),
('QDS_PERSIST_TASK_MAIN_LOOP_SLEEP'),
('QDS_CLEANUP_STALE_QUERIES_TASK_MAIN_LOOP_SLEEP'),
('REQUEST_FOR_DEADLOCK_SEARCH'),
('RESOURCE_QUEUE'),
('SERVER_IDLE_CHECK'),
('SLEEP_BPOOL_FLUSH'),
('SLEEP_DBSTARTUP'),
('SLEEP_DCOMSTARTUP'),
('SLEEP_MASTERDBREADY'),
('SLEEP_MASTERMDREADY'),
('SLEEP_MASTERUPGRADED'),
('SLEEP_MSDBSTARTUP'),
('SLEEP_SYSTEMTASK'),
('SLEEP_TASK'),
('SLEEP_TEMPDBSTARTUP'),
('SNI_HTTP_ACCEPT'),
('SP_SERVER_DIAGNOSTICS_SLEEP'),
('SQLTRACE_BUFFER_FLUSH'),
('SQLTRACE_INCREMENTAL_FLUSH_SLEEP'),
('SQLTRACE_WAIT_ENTRIES'),
('WAIT_FOR_RESULTS'),
('WAITFOR'),
('WAITFOR_TASKSHUTDOWN'),
('WAIT_XTP_HOST_WAIT'),
('WAIT_XTP_OFFLINE_CKPT_NEW_LOG'),
('WAIT_XTP_CKPT_CLOSE'),
('XE_DISPATCHER_JOIN'),
('XE_DISPATCHER_WAIT'),
('XE_TIMER_EVENT')
END
SELECT
R.session_id
,R.request_id
,R.start_time
,CAST('1900-01-01' AS DATETIME2) AS completed_time
,S.[host_name]
,S.[program_name]
,S.login_name
,R.[status]
,R.command
,R.database_id
,R.wait_type
,R.wait_time / 1000 AS blocked_wait_time_sec
,R.last_wait_type
,R.wait_resource
,R.total_elapsed_time / 1000 AS total_elapsed_time_sec
,ST.text
,R.blocking_session_id
,S_B.[host_name] AS blocking_host_name
,S_B.[program_name] AS blocking_program_name
,S_B.login_name AS blocking_login_name
,ST_B.text AS blocking_text
INTO
#TLind_LONG_RUNNING
FROM
sys.dm_exec_requests R
CROSS APPLY
sys.dm_exec_sql_text(R.sql_handle) AS ST
JOIN
sys.dm_exec_sessions S
ON
R.session_id = S.session_id
LEFT OUTER JOIN
sys.dm_exec_connections C
ON
R.blocking_session_id = C.session_id
OUTER APPLY
sys.dm_exec_sql_text(C.most_recent_sql_handle) AS ST_B
LEFT OUTER JOIN
sys.dm_exec_sessions S_B
ON
R.blocking_session_id = S_B.session_id
WHERE
R.[status] NOT IN ('background', 'sleeping')
AND
R.wait_type NOT IN (SELECT WaitType FROM #TLind_IGNORED_WAIT_TYPES)
AND
R.session_id > 50
AND
R.session_id <> @@spid
AND
(R.total_elapsed_time / 1000) > (@StartMonitoringAfterSeconds)
IF EXISTS (SELECT * FROM #TLind_LONG_RUNNING) BEGIN
CREATE UNIQUE CLUSTERED INDEX TLind_LONG_RUNNING_CLU ON #TLind_LONG_RUNNING(session_id, request_id, start_time) WITH IGNORE_DUP_KEY
CREATE TABLE #TLind_BLOCKED_QUERIES
(
session_id SMALLINT NOT NULL
,request_id INT NOT NULL
,start_time DATETIME NOT NULL
,mail_sent BIT DEFAULT(0) NOT NULL
)
CREATE UNIQUE CLUSTERED INDEX TLind_BLOCKED_QUERIES_CLU ON #TLind_BLOCKED_QUERIES(session_id, request_id, start_time) WITH IGNORE_DUP_KEY
WHILE EXISTS(SELECT * FROM #TLind_LONG_RUNNING WHERE completed_time = '1900-01-01') BEGIN
/*********************************
BLOCKED QUERY ACTION
*********************************/
INSERT #TLind_BLOCKED_QUERIES (session_id,request_id,start_time)
SELECT session_id, request_id, start_time
FROM #TLind_LONG_RUNNING
WHERE blocked_wait_time_sec >= 20
AND blocking_session_id > 50
AND blocking_session_id <> session_id
IF @@ROWCOUNT > 0 BEGIN
SET @MAIL_BODY = '<table border="1" align="center" cellpadding="2" cellspacing="0" style="color:black;font-family:consolas;text-align:center;font-size:8.0pt;">' +
'<tr>
<th>Blocked SPID</th>
<th>Blocked Login</th>
<th>Blocked Statement</th>
<th>Blocked Statement Time</th>
<th>blocked_wait_time_sec</th>
<th>Blocking SPID</th>
<th>Blocking Login</th>
<th>Blocking Statement</th>'
SELECT
@MAIL_BODY = @MAIL_BODY +
'<tr>' +
'<td>' + CAST(BQ.session_id AS NVARCHAR(5)) + '</td>' +
'<td>' + LR.login_name + '</td>' +
'<td>' + CAST(ISNULL(LR.text, '...') AS NVARCHAR(100)) + '</td>' +
'<td>' + CONVERT(NVARCHAR(23), LR.start_time, 121) + '</td>' +
'<td>' + CAST(LR.blocked_wait_time_sec AS NVARCHAR(10)) + '</td>' +
'<td>' + CAST(ISNULL(LR.blocking_session_id, 0) AS NVARCHAR(5)) + '</td>' +
'<td>' + ISNULL(LR.blocking_login_name, '...') + '</td>' +
'<td>' + CAST(ISNULL(LR.blocking_text, '...') AS NVARCHAR(100)) + '</td>'
FROM
#TLind_BLOCKED_QUERIES BQ
JOIN
#TLind_LONG_RUNNING LR
ON
BQ.session_id = LR.session_id
AND
BQ.request_id = LR.request_id
AND
BQ.start_time = LR.start_time
WHERE
BQ.mail_sent = 0
ORDER BY
LR.start_time DESC
UPDATE #TLind_BLOCKED_QUERIES SET mail_sent = 0
EXEC msdb.dbo.sp_send_dbmail
@profile_name = <YourEmailProfile>,
@recipients = <Recipients>,
@subject = 'Blocked queries detected!',
@body = @MAIL_BODY,
@body_format='HTML'
END
WAITFOR DELAY '00:00:01'
UPDATE
#TLind_LONG_RUNNING
SET
completed_time = CASE WHEN R.session_id IS NULL AND LR.completed_time = '1900-01-01' THEN GETDATE() ELSE LR.completed_time END
,[host_name] = COALESCE(S.[host_name], LR.[host_name])
,[program_name] = COALESCE(S.[program_name], LR.[program_name])
,login_name = COALESCE(S.[login_name], LR.[login_name])
,[status] = COALESCE(R.[status], LR.[status])
,command = COALESCE(R.command, LR.command)
,database_id = COALESCE(R.database_id, LR.database_id)
,wait_type = COALESCE(R.wait_type, LR.wait_type)
,blocked_wait_time_sec = COALESCE(R.wait_time / 1000, LR.blocked_wait_time_sec)
,last_wait_type = COALESCE(R.last_wait_type, LR.last_wait_type)
,wait_resource = COALESCE(R.wait_resource, LR.wait_resource)
,total_elapsed_time_sec = COALESCE(R.total_elapsed_time / 1000, LR.total_elapsed_time_sec)
,text = COALESCE(ST.text, LR.text)
,blocking_session_id = COALESCE(NULLIF(R.blocking_session_id, 0), LR.blocking_session_id)
,blocking_host_name = COALESCE(S_B.[host_name], LR.blocking_host_name)
,blocking_program_name = COALESCE(S_B.[program_name], LR.blocking_program_name)
,blocking_login_name = COALESCE(S_B.login_name, LR.blocking_login_name)
,blocking_text = COALESCE(ST_B.text, LR.blocking_text)
FROM
#TLind_LONG_RUNNING LR
LEFT OUTER JOIN
sys.dm_exec_requests R
ON
LR.session_id = R.session_id
AND
LR.request_id = R.request_id
AND
LR.start_time = R.start_time
OUTER APPLY
sys.dm_exec_sql_text(R.sql_handle) AS ST
LEFT OUTER JOIN
sys.dm_exec_sessions S
ON
R.session_id = S.session_id
LEFT OUTER JOIN
sys.dm_exec_connections C
ON
R.blocking_session_id = C.session_id
OUTER APPLY
sys.dm_exec_sql_text(C.most_recent_sql_handle) AS ST_B
LEFT OUTER JOIN
sys.dm_exec_sessions S_B
ON
R.blocking_session_id = S_B.session_id
INSERT
#TLind_LONG_RUNNING
SELECT
R.session_id
,R.request_id
,R.start_time
,CAST('1900-01-01' AS DATETIME2) AS completed_time
,S.[host_name]
,S.[program_name]
,S.login_name
,R.[status]
,R.command
,R.database_id
,R.wait_type
,R.wait_time / 1000 AS blocked_wait_time_sec
,R.last_wait_type
,R.wait_resource
,R.total_elapsed_time / 1000 AS total_elapsed_time_sec
,ST.text
,R.blocking_session_id
,S_B.[host_name] AS blocking_host_name
,S_B.[program_name] AS blocking_program_name
,S_B.login_name AS blocking_login_name
,ST_B.text AS blocking_text
FROM
sys.dm_exec_requests R
CROSS APPLY
sys.dm_exec_sql_text(R.sql_handle) AS ST
JOIN
sys.dm_exec_sessions S
ON
R.session_id = S.session_id
LEFT OUTER JOIN
sys.dm_exec_connections C
ON
R.blocking_session_id = C.session_id
OUTER APPLY
sys.dm_exec_sql_text(C.most_recent_sql_handle) AS ST_B
LEFT OUTER JOIN
sys.dm_exec_sessions S_B
ON
R.blocking_session_id = S_B.session_id
WHERE
R.[status] NOT IN ('background', 'sleeping')
AND
R.wait_type NOT IN (SELECT WaitType FROM #TLind_IGNORED_WAIT_TYPES)
AND
R.session_id > 50
AND
R.session_id <> @@spid
AND
(R.total_elapsed_time / 1000) > (@StartMonitoringAfterSeconds)
END
IF (SELECT OBJECT_ID('TLind_LONG_RUNNING')) IS NULL BEGIN
CREATE TABLE TLind_LONG_RUNNING
(
session_id SMALLINT NOT NULL
,request_id INT NOT NULL
,start_time DATETIME NOT NULL
,completed_time DATETIME2 NOT NULL
,[host_name] NVARCHAR(128) NULL
,[program_name] NVARCHAR(128) NULL
,login_name NVARCHAR(128) NOT NULL
,[status] NVARCHAR(30) NOT NULL
,command NVARCHAR(32) NOT NULL
,database_id SMALLINT NOT NULL
,wait_type NVARCHAR(60) NULL
,blocked_wait_time_sec INT NOT NULL
,last_wait_type NVARCHAR(60) NOT NULL
,wait_resource NVARCHAR(256) NOT NULL
,total_elapsed_time_sec INT NOT NULL
,text NVARCHAR(MAX) NULL
,blocking_session_id SMALLINT NULL
,blocking_host_name NVARCHAR(128) NULL
,blocking_program_name NVARCHAR(128) NULL
,blocking_login_name NVARCHAR(128) NULL
,blocking_text NVARCHAR(MAX) NULL
)
END
INSERT TLind_LONG_RUNNING
SELECT * FROM #TLind_LONG_RUNNING
END
DROP TABLE #TLind_LONG_RUNNING
IF (SELECT OBJECT_ID('#TLind_BLOCKED_QUERIES')) IS NOT NULL BEGIN
DROP TABLE #TLind_BLOCKED_QUERIES
END
If you want to do something else instead of sending an email when a blocked query is encountered, just change the highlighted code above to something else.
As always, make sure to test the solution before running it in a production environment.
