SQL Server: Why is it necessary to capture and store information on sessions i.e. spid(s) running on a SQL instance for troubleshooting purpose.

Many a times a DBA wishes for the below information, during performance troubleshooting,

  1. Can I get to know what was being executed 30 minutes back.
  2. Can I get to know which were the most long running sessions, spid(s), during the last 30 minutes back.
  3. Can I get know on who was blocking whom during the last 30 minutes back.
  4. If blocking was present, did the blocking escalate to a chain reaction with multiple spid(s) being blocked out.
  5. If there was no blocking, was my SQL instance being pressurized due to particular wait types.
  6. Were any particular spid(s), running 30 minutes back, resource intensive with high reads and writes
  7. TEMPDB size has suddenly grown huge during the last 30 minutes. Though stabilized now, want to know which spid, from which application was the cause.
  8. etc.

It is not necessary that on a LIVE production SQL instance, a performance issue persists for a duration sufficient enough for the DBA to log on, run profiler or perfmon traces to trace out the root cause.

But on a LIVE production SQL instance, if a performance issue was logged as a complaint and the issue seems to rear up at anytime but for short bursts of duration, then it becomes imperative for the DBA to collect all facts possible by looking back in time. The facts collected helps the DBA along with other log entries and traces to arrive at the root cause of an issue.

Many a times DBA(s) would get request from users stating the DB application is running poorly. Sometimes the complaint starts pouring in and the DBA is left stunned, because nothing has changed on the server. A very stable system. By the time he logs in and starts checking, things get back to normal. Getting back to the users, even they confirm yes, things are ok now, but half an hour before the performance was really poor.

This is where session capture plays an important role in understanding what was being executed on the SQL instance 30 minutes back.

The below code running continuously [every 3 second gap] captures and stores session information on the SQL Server instance. Some of the most important information(s) that can be queried by the DBA are on

  1. “session start time”, “session end time”, “session text”,
  2. “login name”, “application name”,
  3. “wait type”, “wait duration”,
  4. “total reads”, “total writes”, “tempdb usage”,
  5. “blocking spid”, “blocking text”, etc.

Note: on a personal front, I recommend that the session information be stored for not more than 48 hours. Meaning along with the code to capture and store session, you also need a purge code, to delete information collected older than 48 hours. This is to manage the DB size, which hosts the table for storing the session capture data.

CREATE PROC [dbo].[CaptureSessionOnSQL] 
	 
AS
 
SET NOCOUNT ON
	 
BEGIN
    IF NOT EXISTS (SELECT 1 FROM sysobjects WHERE [name]='CaptureSession' AND type='u')
    CREATE TABLE CaptureSession
    (
    DatabaseName nvarchar(100), 
    HostName nvarchar(50),
    SessionID int,
    SessionStatus nvarchar(25),
    LoginName nvarchar(50),
    ApplicationName nvarchar(150),
    SessionText xml,
    TransIsolationLevel smallint,
    WaitType nvarchar(100),
    WaitTime int,
    ReadsTotal bigint,
    WritesTotal bigint,
    CPUTotal int,
    TempDBUsage bigint,
    RequestStartTime datetime,
    RequestEndTime datetime,
    BlockingSessionID int,
    BlockingLoginName nvarchar(50),
    BlockingApplicationName nvarchar(150),
    BlockingSessionText xml,
    CaptureDate datetime
    )
 
 
    WHILE 1=1
    BEGIN
     
    BEGIN TRY
         
        INSERT CaptureSession
        SELECT
        DatabaseName,
        HostName,
        SessionID,
        SessionStatus,
        LoginName,
        ApplicationName,
        (
            SELECT
            text AS [text()]
            FROM sys.dm_exec_sql_text(t1.sql_handle)
            FOR XML PATH(''), TYPE
        ) AS SessionText,
        TransIsolationLevel,
        WaitType,
        WaitTime,
        ReadsTotal,
        WritesTotal,
        CPUTotal,
        TempDBUsage,
        RequestStartTime,
        RequestEndTime,
        BlockingSessionID,
        BlockingLoginName,
        BlockingApplicationName,
        (
           SELECT
            text AS [text()]
            FROM sys.dm_exec_sql_text(t1.most_recent_sql_handle)
            FOR XML PATH(''), TYPE
        ) AS BlockingSessionText,
        GETDATE()
        FROM
        (
                SELECT
                DB_NAME(req1.database_id) as 'DatabaseName',
                ses1.host_name as 'HostName',
                req1.session_id as 'SessionID',
                req1.status as 'SessionStatus', 
                ses1.login_name as 'LoginName',
                ses1.program_name as 'ApplicationName',
                req1.sql_handle,
                req1.transaction_isolation_level as 'TransIsolationLevel',
                req1.wait_type as 'WaitType' ,
                req1.wait_time as 'WaitTime',
                SUM(req1.reads) AS 'ReadsTotal',
                SUM(req1.writes) AS 'WritesTotal',
                SUM(req1.cpu_time) AS 'CPUTotal',
                SUM(spa.internal_objects_alloc_page_count + spa.user_objects_alloc_page_count) AS 'TempDBUsage',
                ses1.last_request_start_time as 'RequestStartTime',
                ses1.last_request_end_time as 'RequestEndTime',
                req1.blocking_session_id as 'BlockingSessionID',
                con1.most_recent_sql_handle,
                COALESCE(ses2.login_name, 'NONE') as 'BlockingLoginName',
                COALESCE(ses2.program_name, 'NONE') as 'BlockingApplicationName'
                FROM sys.dm_exec_requests req1
                LEFT OUTER JOIN sys.dm_exec_connections con1
                ON con1.session_id = req1.blocking_session_id
                INNER JOIN sys.dm_exec_sessions ses1
                ON ses1.session_id = req1.session_id
                LEFT OUTER JOIN sys.dm_exec_sessions ses2
                ON con1.session_id = ses2.session_id
                INNER JOIN sys.dm_db_task_space_usage spa 
                ON ses1.session_id = spa.session_id AND req1.request_id = spa.request_id
                WHERE
                req1.session_id > 50
                GROUP BY
                req1.database_id, ses1.host_name,
                req1.session_id, 
                req1.status, 
                ses1.login_name,
                ses1.program_name,
                req1.sql_handle,
                req1.transaction_isolation_level, req1.wait_type, req1.wait_time,  
                ses1.last_request_start_time, ses1.last_request_end_time, req1.blocking_session_id, 
                con1.most_recent_sql_handle,
                ses2.login_name, ses2.program_name
        ) t1
         
        WAITFOR DELAY '00:00:3'
    END TRY
    BEGIN CATCH
        WAITFOR DELAY '00:00:3'
    END CATCH
    END
END

 

Regards

Vasudev Menon

Like us on FaceBook Follow us on Twitter

Join the fastest growing SQL Server group on FaceBook

Data Platform Virtual Summit 2020

Subscribe to SQLServerGeeks YouTube channel. If you want more learning content in your inbox, subscribe to SQLServerGeeks Bulletin.

SQLServerGeeks YouTube | SQLServerGeeks Bulletin | SQLServerGeeks Twitter

Leave a Reply

Your email address will not be published. Required fields are marked *