This blog post is courtesy of a question I received from Chris Adkin (Twitter) by email.  Chris was trying to use Extended Events to track session level wait information, but he had a new twist that I’ve never been asked about before, he wanted to track all of the waits for a specific SQL Agent job anytime it executed.  I knew immediately when I read the email that this was definitely possible, but it required some additional information about SQL Agent. 

Initially it might seem like this would be a good scenario to filter on sqlserver.session_id, but that won’t work because the session_id is not guaranteed to be the same across executions.  I thought about using one job step to ALTER the event session, but that won’t be guaranteed to catch everything for the next step in the job.  Then I thought back to a few years ago and I wanted to track long running Agent jobs on my servers, and then I remembered that you can do this with the program_name or in Extended Events, the sqlserver.client_app_name global predicate field.  To demonstrate this, I created a job on my VM that calls a simple WAITFOR DELAY in the first job step and then I ran the job and queried sys.dm_exec_sessions to get the program name.

SQLAgent – TSQL JobStep (Job 0x6F4E4936767BEA4CBE088245356A5C54 : Step 1)

If we take this and compare it to the job_id in msdb.dbo.sysjobs for the job, we can see that the guid for the job_id has been transposed to create the program_name being used:

36494E6F-7B76-4CEA-BE08-8245356A5C54

So with this information, we now define a predicate that will allow our Event Session to collect events specifically for our job execution as follows:

DECLARE @JobName NVARCHAR(128) = 'Test';

DECLARE @Predicate NVARCHAR(MAX)='';
DECLARE @sqlcmd NVARCHAR(MAX)='';

SET @sqlcmd ='IF EXISTS(SELECT * FROM sys.server_event_sessions WHERE name=''TrackResourceWaits'')
    DROP EVENT SESSION [TrackResourceWaits] ON SERVER;
CREATE EVENT SESSION [TrackResourceWaits] ON SERVER 
ADD EVENT  sqlos.wait_info
(   WHERE
        (opcode = 1 --End Events Only
            AND duration > 0 -- had to accumulate 100ms of time
            AND ({0})
        ))
ADD TARGET package0.asynchronous_bucketizer
(     SET filtering_event_name=''sqlos.wait_info'',
        source_type=0, -- specifies bucketing on column 
        source=''wait_type'' -- Bucket by wait_type
),
ADD TARGET package0.ring_buffer(SET max_memory=4096)';

SELECT @Predicate = @Predicate + 
    'sqlserver.client_app_name = ''' +
    'SQLAgent - TSQL JobStep (Job 0x'+
    SUBSTRING(job_id,7,2) +
    SUBSTRING(job_id,5,2) +
    SUBSTRING(job_id,3,2) +
    SUBSTRING(job_id,1,2) +
    SUBSTRING(job_id,12,2) +
    SUBSTRING(job_id,10,2) +
    SUBSTRING(job_id,17,2) +
    SUBSTRING(job_id,15,2) +
    SUBSTRING(job_id,20,4) +
    SUBSTRING(job_id,25,12) + 
    ' : Step ' + 
    CAST(step_id AS VARCHAR(3)) + 
    ')'' OR '
FROM( SELECT CAST(j.job_id AS VARCHAR(50)) AS job_id,
            js.step_id
        FROM msdb.dbo.sysjobs AS j
        INNER JOIN msdb.dbo.sysjobsteps AS js
            ON j.job_id = js.job_id
        WHERE j.name = @JobName) AS tab;

-- Append the predicate into the SQL command
SET @sqlcmd = REPLACE(@sqlcmd, '{0}', LEFT(@Predicate, LEN(@Predicate)-3));

-- Create the Event Session
EXEC(@sqlcmd);

Now as I pointed out in my original post about collecting session level wait stats, this doesn’t necessarily provide actionable data since it doesn’t tell us about the other activity on the server that may be causing specific waits to occur.  For example, if you run this and see that there are high I/O waits, but concurrently at the same time there is a DBCC CHECKDB running on the server that is saturating the I/O subsystem, all we know about for the data collected is that there were high I/O waits, it doesn’t tell us why they might exist.  For some wait types this might be very actionable, but I would use caution tracking session or task specific waits because the same waits will not occur on different hardware, or under different conditions on the same exact hardware.