Solved

Host is in a state that cannot perform snapshot

Posted on 2013-12-20
11
4,893 Views
Last Modified: 2014-01-27
Hello,

We have a weird case with backing up VMs on VMware ESX 5.5. It doesn't matter if we use native VMware's VDP, EMC Networker's VBA or VADP solutions, the message is always the same:

2013-12-17 03:00:34 avnwcomm Error <0000>: Plugin returned non-zero exit code (10059). Aborting NetWorker connection.
2013-12-17 03:00:24 avvcbimage Warning <6788>: Found unknown section 'browse-from-catalog' in workorder, ignoring
2013-12-17 03:00:25 avvcbimage Warning <6788>: Found unknown section 'browse-from-catalog' in workorder, ignoring
2013-12-17 03:00:34 avvcbimage Warning <16004>: Soap fault detected, Could not connect to getHostMoref 'esx2.local'., Msg:'SOAP 1.1 fault: SOAP-ENV:Client [no subcode]
2013-12-17 03:00:34 avvcbimage FATAL <0000>: [IMG0009] The Host 'esx2.local' is in a state that cannot perform snapshot operations.
2013-12-17 03:00:34 avvcbimage Error <0000>: [IMG0009] createSnapshot: snapshot creation failed

The google is silent about it. We have restarted services, physical hosts, vcenter, VDP, VBA, Networker, nothing helps. The weirdest thing is that it was working for about a week, and then stopped. No known changes were made to VMware environment. Does anyone have an idea what could be the cause or at least how to diagnose deeply this issue?

Best regards,
Krzysztof
0
Comment
Question by:sevenet
  • 5
  • 2
  • 2
  • +1
11 Comments
 
LVL 117
ID: 39731931
Does this happen if you manully snapshot the VM?
0
 
LVL 8

Expert Comment

by:piyushranusri
ID: 39743130
try to  rebooting the vsphere host first and then see.
1, please see that the Virtual machine startup / shutdown with host feature is disabled before this step

2. Restart the management agents on the host

3. On vCenter Server, restart the vCenter and Management Web servicesand
and then try to take snapshot.

and the very important ...does this happen only with one vm or any vm ??



please share the output
0
 
LVL 19

Expert Comment

by:compdigit44
ID: 39744108
Did you have the same issue running on ESXi 5.1?
If you connect to the ESXi 5.5 host directly using the VI Client are you able to snapshot the VM?
0
 

Author Comment

by:sevenet
ID: 39745939
Sorry for a little delay.

Manual snapshots work OK.

We have restarted management agents on the host, and the host itself too, at the end.

We have restarted vcenter services and the server itself, countless times

It happens to all VMs, regardless of operating system or host on which it runs.

We didn't have a chance to check 5.1 in this environment, as it was already running 5.5, however, we have a lab environment with 5.1 and there are no such issues at all. We cannot downgrade production environment to 5.1 :-(

The interesting thing is that Networker's VBA from EMC was working for about a week, and then stopped with this message (we do not recall any major changes to the environment which could have caused the failure). Then, we tried VADP frmo EMC, and finally to eliminate Networker's problem we installed VDP from VMware. The message is the same. It seems it is originated by either ESX or vCenter (most probable). We plan to reinstall vCenter, but this is rather long-term plan if other ideas fail.
0
 
LVL 117
ID: 39745984
If this is causing long standing service issues, I would now escalate to VMware Support.
0
Highfive + Dolby Voice = No More Audio Complaints!

Poor audio quality is one of the top reasons people don’t use video conferencing. Get the crispest, clearest audio powered by Dolby Voice in every meeting. Highfive and Dolby Voice deliver the best video conferencing and audio experience for every meeting and every room.

 

Author Comment

by:sevenet
ID: 39746479
Yes, we have opened the case, but so far, for about two weeks, noone is able to track the root cause. We have a webex session scheduled for tomorrow. I though maybe someone already found the solution :-) From what I google around, many people have similiar issues. It looks like some kind of ghost problem :-/
0
 
LVL 19

Expert Comment

by:compdigit44
ID: 39746524
What build number of ESXi 5.5 are you using? Also are using an OEM version of ESXi of the generic VMware version from the VMware site?

