Let SQL Server identify the cause of queries that never complete or perform poorly.
Issue
Intermittent failure is the bane of application developers, especially when the cause is never logged and the tools tell you everything is ok. An application I support for a business started having an intermittent failure in the database. The business would be humming along with users entering data and running reports then unpredictably, the database would hang due to table locks and all data entry and report generation would cease. The DBA team and I would peer into SQL Server Management Studio Activity Monitor only to find a stored procedure running that was blocking everything else. Digging further into Activity Monitor showed the stored procedure in question was just doing a select. However, when the stored procedure was killed, everything would return to normal. The stored procedure in question was complex and we did make many changes to eliminate potential issues but the failures still occurred.
Solution
Unable to identify the root cause, I decided to investigate how SSMS Activity Monitor communicated with the database to see if there were additional system tools I could query myself. Using SQL Server Profiler I did capture the query Activity Monitor sent and was able to adapt it into a job that runs periodically to log the queries currently running. This job identified the culprit as a function called by the stored procedure and once modified to avoid parameter sniffing and other execution plan mishaps the failures were eliminated.
The job runs every few minutes, to see which queries the database is running. If it sees the same query running when it runs the next time it logs the query and sends an email.
Follow these steps to configure and set up the query to identify the troubled SQL queries on your database.
1) Create the table maint.SQLServerActivityMonitor for the query to store the results in.
-- Create table to store results
CREATE TABLE [maint].[SQLServerActivityMonitor](
[ID] [int] IDENTITY(0,1) PRIMARY KEY,
[EntryDate] [datetime] NOT NULL,
[Session ID] [smallint] NULL,
[User Process] [bit] NULL,
[Login] [nvarchar](128) NULL,
[Database] [nvarchar](128) NULL,
[Task State] [nvarchar](60) NULL,
[Command] [nvarchar](32) NULL,
[Statement Start Offset] [int] NULL,
[Statement End Offset] [int] NULL,
[Exec Sql Text] [nvarchar](max) NULL,
[Application] [nvarchar](128) NULL,
[Total Elapsed Time (sec)] [int] NULL,
[Wait Time (ms)] [bigint] NULL,
[Wait Type] [nvarchar](60) NULL,
[Wait Resource] [nvarchar](1024) NULL,
[Blocked By] [varchar](10) NULL,
[Head Blocker] [varchar](1) NULL,
[Total CPU (ms)] [int] NULL,
[Total Physical I/O (MB)] [bigint] NULL,
[Memory Use (KB)] [int] NULL,
[Open Transactions] [int] NULL,
[Login Time] [datetime] NULL,
[Last Request Start Time] [datetime] NULL,
[Last Request End Time] [datetime] NULL,
[Host Name] [nvarchar](128) NULL,
[Net Address] [varchar](48) NULL,
[Execution Context ID] [int] NULL,
[Request ID] [int] NULL,
[Workload Group] [sysname] NOT NULL
)
GO
CREATE INDEX SQLServerActivityMonitor_EntryDate ON maint.SQLServerActivityMonitor (EntryDate)
2) Put the code below into a SQL job and update the :setvar variables. Schedule the job to run every 4 minutes or the value you set MaxQueryMinutes to.
-- Specify these parameters based on the name of your database and email address.
-- ResultsDatabase is the database where the table maint.SQLServerActivityMonitor is located.
-- DatabasesToWatch is a list of databases on the SQL Server to observe for long running queries.
-- MaxQueryMinutes is the number of minutes a query can run before the query is logged and an email is sent.
:setvar ResultsDatabase "Database1"
:setvar DatabasesToWatch "('Database1', 'Database2')"
:setvar MaxQueryMinutes "4"
:setvar EmailRecipients "'MyEmailAddress@Somewhere.com'"
DECLARE @dateTimeNow datetime = SYSDATETIME()
-- Store the results in a table.
INSERT INTO $(ResultsDatabase).maint.SQLServerActivityMonitor
(
[EntryDate],
[Session ID],
[User Process],
[Login],
[Database],
[Task State],
[Command],
[Statement Start Offset],
[Statement End Offset],
[Exec Sql Text],
[Application],
[Total Elapsed Time (sec)],
[Wait Time (ms)],
[Wait Type],
[Wait Resource],
[Blocked By],
[Head Blocker],
[Total CPU (ms)],
[Total Physical I/O (MB)],
[Memory Use (KB)],
[Open Transactions],
[Login Time],
[Last Request Start Time],
[Last Request End Time],
[Host Name],
[Net Address],
[Execution Context ID],
[Request ID],
[Workload Group]
)
-- Query is from SQL Server Activity Monitor.
SELECT
[EntryDate] = @dateTimeNow,
[Session ID] = s.session_id,
[User Process] = CONVERT(CHAR(1), s.is_user_process),
[Login] = s.login_name,
[Database] = ISNULL(db_name(r.database_id), N''),
[Task State] = ISNULL(t.task_state, N''),
[Command] = ISNULL(r.command, N''),
[Statement Start Offset] = r.statement_start_offset,
[Statement End Offset] = r.statement_end_offset,
[Exec Sql Text] = details.text,
[Application] = ISNULL(s.program_name, N''),
[Total Elapsed Time (sec)] = r.total_elapsed_time / 1000.0,
[Wait Time (ms)] = ISNULL(w.wait_duration_ms, 0),
[Wait Type] = ISNULL(w.wait_type, N''),
[Wait Resource] = ISNULL(w.resource_description, N''),
[Blocked By] = ISNULL(CONVERT (varchar, w.blocking_session_id), ''),
[Head Blocker] =
CASE
-- session has an active request, is blocked, but is blocking others
WHEN r2.session_id IS NOT NULL AND r.blocking_session_id = 0 THEN '1'
-- session is idle but has an open tran and is blocking others
WHEN r.session_id IS NULL THEN '1'
ELSE ''
END,
[Total CPU (ms)] = s.cpu_time,
[Total Physical I/O (MB)] = (s.reads + s.writes) * 8 / 1024,
[Memory Use (KB)] = s.memory_usage * 8192 / 1024,
[Open Transactions] = ISNULL(r.open_transaction_count,0),
[Login Time] = s.login_time,
[Last Request Start Time] = s.last_request_start_time,
[Last Request End Time] = s.last_request_end_time,
[Host Name] = ISNULL(s.host_name, N''),
[Net Address] = ISNULL(c.client_net_address, N''),
[Execution Context ID] = ISNULL(t.exec_context_id, 0),
[Request ID] = ISNULL(r.request_id, 0),
[Workload Group] = ISNULL(g.name, N'')
FROM sys.dm_exec_sessions s
LEFT OUTER JOIN sys.dm_exec_connections c ON (s.session_id = c.session_id)
LEFT OUTER JOIN sys.dm_exec_requests r ON (s.session_id = r.session_id)
LEFT OUTER JOIN sys.dm_os_tasks t ON (r.session_id = t.session_id AND r.request_id = t.request_id)
LEFT OUTER JOIN
(
-- In some cases (e.g. parallel queries, also waiting for a worker), one thread can be flagged as
-- waiting for several different threads. This will cause that thread to show up in multiple rows
-- in our grid, which we don't want. Use ROW_NUMBER to select the longest wait for each thread,
-- and use it as representative of the other wait relationships this thread is involved in.
SELECT *, ROW_NUMBER() OVER (PARTITION BY waiting_task_address ORDER BY wait_duration_ms DESC) AS row_num
FROM sys.dm_os_waiting_tasks
) w ON (t.task_address = w.waiting_task_address) AND w.row_num = 1
LEFT OUTER JOIN sys.dm_exec_requests r2 ON (r.session_id = r2.blocking_session_id)
LEFT OUTER JOIN sys.dm_resource_governor_workload_groups g ON (g.group_id = s.group_id)
CROSS APPLY sys.dm_exec_sql_text (r.plan_handle) details
WHERE s.is_user_process = 1 -- 0 if the session is a system session. Otherwise, it is 1. Is not nullable.
AND ISNULL(db_name(r.database_id), N'') in $(DatabasesToWatch)
AND s.last_request_start_time > s.last_request_end_time -- Filter out completed queries.
AND (r.total_elapsed_time / 1000.0 / 60.0) > $(MaxQueryMinutes) -- Filter out fast completing queries.
ORDER BY s.session_id;
DECLARE @count int = 0
SELECT @count = COUNT(1) FROM maint.SQLServerActivityMonitor WHERE [EntryDate] = @dateTimeNow
-- Format the data so it is readable in an email.
IF (0 < @count)
BEGIN
DECLARE @subjectText VARCHAR(200), @queryString VARCHAR(1000)
SELECT @subjectText = 'There are ' + CAST(@count as VARCHAR(4)) + ' queries running longer than $(MaxQueryMinutes) minutes.'
SELECT @queryString = 'SELECT
[Database] = LEFT(CONVERT(VARCHAR(15),[Database])+REPLICATE(''-'',15),15)
,[Task State] = LEFT(CONVERT(VARCHAR(10),[Task State])+REPLICATE(''-'',10),10)
,[Login] = LEFT(CONVERT(VARCHAR(25),[Login])+REPLICATE(''-'',25),25)
,[Run Time (sec)] = RIGHT(REPLICATE(''-'',15) + CONVERT(VARCHAR(15),[Total Elapsed Time (sec)]),15)
,[Application] = LEFT(CONVERT(VARCHAR(30),[Application])+REPLICATE(''-'',30),30)
,[Command] = LEFT(CONVERT(VARCHAR(40),[Command])+REPLICATE(''-'',40),40)
FROM $(ResultsDatabase).maint.SQLServerActivityMonitor WHERE [EntryDate] = ''' + CONVERT(VARCHAR(23), @dateTimeNow, 121) + ''''
EXEC msdb.dbo.sp_send_dbmail
@profile_name = 'Support',
@recipients = $(EmailRecipients),
@subject = @subjectText,
@body = 'Run this query for more details.
SELECT *
FROM $(ResultsDatabase).maint.SQLServerActivityMonitor
ORDER BY EntryDate DESC',
@query = @queryString
END
Conclusion
Autonomous performance monitoring provides early warning of potential issues allowing for pre-emptive remediation and peace of mind.
