Sql-server – sys.dm_exec_requests does not show short lived requests

business-intelligencesql serversql-server-2005

We have a third party BI tool. The BI Tool consists of a server service that builds cubes, and an IIS Service that renders dashboards to users. The cube service and the dashboard service are installed on the same machine, REPORTING1.

The BI tool uses a SQL Server database to store dashboard configuration information, called BIDashboards. We currently have BIDashboards stored on a server called SQL02.

The BI tool gets the source data for its cubes from a server called SQL01 that houses several production databases.

SQL01 services a lot of requests when the BI tool loads data. No surprise there.

SQL02 sees its network connection (1GB ethernet) maxed-out every few minutes. Using a combination of Task Manager and Resource Monitor I can see the vast majority of network traffic during these events is being sent to the BI server. I.E. the BI server is making pretty massive requests to SQL02 where the dashboards database is stored.

In an attempt to see what is happening, I created the following set of statements that I can run manually in a SQL Server Management Studio (SSMS) query window:

DECLARE @StopTime datetime;
SET @StopTime = GetDate() + '00:10:00';
DECLARE @T TABLE 
(
    ID INT NOT NULL PRIMARY KEY IDENTITY(1,1)
    , sql_text nvarchar(max)
    , date_stamp datetime
    , session_id int
    , request_id int
);  

WHILE GetDate() < @StopTime
BEGIN
    INSERT INTO @T (sql_text, date_stamp, session_id, request_id)
    SELECT ST.text, R.start_time, R.session_id, R.request_id
    FROM sys.dm_exec_sessions S
        INNER JOIN sys.dm_exec_requests R ON S.session_id = R.session_id
        LEFT JOIN @t T ON t.session_id = R.session_id and T.request_id = R.request_id
    CROSS APPLY sys.dm_exec_sql_text(sql_handle) ST
    WHERE S.login_name = 'BITool'
        AND T.id is null;
END
SELECT *
FROM @t;

This set of statements gathers session and request information, including the actual text of SQL statements, continuously over a 10 minute period. SQL text is added to a temp table if the session_id and request_id does not already exist in the table. Finally, after 10 minutes, the temp table is displayed in the query window.

ID      sql_text        date_stamp                  session_id  request_id
1   [sql text here]     2012-09-20 11:22:44.683     638         2
2   [sql text here]     2012-09-20 11:22:44.793     502         2
3   [sql text here]     2012-09-20 11:22:44.843     641         2
4   [sql text here]     2012-09-20 11:22:44.840     650         2
5   [sql text here]     2012-09-20 11:22:44.860     568         2
6   [sql text here]     2012-09-20 11:22:44.870     545         2
7   [sql text here]     2012-09-20 11:22:44.910     634         2

The issue here is I suspect the statements returned above are not ALL the statements being executed against the server by the specified login_name in the case above, 'BITool'.

In order to verify my suspicion, I modified the statement to select my login_name, start the procedure above, and switch to a new SSMS query window, where I execute:

SELECT * FROM sys.tables;

I press F5 to run this very simple query several times while the procedure is running in the other window, expecting to see a line in the result for each time I executed my query, since each execution should be a new request. I then switch back to the procedure window and wait for the results. When the 10 minutes elapses (I actually shortened the time to 1 minute), the results are returned, however it shows NONE of the SELECT * FROM sys.tables; statements!

I then tried executing a far longer running query, SELECT * FROM sys.tables T, sys.tables T1, sys.tables T2; which in my case returns around 25,000 records. This statement DOES show up in the results from running the procedure.

I can only conclude that sys.dm_exec_requests is only able to display requests that are actually in flight at the precise moment sys.dm_exec_requests is executed. Just for your information, my server is able to execute sys.dm_exec_requests in the above loop around 17,500 times per second, which I know by removing the AND T.id is null; from the WHERE clause while running the long running query!

Is there a way to see ALL the sql statements executed by a given login_name?

Best Answer

sys.dm_exec_requests is only able to display requests that are actually in flight at the precise moment sys.dm_exec_requests is executed. To capture all all requests that go by you need to hook into events, either XEvents or profiler events. Eg. capture RPC:Completed and SQL:BatchCompleted will capture all the queries executed (among other things).