Extended Events for Tracking Backup and Restore Progress

Question

Extended Events for Tracking Backup and Restore Progress

pankaj.chakole

SSC Enthusiast

Points: 124
More actions
December 25, 2016 at 8:33 pm

#401267

Comments posted to this topic are about the item Extended Events for Tracking Backup and Restore Progress
Pankaj Chakole
Database Administrator
Email # pankaj.chakole@gmail.com

Viewing 8 posts - 1 through 7 (of 7 total)

You must be logged in to reply to this topic. Login to reply

Jeff Moden SSC Guru Points: 1003863 More actions · Answer 1

Man that seems like a lot of work. Wouldn't it be easier to just watch the screen during a restore? If it's supposed to be an automated restore, create a job and have it log the output to a file and then just read the file (which could also be easily automated).

--Jeff Moden

RBAR is pronounced "ree-bar" and is a "Modenism" for Row-By-Agonizing-Row.
First step towards the paradigm shift of writing Set Based code:
________Stop thinking about what you want to do to a ROW... think, instead, of what you want to do to a COLUMN.

Change is inevitable... Change for the better is not.

Helpful Links:
How to post code problems
How to Post Performance Problems
Create a Tally Function (fnTally)

Robert Sterbal SSChampion Points: 11047 More actions · Answer 2

I've found the restore progress log works pretty well for the data portion. For the log, I've found it a bit more challenging.

412-977-3526 call/text

AZJim Default port Points: 1432 More actions · Answer 3

I have found the following SQL very handy to do pretty much the same thing -- check on the progress of a back up. You can substitute whatever other command you want (DBCC, RESTORE, etc.). We have a couple of servers where the collating sequence is binary so you must specify the case properly.

select

r.start_time AS 'CmdStartTime'

, r.status AS 'CmdStatus'

--, t.task_state

, r.command AS 'ShortCommand'

, DB_NAME(r.database_id) AS 'DataBase'

, r.wait_type AS 'CmdWaitType'

--, r.last_wait_type

, r.blocking_session_id AS 'CmdBlockingSessionID'

, r.percent_complete AS 'CmdPctComplete'

-- , r.estimated_completion_time

, CASE WHEN ((r.estimated_completion_time/1000)/3600) < 10 THEN '0' +

CONVERT(VARCHAR(10),(r.estimated_completion_time/1000)/3600)

ELSE CONVERT(VARCHAR(10),(r.estimated_completion_time/1000)/3600)

END + ':' +

CASE WHEN ((r.estimated_completion_time/1000)%3600/60) < 10 THEN '0' +

CONVERT(VARCHAR(10),(r.estimated_completion_time/1000)%3600/60)

ELSE CONVERT(VARCHAR(10),(r.estimated_completion_time/1000)%3600/60)

END + ':' +

CASE WHEN ((r.estimated_completion_time/1000)%60) < 10 THEN '0' +

CONVERT(VARCHAR(10),(r.estimated_completion_time/1000)%60)

ELSE CONVERT(VARCHAR(10),(r.estimated_completion_time/1000)%60)

END AS 'TimeRemainingForCmd'

, CAST(((r.total_elapsed_time/1000.0)/60.0) AS dec(5,1)) AS 'CmdElapsedMinutes'

--, r.plan_handle

--, r.total_elapsed_time

--, r.task_address

, sqltxt.text AS 'CmdFullSQLCommandText'

from msdb.sys.dm_exec_requests r

--join msdb.sys.dm_os_tasks t -- if you want i/o statistics

--on r.task_address = t.task_address

OUTER APPLY msdb.sys.dm_exec_sql_text(r.sql_handle) sqltxt

where command like 'BACK%'; -- Remember, some servers are case sensitive

Jeff Moden SSC Guru Points: 1003863 More actions · Answer 4

AZJim (12/27/2016)
I have found the following SQL very handy to do pretty much the same thing -- check on the progress of a back up. You can substitute whatever other command you want (DBCC, RESTORE, etc.). We have a couple of servers where the collating sequence is binary so you must specify the case properly.
select
r.start_time AS 'CmdStartTime'
, r.status AS 'CmdStatus'
--, t.task_state
, r.command AS 'ShortCommand'
, DB_NAME(r.database_id) AS 'DataBase'
, r.wait_type AS 'CmdWaitType'
--, r.last_wait_type
, r.blocking_session_id AS 'CmdBlockingSessionID'
, r.percent_complete AS 'CmdPctComplete'
-- , r.estimated_completion_time
, CASE WHEN ((r.estimated_completion_time/1000)/3600) < 10 THEN '0' +
CONVERT(VARCHAR(10),(r.estimated_completion_time/1000)/3600)
ELSE CONVERT(VARCHAR(10),(r.estimated_completion_time/1000)/3600)
END + ':' +
CASE WHEN ((r.estimated_completion_time/1000)%3600/60) < 10 THEN '0' +
CONVERT(VARCHAR(10),(r.estimated_completion_time/1000)%3600/60)
ELSE CONVERT(VARCHAR(10),(r.estimated_completion_time/1000)%3600/60)
END + ':' +
CASE WHEN ((r.estimated_completion_time/1000)%60) < 10 THEN '0' +
CONVERT(VARCHAR(10),(r.estimated_completion_time/1000)%60)
ELSE CONVERT(VARCHAR(10),(r.estimated_completion_time/1000)%60)
END AS 'TimeRemainingForCmd'
, CAST(((r.total_elapsed_time/1000.0)/60.0) AS dec(5,1)) AS 'CmdElapsedMinutes'
--, r.plan_handle
--, r.total_elapsed_time
--, r.task_address
, sqltxt.text AS 'CmdFullSQLCommandText'
from msdb.sys.dm_exec_requests r
--join msdb.sys.dm_os_tasks t -- if you want i/o statistics
--on r.task_address = t.task_address
OUTER APPLY msdb.sys.dm_exec_sql_text(r.sql_handle) sqltxt
where command like 'BACK%'; -- Remember, some servers are case sensitive

