Monitoring Wait Events of a single Session or Query in SQL Server

Using sys.dm_os_wait_stat is not useful for deep troubleshooting because this view contains wait events for ALL processes/queries running on your instance since last restart. Using command “DBCC SQLPERF (‘sys.dm_os_wait_stats’, CLEAR)” we can reset this view with no restart but on big and stressed instances with many processes and applications running this isn’t a real good solution.

SQL 2008 introduce a new powerful and flexible way to collect performance data: Extended Events.
With EE we can collect performance data for a wide range of counters with almost any filter we want.

The following procedure collect and manage asyncronously data of a SINGLE session.
Using this solution you can collect wait events infos of your session while testing or wait events infos about a single user or application.

NOTE: Stats are collected in a fs folder, so watch carefully space used growing while collecting.

--- 1) Drop the monitor session if it exists.
IF EXISTS (SELECT * FROM sys.server_event_sessions WHERE name = 'WaitMon')
    DROP EVENT SESSION WaitMon ON SERVER
GO

--- 2) Create the new monitor session.
CREATE EVENT SESSION WaitMon ON SERVER
ADD EVENT sqlos.wait_info
    (WHERE sqlserver.session_id = 79 )              ---INSERT HERE the session id to monitor
ADD TARGET package0.asynchronous_file_target       
    (SET FILENAME = N'S:tempEE_WaitMonStats.xel', ---INSERT HERE the correct path for collected data stats
     METADATAFILE = N'S:tempEE_WaitMonStats.xem')
WITH (max_dispatch_latency = 1 seconds);
GO

--- 3) Start the Monitor session
ALTER EVENT SESSION WaitMon ON SERVER STATE = START;
GO

--- 4) >>>>>>...run your query or wait for data collection from spid session....<<<<<<

--- 5) Stop the Monitor session
ALTER EVENT SESSION WaitMon ON SERVER STATE = STOP;
GO

--- 6) Load collected data in a temp table
CREATE TABLE #RawEventData (
    Rowid  INT IDENTITY PRIMARY KEY,
    event_data XML);
GO

INSERT INTO #RawEventData(event_data)
SELECT
    CAST (event_data AS XML) AS event_data
FROM sys.fn_xe_file_target_read_file
        ('S:tempEE_WaitMonStats*.xel',          ---INSERT HERE the correct path for collected data stats 
         'S:tempEE_WaitMonStats*.xem', null, null);
GO

--- 7) Query data to analize wait events
SELECT
    waits.[Wait Type],
    COUNT (*) AS [Wait Count],
    SUM (waits.[Duration]) AS [Total Wait Time (ms)],
    SUM (waits.[Duration]) - SUM (waits.[Signal Duration]) AS [Total Resource Wait Time (ms)],
    SUM (waits.[Signal Duration]) AS [Total Signal Wait Time (ms)]
FROM
    (SELECT
        event_data.value ('(/event/@timestamp)[1]', 'DATETIME') AS [Time],
        event_data.value ('(/event/data[@name=''wait_type'']/text)[1]', 'VARCHAR(100)') AS [Wait Type],
        event_data.value ('(/event/data[@name=''opcode'']/text)[1]', 'VARCHAR(100)') AS [Op],
        event_data.value ('(/event/data[@name=''duration'']/value)[1]', 'BIGINT') AS [Duration],
        event_data.value ('(/event/data[@name=''signal_duration'']/value)[1]', 'BIGINT') AS [Signal Duration]
     FROM #RawEventData
    ) AS waits
WHERE waits.[op] = 'End'
GROUP BY waits.[Wait Type]
ORDER BY [Total Wait Time (ms)] DESC;
GO 

--- 8) Cleanup
DROP TABLE #RawEventData;
GO 

Queries to see rapidly what your MySql is doing NOW

Those queries are useful to admin MySQL instances using mysql client.

1) Check active processes/connections running

mysql> show processlist;

the previous statement doesn’t show all queries text running. To see the complete statements running use:

mysql> show processlist;
--or--
mysql> show full processlist G;

the running queries statements could bee quite long. Use the “G” modifier to see processes in different output paragraphs

2) Check UPTIME
MySql store main infos under metadata views querable using “SHOW STATUS” command. Those are some of the most quick and useful.

mysql> show status like '%uptime%';
+---------------------------+--------+
| Variable_name             | Value  |
+---------------------------+--------+
| Uptime                    | 880329 |
| Uptime_since_flush_status | 8347   |
+---------------------------+--------+
2 rows in set (0.01 sec)

3) Check Connections