Are the device drivers updated on your host? BIOS, NIC's, Storage HBA etc....

Any errors for the host in your SAN logs??

What type of permissions is the backup agent running under ?
0
 

Author Comment

by:sevenet
ID: 39747774
vCenter is 5.5.0 build 1312298

ESXi is generic installation (ISO from VMware): VMware ESXi, 5.5.0, 1331820

We have checked permissions. Just to make sure there are no issues we use administrator account.

There are no errors on SAN. All datastores work OK.
0
 

Author Comment

by:sevenet
ID: 39747803
Here is the most recent log from VDP:
--------------------------------------------------------------------------------------------------------
-----  START avvcbimage log 2013-12-30 23:00:05 CET  [7.0.181-86 Linux-x86_64]
--------------------------------------------------------------------------------------------------------

2013-12-30T23:00:05.321+1:00 avvcbimage Info <5008>: Logging to /usr/local/avamarclient/var-proxy-5/systems_daily-systems_daily-1388440800090-9f618cf4cfbe04eb51e7c62438d310bd7a7d9356-1016-vmimagel.log
2013-12-30T23:00:05.321+1:00 avvcbimage Info <5174>: - Reading /root/.avamar
2013-12-30T23:00:05.321+1:00 avvcbimage Info <5174>: - Reading /usr/local/avamar/etc/usersettings.cfg
2013-12-30T23:00:05.321+1:00 avvcbimage Info <5174>: - Reading /usr/local/avamarclient/var-proxy-5/avvcbimage.cmd
2013-12-30T23:00:05.321+1:00 avvcbimage Info <5174>: - Reading /usr/local/avamarclient/var/avvcbimageAll.cmd
2013-12-30T23:00:05.325+1:00 avvcbimage Info <6673>: CTL listening on port 47040
2013-12-30T23:00:05.327+1:00 avvcbimage Info <10684>: Setting ctl message version to 3 (from 1)
2013-12-30T23:00:05.328+1:00 avvcbimage Info <16136>: Setting ctl max message size to 268435456
2013-12-30T23:00:05.332+1:00 avvcbimage Warning <6788>: Found unknown section 'browse-from-catalog' in workorder, ignoring
2013-12-30T23:00:05.335+1:00 avvcbimage Warning <17809>: VAMI Statistics Push Provider DISABLED.
2013-12-30T23:00:05.359+1:00 avvcbimage Info <18664>: Login(https://vcenter.local:443/sdk) Datacenter: 'PRODUCTION'
2013-12-30T23:00:05.360+1:00 avvcbimage Info <0000>:      - connected to 'VirtualCenter' - version: 'VMware vCenter Server 5.5.0 build-1312298',  apiVersion:'5.5' 
2013-12-30T23:00:05.481+1:00 avvcbimage Info <14692>: Login test is OK.
2013-12-30T23:00:05.713+1:00 avvcbimage Info <0000>: VM Info: VMX version 4(F), ctk enabled(T), fault tolerant (F), Guest OS CentOS 4/5/6 (64-bit), Cloud UUID = NoUUID. version=8
2013-12-30T23:00:05.797+1:00 avvcbimage Info <14625>: WorkOrder Disk Info:
  Disk '2000': file(base):'[LUN0-ESX] dns/dns.vmdk', backItUp=1
               snapshot file:'[LUN0-ESX] dns/dns.vmdk'
               prior size(KB):0, current size(KB):10485760, match=0
               prior change block ID:''
               Datastore:'LUN0-ESX' Directly Accessible=1
2013-12-30T23:00:05.798+1:00 avvcbimage Info <11979>: proxy VM DNS name is: 127.0.0.2,vdp0.local,vdp0,10.1.211.20
2013-12-30T23:00:05.798+1:00 avvcbimage Info <18672>: proxy VM Instance name is: vdp0-proxy-5
2013-12-30T23:00:05.798+1:00 avvcbimage Info <17793>: proxy VM Moref is: vm-726
2013-12-30T23:00:05.798+1:00 avvcbimage Info <16010>: vCenter 'PRODUCTION' is vcenter.local
2013-12-30T23:00:05.798+1:00 avvcbimage Info <11981>: VM's host is esx1.local
2013-12-30T23:00:05.798+1:00 avvcbimage Info <11982>: VM's primary storage location is [LUN0-ESX] dns/dns.vmx
2013-12-30T23:00:05.798+1:00 avvcbimage Info <11983>: VM's vCenter ID is vm-98
2013-12-30T23:00:06.545+1:00 avvcbimage Warning <16004>: Soap fault detected, Could not connect to getHostMoref 'esx1.local'., Msg:'SOAP 1.1 fault: SOAP-ENV:Client [no subcode]
"End of file or no input: Operation interrupted or timed out"
Detail: [no detail]
'
2013-12-30T23:00:06.554+1:00 avvcbimage Warning <16004>: Soap fault detected, Get Host properties problem, Msg:'SOAP 1.1 fault: "":ServerFaultCode [no subcode]
"
Required property obj is missing from data object of type ObjectSpec

while parsing serialized DataObject of type vmodl.query.PropertyCollector.ObjectSpec
at line 2, column 651

while parsing property "objectSet" of static type ArrayOfObjectSpec

while parsing serialized DataObject of type vmodl.query.PropertyCollector.FilterSpec
at line 2, column 445

while parsing call information for method RetrieveProperties
at line 2, column 273

while parsing SOAP body
at line 2, column 258

while parsing SOAP envelope
at line 2, column 0

while parsing HTTP request for method retrieveContents
on object of type vmodl.query.PropertyCollector
at line 1, column 0"
Detail: <InvalidRequestFault xmlns="urn:vim25" xsi:type="InvalidRequest"></InvalidRequestFault>
'
2013-12-30T23:00:07.030+1:00 avvcbimage Warning <16004>: Soap fault detected, Could not connect to getHostMoref 'esx1.local'., Msg:'SOAP 1.1 fault: SOAP-ENV:Client [no subcode]
"End of file or no input: Operation interrupted or timed out"
Detail: [no detail]
'
2013-12-30T23:00:07.039+1:00 avvcbimage Warning <16004>: Soap fault detected, Get Host properties problem, Msg:'SOAP 1.1 fault: "":ServerFaultCode [no subcode]
"
Required property obj is missing from data object of type ObjectSpec

while parsing serialized DataObject of type vmodl.query.PropertyCollector.ObjectSpec
at line 2, column 651

while parsing property "objectSet" of static type ArrayOfObjectSpec

while parsing serialized DataObject of type vmodl.query.PropertyCollector.FilterSpec
at line 2, column 445

while parsing call information for method RetrieveProperties
at line 2, column 273

while parsing SOAP body
at line 2, column 258

while parsing SOAP envelope
at line 2, column 0

while parsing HTTP request for method retrieveContents
on object of type vmodl.query.PropertyCollector
at line 1, column 0"
Detail: <InvalidRequestFault xmlns="urn:vim25" xsi:type="InvalidRequest"></InvalidRequestFault>
'
2013-12-30T23:00:07.039+1:00 avvcbimage Info <0000>: Proxy Host Name=esx1.local() VM Host Name=esx1.local()
2013-12-30T23:00:07.039+1:00 avvcbimage Info <11984>: VM's backup account on vdp0.local is /vcenter.local/VirtualMachines/dns_Unag9GyalhQeq8btPpE68g
2013-12-30T23:00:07.039+1:00 avvcbimage Info <11986>: Changed block tracking is engaged for this VM
2013-12-30T23:00:07.039+1:00 avvcbimage Info <11988>: A reference to a valid prior backup is not available so this will be a full level zero backup.
2013-12-30T23:00:07.050+1:00 avvcbimage Warning <6788>: Found unknown section 'browse-from-catalog' in workorder, ignoring
2013-12-30T23:00:07.053+1:00 avvcbimage Info <5174>: - Reading /usr/local/avamarclient/var-proxy-5/avvcbimage.cmd
2013-12-30T23:00:07.053+1:00 avvcbimage Info <5174>: - Reading /usr/local/avamarclient/var/avvcbimageAll.cmd
2013-12-30T23:00:07.053+1:00 avvcbimage Info <7084>: target[0]=[LUN0-ESX] dns/dns.vmdk
2013-12-30T23:00:07.067+1:00 avvcbimage Info <18664>: Login(https://vcenter.local:443/sdk) Datacenter: 'PRODUCTION'
2013-12-30T23:00:07.067+1:00 avvcbimage Info <0000>:      - connected to 'VirtualCenter' - version: 'VMware vCenter Server 5.5.0 build-1312298',  apiVersion:'5.5' 
2013-12-30T23:00:07.084+1:00 avvcbimage Info <14692>: Login test is OK.
2013-12-30T23:00:07.109+1:00 avvcbimage Info <16041>: VDDK:OBJLIB-LIB: Objlib initialized.

2013-12-30T23:00:07.109+1:00 avvcbimage Info <16041>: VDDK:VixDiskLib: Attempting to locate advanced transport module in "/usr/lib/vmware-vix-disklib".

2013-12-30T23:00:08.151+1:00 avvcbimage Info <16041>: VDDK:VixDiskLib: Advanced transport plugin was successfully loaded into vixDiskLib.

2013-12-30T23:00:08.152+1:00 avvcbimage Info <16041>: VDDK:VixDiskLib: Enabling advanced transport modes.

2013-12-30T23:00:08.152+1:00 avvcbimage Info <16041>: VDDK:OBJLIB-LIB: Objlib initialized.

2013-12-30T23:00:08.153+1:00 avvcbimage Info <16041>: VDDK:VixDiskLib: Initialize transport modes.

2013-12-30T23:00:08.154+1:00 avvcbimage Info <16041>: VDDK:VixDiskLib: Available transport modes: file:san:hotadd:nbdssl:nbd.

2013-12-30T23:00:08.154+1:00 avvcbimage Info <16041>: VDDK:VMware VixDiskLib (5.5) Release build-1284542

2013-12-30T23:00:08.234+1:00 avvcbimage Info <16041>: VDDK:VixDiskLibVim: VixDiskLibVim_Init: Initialization is completed.

2013-12-30T23:00:08.234+1:00 avvcbimage Info <9666>: Available transport modes are file:san:hotadd:nbdssl:nbd
2013-12-30T23:00:08.234+1:00 avvcbimage Info <16041>: VDDK:VixDiskLib: VixDiskLib_PrepareForAccess: Prepare to access disk.

2013-12-30T23:00:08.234+1:00 avvcbimage Info <16041>: VDDK:VixDiskLib: VixDiskLib_Connect: Establish connection.

2013-12-30T23:00:08.234+1:00 avvcbimage Info <16041>: VDDK:VixDiskLibVim: VixDiskLibVim_AllowVMotion: Disable VMotion.

2013-12-30T23:00:10.761+1:00 avvcbimage Info <17818>: VixDiskLib vMotion reservation successfully enabled by 'vSphere Data Protection'
2013-12-30T23:00:10.761+1:00 avvcbimage Info <16011>: Running cleanup of old backups.
2013-12-30T23:00:10.761+1:00 avvcbimage Info <16041>: VDDK:VixDiskLib: VixDiskLib_Cleanup: Remove previous mount points and clean up .

2013-12-30T23:00:10.761+1:00 avvcbimage Info <16041>: VDDK:VixDiskLib: VixDiskLib_Connect: Establish connection.

2013-12-30T23:00:10.761+1:00 avvcbimage Info <16041>: VDDK:VixDiskLib: VixDiskLib_Disconnect: Disconnect.
2013-12-30T23:00:10.761+1:00 avvcbimage Info <16048>: VixDiskLib_Cleanup() found no prior mounts to cleanup.
2013-12-30T23:00:10.781+1:00 avvcbimage Info <18664>: Login(https://vcenter.local:443/sdk) Datacenter: 'PRODUCTION'
2013-12-30T23:00:10.781+1:00 avvcbimage Info <0000>:      - connected to 'VirtualCenter' - version: 'VMware vCenter Server 5.5.0 build-1312298',  apiVersion:'5.5' 
2013-12-30T23:00:10.817+1:00 avvcbimage Info <14692>: Login test is OK.
2013-12-30T23:00:11.912+1:00 avvcbimage Warning <16004>: Soap fault detected, Could not connect to getHostMoref 'esx1.local'., Msg:'SOAP 1.1 fault: SOAP-ENV:Client [no subcode]
"End of file or no input: Operation interrupted or timed out"
Detail: [no detail]
'
2013-12-30T23:00:11.990+1:00 avvcbimage FATAL <0000>: [IMG0009] The Host 'esx1.local' is in a state that cannot perform snapshot operations.
2013-12-30T23:00:11.990+1:00 avvcbimage Info <9772>: Starting graceful (staged) termination, Host is in a state that cannot perform snapshots. (wrap-up stage)
2013-12-30T23:00:11.990+1:00 avvcbimage Error <0000>: [IMG0009] createSnapshot: snapshot creation  or pre/post snapshot script failed
2013-12-30T23:00:11.991+1:00 avvcbimage Error <0000>: [IMG0009] createSnapshot: snapshot creation/pre-script/post-script failed
2013-12-30T23:00:11.991+1:00 avvcbimage Info <9763>: snapshot created:false NOMC:false ChangeBlTrackingAvail:true UsingChBl:true
2013-12-30T23:00:11.991+1:00 avvcbimage Info <16041>: VDDK:VixDiskLib: VixDiskLib_EndAccess: Disk access completed.
2013-12-30T23:00:11.991+1:00 avvcbimage Info <16041>: VDDK:VixDiskLib: VixDiskLib_Connect: Establish connection.
2013-12-30T23:00:11.991+1:00 avvcbimage Info <16041>: VDDK:VixDiskLibVim: VixDiskLibVim_AllowVMotion: Enable VMotion.
2013-12-30T23:00:11.993+1:00 avvcbimage Info <16038>: Final summary, cancelled/aborted 0, snapview 1, exitcode 209: plugin error 09
2013-12-30T23:00:14.224+1:00 avvcbimage Info <17819>: VixDiskLib vMotion reservation successfully released

Open in new window

0
 
LVL 8

Accepted Solution

by:
piyushranusri earned 500 total points
ID: 39747820
did you check with vmware support, might be a type of bug on 5.5
because 5.5 have many bugs that are still ni troubleshooting and they are keep rectifying it on daily basis

meanwhile, give me couple of minute to discuss with them also ..

same issue as another issue has raised and its forwarded to vmware support.
please browse this link
http://www.backupcentral.com/phpBB2/two-way-mirrors-of-external-mailing-lists-3/emc-networker-19/emc-dataprotection-l-soap-errors-123368/

please share the output.
0
 

Author Comment

by:sevenet
ID: 39780442
Hello,

Actually it was my post :-) Since we had a very serious issue with it I tried posting in many places hoping to find an answer as soon as possible. Indeed, increasing LUN size helped, but the above messages are ridiculous comparing to the real reason. I would have never guessed from that output that the problem was the LUN space. Anyway, still no one is able to answer my question why was this space a case :-)

Best regards,
Krzysztof
0

Featured Post

Find Ransomware Secrets With All-Source Analysis

Ransomware has become a major concern for organizations; its prevalence has grown due to past successes achieved by threat actors. While each ransomware variant is different, we’ve seen some common tactics and trends used among the authors of the malware.

Join & Write a Comment

It Is not possible to enable LLDP in vSwitch(at least is not supported by VMware), so in this article we will enable this, and also go trough how to enabled CDP and how to get this information in vSwitches and also in vDS.
In this article, I will show you HOW TO: Create your first Windows Virtual Machine on a VMware vSphere Hypervisor 6.5 (ESXi 6.5) Host Server, the Windows OS we will install is Windows Server 2016.
This Micro Tutorial walks you through using a remote console to access a server and install ESXi 5.1. This example is showing remote access and installation using a Dell server. The hypervisor is the very first component of your virtual infrastructu…
How to install and configure Citrix XenApp 6.5 - Part 1. In this video tutorial we have explained step by step installation of Citrix XenApp 6.5 Server on Windows Server 2008 R2 is explained in this video. We have explained the difference between…

708 members asked questions and received personalized solutions in the past 7 days.

Join the community of 500,000 technology professionals and ask your questions.

Join & Ask a Question

Need Help in Real-Time?

Connect with top rated Experts

20 Experts available now in Live!

Get 1:1 Help Now