Timing Matters

A few weeks ago I got an email from my backup administrator with a message like this:

Set type               : Backup
Set status             : Completed
Set description        : Weekday Backup

Resource name          : \\Server\Backups
Logon account          : System Logon Account
Encryption used        : None

Agent used                     : Yes
Advanced Open File Option used : No

Byte count             : n bytes
Rate                   : n MB/Min

Files                  : n
Directories            : n
Skipped files          : 1
Corrupt files          : 0
Files in use           : 0

Start time             : DOW, Month DD, YYYY 12:25:48 AM
End time               : DOW, Month DD, YYYY 12:29:26 AM

Media used             : media name
File is in use         : \\Server\Backups\BackupFolder\database_name_tlog_YYYYMMDDHHMM.BAK

So I checked the job schedule because when the transaction log backup job runs, it also deletes old backups.  The Log backup job was scheduled to run on the 1/2 hour and according to this report, the BackupExec job finished BEFORE 12:30 AM.  I sent this information to the backup administrator mentioning that it seemed like there must be a time difference between the BackupExec server and the SQL Server.  It turns out that the the SQL Server was 62 seconds ahead of the BackupExec server. 

Apparently BackupExec grabs a list of files to be backed up and then iterates over the list backing up each file, but when it got to this file the SQL Server Agent job had deleted the file.  Thus, BackupExec couldn’t backup the file.

I find this interesting because wouldn’t this also mean that BackupExec would miss any files created during the backup process?  I’m not a expert on backups, beyond knowing how to do SQL Server backups and the fact that I’ve changed tapes and started BackupExec jobs a couple of times, so maybe this is expected and accepted behavior.