Backups fail with alot of errors..
Hello,
Our backups fail and i realy have no idea what to do or where to look.. What could this be?
Backup has failed. Please check the log for additional information.
1 Information 4-7-2013 11:47:25 Task 'Full Lan Backup' changed its state from 'idle' to 'running'.
2 Information 4-7-2013 11:47:25 Task 'Full Lan Backup' was started.
3 Information 4-7-2013 11:47:31 Backup deletion
4 Information 4-7-2013 11:47:37 1 backup(s) have been deleted from archive Full.TIB.
5 Information 4-7-2013 11:47:37 Backup deletion has successfully completed.
6 Information 4-7-2013 11:47:37 Backing up VM(s).
7 Information 4-7-2013 11:47:37 Successfully connected to 'VMware ESXi 5.0.0 build-623860'.
8 Information 4-7-2013 11:47:56 Successfully connected to 'VMware ESXi 5.0.0 build-623860'.
9 Error 4-7-2013 11:49:20 Failed to perform the requested operation.
Additional info:
--------------------
Error code: 13
Module: 149
LineInfo: d1ab7fa1e56ec9b9
Fields:
Message: Failed to perform the requested operation.
--------------------
Error code: 103
Module: 83
LineInfo: a859dd78cc91defd
Fields:
Message: Failed to open the virtual machine ([datastore1] srvv-w2k3-ex01.esep.local/srvv-w2k3-ex01.esep.local.vmx).
--------------------
Error code: 253
Module: 83
LineInfo: c7610e0a857bedf4
Fields:
Message: VMware error: 'Remote method call failed.'.
--------------------
Error code: 32
Module: 0
LineInfo: c7610e0a857bedf4
Fields:
Message: Awaiting task 'CreateSnapshot' has failed. Reason: An error occurred while quiescing the virtual machine. See the virtual machine's event log for details..
--------------------
10 Error 4-7-2013 11:49:21 The operation has failed.
Additional info:
--------------------
Error code: 26
Module: 100
LineInfo: 48afbd3608a410ca
Fields:
Message: The operation has failed.
--------------------
Error code: 1080
Module: 1
LineInfo: d1ab7fa1e56ec832
Fields:
Message:
--------------------
Error code: 13
Module: 149
LineInfo: d1ab7fa1e56ec9b9
Fields:
Message: Failed to perform the requested operation.
--------------------
Error code: 103
Module: 83
LineInfo: a859dd78cc91defd
Fields:
Message: Failed to open the virtual machine ([datastore1] srvv-w2k3-ex01.esep.local/srvv-w2k3-ex01.esep.local.vmx).
--------------------
Error code: 253
Module: 83
LineInfo: c7610e0a857bedf4
Fields:
Message: VMware error: 'Remote method call failed.'.
--------------------
Error code: 32
Module: 0
LineInfo: c7610e0a857bedf4
Fields:
Message: Awaiting task 'CreateSnapshot' has failed. Reason: An error occurred while quiescing the virtual machine. See the virtual machine's event log for details..
--------------------
11 Information 4-7-2013 11:49:21 Successfully connected to 'VMware ESXi 5.0.0 build-623860'.
12 Information 4-7-2013 11:50:55 Creating snapshot (4-7-2013 11:49:22).
13 Information 4-7-2013 11:51:00 Load virtual machine 'vm://A440765D-63CB-7616-4324-E8A5D8BE4168/525c834e-359e-08f9-6a1d-62e41be54e2f?host=ha-host&type=vmwesx' into the disk subsystem.
14 Information 4-7-2013 11:51:00 VMware_VDDK: SSLVerifyIsEnabled: failed to open the product registry key. Falling back to default behavior: verification off. LastError = 0
15 Information 4-7-2013 11:51:00 VMware_VDDK: SSL_VerifyX509: Certificate verification is disabled, so connection will proceed despite the error
16 Information 4-7-2013 11:51:02 VMware_VDDK: SSLVerifyIsEnabled: failed to open the product registry key. Falling back to default behavior: verification off. LastError = 0
17 Information 4-7-2013 11:51:02 VMware_VDDK: SSL_VerifyX509: Certificate verification is disabled, so connection will proceed despite the error
18 Information 4-7-2013 11:51:04 Analyzing partition 'C:'...
19 Information 4-7-2013 11:51:04 Analyzing partition 'D:'...
20 Information 4-7-2013 11:51:04 Analyzing partition 'E:'...
21 Information 4-7-2013 11:51:06 Analyzing partition '2-0'...
22 Information 4-7-2013 11:51:07 Analyzing partition '2-0'...
23 Information 4-7-2013 11:51:08 Create Incremental Backup From: Disk '1', Disk '2' To file: "avfs:/smb?//nas-esep-backup/backup/Full.TIB" Compression: Normal Exclude: Files matching mask Match criterion:
24 Information 4-7-2013 11:51:08 Backing up additional file 'srv-w2k3-dc01.esep.local.nvram'.
25 Information 4-7-2013 11:51:08 Backing up additional file 'srv-w2k3-dc01.esep.local.vmx'.
26 Information 4-7-2013 11:51:08 Backing up additional file 'srv-w2k3-dc01.esep.local.vmxf'.
27 Information 4-7-2013 11:51:08 Backing up additional file 'srv-w2k3-dc01.esep.local_6-000001.vmdk'.
28 Information 4-7-2013 11:51:09 Backing up additional file 'srv-w2k3-dc01.esep.local_6.vmdk'.
29 Information 4-7-2013 11:51:09 Backing up additional file 'srv-w2k3-dc01.esep.local_7-000001.vmdk'.
30 Information 4-7-2013 11:51:09 Backing up additional file 'srv-w2k3-dc01.esep.local_7.vmdk'.
31 Information 4-7-2013 11:51:09 Backing up additional file 'vss_manifests.zip'.
32 Information 4-7-2013 11:51:16 Pending operation 153 started: 'Creating partition image'.
33 Information 4-7-2013 11:51:28 CBT (Changed Block Tracking) information has been successfully retrieved.
34 Information 4-7-2013 11:51:52 Pending operation 153 started: 'Creating partition image'.
35 Information 4-7-2013 11:52:34 CBT (Changed Block Tracking) information has been successfully retrieved.
36 Information 4-7-2013 11:52:50 Pending operation 153 started: 'Creating partition image'.
37 Information 4-7-2013 11:53:55 CBT (Changed Block Tracking) information has been successfully retrieved.
38 Information 4-7-2013 11:54:11 Pending operation 150 started: 'Saving partition structure'.
39 Information 4-7-2013 11:54:11 Pending operation 150 started: 'Saving partition structure'.
40 Information 4-7-2013 11:54:12 Remove snapshot (13-snapshot-1934).
41 Information 4-7-2013 11:54:13 Successfully connected to 'VMware ESXi 5.0.0 build-623860'.
42 Information 4-7-2013 11:55:46 Creating snapshot (4-7-2013 11:54:13).
43 Information 4-7-2013 11:55:48 Load virtual machine 'vm://A440765D-63CB-7616-4324-E8A5D8BE4168/5294cf41-9562-e3d4-a209-cba4e54d2088?host=ha-host&type=vmwesx' into the disk subsystem.
44 Information 4-7-2013 11:55:48 VMware_VDDK: SSLVerifyIsEnabled: failed to open the product registry key. Falling back to default behavior: verification off. LastError = 0
45 Information 4-7-2013 11:55:48 VMware_VDDK: SSL_VerifyX509: Certificate verification is disabled, so connection will proceed despite the error
46 Information 4-7-2013 11:55:49 VMware_VDDK: SSLVerifyIsEnabled: failed to open the product registry key. Falling back to default behavior: verification off. LastError = 0
47 Information 4-7-2013 11:55:49 VMware_VDDK: SSL_VerifyX509: Certificate verification is disabled, so connection will proceed despite the error
48 Information 4-7-2013 11:55:51 Analyzing partition 'C:'...
49 Information 4-7-2013 11:55:52 Analyzing partition 'D:'...
50 Information 4-7-2013 11:55:54 Analyzing partition '2-0'...
51 Information 4-7-2013 11:55:54 Analyzing partition '2-0'...
52 Information 4-7-2013 11:55:55 Create Incremental Backup From: Disk '1', Disk '2' To file: "avfs:/smb?//nas-esep-backup/backup/Full.TIB" Compression: Normal Exclude: Files matching mask Match criterion:
53 Information 4-7-2013 11:55:55 Backing up additional file 'srvv-w2k3-sql01.esep.local-000001.vmdk'.
54 Information 4-7-2013 11:55:55 Backing up additional file 'srvv-w2k3-sql01.esep.local.nvram'.
55 Information 4-7-2013 11:55:56 Backing up additional file 'srvv-w2k3-sql01.esep.local.vmdk'.
56 Information 4-7-2013 11:55:56 Backing up additional file 'srvv-w2k3-sql01.esep.local.vmx'.
57 Information 4-7-2013 11:55:56 Backing up additional file 'srvv-w2k3-sql01.esep.local.vmxf'.
58 Information 4-7-2013 11:55:56 Backing up additional file 'srvv-w2k3-sql01.esep.local_1-000001.vmdk'.
59 Information 4-7-2013 11:55:56 Backing up additional file 'srvv-w2k3-sql01.esep.local_1.vmdk'.
60 Information 4-7-2013 11:55:56 Backing up additional file 'vss_manifests.zip'.
61 Information 4-7-2013 11:55:57 Pending operation 153 started: 'Creating partition image'.
62 Information 4-7-2013 11:56:25 CBT (Changed Block Tracking) information has been successfully retrieved.
63 Information 4-7-2013 11:56:42 Pending operation 153 started: 'Creating partition image'.
64 Information 4-7-2013 11:56:44 CBT (Changed Block Tracking) information has been successfully retrieved.
65 Information 4-7-2013 11:57:17 Pending operation 150 started: 'Saving partition structure'.
66 Information 4-7-2013 11:57:17 Pending operation 150 started: 'Saving partition structure'.
67 Information 4-7-2013 11:57:19 Remove snapshot (10-snapshot-796).
68 Information 4-7-2013 11:57:20 Task 'Full Lan Backup' changed its state from 'running' to 'idle'.
69 Error 4-7-2013 11:57:20 Task 'Full Lan Backup' failed: 'Failed to create a backup.
Additional info:
--------------------
Error code: 3
Module: 435
LineInfo: 555b5abba09501ce
Fields: $module : D:\Acronis\vmProtect\Windows Agent\vmms.exe
Message: Failed to create a backup.
--------------------
Error code: 32786
Module: 114
LineInfo: 28314c961de7d32e
Fields:
Message: Failed to prepare for backing up.
--------------------
Error code: 353
Module: 149
LineInfo: a71592046cb2c5f6
Fields:
Message: Failed to back up the group.
--------------------
Error code: 2
Module: 218
LineInfo: cd07f9d978d3a2a3
Fields:
Message: Error occurred while running the backup and recovery engine.
--------------------'.

