Link to home
Start Free TrialLog in
Avatar of andymilli
andymilliFlag for United Kingdom of Great Britain and Northern Ireland

asked on

Backup Exec 12.5 backup fails - 'User cancelled a Physical Volume Library operation'

I've been having trouble with some backups failing with this message:

"Media mount failed. User canceled a Physical Volume Library operation. V-79-57344-33861 - The media operation was terminated by the user. "

For troubleshooting, we've seperated the job into two: the C drive plus Exchange on one night and the D drive (user data) on the next. The C drive backup works fine but some of the time the D drive backup fails with the above error. That may be a size issue  the C backup is only 21Gb, whereas the D drive has already backed up at least 46Gb (out of 56Gb) before it fails (n.b. The drives are partitions on a single pair of RAID1 disks). On the other hand the failure may be caused by something on the D drive - a corrupted record perhaps?

I'm wondering whether its something to do with the way the media is setup. I can't understand why the log shows so many media used in a single backup (see log below). We only use a single cartridge for a backup, and have a total of 5 cartridges, one for each day of the week, Mon-Fri (Dell Powervault RD1000 160Gb cartridges).  Might the problem be that the data is sometimes appending rather than overwriting? This would cause the drive to become full. Backup Exec shows around 80 media in the main Media Set - all allocated in the last 4 weeks. Can this be right when we only have 5 cartidges?

I've copied the log for last night's failed backup in the code secion below.
Please note the backup job is set to cancel if not completed after 10 hours.

I would really appreciate any help or suggestions as to how to proceed.

Dell PowerEdge 840 Quad-Core Server with 3Gb Ram
Dell Powervault RD1000
Small Business Server 2003
Backup Exec 12.5.
Job Log for NTRL D:
--------------------------------------------------------------------------------
Completed status: Canceled, timed out  
Expand AllCollapse All  
 
Job Information 
Job server: SERVER
Job name: NTRL D:
Job started: 21 April 2009 at 18:00:04
Job type: Backup
Job Log: BEX_SERVER_00214.xml
 
 
 
Drive and media mount requested: 21/04/2009 18:00:05
 
Device and Media Information 
Drive and media information from media mount: 21/04/2009 18:00:20
Drive Name: NTR RD1000 Drive
Media Label: B2D000032
Media GUID: {233d703a-12ca-49fb-a685-5aefd4f36415}
Overwrite Protected Until: 21/04/2009 19:00:20
Appendable Until: 21/04/2009 19:00:20
Targeted Media Set Name: NTR Media Set
 
All Media Used
 B2D000032
 B2D000036
 B2D000071
 B2D000040
 B2D000089
 B2D000074
 B2D000038
 B2D000039
 B2D000094
 B2D000028
 B2D000034
 B2D000054
 B2D000099
 B2D000084
 B2D000109
 B2D000029
 
 
 
 
Job Operation - Backup  
Backup Options 
Media operation - overwrite.
Compression Type: Hardware [if available, otherwise none]
Encryption Type: None
 
 
 
 
 
Server - SERVER 
 
Set Information - D:  
Backup Set Information 
Family Name: "Media created 21/04/2009 18:00:05"
Backup of "D:" as ""
Backup set #1 on storage media #1
Backup set description: "NTRL D:"
Backup Method: Full - Back Up Files - Reset Archive Bit
 
 
 
 
Backup started on 21/04/2009 at 18:00:48.
 
Backup Set Detail Information 
Drive and media mount requested: 21/04/2009 18:01:14
Drive and media information from media mount: 21/04/2009 18:01:23
Drive Name: NTR RD1000 Drive
Media Label: B2D000036
Media GUID: {ff0a23ea-c3f1-48e8-9b08-18fefcd30e3a}
Overwrite Protected Until: 21/04/2009 19:01:23
Appendable Until: 21/04/2009 19:01:23
Targeted Media Set Name: NTR Media Set
 Backup set #1 on storage media #2
 
Drive and media mount requested: 21/04/2009 18:03:24
Drive and media information from media mount: 21/04/2009 18:03:32
Drive Name: NTR RD1000 Drive
Media Label: B2D000071
Media GUID: {a2b7d276-6314-43eb-a8ec-a4682e367de8}
Overwrite Protected Until: 21/04/2009 19:03:32
Appendable Until: 21/04/2009 19:03:32
Targeted Media Set Name: NTR Media Set
 Backup set #1 on storage media #3
 
