Estimate When Long Running SQL Processes Will Finish

Tim Ford, Owner

May 2, 2017

5 Min Read
Estimate When Long Running SQL Processes Will Finish

I don’t know about you but I’m a fan of tips and tricks that make my life easier. Here is a quick tip that has saved me numerous times when it’s come to answering the question: “when will that be done?”

This tip is aimed at the Database Administrators out there because this question usually comes up in regards to backups, index maintenance, DBCC CHECKDB, restore, rollback, and even the occasional (gasp!) DBCC SHRINKFILE and usually involves someone standing over your shoulder in your office watching your screen and looking for answers which usually are not presented in a query window.

To make use of this tip you’ll need to have a working knowledge of the SQL Server Dynamic Management Objects. I’ll be focusing on those DMOs that involve active executions occurring on your SQL Server instance:

  • sys.dm_exec_requests

  • sys.dm_exec_sql_text

sys.dm_exec_requests exposes metadata for actively executing queries (aka requests) running on the local SQL Server instance while sys.dm_exec_sql_text is a function that, when passing in a sql_handle (a unique identifier for a batch of t-sql text running on your server) will return the t-sql text.

The end results of this query will be any actively-executing request where the percent_complete column in sys.dm_exec_requests is populated.

This is a key point to understand since not all types of operations provide a percent_complete value. According to the official documentation for this Dynamic Management Object those operations that do provide this metric are:

  • ALTER INDEX REORGANIZE

  • AUTO_SHRINK option with ALTER DATABASE

  • BACKUP DATABASE

  • DBCC CHECKDB

  • DBCC CHECKFILEGROUP

  • DBCC CHECKTABLE

  • DBCC INDEXDEFRAG

  • DBCC SHRINKDATABASE

  • DBCC SHRINKFILE

  • RECOVERY

  • RESTORE DATABASE

  • ROLLBACK

  • TDE ENCRYPTION

sys.dm_exec_requests provides the sql_handle that sys.dm_exec_sql_text needs to return the actual batch command for the request. sys.dm_exec_requests also provides information via two columns: statement_start_offset and statement_end_offset that will identify the current statement in the batch that is executing at the time. The current session is eliminated from the results by use of the @@spid predicate.

The query that I’m providing in this article is shown below. When run it will return the following KPIs when there is activity of one of the types mentioned above actively executing:

  • session_id – the unique identifier for a session on the local SQL Server instance

  • percent_complete – current percent complete for the request being executed

  • elapsed_seconds – how long has this process been running in seconds

  • wait_type – if this process is waiting for resources then what is the wait type?

  • wait_time – accumulated wait time in milliseconds

  • last_wait_type – the previous wait time if there was a period of waiting prior to the current wait situation

  • est_completion_time – based upon the rate of execution to-date this is a computed column that provides a fairly accurate estimate of when the process will complete.

  • batch_text – the full statement being executed as part of the request

  • statement_executing – the active statement in the batch being run now

SET NOCOUNT ON;SELECT R.session_id, R.percent_complete, R.total_elapsed_time/1000 AS elapsed_seconds, R.wait_type, R.wait_time, R.last_wait_type, DATEADD(s,100/((R.percent_complete)/ (R.total_elapsed_time/1000)), R.start_time) AS est_complete_time, ST.text AS batch_text, CAST(SUBSTRING(ST.text, R.statement_start_offset / 2, (CASE WHEN R.statement_end_offset = -1 THEN DATALENGTH(ST.text)ELSE R.statement_end_offsetEND - R.statement_start_offset ) / 2 ) AS varchar(1024)) AS statement_executingFROM sys.dm_exec_requests AS RCROSS APPLY sys.dm_exec_sql_text(R.sql_handle) AS STWHERE R.percent_complete > 0AND R.session_id <> @@spid;

In order to see this in action I’ll use the following batch of t-sql text:

--First DBCCDBCC CHECKDB (FOO);--Then BackupBACKUP DATABASE [FOO] TO  DISK = N'C:SQLBackupFOO.bak' WITH NOFORMAT, NOINIT,  NAME = N'FOO-Full Database Backup', SKIP, NOREWIND, NOUNLOAD, COMPRESSION,  STATS = 10GO

If I highlight and run just the first command (the DBCC CHECKDB command) then kick off the query that gives us completion data immediately after the doing so the results will look like this:

  • session_id – 61

  • percent_complete – 19.61156

  • elapsed_seconds – 2

  • wait_type – CXPACKET

  • wait_time – 2186

  • last_wait_type - CXPACKET

  • est_completion_time – 2017-04-30 20:13:21.590

  • batch_text – --First DBCC  DBCC CHECKDB (FOO);    --Then Backup  BACKUP DATABASE [FOO] TO  DISK = N'C:SQLBackupFOO.bak'   WITH NOFORMAT,    NOINIT,     NAME = N'FOO-Full Database Backup',    SKIP, NOREWIND, NOUNLOAD, COMPRESSION,     STATS = 10 

  • statement_executing – BACKUP DATABASE [FOO] TO  DISK = N'C:SQLBackupFOO.bak'   WITH NOFORMAT,    NOINIT,     NAME = N'FOO-Full Database Backup',    SKIP, NOREWIND, NOUNLOAD, COMPRESSION,     STATS = 10 

If I execute the full batch consisting of the DBCC CHECKDB command and the BACKUP command and wait for the backup to start before I query for completion information this is what the results look like:

  • session_id – 61

  • percent_complete – 6.930882

  • elapsed_seconds – 13

  • wait_type – ASYNC_IO_COMPLETION

  • wait_time – 1007

  • last_wait_type - ASYNC_IO_COMPLETION

  • est_completion_time – 2017-04-30 20:17:59.613

  • batch_text – --First DBCC  DBCC CHECKDB (FOO);    --Then Backup  BACKUP DATABASE [FOO] TO  DISK = N'C:SQLBackupFOO.bak'   WITH NOFORMAT,    NOINIT,     NAME = N'FOO-Full Database Backup',    SKIP, NOREWIND, NOUNLOAD, COMPRESSION,     STATS = 10

  • statement_executing – BACKUP DATABASE [FOO] TO  DISK = N'C:SQLBackupFOO.bak'   WITH NOFORMAT,    NOINIT,     NAME = N'FOO-Full Database Backup',    SKIP, NOREWIND, NOUNLOAD, COMPRESSION,     STATS = 10

Of course, in this example I’m using a local database on my laptop to provide these results so the completion time isn’t that far in the future. Imagine the insights you can gain should we be dealing with a 20TB database as I often do. I created this script almost 10 years ago and still regularly use it. The last time was less than a week ago after getting paged at 2am because of a failed ETL process that was dependent on a backup process that was running long. It took me longer to log in than it did to identify when the backup would complete and then change the SQL Agent Job that failed to execute after that estimated execution time. Instead of staying up for another 30 minutes I returned to bed before my pillow even cooled.

About the Author

Tim Ford

Owner, SQL Cruise

http://thesqlagentman.com/

Sign up for the ITPro Today newsletter
Stay on top of the IT universe with commentary, news analysis, how-to's, and tips delivered to your inbox daily.

You May Also Like