Recovery Plan Failure During VM Shutdown – Operation Timed Out (300 Seconds)
search cancel

Recovery Plan Failure During VM Shutdown – Operation Timed Out (300 Seconds)

book

Article ID: 393550

calendar_today

Updated On:

Products

VMware Live Recovery

Issue/Introduction

Symptoms

  • During a planned migration, the shutdown of priority VMs may fail with the following error: Operation Timed out: 300 seconds.

  • SRM logs (/var/log/vmware/srm/vmware-dr.log) show repeated timeout errors, for example:

2025-11-29T14:02:02.403+05:30 verbose vmware-dr [01323] [SRM@6876 sub=LocalSite. LocalVcServer. PCM opID=2e####2f-####-####-####-b3########b2-failover:a0eb:####:####:225b-powerOffVm: 6d##: a9##] Starting destruction of filter 'sessionId[52331]52####7d-####-####-####-af########bl'
2025-11-29T14:02:02.404+05:30 error vmware-dr [01336] [SRM@6876 sub=Recovery ctxID=f02dfadd opID=2e####2f-####-####-####-b3########b2-failover:a0eb:####:####:225b-powerOffVm: 6d##: a9##] Wait for guest shutdown failed for VM ' [vim. VirtualMachine:2c####a9-####-####-####-21########ae:vm-10]': N2Dr16TimeoutExceptionE Operation timed out after '300.000000' seconds
2025-11-29T14:02:02.404+05:30 error vmware-dr [01336] [SRM@6876 sub=Recovery ctxID=f02dfadd opID=2e####2f-####-####-####-b3########b2-failover:a0eb:####:####:225b-powerOffVm: 6d##: a9##] Wait for shutdown failed for VM ' [vim.VirtualMachine:2c####a9-####-####-####-21########ae:vm-10]'', bailing out since stop on errors is set. Error: N2Dr16TimeoutExceptionE Operation timed out after '300.000000' seconds
2025-11-29T14:02:02.404+05:30 info vmware-dr[01336] [SRM@6876 sub=DrTask ctxID=f02dfadd opID=2e####2f-####-####-####-b3########b2-failover:a0eb:####:####:225b-powerOffVm: 6d##: a9##] Task 'dr.recovery. RecoveryManager.powerOffVm4' failed

Environment

Site Recovery Manager 8.x

VMware Live Site Recovery 9.0

Cause

The VM required more time to complete its OS-level shutdown.

Justification

  • SRM initiated a PowerState.InitiatePowerOff request.
  • VMware Tools acknowledged the shutdown request (OS_Halt) and began executing it.
  • Tools successfully completed the state change, indicating the VM was performing a clean shutdown.
  • Guest RPC channels (Tools communication) disconnected early, which is expected during OS shutdown.
  • The VM continued internal shutdown tasks (stopping services, flushing data, closing processes) beyond 300 seconds (approximately 13 minutes (from 08:27:02 to 08:40:47).)

Virtual Machine (vmware.log) - 

2025-11-29T08:27:02.309Z In(05) vmx - VigorTransportProcessClientPayload: opID=2e####2f-####-####-####-b3a#####15b2-failover:a0eb:####:####:####--powerOffVm:6d##-ad-72-36## seq=3###154: Receiving PowerState.InitiatePowerOff request.
2025-11-29T08:27:02.309Z In(05) vmx 2e####2f-####-####-####-b3########b2-failover:a0eb:####:####:####-powerOffVm6d##-ad-72-36## Tools: sending 'OS_Halt' (state = 1) state change request
2025-11-29T08:27:02.309Z In(05) vmx 2e####2f-####-####-####-b3########b2-failover:a0eb:####:####:####-powerOffVm:6d##-ad-72-36## Tools: Changing running status: 1 => 2.
2025-11-29T08:27:02.309Z In(05) vmx 2e####2f-####-####-####-b3########b2-failover:a0eb:####:####:####-powerOffVm:6d##-ad-72-36## Tools: [RunningStatus] Last heartbeat value 4313599 (last received 0s ago)
2025-11-29T08:27:02.309Z In(05) vmx 2e####2f-####-####-####-b3########b2-failover:a0eb:####:####:####-powerOffVm:6d##-ad-72-36## Vix: [vmxCommands.c:534]: VMAutomation_InitiatePower1Off. Tried to soft halt. Success = 1
2025-11-29T08:27:02.318Z In(05) vmx - Guest: Executing script for state change 'OS_Halt'.
2025-11-29T08:27:02.329Z In(05) vcpu-2 - Tools: State change '1' progress: last event 0, event 1, success 1.
2025-11-29T08:27:02.400Z In(05) vmx - Guest: Script exit code: 0, success = 1
2025-11-29T08:27:02.400Z In(05) vmx - TOOLS state change 1 returned status 1
2025-11-29T08:27:02.400Z In(05) vmx - Tools: State change '1' progress: last event 1, event 2, success 1.
2025-11-29T08:27:02.400Z In(05) vmx - Tools: State change '1' progress: last event 1, event 4, success 1.
2025-11-29T08:27:02.400Z In(05) vmx - VigorTransport_ServerSendResponse opID=2e####2f-####-####-####-b3a#####15b2-failover:a0eb:####:####:225b-powerOffVm:6d##-ad-72-36## seq=31###54: Completed PowerState.InitiatePowerOff request in 91463 US.
2025-11-29T08:27:02.400Z In(05) vmx - Tools: Changing running status: 2 => 1.
2025-11-29T08:27:02.400Z In(05) vmx - Tools: [RunningStatus] Last heartbeat value 4313599 (last received 0s ago)
2025-11-29T08:27:02.400Z In(05) vmx - Guest: Initiating halt.
2025-11-29T08:27:02.443Z In(05) vcpu-0 - GuestRpc: Reinitializing Channel 1(toolbox-dnd)
2025-11-29T08:27:02.443Z In(05) vcpu-0 - TOOLS: appName=toolbox-dnd, oldStatus=1, status=0, guestInitiated=1.
2025-11-29T08:27:02.443Z In(05) vmx - GuestRpc: Got error for channel 1 connection 504: Remote disconnected
2025-11-29T08:27:02.443Z In(05) vmx - GuestRpc: GuestRpcResetVsockChannel: channel 1
2025-11-29T08:40:42.376Z In(05) vmx - TOOLS autoupgrade protocol version 0
2025-11-29T08:40:42.379Z In(05) vmx - ToolsGetAppInfoEnabledFromConfigStore: Returning the cached value: '1'.
2025-11-29T08:40:42.386Z In(05) vmx - GuestRpc: Got error for channel 0 connection 8: Remote disconnected
2025-11-29T08:40:42.386Z In(05) vmx - GuestRpc: GuestRpcResetVsockChannel: channel 0
2025-11-29T08:40:42.386Z In(05) vcpu-1 - GuestRpc: Reinitializing Channel 0(toolbox)
2025-11-29T08:40:42.386Z In(05) vcpu-1 - Tools: [AppStatus] Last heartbeat value 43###19 (last received 0s ago)
2025-11-29T08:40:42.386Z In(05) vcpu-1 - TOOLS: appName=toolbox, oldStatus=1, status=0, guestInitiated=1.
2025-11-29T08:40:45.117Z In(05) vcpu-1 - VMXNET3 user: Quiesce device 0.
2025-11-29T08:40:45.117Z In(05) vcpu-1 - VMXNET3 user: UPT support is not requested
2025-11-29T08:40:45.117Z In(05) vcpu-1 - Ethernet0 MAC Address: 00:##:##:##:##:ab
2025-11-29T08:40:45.118Z In(05) vcpu-1 - VMXNET3 user: Ethernet0 RSS fields requested by vmx: 3
2025-11-29T08:40:47.119Z In(05) vcpu-3 - PCIXHCI: Interrupt type changed from MSIX to INTX
2025-11-29T08:40:47.188Z In(05) vcpu-0 - PIIX4: PM Soft Off.  Good-bye.
2025-11-29T08:40:47.188Z In(05) vcpu-0 - Chipset: The guest has requested that the virtual machine be powered off.
2025-11-29T08:40:47.188Z No(00) vcpu-0 - ConfigDB: Setting softPowerOff = "TRUE"
2025-11-29T08:40:47.199Z In(05) vcpu-0 - VMX: Issuing power-off request...
2025-11-29T08:40:47.199Z In(05) vmx - Stopping VCPU threads...
2025-11-29T08:40:47.199Z In(05) vcpu-1 - VMMon_WaitForExit: vcpu-1: worldID=12####65
2025-11-29T08:40:47.199Z In(05) vcpu-2 - VMMon_WaitForExit: vcpu-2: worldID=12####66
2025-11-29T08:40:47.199Z In(05) vcpu-0 - VMMon_WaitForExit: vcpu-0: worldID=12####63
2025-11-29T08:40:47.199Z In(05) vcpu-3 - VMMon_WaitForExit: vcpu-3: worldID=12####67
2025-11-29T08:40:47.199Z In(05) vmx - MKSThread: Requesting MKS exit
2025-11-29T08:40:47.199Z In(05) vmx - Stopping MKS/SVGA threads
2025-11-29T08:40:47.200Z In(05) svga - SWBScreen: Screen 1 Destroyed: xywh(0, 0, 1592, 690) flags=0x2
2025-11-29T08:40:47.200Z In(05) svga - SVGA thread is exiting the main loop
2025-11-29T08:40:47.200Z In(05) vmx - MKS/SVGA threads are stopped
2025-11-29T08:40:47.200Z In(05) vmx - USB: DevID(2000########0003): Disconnecting device.
2025-11-29T08:40:47.200Z In(05) vmx -

Although the shutdown request from SRM and VMware Tools was received and processed immediately, the VM took significantly longer to complete the full power-off sequence. This delay occurred inside the guest operating system, not on the VMware layer.

Several OS-level factors can cause a delayed shutdown. Based on the logs, the VM went through a slow and extended shutdown sequence, which indicates that the OS was still completing internal tasks before allowing the final power-off.

Resolution

Workaround 

Increase Recovery Power-Off Timeout in SRM

  • Log in to the vSphere Web Client and go to Site Recovery -- Open Site Recovery.

  • On the Site Recovery home tab, select the site pair and click View Details.

  • In the left pane, navigate to Configure -- Advanced Settings -- Recovery.

  • Click Edit.

  • Change recovery.powerOffTimeout from 300 seconds (default) to 900 seconds.

  • Repeat steps 1–5 on the other site.

  • Restart Site Recovery Manager services on both sites for changes to take effect.

Resolution

Investigate Slow Guest OS Shutdown

  • If VMs still take longer than expected, engage the guest OS vendor to identify processes or services causing extended shutdown times.