Drive and media mount requested: 21/04/2009 18:04:32
Drive and media information from media mount: 21/04/2009 18:04:38
Drive Name: NTR RD1000 Drive
Media Label: B2D000040
Media GUID: {7029d8a6-3c55-4f73-9d7e-5544416886e0}
Overwrite Protected Until: 21/04/2009 19:04:38
Appendable Until: 21/04/2009 19:04:38
Targeted Media Set Name: NTR Media Set
 Backup set #1 on storage media #4
 
Drive and media mount requested: 21/04/2009 18:06:43
Drive and media information from media mount: 21/04/2009 18:06:48
Drive Name: NTR RD1000 Drive
Media Label: B2D000089
Media GUID: {2adc1d1a-e29f-49a3-92b2-57306778715c}
Overwrite Protected Until: 21/04/2009 19:06:48
Appendable Until: 21/04/2009 19:06:48
Targeted Media Set Name: NTR Media Set
 Backup set #1 on storage media #5
 
Drive and media mount requested: 21/04/2009 18:09:05
Drive and media information from media mount: 21/04/2009 18:09:10
Drive Name: NTR RD1000 Drive
Media Label: B2D000074
Media GUID: {86e642fc-54f9-4e9c-a139-a00afef60c47}
Overwrite Protected Until: 21/04/2009 19:09:10
Appendable Until: 21/04/2009 19:09:10
Targeted Media Set Name: NTR Media Set
 Backup set #1 on storage media #6
 
Drive and media mount requested: 21/04/2009 18:11:43
Drive and media information from media mount: 21/04/2009 18:11:50
Drive Name: NTR RD1000 Drive
Media Label: B2D000038
Media GUID: {ca4170f7-7fdb-4597-9a57-b2d981dec621}
Overwrite Protected Until: 21/04/2009 19:11:50
Appendable Until: 21/04/2009 19:11:50
Targeted Media Set Name: NTR Media Set
 Backup set #1 on storage media #7
 
Drive and media mount requested: 21/04/2009 18:14:32
Drive and media information from media mount: 21/04/2009 18:14:38
Drive Name: NTR RD1000 Drive
Media Label: B2D000039
Media GUID: {e911897c-e89c-47ec-91b4-7a8b3a4aae4e}
Overwrite Protected Until: 21/04/2009 19:14:38
Appendable Until: 21/04/2009 19:14:38
Targeted Media Set Name: NTR Media Set
 Backup set #1 on storage media #8
 
Drive and media mount requested: 21/04/2009 18:17:20
Drive and media information from media mount: 21/04/2009 18:17:26
Drive Name: NTR RD1000 Drive
Media Label: B2D000094
Media GUID: {8cce6332-d1e9-4f0c-805e-bafb8ae7420d}
Overwrite Protected Until: 21/04/2009 19:17:26
Appendable Until: 21/04/2009 19:17:26
Targeted Media Set Name: NTR Media Set
 Backup set #1 on storage media #9
 
Drive and media mount requested: 21/04/2009 18:19:56
Drive and media information from media mount: 21/04/2009 18:20:04
Drive Name: NTR RD1000 Drive
Media Label: B2D000028
Media GUID: {fcd8c9ca-9fb7-4b82-8c6f-750740e59097}
Overwrite Protected Until: 21/04/2009 19:20:04
Appendable Until: 21/04/2009 19:20:04
Targeted Media Set Name: NTR Media Set
 Backup set #1 on storage media #10
 
Drive and media mount requested: 21/04/2009 18:21:29
Drive and media information from media mount: 21/04/2009 18:21:34
Drive Name: NTR RD1000 Drive
Media Label: B2D000034
Media GUID: {11f97e04-cadd-4fee-a241-4799ab35539e}
Overwrite Protected Until: 21/04/2009 19:21:34
Appendable Until: 21/04/2009 19:21:34
Targeted Media Set Name: NTR Media Set
 Backup set #1 on storage media #11
 
Drive and media mount requested: 21/04/2009 18:23:04
Drive and media information from media mount: 21/04/2009 18:23:12
Drive Name: NTR RD1000 Drive
Media Label: B2D000054
Media GUID: {4ae343bf-412c-4ac9-8285-411698afa2c2}
Overwrite Protected Until: 21/04/2009 19:23:12
Appendable Until: 21/04/2009 19:23:12
Targeted Media Set Name: NTR Media Set
 Backup set #1 on storage media #12
 
