cancel
Showing results for 
Search instead for 
Did you mean: 

Backup Job Taking unusually long

peter_elliott
Level 4
Hi,

We have a new server running Backup Exec 11d. We backing up the same amount as our old server which took 5 and a half hours but for some reason it now takes 10 hours!

I have noticed that one part of the job takes four hours on its own which probably explains why it takes longer. This is copied from the job log:

Backup Set Information
Family Name: "Media created 2/14/2007 11:00:00 PM"
Backup of "\\TRIN-STAFF\D: TRIN-STAFF_Data"
Backup set #19 on storage media #2
Backup set description: "Wednesday"
Backup Method: Full - Back Up Files - Reset Archive Bit




Backup started on 2/15/2007 at 1:02:59 AM.

Backup Set Detail Information
Drive and media mount requested: 2/15/2007 1:05:13 AM
Drive and media information from media mount: 2/15/2007 1:05:54 AM
Drive Name: Wed
Media Label: B2D000120
Media GUID: {5c88c538-bc50-4a31-aac6-cae8b8427e81}
Overwrite Protected Until: 2/15/2007 2:05:54 AM
Appendable Until: 12/31/9999 12:00:00 AM
Targeted Media Set Name: Trinity College Media Set
Backup set #19 on storage media #3

Drive and media mount requested: 2/15/2007 2:00:14 AM
Drive and media information from media mount: 2/15/2007 2:00:54 AM
Drive Name: Wed
Media Label: B2D000121
Media GUID: {72b889fc-79d9-4e05-83f0-bbe7d85ae1a5}
Overwrite Protected Until: 2/15/2007 3:00:54 AM
Appendable Until: 12/31/9999 12:00:00 AM
Targeted Media Set Name: Trinity College Media Set
Backup set #19 on storage media #4
The item \\TRIN-STAFF\D:\Data\Shared\MultiDept\Menu\menu.ldb in use - skipped.
The item \\TRIN-STAFF\D:\Data\Shared\MultiDept\Menu\menu.mdb in use - skipped.

Drive and media mount requested: 2/15/2007 2:27:32 AM
Drive and media information from media mount: 2/15/2007 2:28:12 AM
Drive Name: Wed
Media Label: B2D000122
Media GUID: {bb5baf2b-8016-4f6e-a400-94b805d25d32}
Overwrite Protected Until: 2/15/2007 3:28:12 AM
Appendable Until: 12/31/9999 12:00:00 AM
Targeted Media Set Name: Trinity College Media Set
Backup set #19 on storage media #5

Drive and media mount requested: 2/15/2007 2:54:52 AM
Drive and media information from media mount: 2/15/2007 2:55:34 AM
Drive Name: Wed
Media Label: B2D000123
Media GUID: {bf7050ec-0be2-4108-9198-9676a800bbef}
Overwrite Protected Until: 2/15/2007 3:55:34 AM
Appendable Until: 12/31/9999 12:00:00 AM
Targeted Media Set Name: Trinity College Media Set
Backup set #19 on storage media #6
The item \\TRIN-STAFF\D:\Data\Users\get20\Mirror\update.log in use - skipped.

Drive and media mount requested: 2/15/2007 3:33:22 AM
Drive and media information from media mount: 2/15/2007 3:34:04 AM
Drive Name: Wed
Media Label: B2D000124
Media GUID: {91c2ffe9-7c71-498c-a8f4-d2b8e7e88c0b}
Overwrite Protected Until: 2/15/2007 4:34:04 AM
Appendable Until: 12/31/9999 12:00:00 AM
Targeted Media Set Name: Trinity College Media Set
Backup set #19 on storage media #7

Drive and media mount requested: 2/15/2007 4:05:20 AM
Drive and media information from media mount: 2/15/2007 4:06:02 AM
Drive Name: Wed
Media Label: B2D000125
Media GUID: {d6097026-f294-4c57-83c2-759e8ccb3ff3}
Overwrite Protected Until: 2/15/2007 5:06:02 AM
Appendable Until: 12/31/9999 12:00:00 AM
Targeted Media Set Name: Trinity College Media Set
Backup set #19 on storage media #8



