Skip to main content

VMProtect9 fails to backup Domain Controller...

Thread needs solution

I am running ESXI 5.5. Trying to back up one of our Domain controllers (Server 2003 R2) using app-aware (active Directory). Our vmprotect instance is the Windows version.

The initial backup went just fine. When VMProtect goes to make the next (incrimental) backup, it claims to have succeed, but actually fails. The log:
Backup has been successfully completed.
1 Information 1/20/2014 11:53:44 AM Task 'Back up TRDC02 Domain Controller' changed its state from 'idle' to 'running'.
2 Information 1/20/2014 11:53:44 AM Task 'Back up TRDC02 Domain Controller' was started.
3 Information 1/20/2014 11:53:45 AM Backing up VM(s).
4 Information 1/20/2014 11:53:46 AM Successfully connected to 'VMware vCenter Server 5.5.0 build-1312298'.
5 Information 1/20/2014 11:53:46 AM Successfully connected to 'VMware ESXi 5.5.0 build-1331820' through VMware vCenter Server.
6 Information 1/20/2014 11:53:47 AM Successfully connected to 'VMware ESXi 5.5.0 build-1331820' through VMware vCenter Server.
7 Information 1/20/2014 11:53:47 AM Successfully connected to 'VMware ESXi 5.5.0 build-1331820' through VMware vCenter Server.
8 Information 1/20/2014 11:53:47 AM Successfully connected to 'VMware ESXi 5.5.0 build-1331820' through VMware vCenter Server.
9 Information 1/20/2014 11:53:49 AM Successfully connected to 'VMware vCenter Server 5.5.0 build-1312298'.
10 Information 1/20/2014 11:53:52 AM Successfully connected to 'VMware vCenter Server 5.5.0 build-1312298'.
11 Information 1/20/2014 11:53:52 AM Successfully connected to 'VMware ESXi 5.5.0 build-1331820' through VMware vCenter Server.
12 Information 1/20/2014 11:54:42 AM Collected meta backup started for application: Active Directory
13 Information 1/20/2014 11:54:42 AM Meta collection started for application: Active Directory
14 Information 1/20/2014 11:55:04 AM Creating snapshot (1/20/2014 11:54:43 AM).
15 Information 1/20/2014 11:55:06 AM Loading virtual machine 'vm://2DB71899-EBCB-491F-9460-1A1297FD9A65/5012fc1c-6d25-bc7a-6cf1-0e8dffd96856?host=host-41&type=vmwesx' into the disk subsystem.
16 Information 1/20/2014 11:55:07 AM VMware_VDDK: SSLVerifyIsEnabled: failed to open the product registry key. Falling back to default behavior: verification off. LastError = 0
17 Information 1/20/2014 11:55:07 AM VMware_VDDK: SSL_VerifyX509: Certificate verification is disabled, so connection will proceed despite the error
18 Information 1/20/2014 11:55:09 AM VMware_VDDK: SSLVerifyIsEnabled: failed to open the product registry key. Falling back to default behavior: verification off. LastError = 0
19 Information 1/20/2014 11:55:09 AM VMware_VDDK: SSL_VerifyX509: Certificate verification is disabled, so connection will proceed despite the error
20 Information 1/20/2014 11:55:10 AM Analyzing partition 'C:'...
21 Information 1/20/2014 11:55:10 AM Analyzing partition 'D:'...
22 Information 1/20/2014 11:55:18 AM Analyzing partition '2-0'...
23 Information 1/20/2014 11:55:18 AM Analyzing partition '2-0'...
24 Information 1/20/2014 11:55:19 AM Create Incremental Backup From: Disk '1', Disk '2' To file: "avfs:/local?E:/TRDC02-DomainController.TIB" Compression: High Exclude: Files matching mask Match criterion:
25 Information 1/20/2014 11:55:20 AM Backing up additional file 'TRDC02-000001.vmdk'.
26 Information 1/20/2014 11:55:21 AM Backing up additional file 'TRDC02.nvram'.
27 Information 1/20/2014 11:55:22 AM Backing up additional file 'TRDC02.vmdk'.
28 Information 1/20/2014 11:55:23 AM Backing up additional file 'TRDC02.vmx'.
29 Information 1/20/2014 11:55:24 AM Backing up additional file 'TRDC02.vmxf'.
30 Information 1/20/2014 11:55:24 AM Backing up additional file 'TRDC02_1-000001.vmdk'.
31 Information 1/20/2014 11:55:25 AM Backing up additional file 'TRDC02_1.vmdk'.
32 Information 1/20/2014 11:55:26 AM Backing up additional file '82AD566D-4544-4341-83E8-BFBEF2847028_ad'.
33 Information 1/20/2014 11:55:26 AM Backing up additional file 'vss_manifests.zip'.
34 Information 1/20/2014 11:55:33 AM Error occurred while reading the file.
Additional info:
--------------------
Error code: 1
Module: 4
LineInfo: 7ceb2cdc9fb12059
Fields: function : ReadFile
Message: Error occurred while reading the file.
--------------------
Error code: 65520
Module: 0
LineInfo: bd28fdbd64edb8bf
Fields: code : 2147943850
Message: Insufficient system resources exist to complete the requested service
--------------------
35 Error 1/20/2014 11:55:33 AM Cannot perform this operation in quiet mode.

