Executing long running custom VMware tools scripts for power off or suspend tasks fail with the error: A general system error occurred: Invalid Fault

Products

• VMware vCenter Server

Issue/Introduction

Symptoms:

• Executing long running custom VMware tools scripts for power off or suspend tasks fail
• You see this error:
  
  For vCenter Server 5.1:
  
  A general system error occurred: Unknown error
  
  
  For vCenter Server 5.5:
  
  A general system error occurred: Invalid fault
  
  
• In the vpxd.log file, you see entries similar to:
  
  [01396 info 'commonvpxLro' opID=7bcaa177] [VpxLRO] -- BEGIN task-internal-116738 -- vm-404 -- vim.VirtualMachine.acquireTicket -- 4750ba25-0ba7-9375-5b4c-e661f3d1ea71(5235426c-2415-92b3-bd32-569b9e55d94c)
  [01396 info 'commonvpxLro' opID=7bcaa177] [VpxLRO] -- FINISH task-internal-116738 -- vm-404 -- vim.VirtualMachine.acquireTicket --
  [01396 info 'Default' opID=7bcaa177] [VpxLRO] -- ERROR task-internal-116738 -- vm-404 -- vim.VirtualMachine.acquireTicket: vim.fault.InvalidState:
  --> Result:
  --> (vim.fault.InvalidState) {
  --> dynamicType = <unset>,
  --> faultCause = (vmodl.MethodFault) null,
  --> msg = "Received SOAP response fault from [<cs p:00000000142565f0, TCP:[ESXi Host]:443>]: acquireTicket
  --> Received SOAP response fault from [<cs p:1f3b6148, TCP:localhost:8307>]: acquireTicket
  --> The operation is not allowed in the current state.",
  --> }
  
  

  Note: These are the location of vpxd.log file:

  • For vCenter Server 5.x and earlier versions on Windows XP, 2000, 2003:
    
    %ALLUSERSPROFILE%\Application Data\VMware\VMware VirtualCenter\Logs\
    
    
  • For vCenter Server 5.x and earlier versions on Windows Vista, 7, 2008:
    
    C:\ProgramData\VMware\VMware VirtualCenter\Logs\
    
    

• In the hostd.log file, located at /var/log/, you see entries similar to:
  
  
  For ESXi 5.1:
  
  

  YYYY-DD-MM TIME [7E344B90 info 'Vimsvc.TaskManager' opID=A8F2B1E2-00010504-fc-a1] Task Created : haTask-13-vim.VirtualMachine.shutdownGuest-306189345

  YYYY-DD-MM TIME [7E281B90 verbose 'Vmsvc.vm:/vmfs/volumes/54189577-ed3f3863-90cf-005056030690/RHEL6-1/RHEL6-1.vmx' opID=A8F2B1E2-00010504-fc-a1] Shutting down guest

  YYYY-DD-MM TIME [7E281B90 info 'Vmsvc.vm:/vmfs/volumes/54189577-ed3f3863-90cf-005056030690/RHEL6-1/RHEL6-1.vmx' opID=A8F2B1E2-00010504-fc-a1] State Transition (VM_STATE_ON -> VM_STATE_SHUTTING_DOWN)

  YYYY-DD-MM TIME [7E281B90 info 'Vmsvc.vm:/vmfs/volumes/54189577-ed3f3863-90cf-005056030690/RHEL6-1/RHEL6-1.vmx' opID=A8F2B1E2-00010504-fc-a1] Shutdown failed: Error: (1) Unknown error

  
  
  For ESXi 5.5:
  
  [355C2B70 info 'Vimsvc.ha-eventmgr' opID=197C727B-00006704-b9-2c user=vpxuser] Event 444 : [VM name] cannot shut down the guest OS on [Host name] in ha-datacenter: vix error code = 1

  [355C2B70 info 'Default' opID=197C727B-00006704-b9-2c user=vpxuser] AdapterServer caught exception: vim.fault.GenericVmConfigFault

  [355C2B70 info 'Vimsvc.TaskManager' opID=197C727B-00006704-b9-2c user=vpxuser] Task Completed : haTask-3-vim.VirtualMachine.shutdownGuest-518775136 Status error

  [355C2B70 info 'Solo.Vmomi' opID=197C727B-00006704-b9-2c user=vpxuser] Activation [N5Vmomi10ActivationE:0x34caaa00] : Invoke done [shutdownGuest] on [vim.VirtualMachine:3]

  [355C2B70 info 'Solo.Vmomi' opID=197C727B-00006704-b9-2c user=vpxuser] Throw vim.fault.GenericVmConfigFault

  [355C2B70 info 'Solo.Vmomi' opID=197C727B-00006704-b9-2c user=vpxuser] Result:

  
  

  --> }

  --> ],

  --> reason = "vix error code = 1",

  --> messageInfo = (vim.vm.Message) [

  --> (vim.vm.Message) {

  --> dynamicType = <unset>,

  --> id = "msg.vix.vigor.error",

  --> argument = (anyType) [

  --> "1"

  --> ],

  --> text = "vix error code = 1",

  --> }

  --> ],

  --> msg = "vix error code = 1

  --> "

  --> }

  [355C2B70 error 'SoapAdapter' opID=197C727B-00006704-b9-2c user=vpxuser] Method vim.VirtualMachine.shutdownGuest threw undeclared fault of type vim.fault.GenericVmConfigFault
  
  
• In the vmware.log files, located at /vmfs/volumes/vm_datastore/ vmname/vmware.log, for virtual machine show a 30 second gap before VMware tools gives a timeout error similar to:
  
  

  | vmx| I120: Tools: sending 'OS_Halt' (state = 1) state change request

  | vmx| I120: Vix: [3948195 vmxCommands.c:529]: VMAutomation_InitiatePowerOff. Tried to soft halt. Success = 1

  | vmx| I120: Tools: Timed out waiting for state change status.

  | vmx| I120: Vix: [3948195 mainDispatch.c:3884]: VMAutomationReportPowerStateChange: Reporting power state change (opcode=2, err=0).

Environment

VMware vCenter Server 5.1.x
VMware vCenter Server 5.5.x

Cause

This issue occurs because VMware tools are designed for very short running tasks that are generated by scripts before a power off or resume operation.

Resolution

To work around this issue, it is recommended that long running operations must be done asynchronously outside of custom tools scripts. Ensure that the VMware tools custom script is completed within 30 seconds.

Additional Information

This issue does not occur for power-on or resume scripts as the status of the operation is not dependent on the tools state change request.

To set up custom scripts with VMware tools, see the Using Custom VMware Tools Scripts section in the ESXi and vCenter Server 5.5 Guide.

完了まで時間のかかる VMware tools のパワーオフやサスペンド用カスタムスクリプトを実行すると、次のエラーで失敗する：A general system error occurred: Invalid Fault