Veritas backup job delays for 6 hours

[pecina08]

I have a intermittent problem with my Veritas backup job. I have a Windows 2003 SBS with SP1 with Veritas 9.1 Backup Exec installed. My job is set up to backup (Full Backup with reset archive bit) itself first and then the remote servers. All servers are on the same subnet and are physically in the same closet. So no WAN links. The problem that I am running into is that some times the job will delay for 6 hours. Since it does full backup on my servers when it delays it is backing them up during business hours causing one of my application server to slow down. I know I can change the selection order for the application server and I will not have this problem, but that is just a work around. The big problem is that it does this intermittently with different media. I have been monitoring this problem for the past three weeks. The job delays after it scans all sources that needs to backup. Here is the bengine*.log file from the server:

338 2/20/2006 21:00:03: DeviceManager: processing pending requests
338 2/20/2006 21:00:03: DeviceManager: query cache miss
338 2/20/2006 21:00:03: DeviceManager: query result = 0x00000000
338 2/20/2006 21:00:03: Available and held drives from the pool
338 2/20/2006 21:00:03: DELL 1 {4ca203e4-35c0-47ee-98c9-a0e3935474af}
338 2/20/2006 21:00:03: Drives not in use by the Engine
338 2/20/2006 21:00:03: DELL 1 {4ca203e4-35c0-47ee-98c9-a0e3935474af}
338 2/20/2006 21:00:03: Drives available (not in use and not held)
338 2/20/2006 21:00:03: DELL 1 {4ca203e4-35c0-47ee-98c9-a0e3935474af}
338 2/20/2006 21:00:03: Handing out drive:
338 2/20/2006 21:00:03: DELL 1 {4ca203e4-35c0-47ee-98c9-a0e3935474af}
338 2/20/2006 21:00:03: DeviceManager: going to sleep for 900000 msecs
5d0 2/20/2006 21:00:03: BackupJob: acquired device DELL 1
5d0 2/20/2006 21:00:03: BackupJob: trying to mount appending volume
5d0 2/20/2006 21:00:04: BackupJob: unable to mount appending volume, attempting scratch mount
338 2/20/2006 21:15:03: DeviceManager: timeout event fired
338 2/20/2006 21:15:03: DeviceManager: processing pending requests
338 2/20/2006 21:15:03: DeviceManager: going to sleep for 900000 msecs

<<This gets repeated 21 times until you see the following>>

338 2/21/2006 2:45:03: DeviceManager: timeout event fired
338 2/21/2006 2:45:03: DeviceManager: processing pending requests
338 2/21/2006 2:45:03: DeviceManager: going to sleep for 900000 msecs
5d0 2/21/2006 3:00:00: Block size: 65536
5d0 2/21/2006 3:00:00: Buffer size: 65536
5d0 2/21/2006 3:00:00: Num buffers: 10
5d0 2/21/2006 3:00:00: High water: 0
5d0 2/21/2006 3:00:00: BackupJob: medium successfully mounted
5d0 2/21/2006 3:00:00: Media Label: LTO000006
5d0 2/21/2006 3:00:00: Media GUID: {66790667-FFB8-4A69-BFA7-12C7741540F6}
5d0 2/21/2006 3:00:00: Overwrite Protected Until: 2/26/2006 11:00:00 AM
5d0 2/21/2006 3:00:00: Appendable Until: 2/22/2006 11:00:00 AM
5d0 2/21/2006 3:00:00: TAPEALERT: Get TapeAlert Flags Return Code = 0X0
5d0 2/21/2006 3:00:00: TAPEALERT: TapeAlert Device Flag = 0X0
5d0 2/21/2006 3:00:00: TAPEALERT: TapeAlert Changer Flag = 0X0

I have turned on/off AOFO for my job and it will still delay. I have changed the order in the selection by selecting a remote server and then this server but still the job delays with the same error. I have searched around forums and one user in the Veritas forum had the same issue, but with Exchange Mailboxes on a remote server and his problem was the Remote Agent. This server is a Domain Controller, DNS, WINS, Print Server, Norton Antivirus Server and of course Veritas Backup Server. It is not creating any Dr Watson logs, and the Event logs are no help either. I have added SP3 for the Veritas Back Exec 9.1 and updated my drivers for the Power Vault 110T Ultrium LTO2 tape device and still the job delays for six hours. Any advice or information would be greatly appreciated I am really lost on this one.