I remembered that there was a command for figuring out what percent a KILL command had completed and went looking for it (I'm old... looking for something in my library is easier than remembering lately :-D). Did a quick study and wrote some code. When I finally return to this thread, there you are with code that has remarkably similar and sometimes identically named columns as what I came up with. We even selected mostly the same functionality. Great minds think alike. 🙂

I'll post mine anyway because I calculated things a bit differently and I also believe you'll like what I've done with the QUERY column (thank you Orlando!). The duration and "time to go" work for more than 24 hours like I believe yours do.

SELECT DBName = DB_NAME(r.database_id)

,Command = r.command

,SessionStartDT = CONVERT(CHAR(16),r.start_time,120)

,CurrentDT = CONVERT(CHAR(16),GETDATE(),120)

,EstCmdEndDT = CONVERT(CHAR(16),DATEADD(ss,estimated_completion_time/1000, GETDATE()),120)

,CmdTimeToGo = CONVERT(VARCHAR(10),DATEDIFF(hh,0,DATEADD(ss,estimated_completion_time/1000, 0)))

+ RIGHT(CONVERT(CHAR(8),DATEADD(ss,estimated_completion_time/1000, 0),108),6)

,CmdPctComplete = r.percent_complete

,SessionDuration = CONVERT(VARCHAR(10),DATEDIFF(hh,0,GETDATE()-r.start_time))

+ RIGHT(CONVERT(CHAR(8),GETDATE()-r.start_time,108),6)

,UserName = USER_NAME(r.[user_id])

,SPID = r.session_id

,BlockingSPID = r.blocking_session_id

,Query = (SELECT '--' + CHAR(10) + a.[text] + CHAR(10) AS [processing-instruction(QueryCode)] FOR XML PATH(''),TYPE)

FROM sys.dm_exec_requests r

CROSS APPLY sys.dm_exec_sql_text(r.[sql_handle]) a

WHERE r.command IN ('BACKUP DATABASE','RESTORE DATABASE','DBCC CHECKDB','KILL','UPDATE STATISTICS')

ORDER BY DBName

;

[EDIT] p.s. Do you also dislike Extended Events as much as I do? :w00t:

[EDIT2] The CmdTimeToGo and CmdPctComplete don't appear to include the Transaction Log for Backups (which is usually very short for me because of the PIT backups I do) nor the Redo/Undo phases of a Restore. I can live with that but just wanted folks to know.

--Jeff Moden

RBAR is pronounced "ree-bar" and is a "Modenism" for Row-By-Agonizing-Row.
First step towards the paradigm shift of writing Set Based code:
________Stop thinking about what you want to do to a ROW... think, instead, of what you want to do to a COLUMN.

Change is inevitable... Change for the better is not.

Helpful Links:
How to post code problems
How to Post Performance Problems
Create a Tally Function (fnTally)

Jeff Moden SSC Guru Points: 1003863 More actions · Answer 5

@pankaj.chakole,

My apologies. I got caught up in the moment because of a different thought process than most. Like I said, I wouldn't use Extended Events for this particular thing.

That, not withstanding, I wanted to tell you "Nice Article". It's a nice easy read and the graphics that you included are in all the right spots and large enough to read.

Something unsaid in the article is that is also provides a very nice, step-by-step introduction in how to use the much-improved post-2008 version of Extended Events. Well done!

--Jeff Moden

RBAR is pronounced "ree-bar" and is a "Modenism" for Row-By-Agonizing-Row.
First step towards the paradigm shift of writing Set Based code:
________Stop thinking about what you want to do to a ROW... think, instead, of what you want to do to a COLUMN.

Change is inevitable... Change for the better is not.

Helpful Links:
How to post code problems
How to Post Performance Problems
Create a Tally Function (fnTally)

pankaj.chakole SSC Enthusiast Points: 124 More actions · Answer 6

Thanks for the feedback, Jeff Moden. from my point of view its really very nice feature as earlier I was using dm_exec_requests to check the progress but one question still remained in mind "What is happening in background, where is the backup or restore progress stucked." This new feature gave me that answer 🙂

Pankaj Chakole
Database Administrator
Email # pankaj.chakole@gmail.com

thpraveen SSC Rookie Points: 27 More actions · Answer 7

In a single word, I would like to say this article is really really outstanding 🙂