- Log in to post comments

Hi Vasily,
I see some events. Not sure if they belong to this backup job/problem.
Event Type: Error
Event Source: MSExchangeIS
Event Category: Exchange VSS Writer
Event ID: 9607
Date: 4-7-2013
Time: 13:30:40
User: N/A
Computer: SRVV-W2K3-EX01
Description:
Error code 0x50d when preparing for backup.
-----------------------------------------------------------
Event Type: Information
Event Source: MSExchangeIS
Event Category: Exchange VSS Writer
Event ID: 9614
Date: 4-7-2013
Time: 13:30:40
User: N/A
Computer: SRVV-W2K3-EX01
Description:
Exchange VSS Snapshot has aborted snapshot successfully.
-----------------------------------------------------------
Event Type: Information
Event Source: ESENT
Event Category: ShadowCopy
Event ID: 2001
Date: 4-7-2013
Time: 13:30:53
User: N/A
Computer: SRVV-W2K3-EX01
Description:
certsrv.exe (1264) Shadow copy 3 freeze started.
-----------------------------------------------------------
Event Type: Information
Event Source: ESENT
Event Category: ShadowCopy
Event ID: 2003
Date: 4-7-2013
Time: 13:30:56
User: N/A
Computer: SRVV-W2K3-EX01
Description:
certsrv.exe (1264) Shadow copy 3 freeze stopped.
-----------------------------------------------------------
Event Type: Information
Event Source: MSExchangeIS
Event Category: Exchange VSS Writer
Event ID: 9648
Date: 4-7-2013
Time: 13:31:00
User: N/A
Computer: SRVV-W2K3-EX01
Description:
Exchange VSS Snapshot backup has been shutdown successfully.
-----------------------------------------------------------
Acronis backup job failed at 99%.. with again the following information. Any idea?
Failed to perform the requested operation.
Additional info:
--------------------
Error code: 13
Module: 149
LineInfo: d1ab7fa1e56ec9b9
Fields:
Message: Failed to perform the requested operation.
--------------------
Error code: 103
Module: 83
LineInfo: a859dd78cc91defd
Fields:
Message: Failed to open the virtual machine ([datastore1] srvv-w2k3-ex01.esep.local/srvv-w2k3-ex01.esep.local.vmx).
--------------------
Error code: 253
Module: 83
LineInfo: c7610e0a857bedf4
Fields:
Message: VMware error: 'Remote method call failed.'.
--------------------
Error code: 32
Module: 0
LineInfo: c7610e0a857bedf4
Fields:
Message: Awaiting task 'CreateSnapshot' has failed. Reason: An error occurred while quiescing the virtual machine. See the virtual machine's event log for details..
--------------------
- Log in to post comments

