total_elapsed_time shows a negative value?

Oopps! Upgrade your browser pretty please. Oopps! Upgrade your browser pretty please.

Yet another flaw in the DMVs. Apparently the designer of the dm_exec_requests has it’s own visions and ideas about how time flows. 🙂 Let me explain.
The following script:

select R.session_id
, R.blocking_session_id
, T.text
, r.status
, DB = db_name(R.database_id)
,R.total_elapsed_time
, R.percent_complete
, R.estimated_completion_time 
from sys.dm_exec_requests R 
cross apply sys.dm_exec_sql_text(R.sql_handle) T

Shows the cumulative statistics for sessions and their total_elapsed_time. (total_elapsed_time is measuring the performance statistics for a cached plan, and specifically its total elapsed time in microseconds for the completed executions of the chached plan). Hm, a quick note comes to mind: wait a second – how does this deal with parallelism? After all, we can have 2 plans for the same query – one for parallel execution and one for single CPU. What time is accounted for in this DMV in the total_elapsed_time in either case?

The parallelism aside, I’d like to point out the paradox of this field though. I find it remarcable that the field may contain a negative value. Apparently, the DMVs designers’ idea of time is a bit crooked and futuristic: if we have a query whose plan remains cached for a long time and the query keeps executing at times, eventually the value in the total_elapsed_time column will overflow its limit and will roll over and start flowing up from the negative values. I could go on a rant here and ask philosophical questions at large: what is up, what is down and how do you consider measuring time in negative values. But I think noone will care to read the rant, so I will spare it. Instead, I will give a real life example of the occurence of this case: a BizTalk server.