Virtual machine Power on requests from vRealize Operations manager fail
search cancel

Virtual machine Power on requests from vRealize Operations manager fail

book

Article ID: 301405

calendar_today

Updated On:

Products

VMware Aria Suite VMware vCenter Server

Issue/Introduction

This article resolves port miss-configuration when using a custom port for the VMware vCenter Workflow Manager.

Symptoms:

Note: The log entries referenced below were found when logging was set to debug or verbose. For information on changing the logging level see the Additional Information section.

  • Powering on a virtual machine from vRealize Operation Manager fails.
  • In the workflow-manager.log file, there are entries similar to:

    2016-12-29T10:23:51.451-05:00 [pool-9-thread-2 DEBUG opID=] [WorkflowBodyHandlerImpl] -- Creating proxy object for moId vm-11xxx
    2016-12-29T10:23:51.454-05:00 [pool-5-thread-2 DEBUG opID=] [TaskInvoker] -- Issuing PowerOnVM_Task on ManagedObjectReference: type = VirtualMachine, value = vm-11xxx, serverGuid = null
    2016-12-29T10:23:51.454-05:00 [pool-5-thread-2 DEBUG opID=1354c09e-AC] [WorkflowImpl] -- Updating pre-specified key parentTaskMoId
    2016-12-29T10:23:51.454-05:00 [pool-5-thread-2 INFO opID=1354c09e-AC] [WorkflowImpl] -- BEGIN executing WSDL method PowerOnVM_Task on vm-11xxx
    …
    …
    2016-12-29T10:23:51.581-05:00 [workerThreadpool-14 DEBUG opID=1354c09e-AC] [WorkflowImpl] -- Processing results for step VmLockingHandler-QueryLockRequirements in PowerOnVM_Task
    2016-12-29T10:23:51.581-05:00 [workerThreadpool-14 DEBUG opID=1354c09e-AC] [WorkflowImpl] -- Finished step: VmLockingHandler-QueryLockRequirements
    2016-12-29T10:23:51.581-05:00 [workerThreadpool-14 DEBUG opID=1354c09e-AC] [WorkflowImpl] -- Running step: VmLockingHandler-AcquireLock
    2016-12-29T10:23:51.581-05:00 [workerThreadpool-14 DEBUG opID=1354c09e-AC] [LockingStepImpl] -- Making lock acquire request for requestId xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx
    2016-12-29T10:23:51.581-05:00 [workerThreadpool-14 DEBUG opID=1354c09e-AC] [SchedulerImpl] -- Acquiring locks for xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx
    2016-12-29T10:23:51.585-05:00 [VlsiClientPool-14 DEBUG opID=1354c09e-AC] [wire] -- >> "<?xml version='1.0' encoding='UTF-8'?><soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/" xmlns:soapenc="http://schemas.xmlsoap.org/soap/encoding/" xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"><soapenv:Header><stepContribution xsi:type="string">5</stepContribution><parentTask xsi:type="string">task-399060</parentTask><isWorkflowRedirect xsi:type="string">true</isWorkflowRedirect><workflow_user_session xsi:type="string">xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx</workflow_user_session><operationID xsi:type="string">1354c09e-AC</operationID></soapenv:Header><soapenv:Body><AcquireLockSLM xmlns="urn:internalvim25" xmlns:internalvim25="urn:internalvim25"><_this type="StateLockManager">StatelockManager</_this><requestId>xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx</requestId><spec><object serverguid="XXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX" type="VirtualMachine">vm-11xxx</object><lockType>exclusive</lockType></spec></AcquireLockSLM></soapenv:Body></soapenv:Envelope>"
    …
    …
    2016-12-29T10:23:51.589-05:00 [VlsiClientPool-14 DEBUG opID=1354c09e-AC] [SchedulerImpl] -- Lockacquire returned for xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx
    2016-12-29T10:23:51.589-05:00 [VlsiClientPool-14 ERROR opID=1354c09e-AC] [SchedulerImpl] -- Locks were not granted for xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx. Will retry later

    The workflow-manager.log file is located at:
    • Windows installed vCenter Server - C:\ProgramData\VMware\vCenterServer\logs\workflow\
    • vCenter Server Appliance - /var/log/vmware/workflow/
       
  • After the above entries in the workflow-manager.log file there are no further retry events listed.
  • In the vpxd.log file, there are entries similar to:

    2016-12-29T10:23:51.586-05:00 verbose vpxd[29952] [Originator@6876 sub=Default opID=1354c09e-AC-7f] [VpxVmomi] Invoking [acquire] on [vim.modularity.StateLockManager:StatelockManager] session [xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx(xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)]
    2016-12-29T10:23:51.586-05:00 info vpxd[07500] [Originator@6876 sub=vpxLro opID=1354c09e-AC-7f] [VpxLRO] -- BEGIN task-internal-23869691 -- StatelockManager -- vim.modularity.StateLockManager.acquire -- xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx(xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
    2016-12-29T10:23:51.586-05:00 verbose vpxd[07500] [Originator@6876 sub=vpxdStateLockManager opID=1354c09e-AC-7f] Acquire: xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx vim.VirtualMachine:vm-11xxx
    2016-12-29T10:23:51.586-05:00 verbose vpxd[07500] [Originator@6876 sub=vpxdStateLockManager opID=1354c09e-AC-7f] Failed to acquire lock for requestID: xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx, moID vm-11xxx. Registering callback

    And

    2016-12-29T10:23:53.722-05:00 error vpxd[10220] [Originator@6876 sub=HttpConnectionPool-000001] [ConnectComplete] Connect failed to <cs p:000000002bac7660, TCP:localhost:8088>; cnx: (null), error: class Vmacore::SystemException(No connection could be made because the target machine actively refused it)
    2016-12-29T10:23:53.738-05:00 warning vpxd[31304] [Originator@6876 sub=vpxdStateLockManager opID=2cf5c62f] Ignoring exception while invoking LocksReleased: No connection could be made because the target machine actively refused it


    For more information on the logging locations in vCenter Server, see Location of VMware vCenter Server 6.0 log files (2110014).

Environment

VMware vCenter Server Appliance 6.0.x
VMware vCenter Server 6.0.x

Cause

This issue occurs when the VMware vCenter Workflow Manager service is configured to use custom ports (Default ports used by the service are 8088 and 19999).

Resolution

To resolve this issue, update the vpxd.cfg file on vCenter Server to use custom ports when communicating with the VMware Workflow Manager:
  1. Open the vpxd.cfg file in a plain text editor.
    • Windows installed vCenter Server - C:\ProgramData\VMware\VMware VirtualCenter\
    • vCenter Server Appliance - /etc/vmware-vpx/
       
  2. Add these entries to the vpxd.cfg file:

    <vpxd>
    ....
    ....
    <stateLockManager>
    <callbackUrl>localhost:Custom_Port</callbackUrl>
    </stateLockManager>
    ....
    ....
    </vpxd>
     
  3. Restart the vCenter Server Service. For more information, see How to stop, start, or restart vCenter Server 6.x services (2109881).

Additional Information

To increase logging on the Workflow Manager:
  1. Open the workflow.log4j.properties file in a plain text editor.
    • Windows installed vCenter Server - C:\Program Files\VMware\vCenter Server\workflow\conf\
    • vCenter Server Appliance - /etc/vmware/vmware-vpx-workflow/conf/
       
  2. Edit these lines setting them to Debug:

    log4j.rootCategory
    log4j.appender.console.Threshold
    log4j.logger.com.vmware.vim.workflow
    log4j.logger.com.vmware.vim.workflow.startup

    For example:

    log4j.rootCategory=DEBUG,Rolling
    log4j.appender.console.Threshold=DEBUG
    log4j.logger.com.vmware.vim.workflow=DEBUG
    log4j.logger.com.vmware.vim.workflow.startup=DEBUG,Startup
 
To increase logging for the VMware VirtualCenter Server service, see Increasing VMware vCenter Server and VMware ESX/ESXi logging levels (1004795).

Increasing VMware vCenter Server and VMware ESX/ESXi logging levels
How to stop, start, or restart vCenter Server 6.x services
Stopping, starting, or restarting VMware vCenter Server Appliance 6.x services
Location of VMware vCenter Server 6.0 log files

Powered by Wolken Software