Error code: 0x10407
Tag: 0xFDC1CBDF2C233660
Error occurred while reading the file. Insufficient system resources exist to complete the requested service

Error code: 0x40001
Tag: 0xFDC1CBDF2C233661
36 Information 1/20/2014 11:55:34 AM Remove snapshot (snapshot-3597).
37 Information 1/20/2014 11:55:44 AM The disaster recovery plan has been successfully created as file 'DRP for Back up TRDC02 Domain Controller' in location '\\trstorage\Backups\VM_Backups\'.
38 Information 1/20/2014 11:55:44 AM Task 'Back up TRDC02 Domain Controller' changed its state from 'running' to 'idle'.
39 Information 1/20/2014 11:55:44 AM Task 'Back up TRDC02 Domain Controller' succeeded.

Ideas? I verified that vmware tools (vss provider) is installed in the VM.

Attachment Size
log.zip 2.18 KB
0 Users found this helpful
frestogaslorastaswastavewroviwroclolacorashibushurutraciwrubrishabenichikucrijorejenufrilomuwrigaslowrikejawrachosleratiswurelaseriprouobrunoviswosuthitribrepakotritopislivadrauibretisetewrapenuwrapi
Posts: 22
Comments: 3800

Hi Bill,

The problem here appears to be related to the specifics of Windows OS where vmProtect Agent is installed. The error "Insufficient system resources exist to complete the requested service" is a common one and is related to file copying operation (when vmProtect tries to copy the data over to backup location). I'd recommended first of all increasing the IRPStackSize value up to 18 as described in http://social.technet.microsoft.com/Forums/windowsserver/en-US/5fb3cd43… . If this doesn't help then check Windows Event log for errors occurred while the backup was running - it may give you more clues.

The possible workaround is to install vmProtect as Virtual Appliance onto the ESXi host where the VM resides and back up the AD VM to the share on the original Windows Machine (share the E: drive to make it accessible over network, so that you can back up to it from the Virtual Appliance). The performance should be approximately the same unless you are have direct SAN access set up (ESXi datastore LUNs are attached to Windows Agent).

I'd recommended to localize the issue first of all, i.e. try running a virtual appliance to make sure that the problem is related to Windows Agent only and after it is confirmed - try inreasing the IRPStackSize value on the Windows Agent side.

Thank you.
--
Best regards,
Vasily
Acronis vmProtect Program Manager

Will try the stack size and let you know. I am running VMProtect in a Windows machine, not the appliance (created my own appliance on a stand alone Server 2003 R2 machine). The Linux appliance ate up a lot of resources and HATED my Windows share in the off-site location :P

Will try the stack size and let you know. I am running VMProtect in a Windows machine, not the appliance (created my own appliance on a stand alone Server 2003 R2 machine). The Linux appliance ate up a lot of resources and HATED my Windows share in the off-site location :P