Backup completed on 2/15/2007 at 4:40:44 AM.

Can any explain why this should take so much longer?

Thanks in advance.
8 REPLIES 8

perry_baker
Level 6
Employee Accredited
There's actually not quite enough information to provide a solid answer. It could be a combination of things or it could be specific to a particular resource.

From what I do see the job is backing data on the D: drive that spans from Media #3 through Media #8. One possibility is that you have enabled BE to pre-allocate the B2D files and the BKF files dont yet exist so BE is taking the time to create and grow the BKF files to the pre-allocated size.

Another possibility is that something is taking place on the server's D: drive at the same time as the backup. I see there are some SQL data files that are skipped. Perhaps there is something relative to SQL operations that are taking place at the same time that is having an unexpected effect.

There are other possibilities like...
*Multiple Backup Jobs to a single B2D device
*unexpected network variables if it's a remote backup

But if you have limited the scope to this one resource, the D: drive of this one server, then you will probably be looking at reviewing the activities that occur during the backup operation for the D: drive only. This would mean researching settings for SQL since we know its a party to the D: drive and any other applications installed on this server. I think that's where you'll find the answer to the problem.

peter_elliott
Level 4
Hi,

Thanks very much for your reply. Could you tell me how I could check to see if BE is enabled to pre-allocate the B2D files? Is there any other information I could send that might make things clearer?

Thanks

Peter

perry_baker
Level 6
Employee Accredited
To check if pre-allcation is enabled you right click the Backup-to-Disk folder, select Properties, on the General tab, in the lower half of the window is a check box available for "Allocate the maximum size for backup-to-disk files". If that option is selected and the size of the B2D file is 'large' it could be that the extra time is being used to create and grow those files...

Can post the same portion of a job log from a previous job which did not display the longer run time?

Also it would help to see the whole section titled Backup Set Summary for "\\TRIN-STAFF\D: TRIN-STAFF_Data" from the quicker and longer backup operations

peter_elliott
Level 4
Hi,

Thanks for the reply. I checked the B2D folders and the 'Allocate maximum size..' button was checked. I'm not sure what the difference or best option is: should I just uncheck the button and leave it to 'maximum number of backsets' to 100 or should I make maximun size for B2D less?

Below I pasted part of the job log from a quicker job. Lots of files are still being skipped. I did think this job was quicker because the throughput seemed higher than usual:



Set Information - \\TRIN-STAFF\D: TRIN-STAFF_Data
Backup Set Information
Family Name: "Media created 2/25/2007 11:00:04 PM"
Backup of "\\TRIN-STAFF\D: TRIN-STAFF_Data"
Backup set #20 on storage media #3
Backup set description: "ToDisk_SundayJob"
Backup Method: Full - Back Up Files - Reset Archive Bit




Backup started on 2/26/2007 at 12:27:07 AM.

Backup Set Detail Information
Drive and media mount requested: 2/26/2007 1:00:30 AM
Drive and media information from media mount: 2/26/2007 1:01:10 AM
Drive Name: Sun
Media Label: B2D000231
Media GUID: {958595b1-f25a-4e66-beb9-71aad8d9cb8c}
Overwrite Protected Until: 2/26/2007 2:01:10 AM
Appendable Until: 12/31/9999 12:00:00 AM
Targeted Media Set Name: Trinity College Media Set
Backup set #20 on storage media #4
The item \\TRIN-STAFF\D:\Data\Shared\MultiDept\Menu\menu.ldb in use - skipped.
The item \\TRIN-STAFF\D:\Data\Shared\MultiDept\Menu\menu.mdb in use - skipped.

Drive and media mount requested: 2/26/2007 1:21:14 AM
Drive and media information from media mount: 2/26/2007 1:21:52 AM
Drive Name: Sun
Media Label: B2D000232
Media GUID: {b513416f-b20e-49e3-92f8-6156b4b29b54}
Overwrite Protected Until: 2/26/2007 2:21:52 AM
Appendable Until: 12/31/9999 12:00:00 AM
Targeted Media Set Name: Trinity College Media Set
Backup set #20 on storage media #5

