Copy to tape failing with error 0xe0009585 after backup to disk ran fine

[Artegic]

I have Backup Exec 2012 with all current patches running on Windows Server 2008 backing up several Windows and Linux VMs from a VMware ESXi 5.0 host in a D2D2T scheme with daily incremental and weekly full backups. GRT is enabled for the Windows VMs.

Most of the VMs are backed up without problems. For one Windows 7 VM, however, the tape copy job after the daily incremental backup reports the following error every time (translated from German):

Final error: 0xe0009585 - Unable to open a disk of the virtual machine.
Final error category: Resource error

You'll find additional information on this error at the link V-79-57344-38277
http://entced.symantec.com/entt?product=BE&version=14.0.1798.1300&module=eng-no_fs-base_task&error=V-79-57344-38277&language=EN&build=Retail&os=Windows

Copy
V-79-57344-38277 - Unable to open a disk of the virtual machine.

- WARNING: "VMVCB::\\uranus\VCGuestVm\(DC)ha-datacenter(DC)\vm\rds - Win7 Prof.\rds - Win7 Prof.\Windows 7 Prof..vmdk" is damaged. File check not possible.

The incremental backup to disk itself runs fine; its only the subsequent copy to tape that fails. (Leaving me wondering why that copy job needs to open the disk of the virtual machine at all.) Also, the copy job after the weekly full backup runs without an error; it's only the copy job after the incremental that fails. (Leaving me wondering why the virtual disk is damaged on weekdays but ok on weekends.)

The link V-79-57344-38277 produces offers four tech articles: one referring to a restore problem; two referring to an error message I do not get ("You do not have access rights to this file."); and one describing a problem that was fixed with Hotfix 199866 which I have installed already.

A KB search turned up article TECH198982 which seems to fit my symptoms but identifies no cause and as only solution proposes to install Service Pack 3 which I have installed already. All other hits either refer to the "no access rights" message above, or to restore, or describe scenarios that would affect backups of all VMs, not just one of them.

Ideas?

Thanks,

Tilman

[lmosla]

It is possible that the job got corrupted or there is a conflict with something else running at the same time.

Check to see if Windows Application/Security Event Logs have errors during the backup job.

has the machine been rebooted recently 

also see if recreating the job clears up the errors

[Artegic]

Thanks for the reply.

I checked the event logs on both server and client. The client shows no errors or warnings at the time the backup job is running. On the server there is the Backup Exec/34113 event when Backup Exec reports the failed job, but no other errors.

I have now recreated the copy job and will check how it'll behave tonight.

[Colin_Weaver]

I am not sure why this would not break operations well before the duplicate of the incremental but do you have a full stop/period/decimal point character (.) at the end of the name of your VM (i.e. rds - Win7 Prof. )

Whilst I do not know for sure that this would be a problem, we have had issues with things like & characters in the past and it is therefore possible the a . character could be having an effect.

Do any of the VM's that don't have a problem also have a . at the end of their names?

[Artegic]

There is one other VM whose name ends in a period '.' and that one is backed up without a problem both fully and incrementally:

"VMVCB::\\uranus\VCGuestVm\(DC)ha-datacenter(DC)\vm\TEST Windows 7 Prof."

The configuration is however not quite identical. This one is backed up directly to tape. The failing one goes to a disk deduplication volume first before being copied to tape, and it's only the second step that fails.

Meanwhile, tonight I had another completely different D2D2T job also fail in the copy to tape step after the backup to disk failed. No idea if that's related. This one backs up an Exchange 2010 server, and the error was:

Final error: 0xe00002f7 - Cannot extract mailbox messages from the Exchange backup. Review the job log for more information
V-79-57344-759 - Unable to complete the operation for the following reason: VFF Open Failure.  This can be caused by low memory or disk resources.

I found TECH205240 but this isn't a DAG, I did back up to disk, and it's strange that the error shows up on the copy to tape job after the backup job proper completed without errors. Again, no errors in the event log except for a probably unrelated MSExchangeTransport/1035 "LogonDenied error during incoming authentication".

[Artegic]

With the recreated copy job, there are now two VMs producing this error:

"VMVCB::\\uranus\VCGuestVm\(DC)ha-datacenter(DC)\vm\rds - Win7 Prof.\rds - Win7 Prof.\Windows 7 Prof..vmdk"

"VMVCB::\\uranus\VCGuestVm\(DC)ha-datacenter(DC)\vm\lexware\lexware\lexwaretemp.vmdk"

As you can see, the second one's name does not end in a period, so that cause is excluded.

Meanwhile, the error from the Exchange server has not reoccurred.

I have now added the first one (rds - Win7 Prof.) to the direct to tape job as a test and will report back the results. In the meantime, I'd be grateful for any hints.

Thanks,
Tilman

[lmosla]

For further troubleshooting run SGmon Using the Backup Exec Debug Monitor (SGMon) for troubleshooting

[pkh]

Just a wild guess.  Could it be that (DC)ha-datacenter(DC)  is the problem because of the ( ) brackets?

[Artegic]

@pkh: I think I can exclude that as a cause. The "(DC)ha-datacenter(DC)" string appears identically in all our VMware backup jobs, those that work fine as well as those that exhibit the error.

As another test, I added the failing VM "rds - Win7 Prof." to the job backing up VMs directly to tape. That backup ran without a problem. The failure only happens with D2D2T.

I'm trying to find my way around SGMon now. So far I'm a bit at a loss which capture categories to select and how to find the needle of messages related to the failure in the haystack of apparent routine messages. Any hints on what to look for or how to weed out the noise welcome.

[Artegic]

Sorry for the silence. Other problems with that Backup Exec installation are currently preventing me from pursuing this one. Will report back as soon as I have new findings.