Drive and media mount requested: 21/04/2009 18:23:46
Drive and media information from media mount: 21/04/2009 18:23:52
Drive Name: NTR RD1000 Drive
Media Label: B2D000099
Media GUID: {17a8e69a-e1bc-48a8-8ca3-9c54943982cb}
Overwrite Protected Until: 21/04/2009 19:23:52
Appendable Until: 21/04/2009 19:23:52
Targeted Media Set Name: NTR Media Set
 Backup set #1 on storage media #13
 
Drive and media mount requested: 21/04/2009 18:24:41
Drive and media information from media mount: 21/04/2009 18:24:48
Drive Name: NTR RD1000 Drive
Media Label: B2D000084
Media GUID: {f7ac12fd-d212-448c-980d-30d8fc0f040a}
Overwrite Protected Until: 21/04/2009 19:24:48
Appendable Until: 21/04/2009 19:24:48
Targeted Media Set Name: NTR Media Set
 Backup set #1 on storage media #14
 
Drive and media mount requested: 21/04/2009 18:26:00
Drive and media information from media mount: 21/04/2009 18:26:08
Drive Name: NTR RD1000 Drive
Media Label: B2D000109
Media GUID: {2c5b09c6-0519-497b-97de-4c3173abc239}
Overwrite Protected Until: 21/04/2009 19:26:08
Appendable Until: 21/04/2009 19:26:08
Targeted Media Set Name: NTR Media Set
 Backup set #1 on storage media #15
 
Drive and media mount requested: 21/04/2009 18:27:17
Drive and media information from media mount: 21/04/2009 18:27:22
Drive Name: NTR RD1000 Drive
Media Label: B2D000029
Media GUID: {87457210-eaff-4bd8-8811-d636de5310ff}
Overwrite Protected Until: 21/04/2009 19:27:22
Appendable Until: 21/04/2009 19:27:22
Targeted Media Set Name: NTR Media Set
 Backup set #1 on storage media #16
 
Drive and media mount requested: 21/04/2009 18:29:11
Media mount failed.
User canceled a Physical Volume Library operation.
 
V-79-57344-33861 - The media operation was terminated by the user.
 
 
 
Backup completed on 22/04/2009 at 06:00:14.
 
Backup Set Summary 
Backed up 103328 files in 7661 directories.
Processed 46,313,766,682 bytes in  26 minutes and  48 seconds.
Throughput rate: 1648 MB/min
Compression Type: None
 
 
 
 
 
 
 
 
 
 
Job Completion Status 
Job ended: 22 April 2009 at 06:00:14
Completed status: Canceled, timed out
The job was automatically canceled because it 
exceeded the job's maximum configured 
run time.
 
 
 
Errors 
Click an error below to locate it in the job log
Backup- D: Media mount failed.
User canceled a Physical Volume Library operation.
V-79-57344-33861 - The media operation was terminated by the user.

Open in new window

Avatar of honmapog
honmapog
Flag of Ireland image

In Tools/Options/Media Management, make sure to select "Overwrite recyclable media contained in the targeted media set before overwriting scratch media."

If you look at your media through Windows Explorer, how much free space do you have left on the disk?

How big is each of the bkf files you have on the disk?
Avatar of andymilli

ASKER

Thanks for your help, honmapog!

The option "Overwrite scratch media..." was ticked, so I've now ticked "Overwrite recyclable media..." as per your suggestion.

On the disk where the backup failed, the free space is only 1,028,096 bytes.

There are 18 bkf files from the failed backup, the 6 biggest are exactly 4,194,319 KB, the rest are varying sizes (2KB, 872MB, 1.2GB, 1.8GB, 2GB, 3.4GB etc). There are also files from previous backups.
ASKER CERTIFIED SOLUTION
Avatar of honmapog
honmapog
Flag of Ireland image

Link to home
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.
Start Free Trial
Thanks.

I've now changed the append period to Infinite. It's due to backup the D drive tonight so I'll see how that goes.
Sorry, it was the C drive last night, the D drive is tonight. I'll be using the same same cartridge as the one that failed last week.
The backup failed last night. I retired and deleted all media less than  4,194,319 KB  and also deleted them from the cartridge. I ran the backup again, and it failed again.

After the last backup I had a look at the cartridge in My Computer, and it was showing it as full. There were a number of old backups of exchange on there (each in a seperate folder called, for example, IMG000068). I deleted these from the cartridge as they are not needed, and I ran the backup again. This time it worked!

Tomorrow I wll try re-merging the two backups (The C-drive & Exchange backup and the D-drive backup) and see if that will now work.
Okay, I merged the two backups into a single backup which I have running daily for a few days now, and it seems to be working. Thanks very much for your help!