I am assuming the changes are to be made on the Domain Controller, so...
I set the IPRPStackSize to 0x20, PoolUsageMaximum to 50 (decimal), PagedPoolSize to ffffffff and rebooted the VM. (domain controller)
Same issue.
Cleared event logs in the VM, re-ran the job again, same issue. event logs in the VM show no issues. VMware snapshot provider starts as usual.
The backup job starts, snapshot made, gets to 4% (in a minute or so), then removes snapshot and fails.
Which one do I change to see if it gets further?

Log:
Backup has been successfully completed.
1 Information 1/21/2014 3:33:10 PM Task 'Back up TRDC02 Domain Controller' changed its state from 'idle' to 'running'.
2 Information 1/21/2014 3:33:10 PM Task 'Back up TRDC02 Domain Controller' was started.
3 Information 1/21/2014 3:33:10 PM Backing up VM(s).
4 Information 1/21/2014 3:33:11 PM Successfully connected to 'VMware vCenter Server 5.5.0 build-1312298'.
5 Information 1/21/2014 3:33:11 PM Successfully connected to 'VMware ESXi 5.5.0 build-1331820' through VMware vCenter Server.
6 Information 1/21/2014 3:33:12 PM Successfully connected to 'VMware ESXi 5.5.0 build-1331820' through VMware vCenter Server.
7 Information 1/21/2014 3:33:12 PM Successfully connected to 'VMware ESXi 5.5.0 build-1331820' through VMware vCenter Server.
8 Information 1/21/2014 3:33:12 PM Successfully connected to 'VMware ESXi 5.5.0 build-1331820' through VMware vCenter Server.
9 Information 1/21/2014 3:33:13 PM Successfully connected to 'VMware vCenter Server 5.5.0 build-1312298'.
10 Information 1/21/2014 3:33:17 PM Successfully connected to 'VMware vCenter Server 5.5.0 build-1312298'.
11 Information 1/21/2014 3:33:17 PM Successfully connected to 'VMware ESXi 5.5.0 build-1331820' through VMware vCenter Server.
12 Information 1/21/2014 3:34:07 PM Collected meta backup started for application: Active Directory
13 Information 1/21/2014 3:34:07 PM Meta collection started for application: Active Directory
14 Information 1/21/2014 3:34:23 PM Creating snapshot (1/21/2014 3:34:08 PM).
15 Information 1/21/2014 3:34:25 PM Loading virtual machine 'vm://2DB71899-EBCB-491F-9460-1A1297FD9A65/5012fc1c-6d25-bc7a-6cf1-0e8dffd96856?host=host-41&type=vmwesx' into the disk subsystem.
16 Information 1/21/2014 3:34:26 PM VMware_VDDK: SSLVerifyIsEnabled: failed to open the product registry key. Falling back to default behavior: verification off. LastError = 0
17 Information 1/21/2014 3:34:26 PM VMware_VDDK: SSL_VerifyX509: Certificate verification is disabled, so connection will proceed despite the error
18 Information 1/21/2014 3:34:28 PM VMware_VDDK: SSLVerifyIsEnabled: failed to open the product registry key. Falling back to default behavior: verification off. LastError = 0
19 Information 1/21/2014 3:34:28 PM VMware_VDDK: SSL_VerifyX509: Certificate verification is disabled, so connection will proceed despite the error
20 Information 1/21/2014 3:34:29 PM Analyzing partition 'C:'...
21 Information 1/21/2014 3:34:30 PM Analyzing partition 'D:'...
22 Information 1/21/2014 3:34:38 PM Analyzing partition '2-0'...
23 Information 1/21/2014 3:34:38 PM Analyzing partition '2-0'...
24 Information 1/21/2014 3:34:39 PM Create Incremental Backup From: Disk '1', Disk '2' To file: "avfs:/local?E:/TRDC02-DomainController.TIB" Compression: High Exclude: Files matching mask Match criterion:
25 Information 1/21/2014 3:34:40 PM Backing up additional file 'TRDC02-000001.vmdk'.
26 Information 1/21/2014 3:34:41 PM Backing up additional file 'TRDC02.nvram'.
27 Information 1/21/2014 3:34:42 PM Backing up additional file 'TRDC02.vmdk'.
28 Information 1/21/2014 3:34:43 PM Backing up additional file 'TRDC02.vmx'.
29 Information 1/21/2014 3:34:43 PM Backing up additional file 'TRDC02.vmxf'.
30 Information 1/21/2014 3:34:44 PM Backing up additional file 'TRDC02_1-000001.vmdk'.
31 Information 1/21/2014 3:34:45 PM Backing up additional file 'TRDC02_1.vmdk'.
32 Information 1/21/2014 3:34:46 PM Backing up additional file '82AD566D-4544-4341-83E8-BFBEF2847028_ad'.
33 Information 1/21/2014 3:34:46 PM Backing up additional file 'vss_manifests.zip'.
34 Information 1/21/2014 3:34:54 PM Error occurred while reading the file.
Additional info:
--------------------
Error code: 1
Module: 4
LineInfo: 7ceb2cdc9fb12059
Fields: function : ReadFile
Message: Error occurred while reading the file.
--------------------
Error code: 65520
Module: 0
LineInfo: bd28fdbd64edb8bf
Fields: code : 2147943850
Message: Insufficient system resources exist to complete the requested service
--------------------
35 Error 1/21/2014 3:34:54 PM Cannot perform this operation in quiet mode.