[Artegic]

Update: general problems with that Backup Exec installation have prevented the job in question from running between 2013-12-24 and 2014-01-18. When it was finally able to run again this Monday, the error was back exactly as before.

Yesterday I made a configuration change, adding a monthly copy stage and modifying the schedule of the backup stage, and scheduled an out of cycle full backup to make the warning about changed settings go away. On the following regular incremental job, the error had changed as follows:

• The backup to disk, which previously completed without errors, now reports error V-79-57344-34009 - An error was encountered creating on-disk catalog. If this is an incremental backup, cataloging of the generated media may not work correctly.
• The copy to tape, which previously reported error V-79-57344-38277 as described in the OP, now completes without errors.

SGMon produces an enormous heap of messages but nothing that appears in any way related to the problem. I'm at a complete loss what to try next.

Thanks in advance for any hints.

Tilman

[Artegic]

Another update: The error V-79-57344-34009 actually prevented the failing VM "rds - Win7 Prof." from being backed up to disk in the first place, so it's unsurprising in hindsight that it wouldn't trigger the error in the subsequent copy to tape stage anymore.

Now with the next regular full backup, the error V-79-57344-34009 has gone away, and V-79-57344-38277 is back.

[Artegic]

I have now captured a SGMon log from a failing copy job. It covers an interval of 8:30 mins and is 40 MB in size. The actual job ran for 7:13 mins. Neither "V-79-57344-38277" nor "E0009585" appear in the log literally, but a search for "9585" revealed this block of messages:

BEREMOTE: [02.05.14 11:05:55] [8136]     2014-02-05T11:05:55.118 [fsys\shared]        - vddkWrapper::FindMatchingDisk FindFirstFile failed for \\.pdvfs\GOLGI\2\BEData\STHVMDK\IMG001235\Windows 7 Prof.*.vmdk. Windows Error = 2
BEREMOTE: [02.05.14 11:05:55] [8136]     2014-02-05T11:05:55.118 [fsys\shared]        - vddkWrapper::VixDiskLib_OpenLocal: FindMatchingDisk returned empty string. Disk, = \\.pdvfs\GOLGI\2\BEData\STHVMDK\IMG001242\Windows 7 Prof..vmdk, ancestor location = \\.pdvfs\GOLGI\2\BEData\STHVMDK\IMG001235
BEREMOTE: [02.05.14 11:05:55] [8136]     2014-02-05T11:05:55.118 [fsys\vmvcb\pdi]     - Could not open the local disk \\.pdvfs\GOLGI\2\BEData\STHVMDK\IMG001242\Windows 7 Prof..vmdk. Error Text: 'Invalid disk chain: cannot mix hosted and managed style disks in the same chain' Error: '16030'
BEREMOTE: [02.05.14 11:05:55] [8136]     2014-02-05T11:05:55.119 [ndmp\loops]         - LP_ENV::MsgError: error 0xe0009585 processing object rds - Win7 Prof.\Windows 7 Prof..vmdk

Again, this happens reproducibly, only on the copy to tape stage of an incremental backup, and only for this single VM. Copies of three other VMs included in the same job work fine. The preceding backup to disk stage completed without errors or warnings for all four VMs. For full backup runs of the same job, both backup to disk and copy to tape complete without errors or warnings.

Ideas?

Thanks,
Tilman

[Artegic]

I tried opening a support case for this last Friday but only got an automated E-mail answer: "We received your request and are working to grant you access to view and manage your support cases." Since then, nothing. Even tried a second time, with the same result. The two case numbers, 05992961 and 05993223, don't even appear on our account in the support portal so far. I guess I'll have to use the phone again.

[Artegic]

The case has now appeared in the support portal, and I got an E-mail from a support technician saying:

I would really appreciate if you could provide me with an update on the status of this issue.

Which left me a bit baffled. What kind of status update am I supposed to provide on a case where nothing has happened yet? I tried to call back but was told by the call management system that the person handling the case was unavailable. I guess it will take some time before I'll get anywhere there.

Meanwhile I would still be grateful for any hints about things I could try on my own.

[Artegic]

Things are starting to move. Today I had a WebEx session with a Symantec support engineer, who noticed that the issue involved virtualization and should consequently be reassigned to the VM team. Obviously he couldn't trust my problem description which said exactly that, and had to see it with his own eyes.

I do hope that reassignment will now lead to some actual progress.

[Artegic]

Update: After many WebEx sessions with an engineer from the VM team the case has been escalated. Now going through everything once again with the new engineer. No sign of a solution so far.

[Artegic]

Update: Last week I installed the recently released Service Pack 4. No improvement, the error occurs as before.

[Artegic]

Update: According to the last support engineer I spoke to the problem has been reproduced in the lab now (a mere two months after I opened the case) and it is now confirmed that the problem is caused by the name of the VMDK file "Windows 7 Prof..vmdk" having two dots in a row before the VMDK extension.

(The other VM I have with a name ending on a dot had originally been created as a copy of another VM so its VMDK file is named like "Windows 7 Prof._1.vmdk" which doesn't trigger the problem.)

Technote TECH216480 has been created for the case.

The workaround hinted at in the technote is to first duplicate the backup from the deduplication storage to a separate (non-deduplication) disk storage and in a second step from there to tape. I have not tested that as it would be too complicated to set up in my environment. Instead I am backing up the affected machine directly to tape which works fine.

[Artegic]

The jury (ie. Symantec engineering) is still out on the case.

In the meantime I have switched to backing up that VM with RAWS instead of AVVI, which also works fine. As a long term solution I plan renaming the VMDK file, but the procedure for that is rather complicated and involves a downtime for the VM, so it won't be for tomorrow.