Hi Joey,
The job is marked as failed since there was a backup failure on [datastore1] srvv-w2k3-ex01.esep.local/srvv-w2k3-ex01.esep.local.vmx VM. It goes up to 99% because it backs up the other VMs selected in the backup task (which can be backed up properly). The VSS events you quoted seem to be normal ones (type: Information) so it must be something else.
I'd recommended to perform manual snapshot of this VM via vSphere Client with the following options: quiesced=on, snapshot memory=off (vmProtect calls snapshot with the same parameters). This attempt should fail and you will be able to track it down by checking VMware KB articles or contacting VMware support for assistance.
Thank you.
--
Best regards,
Vasily
Acronis vmProtect Program Manager
- Log in to post comments

Hello Vasily,
A manual snapshot is completed:
Create virtual machine snapshot srvv-w2k3-ex01.****.local Completed.
Used the options you mentioned. Should i retry the acronis backup?
- Log in to post comments

I was able to complete a full backup after making a manual snapshot as you mentioned.
- Log in to post comments

Hi Joey,
Thank you for the notes. In general the rule is the following: as long as VMware quiesced snapshot works, the vmProtect backup will succeed. The quiesced snapshots may fail intermittently in vSphere environment (depending on the ESX(i) hosts load/VM load and many other factors). In the 9th version of vmProtect which is currently in Beta stage (see http://forum.acronis.com/forum/42675) we have added an option to automatically re-try the failed VM processing (i.e. retry the snapshot operation) under Backup Options->Error Handling. This option should help with such cases.
Thank you.
--
Best regards,
Vasily
Acronis vmProtect Program Manager
- Log in to post comments

Hi Joey, I'm just checking up here. I wanted to know what version you currently have on right now. I was just browsing around for a stable one.
- Log in to post comments