Error code: 0x10407
Tag: 0xFDC1CBDF2C233660
Error occurred while reading the file. Insufficient system resources exist to complete the requested service

Error code: 0x40001
Tag: 0xFDC1CBDF2C233661
36 Information 1/21/2014 3:34:54 PM Remove snapshot (snapshot-3611).
37 Information 1/21/2014 3:34:55 PM Task 'Back up TRDC02 Domain Controller' changed its state from 'running' to 'idle'.
38 Information 1/21/2014 3:34:55 PM Task 'Back up TRDC02 Domain Controller' succeeded.

frestogaslorastaswastavewroviwroclolacorashibushurutraciwrubrishabenichikucrijorejenufrilomuwrigaslowrikejawrachosleratiswurelaseriprouobrunoviswosuthitribrepakotritopislivadrauibretisetewrapenuwrapi
Posts: 22
Comments: 3800

Hi Bill,

The IRPStackSize value should be increased on the Windows machine where you have vmProtect Agent installed (the standalone Windows Server 2003 R2). Looks like you increased it on the wrong computer (DC) :( . In fact this value makes sense mostly for Windows Server 2003, while it's not applicable to Win2k8 or higher.

Thank you.
--
Best regards,
Vasily
Acronis vmProtect Program Manager

I took IRPStackSize to 32, same issue. I also changed PoolUsageMaximum to 60 and PagedPoolSize to FFFFFFFF and rebooted.
No change. Nothing in the Windows event logs.

So is this strictly a server 2003 issue? I COULD use a different OS if needed for my appliance :D What ones are supported (and recommended)?

Added info: Here is the appliance set up:
Server 2003 R2 (sp2) 64-bit
2 Gigs RAM
Dual Xeon processors (older ones)
129 GB left on boot drive
ISCSI connection to backup storage drive.

I DO have another server I could use that has 4 gigs RAM and I-5 processor (quad core, same speed as old xeons) if needed.

I created a new appliance with Server 2008 R2 and looks like the backup is proceeding (although a full is being done since too many changes occured I guess)

It is at 25% and still going. Only thing in the logs so far is:
Forced sector-by-sector mode.
Additional info:
--------------------
Error code: 46
Module: 7
LineInfo: a5695862aaf8e775
Fields: PartitionId : 221
Message: Forced sector-by-sector mode.
--------------------
Error code: 28
Module: 7
LineInfo: 89d94b01b483dcca
Fields:
Message: Run list is corrupted.
--------------------
:)