There is just one problem the remains (and which may have played a big part of the problem in the first place). The backup creates a folder on the cartridge called something like IMG000074. This folder contains the backup files for exchange and is around 11.8GB. But each time the backup is run, a new folder is created with a new name, but the folder from the previous backup remains. Unless I manually delete redundant folders regularly, the cartidge with eventually become full and the backup will fail.

So how do I set it to overwrite, re-use or delete this folder?
In version 12.5 these folders are supposed to be deleted automatically (this was not the case in version 11d).
There is a way of stopping them from being deleted in the registry. Maybe you have that option set.

To make Backup Exec automattically deletes IMG folders when they are overwritable, make sure the registry key HKLM\Software\Symantec\Backup Exec For Windows\Backup Exec\Engine\Misc\AutoExpireGRT is present and set to 1
Thanks, honmapog. Sorry for the delay responding, I got accidentally locked out of my account. Customer services have now sorted it out for me.

The key you mention (HKLM\Software\Symantec\Backup Exec For Windows\Backup Exec\Engine\Misc\AutoExpireGRT) is already set to 1, so that doesn't seem to be the solution. Any other suggestion?

When you delete the IMG folders manually, do you also move them to "retired media set" in Backup Exec and then delete them from the "Retired Media Set". That removes the entry from the Backup Exec database. If you have IMGxxxxxxx entries in the database (in the "All Media" section of the GUI in the Media tab) that do no longer exists physically on the file system, maybe you're confusing the automatic cleanup process.
Only the latest IMG media appears in the database, so I assume that the previous days IMG media is being deleted by Backup Exec. However, the old IMG folder is still on the cartridge as well as the new one. I just delete it using Windows Explorer.
Ok, see how things go with new IMG folders. Are they still deleted from the database, but not from the cartridge?
Make sure Antivirus is not scanning the RD1000.
It's the same for new folders. Although I've deleted folders on some cartridges, I haven't deleted any folders from Monday's cartridge for the last 3 or 4 weeks.  The following folders are on the tape:
  IMG000070   27/04/2009   20:53
  IMG000078   11/05/2009   20:38
  IMG000083   18/05/2009   20:34
  VERITAS      22/12/2009   19:00

As usual there is only one IMG media in the database, the one from last night's backup:
  IMG000083    Media Created 18/05/2009 18:00:05    Overwritable   Not Appendable

Symantec Endpoint scans the RD1000, but the scheduled scan only runs at weekends when the backup is not running.
That looks like possibly a new bug. I can't find any references to it in Symantec's KB, but it's not normal that the "media" is removed from the database, but not from the phyisical cartridge.
There is one known problem: http://seer.entsupport.symantec.com/docs/317211.htm, but it doesn't match your symptoms as your IMG folder still contains several GB's of data.
I've been thinking about this. This is what happens:
1. During the nightly backup, Backup Exec creates a new IMG media in the database and a corresponding folder on the cartridge.
2. The following morning, the cartridge is swapped for a different one (we have one each weekday).
3.. That night, Backup Exec deletes the media created the previous night, but it cannot delete the folder as it is on the previous night's cartridge.

From that, it seems to me that the media needs to remain in the database until the corresponding day the following week. That way, the correct cartidge is in the drive and it can delete from the database and the cartridge at the same time.

I don't know whether it is relevant, but I notice that the IMG media appears in "Online Media" whereas the B2D media appear in "Offline media". Is this right?



Your theory makes sense.
Maybe you can solve it by changing your overwrite protection period on the media set.
Auto-expiry of IMG folders only happens when the corresponding IMG folder is overwritable. So if you make sure the IMG folder only becomes overwritable when the cartridge is back in the drive, the problem may be worked around. I think an overwrite protection period of 6 days should fo the trick.
Last week I set the overwrite protection for the Media Set to 6 days. I wasn't sure it would work as I got a warning message saying the overwrite protection is set to none, but from that point, the previous nights IMG media in the database was not being deleted. I've had to wait a week, though, to see if the media is deleted from both the database and from the cartridge on the corresponding day the next week, and it looks like it is working! The media from last Wednesday was last night deleted correctly from the database and from the Wednesday cartridge.

I'll monitor it for a few days to ensure it is working properly, but assuming it is, then the problem is finally fully solved and I will award the points. Thank you very much for all your help, and thanks for staying with me over several weeks, I'm very grateful.
I hate RD1000 drives.  They really cause me a lot of trouble.  I know this post is very old but I think you need to separate your job.  Backup your data and Exchange separately.  You divided them using the partition, instead have a second job that only backs up Exchange and turn off AOFO on this second job.