Drive and media mount requested: 2/26/2007 1:39:21 AM
Drive and media information from media mount: 2/26/2007 1:39:58 AM
Drive Name: Sun
Media Label: B2D000233
Media GUID: {77f70551-443e-4ce4-957e-26c7e86a2233}
Overwrite Protected Until: 2/26/2007 2:39:58 AM
Appendable Until: 12/31/9999 12:00:00 AM
Targeted Media Set Name: Trinity College Media Set
Backup set #20 on storage media #6
The item \\TRIN-STAFF\D:\Data\Users\ac493\transfer\vb\cat\menu.ldb in use - skipped.
The item \\TRIN-STAFF\D:\Data\Users\ac493\transfer\vb\cat\menu.mdb in use - skipped.
The item \\TRIN-STAFF\D:\Data\Users\get20\Mirror\update.log in use - skipped.

Drive and media mount requested: 2/26/2007 2:06:12 AM
Drive and media information from media mount: 2/26/2007 2:06:50 AM
Drive Name: Sun
Media Label: B2D000234
Media GUID: {fde0e6d8-df30-4186-81e7-d5c4e5aca8c0}
Overwrite Protected Until: 2/26/2007 3:06:50 AM
Appendable Until: 12/31/9999 12:00:00 AM
Targeted Media Set Name: Trinity College Media Set
Backup set #20 on storage media #7

Drive and media mount requested: 2/26/2007 2:27:45 AM
Drive and media information from media mount: 2/26/2007 2:28:24 AM
Drive Name: Sun
Media Label: B2D000235
Media GUID: {15edc183-fe8f-4477-b5e4-8f05f7628c61}
Overwrite Protected Until: 2/26/2007 3:28:24 AM
Appendable Until: 12/31/9999 12:00:00 AM
Targeted Media Set Name: Trinity College Media Set
Backup set #20 on storage media #8



Backup completed on 2/26/2007 at 2:53:07 AM.

Backup Set Summary
Backed up 439547 files in 25527 directories.
5 items were skipped.
Processed 107095025535 bytes in 2 hours, 22 minutes, and 48 seconds.
Throughput rate: 715 MB/min

Thanks for your help

peter

perry_baker
Level 6
Employee Accredited
The backup was a little over an hour faster...now doubt about that.

Is that the amount of time that you feel the overall job has increased?


Below is the part of the faster job that interests me most.
Backup Set Summary
Backed up 439547 files in 25527 directories.
5 items were skipped.
Processed 107095025535 bytes in 2 hours, 22 minutes, and 48 seconds.
Throughput rate: 715 MB/min

Can you post the same information about the slower job?
What I'm looking for is to see if the transfer rate is slower or if the amount of data being backed up has increased or a combination of the two.

The pre-allocation could have contributed because the job could have been taking the time to grow the files. You may want to test it by simply deselecting that option for your next backup and see what you encounter. I would leave the other options as currently set. You don't want to change too much at one time otherwise you may not know exactly what resoled the problem for you.

What is the currently configured size for the B2D files?

peter_elliott
Level 4
Hi,

The old job used in total used to take about 5:30 hrs now it take about 9:30 hrs. At the moment all B2d files are set to 'Allocate maximum size for backup-to-disk files' which is set to 10Gb. and concurrent operations is set to 1.

Here is the log from the slower job:

Set Information - \\TRIN-STAFF\D: TRIN-STAFF_Data
Backup Set Information
Family Name: "Media created 2/28/2007 11:00:01 PM"
Backup of "\\TRIN-STAFF\D: TRIN-STAFF_Data"
Backup set #20 on storage media #3
Backup set description: "Wednesday"
Backup Method: Full - Back Up Files - Reset Archive Bit




Backup started on 3/1/2007 at 1:15:18 AM.