mysql> show status like '%conn%';
+-----------------------------------------------+---------+
| Variable_name                                 | Value   |
+-----------------------------------------------+---------+
| Aborted_connects                              | 0       |
| Connection_errors_accept                      | 0       |
| Connection_errors_internal                    | 0       |
| Connection_errors_max_connections             | 0       |
| Connection_errors_peer_address                | 0       |
| Connection_errors_select                      | 0       |
| Connection_errors_tcpwrap                     | 0       |
| Connections                                   | 4094917 |
| Max_used_connections                          | 222     |
| Performance_schema_session_connect_attrs_lost | 0       |
| Ssl_client_connects                           | 0       |
| Ssl_connect_renegotiates                      | 0       |
| Ssl_finished_connects                         | 0       |
| Threads_connected                             | 120     |
+-----------------------------------------------+---------+
14 rows in set (0.00 sec)

4) Check Caching Status
Caching mechanism are managed using startup parameters. First you have to check if caching is enabled:

mysql> show variables like '%query_cache%';
+------------------------------+----------+
| Variable_name                | Value    |
+------------------------------+----------+
| have_query_cache             | YES      |
| query_cache_limit            | 2097152  |
| query_cache_min_res_unit     | 4096     |
| query_cache_size             | 33554432 |
| query_cache_type             | ON       |
+------------------------------+----------+
5 rows in set (0.00 sec)

If query caching is enabled caching metadata infos are visible simply in this way.

mysql> show status like 'QCache%';
+-------------------------+----------+
| Variable_name           | Value    |
+-------------------------+----------+
| Qcache_free_blocks      | 957      |
| Qcache_free_memory      | 15523704 |
| Qcache_hits             | 1978478  |
| Qcache_inserts          | 132298   |
| Qcache_lowmem_prunes    | 6037     |
| Qcache_not_cached       | 5969     |
| Qcache_queries_in_cache | 3389     |
| Qcache_total_blocks     | 8396     |
+-------------------------+----------+
8 rows in set (0.00 sec)

5) Check Instance Wait Time using PERFORMANCE_SCHEMA
Starting with release 5.5 MySql introduce the new performance_schema. Now performance critical conditions can be analized quering a group of system tables realtime dinamically updated.
First we’ll check if performance_schema is turned on. This option can be turned on using startup parameter file.

mysql> SHOW VARIABLES LIKE 'performance_schema';
+--------------------+-------+
| Variable_name      | Value |
+--------------------+-------+
| performance_schema | ON    |
+--------------------+-------+

If performance_schema is started there are many tables available to check your instance status (use SHOW TABLES under performance schema to see the complete list). Here we’ll start with one of the most simple, used to analize instance wait conditions in realtime:

mysql> SELECT * FROM events_waits_currentG
*************************** 1. row ***************************
            THREAD_ID: 0
             EVENT_ID: 5523
           EVENT_NAME: wait/synch/mutex/mysys/THR_LOCK::mutex
               SOURCE: thr_lock.c:525
          TIMER_START: 201663444489586
            TIMER_END: 201660494576112
           TIMER_WAIT: 86526
                SPINS: NULL
        OBJECT_SCHEMA: NULL
          OBJECT_NAME: NULL
          OBJECT_TYPE: NULL
OBJECT_INSTANCE_BEGIN: 142270668
     NESTING_EVENT_ID: NULL
            OPERATION: lock
      NUMBER_OF_BYTES: NULL
                FLAGS: 0
...

SQL Jobs Monitoring: check last run datetime and duration

A simple query to check rapidly your job’s status and duration.
Useful for fast monitoring on many instances.

No more thing s to say: this is the code based on msdb..sysjobs and msdb..sysjobhistory. It’s easy if necessary filtering a single job id or jobs durations too long.

select job_id,
job_name,
run_datetime,
SUBSTRING(run_duration, 1, 2) + ':' + SUBSTRING(run_duration, 3, 2) + ':' +
SUBSTRING(run_duration, 5, 2) AS run_duration,
convert(int,SUBSTRING(run_duration, 1, 2))*60 +
convert(int,SUBSTRING(run_duration, 3, 2)) as [min],
convert(float,SUBSTRING(run_duration, 5, 2)) as [sec]

from
(
select j.job_id,
job_name,
DATEADD(hh, -7, run_datetime) as run_datetime,
run_duration = RIGHT('000000' + CONVERT(varchar(6), h.run_duration), 6)
from
(
select
j.name as job_name,
run_datetime = max(CONVERT(DATETIME, RTRIM(run_date)) +
(run_time * 9 + run_time % 10000 * 6 + run_time % 100 * 10) / 216e4)
from msdb..sysjobhistory h
inner join msdb..sysjobs j
on h.job_id = j.job_id
group by j.name
) t
inner join msdb..sysjobs j
on t.job_name = j.name
inner join msdb..sysjobhistory h
on j.job_id = h.job_id and
t.run_datetime = CONVERT(DATETIME, RTRIM(h.run_date)) + (h.run_time * 9 + h.run_time % 10000 * 6 + h.run_time % 100 * 10) / 216e4
) dt
--where job_Id=@job_id