Thursday, 1 June 2017

sys.dm_exec_requests: total_elapsed_time column might return inconsistent data

Developing useful scripts for administration purposes, I have found a bug with respect to data recollected by 'sys.dm_exec_requests' dynamic management view on SQL Server 2008 R2 SP2 while I was analysing the total elapsed time for a particular SQL query. Let me expand on what I am saying. I did detect an error in the 17th second of the execution with 'session_id' equal to 63 (see it in the picture). Following the sequence of each result in the execution of queries, I need to draw your attention to the second query and its second column where the total elapsed time according to 'sys.dm_exec_requests' should be 17 and not 938 seconds since the previous one was 16. Now, checking the value of the third column (calculated by subtracting the 'start_time' value from GETDATE function), you will verify that this time is accurate whereas the second one is false. The value for the second and third columns should be the same but they are different.

To sum up, for this particular and real case, the column 'total_elapsed_time' returns inconsistent information about elapsed execution time of a process when it exceeds 16 seconds. Despite of the fact that I have not seen the same issue in other versions like SQL Server 2012/2014/2016/2017, it is better not to trust in DMVs so much. Therefore, I suggest working with caution. That is all for now, let me know any remark you may have. Stay tuned.

No comments:

Post a Comment