SQLBill,
I thought you may be on to something with the time of completion versus the time of start of a back up operation so I looked back at the successful job logs.
Here is the job log from the last successful backup we had:
____________________________
Job server: SDISERVER
Job name: Daily
Job started: Wednesday, November 17, 2004 at 11:00:05 PM
Job type: Backup
Job Log: BEX00211.xml
Device and Media Information
Drive Name: DELL 1
Media Label: 4MM000012
Media GUID: {B3566618-D259-4944-A11B-2EF4C600A240}
Overwrite Protected Until: 12/31/9999 12:00:00 AM
Appendable Until: 12/31/9999 12:00:00 AM
Targeted Media Set Name: Media Set 1
Job Operation - Backup
Backup Options
Media operation - overwrite.
Hardware compression enabled.
Starting Pre Job Command < c:\navstop.bat >
Server - SDISERVER
Set Information - \\SDISERVER\Microsoft Exchange Mailboxes
Backup Set Information
Family Name: "Media created 11/17/2004 11:00:05 PM"
Backup of "\\SDISERVER\Microsoft Exchange Mailboxes "
Backup set #1 on storage media #1
Backup set description: "Daily"
Backup Type: FULL - Back up messages - Reset archive bit
Microsoft Exchange Server Agent: Started
Backup started on 11/17/2004 at 11:00:22 PM.
Backup completed on 11/18/2004 at 12:21:04 AM.
Backup Set Summary
Backed up 51223 mail message(s) in 830 folder(s) in 17 mailbox(es)
Processed 3,192,631,351 bytes in 1 hour, 20 minutes, and 42 seconds.
Throughput rate: 37.7 MB/min
Set Information - \\SDISERVER\Microsoft Information Store\First Storage Group
Backup Set Information
Family Name: "Media created 11/17/2004 11:00:05 PM"
Backup of "\\SDISERVER\Microsoft Information Store\First Storage Group "
Backup set #2 on storage media #1
Backup set description: "Daily"
Backup Type: FULL - Database & Logs (flush committed logs)
Microsoft Exchange Server Agent: Started
Backup started on 11/18/2004 at 12:21:04 AM.
Backup Set Detail Information
Log Files
Backup completed on 11/18/2004 at 12:39:03 AM.
Backup Set Summary
Backed up 2 Exchange Server store(s)
Backed up 0 Exchange Server log(s)
Processed 3,719,472,016 bytes in 17 minutes and 59 seconds.
Throughput rate: 197 MB/min
Set Information - D: Data
Backup Set Information
Family Name: "Media created 11/17/2004 11:00:05 PM"
Backup of "D: Data"
Backup set #3 on storage media #1
Backup set description: "Daily"
Backup Type: FULL - Back Up Files - Reset Archive Bit
Backup started on 11/18/2004 at 12:39:04 AM.
Backup completed on 11/18/2004 at 2:16:32 AM.
Backup Set Summary
Backed up 27278 files in 1955 directories.
Processed 21,523,498,591 bytes in 1 hour, 37 minutes, and 28 seconds.
Throughput rate: 211 MB/min
Set Information - \\SDISERVER\Microsoft Exchange Public Folders
Backup Set Information
Family Name: "Media created 11/17/2004 11:00:05 PM"
Backup of "\\SDISERVER\Microsoft Exchange Public Folders "
Backup set #4 on storage media #1
Backup set description: "Daily"
Backup Type: FULL - Back up messages - Reset archive bit
Microsoft Exchange Server Agent: Started
Backup started on 11/18/2004 at 2:16:33 AM.
Backup completed on 11/18/2004 at 2:16:35 AM.
Backup Set Summary
Backed up 0 mail message(s) in 1 folder(s) in 0 mailbox(es)
Processed 2,226 bytes in 2 seconds.
Throughput rate: 0.064 MB/min
Set Information - C: Dell Server
Backup Set Information
Family Name: "Media created 11/17/2004 11:00:05 PM"
Backup of "C: Dell Server"
Backup set #5 on storage media #1
Backup set description: "Daily"
Backup Type: FULL - Back Up Files - Reset Archive Bit
Backup started on 11/18/2004 at 2:16:36 AM.
Backup completed on 11/18/2004 at 2:16:43 AM.
Backup Set Summary
Backed up 308 files in 53 directories.
Processed 11,095,315 bytes in 7 seconds.
Throughput rate: 90.7 MB/min
Set Information - \\SDISERVER\System?State
Backup Set Information
Family Name: "Media created 11/17/2004 11:00:05 PM"
Backup of "\\SDISERVER\System?State "
Backup set #6 on storage media #1
Backup set description: "Daily"
Backup Type: FULL - Back Up Files - Reset Archive Bit
Backup started on 11/18/2004 at 2:16:44 AM.
Backup Set Detail Information
Drive Name: DELL 1
Media Label: 4MM000022
Media GUID: {28F6257F-BD02-4A36-A966-37DEC6D3A719}
Overwrite Protected Until: 12/31/9999 12:00:00 AM
Appendable Until: 12/31/9999 12:00:00 AM
Targeted Media Set Name: Media Set 1
Backup set #6 on storage media #2
Backup completed on 11/18/2004 at 7:57:54 AM.
Backup Set Summary
Backed up 2017 files in 96 directories.
Processed 307,918,692 bytes in 1 minute and 44 seconds.
Throughput rate: 169 MB/min
Job Completion Status
Job ended: Thursday, November 18, 2004 at 7:58:20 AM
Completed status: Successful
******end
Now here is the first CANCELLED job log:
_____________
Job server: SDISERVER
Job name: Daily
Job started: Thursday, November 18, 2004 at 11:00:00 PM
Job type: Backup
Job Log: BEX00213.xml
Device and Media Information
Drive Name: DELL 1
Media Label: 4MM000022
Media GUID: {28F6257F-BD02-4A36-A966-37DEC6D3A719}
Overwrite Protected Until: 12/31/9999 12:00:00 AM
Appendable Until: 12/31/9999 12:00:00 AM
Targeted Media Set Name: Media Set 1
Job Operation - Backup
Backup Options
Media operation - overwrite.
Hardware compression enabled.
Starting Pre Job Command < c:\navstop.bat >
Server - SDISERVER
Set Information - \\SDISERVER\Microsoft Exchange Mailboxes
Backup Set Information
Family Name: "Media created 11/18/2004 11:00:01 PM"
Backup of "\\SDISERVER\Microsoft Exchange Mailboxes "
Backup set #1 on storage media #1
Backup set description: "Daily"
Backup Type: FULL - Back up messages - Reset archive bit
Microsoft Exchange Server Agent: Started
Backup started on 11/18/2004 at 11:00:17 PM.
Backup completed on 11/18/2004 at 11:34:19 PM.
Backup Set Summary
Backed up 51400 mail message(s) in 830 folder(s) in 17 mailbox(es)
Processed 3,197,328,990 bytes in 34 minutes and 2 seconds.
Throughput rate: 89.6 MB/min
Set Information - \\SDISERVER\Microsoft Information Store\First Storage Group
Backup Set Information
Family Name: "Media created 11/18/2004 11:00:01 PM"
Backup of "\\SDISERVER\Microsoft Information Store\First Storage Group "
Backup set #2 on storage media #1
Backup set description: "Daily"
Backup Type: FULL - Database & Logs (flush committed logs)
Microsoft Exchange Server Agent: Started
Backup started on 11/18/2004 at 11:34:21 PM.
Backup Set Detail Information
Log Files
Backup completed on 11/18/2004 at 11:52:22 PM.
Backup Set Summary
Backed up 2 Exchange Server store(s)
Backed up 0 Exchange Server log(s)
Processed 3,724,714,994 bytes in 18 minutes and 1 second.
Throughput rate: 197 MB/min
Set Information - D: Data
Backup Set Information
Family Name: "Media created 11/18/2004 11:00:01 PM"
Backup of "D: Data"
Backup set #3 on storage media #1
Backup set description: "Daily"
Backup Type: FULL - Back Up Files - Reset Archive Bit
Backup started on 11/18/2004 at 11:52:23 PM.
Backup completed on 11/19/2004 at 1:26:51 AM.
Backup Set Summary
Backed up 27285 files in 1955 directories.
Processed 21,546,446,797 bytes in 1 hour, 34 minutes, and 28 seconds.
Throughput rate: 218 MB/min
Set Information - \\SDISERVER\Microsoft Exchange Public Folders
Backup Set Information
Family Name: "Media created 11/18/2004 11:00:01 PM"
Backup of "\\SDISERVER\Microsoft Exchange Public Folders "
Backup set #4 on storage media #1
Backup set description: "Daily"
Backup Type: FULL - Back up messages - Reset archive bit
Microsoft Exchange Server Agent: Started
Backup started on 11/19/2004 at 1:26:53 AM.
Backup completed on 11/19/2004 at 1:26:55 AM.
Backup Set Summary
Backed up 0 mail message(s) in 1 folder(s) in 0 mailbox(es)
Processed 2,226 bytes in 2 seconds.
Throughput rate: 0.064 MB/min
Set Information - C: Dell Server
Backup Set Information
Family Name: "Media created 11/18/2004 11:00:01 PM"
Backup of "C: Dell Server"
Backup set #5 on storage media #1
Backup set description: "Daily"
Backup Type: FULL - Back Up Files - Reset Archive Bit
Backup started on 11/19/2004 at 1:26:56 AM.
Backup completed on 11/19/2004 at 1:27:03 AM.
Backup Set Summary
Backed up 308 files in 53 directories.
Processed 11,095,315 bytes in 7 seconds.
Throughput rate: 90.7 MB/min
Set Information - \\SDISERVER\System?State
Backup Set Information
Family Name: "Media created 11/18/2004 11:00:01 PM"
Backup of "\\SDISERVER\System?State "
Backup set #6 on storage media #1
Backup set description: "Daily"
Backup Type: FULL - Back Up Files - Reset Archive Bit
Backup started on 11/19/2004 at 1:27:04 AM.
Backup Set Detail Information
Media mount failed.
User canceled a Physical Volume Library operation.
The media operation was terminated by the user.
Backup completed on 11/19/2004 at 3:30:07 AM.
Backup Set Summary
Backed up 1057 files in 48 directories.
Processed 134,269,730 bytes in 48 seconds.
Throughput rate: 160 MB/min
Job Completion Status
Job ended: Friday, November 19, 2004 at 3:30:07 AM
Completed status: Canceled
Final error: 0x0 -
Final error category: Other Errors
Errors
Click an error below to locate it in the job log
Backup - \\SDISERVER\System?State Media mount failed.
User canceled a Physical Volume Library operation.
The media operation was terminated by the user.
******end************
More than enough space on the tape. The successful job had more data backedup than the cancelled.
We only have one tape Back up unit.
If indeed it is the timing issue where one process ends and the other one starts too early, how does one remedy this?
HELP..
Thanks