Extended Events for Tracking Backup and Restore Progress

  • pankaj.chakole

    SSC Enthusiast

    Points: 121

    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

  • Jeff Moden

    SSC Guru

    Points: 996810

    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".
    "If "pre-optimization" is the root of all evil, then what does the resulting no optimization lead to?"

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

  • Robert Sterbal

    SSChampion

    Points: 10988

    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

    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: 996810

    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".
    "If "pre-optimization" is the root of all evil, then what does the resulting no optimization lead to?"

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

  • Jeff Moden

    SSC Guru

    Points: 996810

    @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".
    "If "pre-optimization" is the root of all evil, then what does the resulting no optimization lead to?"

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

  • pankaj.chakole

    SSC Enthusiast

    Points: 121

    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

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

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

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