I'm trying to get the VMware image backups working...
And in fact, if I shut down the VM I'm trying to back up, it works just fine.
However, if the VM is running, I get errors in vSphere saying it's unable access vmname/vmname.vmx... and also vmname/vmname.nvram
Then it fails. The Activity log in the avamar administrator shows "Cancelled" and "10013" as the error code.
I tried manually copying this file to another location on the same datastore using the vSphere client, and it also fails with the same error (in vSphere)... "unable to access file..."
If I manually snapshot a VM using the vSphere client, the snapshot works just fine.
2010-03-29 14:49:12 avvcbimage Info <5241>: Logging to /usr/local/avamar/var/MOD-1269888518992-a5c2af6a74e913a88014f83172b2e9dd912a67a8-3016-vmimage.log 2010-03-29 14:49:12 avvcbimage Info <5174>: - Reading /usr/local/avamar/var/avvcbimage.cmd 2010-03-29 14:49:12 avvcbimage Info <6636>: CTL listening on port 59487 2010-03-29 14:49:12 avvcbimage Info <5174>: - Reading /usr/local/avamar/var/avvcbimage.cmd 2010-03-29 14:49:12 avvcbimage Info <7045>: target[0]=[satastore-3] Test2/Test2.vmdk 2010-03-29 14:49:12 avvcbimage Info <9642>: a VM snapshot has been requested 2010-03-29 14:49:17 avvcbimage Info <9645>: Requesting create snapshot progress from MC: query #1. 2010-03-29 14:49:18 avvcbimage Info <9649>: Create snapshot succeeded on cycle #1. 2010-03-29 14:49:18 avvcbimage Info <9650>: snapshot moref is snapshot-284 2010-03-29 14:49:18 avvcbimage Info <9651>: create snapshot succeeded: moref='snapshot-284' : query count=1 : vmInfo='
2010-03-29 14:49:20 avvcbimage Info <0000>: VixDiskLib: Advanced transport plugin was successfully loaded into vixDiskLib. Accelerated transport modes available.
2010-03-29 14:49:20 avvcbimage Info <0000>: VixDiskLib: Enabling advanced transport modes.
2010-03-29 14:49:20 avvcbimage Info <0000>: VMware VixDiskLib (1.1) Release build-163495
2010-03-29 14:49:20 avvcbimage Info <0000>: System libcrypto.so.0.9.8 library is older than our library (90802F < 90807F)
2010-03-29 14:49:20 avvcbimage Info <0000>: System libcrypto.so.6 library is older than our library (90802F < 90807F)
2010-03-29 14:49:20 avvcbimage Info <9616>: Available transport modes are file:san:hotadd:nbdssl:nbd 2010-03-29 14:49:20 avvcbimage Info <9617>: Calling ConnectEx with servername=creative51.caii-dc.com vmxspec=moref=vm-242 on port 0 snapshot(snapshot-284) 2010-03-29 14:49:20 avvcbimage Info <9618>: virtual machine will be connected readonly 2010-03-29 14:49:20 avvcbimage Info <0000>: UUID: SMBIOS UUID is reported as '42 09 8c 2c 27 5b 8c 0c-29 05 86 f1 cb 90 c0 32'.
2010-03-29 14:49:20 avvcbimage Info <9619>: VixDiskLib_ConnectEx returned VIX_OK 2010-03-29 14:49:20 avvcbimage Info <9654>: spawnp->get_stdio_fd(0) on avtar with pipe #97 on start 2010-03-29 14:49:20 avvcbimage Info <7213>: Generating PAX stream blocksize 512 to path "" 2010-03-29 14:49:20 avvcbimage Info <9656>: Adding file 'avamar vm configuration.xml' (1284 bytes) 2010-03-29 14:49:20 avvcbimage Info <9656>: Adding file 'snapshot description.xml' (441 bytes) 2010-03-29 14:49:20 avvcbimage Info <9656>: Adding file 'vm.ovf' (55 bytes) 2010-03-29 14:49:20 avvcbimage Info <9656>: Adding file 'vm.vmx' (0 bytes) 2010-03-29 14:49:20 avvcbimage Error <0000>: vmx file is suspiciously small (under 30 bytes), please examine the log on the Avamar Administrator for root cause analysis 2010-03-29 14:49:20 avvcbimage Error <9710>: Backup of VM metadata failed. 2010-03-29 14:49:20 avvcbimage Info <9713>: snapshot created:true NOMC:false ChangeBlTrackingAvail:false UsingChBl:true 2010-03-29 14:49:20 avvcbimage Info <6649>: Process 6434 (/usr/local/avamar/bin/avtar) for workorder MOD-1269888518992 started 2010-03-29 14:49:20 avvcbimage Info <9622>: Disconnected from VM 2010-03-29 14:49:20 avvcbimage Info <8651>: Closing pax stream 2010-03-29 14:49:20 avvcbimage Info <9652>: Requesting snapshot (Avamar-1269888552a5c2af6a74e913a88014f83172b2e9dd912a67a8) removal 2010-03-29 14:49:20 avvcbimage Info <6651>: Process 6434 (/usr/local/avamar/bin/avtar) finished (code 163: Externally cancelled) 2010-03-29 14:49:20 avvcbimage Warning <6653>: CTL workorder "MOD-1269888518992" non-zero exit status 'code 163: Externally cancelled' 2010-03-29 14:49:22 avvcbimage Error <9718>: Avtar exited with 'code 163: Externally cancelled' 2010-03-29 14:49:22 avvcbimage Info <9722>: process_ctl_man_exit detected avtar termination 2010-03-29 14:49:22 avvcbimage Info <9723>: Final summary, cancelled/aborted 0, snapview 0, exitcode 0
1) I thought we were supposed to be able to do this (backup a running VM).... it implies this in the manual where it says it will use a snapshot if the VM is powered on. Is this incorrect?
2) So snapshots do not overcome this problem? I thought that was basically the same theory behind VSS, and the "snapshot" systems of yesterday (backup exec open file option, etc.)... that is, it "snapshots" the VM in a particular moment in time, and therefore, this is restorable. But I suppose this isn't actually the case, either?
It seems this is a problem on VMware's end, and they do not have a fix as of yet. However, there is a workaround. The workaround is a setting that causes the Avamar to ignore those files, and backup the VM without them. This means you cannot restore from nothing, but must instead restore to an existing VM (which makes sense, given the files that it can't get).
I tested it, and it does work.
The solution is simply to add the following option in the dataset:
--x22 = 8192
Of course, it would be nice if the solution worked as intended, but this will do for now... I just wanted to share here to save people time on it...
One of my costumers has the same issue, the workaround works good for the backup, you cant do a restore from zero, you need to create a virtual machine with the same numbers of disks, and same size, then you can do the restore to the vm you already create, you dont have to have any snapshot cause the restore is gonna fail.
Are there any release notes on the 5.0.1 build 32 release specifically? Is it just an upgrade to the avamar proxy or is it a full upgrade to the Avamar nodes themselves?
You can download release notes directly from powerlink. I could not reproduce this issue with 5.0.1 build 32 when MCS-to-vCenter Authentication is properly configured (Admin guide, page 456)
caii-marcosa
8 Posts
3277
0
Posted March 29th, 2010 15:00
Just to provide some more info...
Avamar version 5.0.0.410
ESX version 4.0.0, 236512 (8 hosts, in a cluster doing DRS)
Log of failure:
--------------------------------------------------------------------------------------------------------
----- START avvcbimage log 2010-03-29 14:49:12 EDT [5.0.100-409 Linux-i686]
--------------------------------------------------------------------------------------------------------
2010-03-29 14:49:12 avvcbimage Info <5241>: Logging to /usr/local/avamar/var/MOD-1269888518992-a5c2af6a74e913a88014f83172b2e9dd912a67a8-3016-vmimage.log
2010-03-29 14:49:12 avvcbimage Info <5174>: - Reading /usr/local/avamar/var/avvcbimage.cmd
2010-03-29 14:49:12 avvcbimage Info <6636>: CTL listening on port 59487
2010-03-29 14:49:12 avvcbimage Info <5174>: - Reading /usr/local/avamar/var/avvcbimage.cmd
2010-03-29 14:49:12 avvcbimage Info <7045>: target[0]=[satastore-3] Test2/Test2.vmdk
2010-03-29 14:49:12 avvcbimage Info <9642>: a VM snapshot has been requested
2010-03-29 14:49:17 avvcbimage Info <9645>: Requesting create snapshot progress from MC: query #1.
2010-03-29 14:49:18 avvcbimage Info <9649>: Create snapshot succeeded on cycle #1.
2010-03-29 14:49:18 avvcbimage Info <9650>: snapshot moref is snapshot-284
2010-03-29 14:49:18 avvcbimage Info <9651>: create snapshot succeeded: moref='snapshot-284' : query count=1 : vmInfo='
'
2010-03-29 14:49:18 avvcbimage Info <0000>: VixDiskLib: config options: libdir '/usr/lib/vmware', tmpDir '/tmp/vmware-root'.
2010-03-29 14:49:20 avvcbimage Info <0000>: VixDiskLib: Advanced transport plugin was successfully loaded into vixDiskLib. Accelerated transport modes available.
2010-03-29 14:49:20 avvcbimage Info <0000>: VixDiskLib: Enabling advanced transport modes.
2010-03-29 14:49:20 avvcbimage Info <0000>: VMware VixDiskLib (1.1) Release build-163495
2010-03-29 14:49:20 avvcbimage Info <0000>: System libcrypto.so.0.9.8 library is older than our library (90802F < 90807F)
2010-03-29 14:49:20 avvcbimage Info <0000>: System libcrypto.so.6 library is older than our library (90802F < 90807F)
2010-03-29 14:49:20 avvcbimage Info <9616>: Available transport modes are file:san:hotadd:nbdssl:nbd
2010-03-29 14:49:20 avvcbimage Info <9617>: Calling ConnectEx with servername=creative51.caii-dc.com vmxspec=moref=vm-242 on port 0 snapshot(snapshot-284)
2010-03-29 14:49:20 avvcbimage Info <9618>: virtual machine will be connected readonly
2010-03-29 14:49:20 avvcbimage Info <0000>: UUID: SMBIOS UUID is reported as '42 09 8c 2c 27 5b 8c 0c-29 05 86 f1 cb 90 c0 32'.
2010-03-29 14:49:20 avvcbimage Info <9619>: VixDiskLib_ConnectEx returned VIX_OK
2010-03-29 14:49:20 avvcbimage Info <9654>: spawnp->get_stdio_fd(0) on avtar with pipe #97 on start
2010-03-29 14:49:20 avvcbimage Info <7213>: Generating PAX stream blocksize 512 to path ""
2010-03-29 14:49:20 avvcbimage Info <9656>: Adding file 'avamar vm configuration.xml' (1284 bytes)
2010-03-29 14:49:20 avvcbimage Info <9656>: Adding file 'snapshot description.xml' (441 bytes)
2010-03-29 14:49:20 avvcbimage Info <9656>: Adding file 'vm.ovf' (55 bytes)
2010-03-29 14:49:20 avvcbimage Info <9656>: Adding file 'vm.vmx' (0 bytes)
2010-03-29 14:49:20 avvcbimage Error <0000>: vmx file is suspiciously small (under 30 bytes), please examine the log on the Avamar Administrator for root cause analysis
2010-03-29 14:49:20 avvcbimage Error <9710>: Backup of VM metadata failed.
2010-03-29 14:49:20 avvcbimage Info <9713>: snapshot created:true NOMC:false ChangeBlTrackingAvail:false UsingChBl:true
2010-03-29 14:49:20 avvcbimage Info <6649>: Process 6434 (/usr/local/avamar/bin/avtar) for workorder MOD-1269888518992 started
2010-03-29 14:49:20 avvcbimage Info <9622>: Disconnected from VM
2010-03-29 14:49:20 avvcbimage Info <8651>: Closing pax stream
2010-03-29 14:49:20 avvcbimage Info <9652>: Requesting snapshot (Avamar-1269888552a5c2af6a74e913a88014f83172b2e9dd912a67a8) removal
2010-03-29 14:49:20 avvcbimage Info <6651>: Process 6434 (/usr/local/avamar/bin/avtar) finished (code 163: Externally cancelled)
2010-03-29 14:49:20 avvcbimage Warning <6653>: CTL workorder "MOD-1269888518992" non-zero exit status 'code 163: Externally cancelled'
2010-03-29 14:49:22 avvcbimage Error <9718>: Avtar exited with 'code 163: Externally cancelled'
2010-03-29 14:49:22 avvcbimage Info <9722>: process_ctl_man_exit detected avtar termination
2010-03-29 14:49:22 avvcbimage Info <9723>: Final summary, cancelled/aborted 0, snapview 0, exitcode 0
--------------------------------------------------------------------------------------------------------
----- END avvcbimage log 2010-03-29 14:49:27 EDT (1 warning, 3 errors, 0 fatal errors)
--------------------------------------------------------------------------------------------------------