Backup Set Detail Information
Drive and media mount requested: 3/1/2007 2:11:04 AM
Drive and media information from media mount: 3/1/2007 2:11:42 AM
Drive Name: Wed
Media Label: B2D000270
Media GUID: {729ea809-60b7-4803-abaa-e86008261ebf}
Overwrite Protected Until: 3/1/2007 3:11:42 AM
Appendable Until: 12/31/9999 12:00:00 AM
Targeted Media Set Name: Trinity College Media Set
Backup set #20 on storage media #4
The item \\TRIN-STAFF\D:\Data\Shared\MultiDept\Menu\menu.ldb in use - skipped.
The item \\TRIN-STAFF\D:\Data\Shared\MultiDept\Menu\menu.mdb in use - skipped.

Drive and media mount requested: 3/1/2007 2:37:30 AM
Drive and media information from media mount: 3/1/2007 2:38:10 AM
Drive Name: Wed
Media Label: B2D000271
Media GUID: {a183a92f-a397-47bf-9b60-92cc80b7367b}
Overwrite Protected Until: 3/1/2007 3:38:10 AM
Appendable Until: 12/31/9999 12:00:00 AM
Targeted Media Set Name: Trinity College Media Set
Backup set #20 on storage media #5
The item \\TRIN-STAFF\D:\Data\Users\ac493\transfer\vb\cat\menu.ldb in use - skipped.
The item \\TRIN-STAFF\D:\Data\Users\ac493\transfer\vb\cat\menu.mdb in use - skipped.

Drive and media mount requested: 3/1/2007 3:03:06 AM
Drive and media information from media mount: 3/1/2007 3:03:44 AM
Drive Name: Wed
Media Label: B2D000272
Media GUID: {59454027-7f67-4756-baaf-7e48ca41aafc}
Overwrite Protected Until: 3/1/2007 4:03:44 AM
Appendable Until: 12/31/9999 12:00:00 AM
Targeted Media Set Name: Trinity College Media Set
Backup set #20 on storage media #6

Drive and media mount requested: 3/1/2007 3:40:50 AM
Drive and media information from media mount: 3/1/2007 3:41:28 AM
Drive Name: Wed
Media Label: B2D000273
Media GUID: {d5858828-2aae-41ed-b24c-e68640276853}
Overwrite Protected Until: 3/1/2007 4:41:28 AM
Appendable Until: 12/31/9999 12:00:00 AM
Targeted Media Set Name: Trinity College Media Set
Backup set #20 on storage media #7

Drive and media mount requested: 3/1/2007 4:10:40 AM
Drive and media information from media mount: 3/1/2007 4:11:18 AM
Drive Name: Wed
Media Label: B2D000274
Media GUID: {920f90b5-80b1-4d1a-bf3d-905b19607948}
Overwrite Protected Until: 3/1/2007 5:11:18 AM
Appendable Until: 12/31/9999 12:00:00 AM
Targeted Media Set Name: Trinity College Media Set
Backup set #20 on storage media #8



Backup completed on 3/1/2007 at 4:50:06 AM.

Backup Set Summary
Backed up 427010 files in 24298 directories.
4 items were skipped.
Processed 107380036822 bytes in 3 hours, 31 minutes, and 36 seconds.
Throughput rate: 484 MB/min



Thanks again for your help.

Peter

perry_baker
Level 6
Employee Accredited
The amount of data being backed up is pretty consistent between the slow job and the fast job...at least for the resource you've used in this thread.

The throughput is lower, but thats simply a calculation based on the time the backup started and finished and not based on the capability of the network. So if a job sat prompting for media for an hour then that hour of no activity would be considered in the calculation of throughput. In your case it simply seems to be taking longer to actually backup the data because there don't seem to be any other contributing factors.

This one resource appears to be only 20% of the increased time to complete a backup since it takes about an hour longer and the total time increased by 5 hours. So there are other resources that have an increased backup time as well.

This really looks like it needs some deeper analysis than what can be done in the forums. I think you need to open a support case so that a technician can really dig into this as a whole.

peter_elliott
Level 4
ok thanks for all your help. I'll try getting through to a technician.

Thanks again

peter