Link to home
Create AccountLog in
Avatar of Olaf Berli
Olaf BerliFlag for Norway

asked on

Backup Exec jobs delayed

Customer has Win2k3 server as a PDC. Backup Exec 11d is installed with a Sony Tape drive. Complete backup scheduled every evening at 23.00. Working fine most of the time.

Some days, however, nothing seems to happen for the first 4 hours after the backup job starts. The log shows nothing. After 4 hours, the backup job starts (or rather continues) until it is finished without errors.

The log from a delayed job looks like this:
Family Name: "Media created 28.09.2007 23:00:02"
Backup of "C: "
Backup set #1 on storage media #1
Backup set description: "Daglig backup"
Backup Method: Full - Back Up Files - Reset Archive Bit

Backup started on 29.09.2007 at 04:01:45.
Backup completed on 29.09.2007 at 04:31:08.

while a normal log looks like:
Family Name: "Media created 01.10.2007 23:00:02"
Backup of "C: "
Backup set #1 on storage media #1
Backup set description: "Daglig backup"
Backup Method: Full - Back Up Files - Reset Archive Bit

Backup started on 01.10.2007 at 23:00:51.
Backup completed on 01.10.2007 at 23:30:30.

Any ideas what may be causing this delay?

Olaf

Avatar of cooledit
cooledit
Flag of Ireland image

Hej Olaf

first of all the backup does not seems to be very large, is this a dat72 drive ?

it basically only runs for 3 min.

1.   does this backup include System state, using the VSS option.
2.   How big is the backup
3.   look at your jobsetup "scheduler" does it say start at 23.00 but no later than 23.00 the day after
      you can change the backup window if you like.
4.   Does it state preprocessing during the first 2 hours.


Cooledit
Avatar of Olaf Berli

ASKER

Hei cooledit!

Trying to answer your questions:

The tape drive is a Sony SDX-520C with AIT tapes. Current backup size is approx. 14B.

The backup includes: Everything on two disk partitions (C: and E:) + SystemState using VSS

Job scheduler says: Start no earlier than 23:00 and no earlier than 22:59:59. (It also says "Effective date 13.09.2007" - seems a bit strange....  it was the daythe job was created)

When job "fails" or is delayed, I can't see any activity at all for the first 4 hours after the job starts. The job then runs normally.

Here is the log for a failed job (sorry for the length...)

Byte count          : 14 125 769 998 bytes
Job rate            :  MB/Min (Byte count of all backup sets divided by Elapsed time for all backup sets)
Files               : 70 384Directories         : 6 480
Skipped files       : 0
Corrupt files       : 0
Files in use        : 0
Original start time : 27. september 2007 23:00:00
Job started         : 28. september 2007 23:00:02
Job ended           : 29. september 2007 08:50:14
Elapsed time        : 09:50:12
 
Set Detail Information - Backup \\RK-SRV1\C:
Set type               : Backup
Set status             : Completed
Set description        : Daglig backup
Resource name          : \\RK-SRV1\C:
Logon account          : System Logon
AccountEncryption key         : No
Agent used                     : Yes
Advanced Open File Option used : No
Image used                     : No

Byte count             : 2 535 037 115 bytes
Rate                   : 82,00 MB/Min
Files                  : 13 714
Directories            : 1 961
Skipped files          : 0
Corrupt files          : 0
Files in use           : 0
Start time             : 29. september 2007 04:01:45
End time               : 29. september 2007 04:31:08
Media used             : AIT000002
 
Set Detail Information - Backup \\RK-SRV1\E:
Set type               : Backup
Set status             : Completed
Set description        : Daglig backup
Resource name          : \\RK-SRV1\E:
Logon account          : System Logon
AccountEncryption key         : No
Agent used                     : Yes
Advanced Open File Option used : No
Image used                     : No

Byte count             : 10 319 282 551 bytes
Rate                   : 87,00 MB/Min
Files                  : 56 670
Directories            : 4 518
Skipped files          : 0
Corrupt files          : 0
Files in use           : 0
Start time             : 29. september 2007 04:31:12
End time               : 29. september 2007 06:24:02
Media used             : AIT000002
 
Set Detail Information - Backup \\RK-SRV1\System?State
Set type               : Backup
Set status             : Completed
Set description        : Daglig backup
Resource name          : \\RK-SRV1\System?State
Logon account          : System Logon
AccountEncryption key         : No
Agent used                     : Yes
Advanced Open File Option used : Microsoft Volume Shadow Copy Service (VSS)
Image used                     : No
 
Byte count             : 1 271 450 332 bytes
Rate                   : 92,00 MB/Min
Files                  : 0
Directories            : 1
Skipped files          : 0
Corrupt files          : 0
Files in use           : 0
Start time             : 29. september 2007 06:24:09
End time               : 29. september 2007 06:37:16
Media used             : AIT000002
 
ASKER CERTIFIED SOLUTION
Avatar of cooledit
cooledit
Flag of Ireland image

Link to home
membership
Create an account to see this answer
Signing up is free. No credit card required.
Create Account
Trying to set the 'start no later than' to 01.00.00 next day. Will check to see what happens. Not too optimistic - after all, the scheduler seems to start at 23:00 as it should.

Resource order is set to C: E: and SystemState. Is this what you mean?
VSS is manual, yes.

C: has 13GB free (19GB total), E: has 39GB free (50GB total)
Will see if the above mentioned change will help. If not - only one SystemState will be ok.

Olaf
 
Hi again.

I may have found something, but don't know how to fix....

In the 'Alert History' I found that on the days where the backup was delayed by 5 hours (job started at 23:00 and waits until 04:00 before doing anything) there is an alert: 'Do you want to overwrite imported Media?' According to the log, the user has responded to this at 04:01. Obviously an automatic response. There are also some database maintenance taking place at 04:00. Could this explain the behaviour of the backup job? How could it be fixed?

Olaf
SOLUTION
Link to home
membership
Create an account to see this answer
Signing up is free. No credit card required.
Create Account
Thanks.

Yes, it seems like there may have been a problem here. Noticed that the alert said "Imported Media". This may be caused by using tapes that have been used with different backup software previously. As soon as these tapes have been used once in this system, they are removed from the "Imported Media" folder and put into the currently used media pool. Seems like this is the cause of the delay.

Thanksl for the help to you and to cooledit who helped me sort out other possible causes.

Olaf