Thanks
P

 

[steveot]

Try installing SP4a for Veritas.

Update to the Latest Veritas Driver and not the OEM

 

[pecina08]

I apologize I did install SP4a my mind must have been some where else. I will though install the Veritas Drivers today and monitor the jobs. As I mentioned this is an intermittent problem. I will keep you posted. Thanks for the response.

 

[pecina08]

I have installed the latest Veritas updated drivers to the system and I once in a while the backup still delays for six hours. See the following from bengine*.log file:

1d8 2/28/2006 21:00:02: BackupJob: acquired device DELL 1
1d8 2/28/2006 21:00:02: BackupJob: trying to mount appending volume
1d8 2/28/2006 21:00:04: BackupJob: unable to mount appending volume, attempting scratch mount
e64 2/28/2006 21:15:02: DeviceManager: timeout event fired
e64 2/28/2006 21:15:02: DeviceManager: processing pending requests
e64 2/28/2006 21:15:02: DeviceManager: going to sleep for 900000 msecs
e64 2/28/2006 21:30:02: DeviceManager: timeout event fired
e64 2/28/2006 21:30:02: DeviceManager: processing pending requests
e64 2/28/2006 21:30:02: DeviceManager: going to sleep for 900000 msecs
e64 2/28/2006 21:45:02: DeviceManager: timeout event fired
e64 2/28/2006 21:45:02: DeviceManager: processing pending requests
e64 2/28/2006 21:45:02: DeviceManager: going to sleep for 900000 msecs
e64 2/28/2006 22:00:02: DeviceManager: timeout event fired
e64 2/28/2006 22:00:02: DeviceManager: processing pending requests
e64 2/28/2006 22:00:02: DeviceManager: going to sleep for 900000 msecs
e64 2/28/2006 22:15:02: DeviceManager: timeout event fired
e64 2/28/2006 22:15:02: DeviceManager: processing pending requests
e64 2/28/2006 22:15:02: DeviceManager: going to sleep for 900000 msecs
e64 2/28/2006 22:30:02: DeviceManager: timeout event fired
e64 2/28/2006 22:30:02: DeviceManager: processing pending requests
e64 2/28/2006 22:30:02: DeviceManager: going to sleep for 900000 msecs
e64 2/28/2006 22:45:02: DeviceManager: timeout event fired
e64 2/28/2006 22:45:02: DeviceManager: processing pending requests
e64 2/28/2006 22:45:02: DeviceManager: going to sleep for 900000 msecs
e64 2/28/2006 23:00:02: DeviceManager: timeout event fired
e64 2/28/2006 23:00:02: DeviceManager: processing pending requests
e64 2/28/2006 23:00:02: DeviceManager: going to sleep for 900000 msecs
e64 2/28/2006 23:15:02: DeviceManager: timeout event fired
e64 2/28/2006 23:15:02: DeviceManager: processing pending requests
e64 2/28/2006 23:15:02: DeviceManager: going to sleep for 900000 msecs
e64 2/28/2006 23:30:02: DeviceManager: timeout event fired
e64 2/28/2006 23:30:02: DeviceManager: processing pending requests
e64 2/28/2006 23:30:02: DeviceManager: going to sleep for 900000 msecs
e64 2/28/2006 23:45:02: DeviceManager: timeout event fired
e64 2/28/2006 23:45:02: DeviceManager: processing pending requests
e64 2/28/2006 23:45:02: DeviceManager: going to sleep for 900000 msecs
e64 3/1/2006 0:00:02: DeviceManager: timeout event fired
e64 3/1/2006 0:00:02: DeviceManager: processing pending requests
e64 3/1/2006 0:00:02: DeviceManager: going to sleep for 900000 msecs

Is there a way to change the sleep time for the device in Backup Exec? Any help would be great!

 

[steveot]

Is backup exec prompting for something? Anything in active alerts?

Is the job set to append only or append/overwrite.

 

[pecina08]

There is nothing on the active alerts. The job is setup to append/overwrite. I have configured the BeUtility to respond to yes on overwrite media. The whole thing that throws me off is that the problem only happens once in a while. Here are the bengine*.log for a good backup and a bad backup:

---BAD BACKUP AKA DELAYED BACKUP---

1d8 2/28/2006 21:00:02: BackupJob: acquired device DELL 1
1d8 2/28/2006 21:00:02: BackupJob: trying to mount appending volume
1d8 2/28/2006 21:00:04: BackupJob: unable to mount appending volume, attempting scratch mount
e64 2/28/2006 21:15:02: DeviceManager: timeout event fired
e64 2/28/2006 21:15:02: DeviceManager: processing pending requests
e64 2/28/2006 21:15:02: DeviceManager: going to sleep for 900000 msecs
e64 2/28/2006 21:30:02: DeviceManager: timeout event fired
e64 2/28/2006 21:30:02: DeviceManager: processing pending requests
e64 2/28/2006 21:30:02: DeviceManager: going to sleep for 900000 msecs

<<IT REPEATS UNTIL 3:00 AM>>

e64 3/1/2006 2:45:02: DeviceManager: going to sleep for 900000 msecs
1d8 3/1/2006 3:00:01: Block size: 65536
1d8 3/1/2006 3:00:01: Buffer size: 65536
1d8 3/1/2006 3:00:01: Num buffers: 10
1d8 3/1/2006 3:00:01: High water: 0
1d8 3/1/2006 3:00:01: BackupJob: medium successfully mounted


---GOOD BACKUP AKA DOES NOT DELAY---

3b4 3/1/2006 21:00:01: BackupJob: acquired device DELL 1
3b4 3/1/2006 21:00:01: BackupJob: trying to mount appending volume
3b4 3/1/2006 21:00:04: BackupJob: unable to mount appending volume, attempting scratch mount
3b4 3/1/2006 21:01:07: Block size: 65536
3b4 3/1/2006 21:01:07: Buffer size: 65536
3b4 3/1/2006 21:01:07: Num buffers: 10
3b4 3/1/2006 21:01:07: High water: 0

I would like to know how to change the Device Manager timeout. change it from 90000 seconds (15 minutes) to 30 seconds so if it does delay the delay will only be 12 minutes rather than 6 hours!

Thanks P.

 

[lb63640]

Have you tried uninstalling and reinstalling?

 

[pecina08]

No, that I was waiting to leave that as the last option I was hoping that someone may have experienced this problem before. But I am more than likely going to uninstall if no resolution comes about in the next two weeks.

 

[pecina08]

the problem has not been resolved I have now uninstalled and re-installed Veritas. I have updated Veritas with SP4a and the latest drivers. Ran a backup job yesterday with no problems. I will post my last response next week after a couple of backups have been processed.

 

[SQLScholar]

I am getting a similar problem - does the windows Event log have anything in it?

I think ours has been traced to a dodgy SCSI card which occationally it has trouble connecting to the device (so it sits there doing nothing for 7 hours)

Dan

----------------------------------------
There are 2 types of computer, the prototype and the obsolete!!
----------------------------------------
No D, just plank - and its not my fault

 

[pecina08]

Dan,

Unfortunately no the Event logs do not show anything. If you have the Veritas Engine to debug. You will find a bengine*.log file. That log file will show how Backup Exec Enginge is working. During the Backup you will see that device is sent a sleepmode command of "DeviceManager: going to sleep for 900000 msecs" which equates to 15 minutes. While at times randomly not every backup this thing will loop and it would delay the backup for 6 hours. Last Night was my second job with the fresh install of Veritas and so far so good. Crossing my fingers here. I would beleive that you would recieve an error at the end of the job indicating a bad device if it was the cable, but not too sure. Anyways, I will still monitor my backups and give a good update in about a week. At the same time I hope someone does find a resolution to the problem. I even posted the same problem in the Veritas Support Forums and a Symantec Employee just gave me some links about how to cut down the time on a backup job. Defrag volumes, clean tape drive... unnecessary info. Main question I posted to him was how to change that 900000 millescond in Veritas. He did not reply. Let me know if you find anything on this issue. Tried resolving my problemf for two months and I gave up and did a re-install.

P

 

[pecina08]

The re-install has fixed my problem unfortunately that was my solution!