frestogaslorastaswastavewroviwroclolacorashibushurutraciwrubrishabenichikucrijorejenufrilomuwrigaslowrikejawrachosleratiswurelaseriprouobrunoviswosuthitribrepakotritopislivadrauibretisetewrapenuwrapi
Posts: 22
Comments: 3800

Hi Bill,

Yes, the problem is specific to Win2k3 but not really to the hardware specs of your system (the ones you listed are more than enough) - some dancing with IRPStackSize value should've helped (I've seen cases when IRPStackSize=20 didn't work, while IRPStackSize=18 did the trick - it's really kind of a magic parameter :)). Though from what I can see you had more success with vmProtect Agent Win2k8 R2, so let's stick to it.

The last quoted message from the logs means that the backup is made in sector-by-sector mode since there were errors found on the file system. It makes sense to run chkdsk inside the guest OS of the backed up VM.

There is a known issue (see http://forum.acronis.com/forum/42770#comment-134286) describing similar symptoms but it is related only to backup of Win2k8 and higher guest OSes, while in your case you're backing up a DC installed on Win2k3, so it must be something on the guest OS file system and chkdsk should help to reveal it.

Thank you.
--
Best regards,
Vasily
Acronis vmProtect Program Manager

Cool cool. Ran chkdsk and fixed it. FYI, I LOVE the feature that warns you... Points out issues before they otherwise get noticed!!!
BTW.. in some of the posts, Acronis recommends changing a VM size to fix certain issues.. What if its a vRDM?
Thanks again for all the help!

frestogaslorastaswastavewroviwroclolacorashibushurutraciwrubrishabenichikucrijorejenufrilomuwrigaslowrikejawrachosleratiswurelaseriprouobrunoviswosuthitribrepakotritopislivadrauibretisetewrapenuwrapi
Posts: 22
Comments: 3800

Hi Bill,

Glad I could help :) Can you show me some links where changing the VM size is recommended, so that I can check? I don't recall any specific issues where these actions might be necessary. We do adjust the size of the disks upon the restore in some cases (align the sectors), but it's really not something that should be done manually.

Thank you.
--
Best regards,
Vasily
Acronis vmProtect Program Manager

http://kb.acronis.com/content/36993 (seeing the 46/24 messages on a cpl vm's, ran chkdsk already)

Also, Any idea why the VMProtect recovery plan would have the IP address of the ISCSI nic instead of the one connected to Vcenter? (the one that the admins / users can get to)
1. Connect to the agent at https://192.168.200.28:9877. Should be 10.0.1.28:9877

Installed with the ISCSI nic turned off, so VCenter plugin is fine, etc. Just wrong address in that message. Is it editable?

And yes, the host shows right with the vcenter address on the network :D

frestogaslorastaswastavewroviwroclolacorashibushurutraciwrubrishabenichikucrijorejenufrilomuwrigaslowrikejawrachosleratiswurelaseriprouobrunoviswosuthitribrepakotritopislivadrauibretisetewrapenuwrapi
Posts: 22
Comments: 3800

Hi Bill,

Concerning KB 36993 - I've posted the link to the thread where these messages were explained: http://forum.acronis.com/forum/42770#comment-134286 . In short it's safe to ignore them for Win2k8+ guest VMs.

The address of the vmProtect agent in DRP is picked up from the OS settings and vmProtect takes the 1st discovered NIC (in your case it appears that iSCSI interface is the first one and therefore it is picked up). This setting is not configurable at the moment unfortunately.

Thank you.
--
Best regards,
Vasily
Acronis vmProtect Program Manager

Vasily wrote:

Hi Bill,

The address of the vmProtect agent in DRP is picked up from the OS settings and vmProtect takes the 1st discovered NIC (in your case it appears that iSCSI interface is the first one and therefore it is picked up). This setting is not configurable at the moment unfortunately.

LOL I fixed it the 'old school' easy way. Very High tech and hush-hush...
I set both nics to dhcp, reversed the cables, then set the addresses back in to the correct NICs. :D Now the report has the right IP Address :P