Virtual machine hangs due to RCU stall and sapstartsrv soft lockup on RHEL guest

Products

• VMware vSphere ESXi

Issue/Introduction

A virtual machine (VM) running Red Hat Enterprise Linux (RHEL) and SAP becomes unresponsive. The following indicators are observed, starting from the hypervisor layer and progressing to the internal guest logs:

Initial observation at the host level shows the VM is powered on but unresponsive to network or console input. The vmware.log confirms the hypervisor has lost communication with the internal VMware Tools service.

/vmfs/volumes/datastore/vm name/vmware.log: The logs indicate VMware Tools heartbeat timeouts and internal RPC failures while the guest is hung.

YYYY-MM-DDThh:mm:ss| vmx| | I005: GuestRpcSendTimedOut: message to toolbox timed out.
YYYY-MM-DDThh:mm:ss| vmx| | I005: Tools: [AppStatus] Last heartbeat value #### (last received 20s ago)
YYYY-MM-DDThh:mm:ss| vmx| | I005: GuestRpc: app toolbox's second ping timeout; assuming app is down
YYYY-MM-DDThh:mm:ss| vcpu-0| | I005: Tools: Tools heartbeat timeout.
YYYY-MM-DDThh:mm:ss| vmx| | I005: Guest: *** WARNING: GuestInfo collection interval longer than expected; actual=218 sec, expected=30 sec. ***

Upon rebooting the VM and gaining access to the console, the guest kernel logs show that the internal OS watchdog triggered due to scheduling stalls.

/var/log/messages: The Guest kernel log shows RCU scheduling stalls followed by soft lockups on one or more CPUs, specifically involving sapstartsrv or kworker processes:

MM-DDThh:mm:ss #### kernel: rcu: INFO: rcu_sched self-detected stall on CPU
MM-DDThh:mm:ss #### kernel: rcu: Possible timer handling issue on cpu=1
MM-DDThh:mm:ss #### kernel: rcu: rcu_sched kthread starved for #### jiffies! ->cpu=1
MM-DDThh:mm:ss #### kernel: watchdog: BUG: soft lockup - CPU#1 stuck for ####s! [sapstartsrv:####]
MM-DDThh:mm:ss #### kernel: watchdog: BUG: soft lockup - CPU#0 stuck for ####s! [kworker/0:1H:####]

Environment

VMware vSphere ESXi 

Cause

A definitive root cause cannot be established at the hypervisor layer. The logs indicate an internal guest OS unresponsiveness, specifically an RCU (Read-Copy-Update) scheduling stall and soft lockup involving the sapstartsrv process. These events occurred without correlated errors or interruptions from the ESXi hypervisor.

Resolution

Follow these steps to eliminate host-level issues:

Note: Perform these validation steps sequentially to rule out underlying infrastructure factors. Once you have verified that host CPU and storage are not the cause, proceed to engage the OS vendor.

1. Engage the OS and application vendors to investigate RHEL and SAP support resources if the above symptoms in Guest Operating system logs holds a match.
2. Resource contention can also occur due to CPU starvation.
   
   1. Review ESXi host performance metrics, specifically CPU Ready (%RDY), for the affected virtual machine around the incident time to rule out host-level CPU contention. For detailed steps, see Troubleshooting VM performance
      
      1. Click on the affected Host > Monitor > Performance to check for spikes or sustained high CPU Ready time (%RDY) leading up to and during the exact timeframe of the lockups. As a general rule, %RDY values consistently above 5% to 10% per vCPU are abnormal.
      2. High CPU Ready time means the VM is ready to execute tasks but is waiting for the ESXi scheduler to assign it physical CPU cycles (typically due to host CPU overcommitment or improperly sized VMs).
         Note: If the hypervisor delays giving CPU time to the VM for too long, the internal watchdog timers in the Linux kernel expire. The guest OS interprets this hypervisor-induced pause as a frozen process, which triggers the false "RCU stall" and "soft lockup" errors seen in the logs.
3. Further validation can also be performed if storage latency leads to resource contention for Guest Operating System. If the storage subsystem is slow, I/O threads in the guest (like kworker) may hang, leading to soft lockups.
   1. Log in to the ESXi host via SSH and run esxtop. Press 'u' to switch to the disk device view.
   2. Metrics to monitor are as below: For threshols refer Using esxtop to identify storage performance issues for ESXi
      
      1. DAVG: Latency from the ESXi host to the storage array. Persistent values above 20ms or spikes to 2,000ms+ indicate a physical storage or fabric issue.
      2. KAVG: Time spent in the ESXi storage stack. High KAVG indicates queuing within the hypervisor.
      3. GAVG: The total latency seen by the VM.
   3. Review /var/run/log/vmkernel.log for warnings such as: performance has deteriorated. I/O latency increased.
      Log snippet for reference: 
      [YYYY-MM-DDTHH:MM:SS] cpu51:#)WARNING: ScsiDeviceIO: 513: Device naa.########## performance has deteriorated. I/O latency increased from average value of 38762 microseconds to 776315 microseconds.
[YYYY-MM-DDTHH:MM:SS] cpu47:#)WARNING: ScsiDeviceIO: 1443: Device naa.######### performance has deteriorated. I/O latency increased from average value of 12017 microseconds to 254228 microseconds.

Additional Information

Soft lockup and rcu_sched can srall for multiple reasons. One such example can be seen from vendor documentation as below: 

System hangs with soft lockup and rcu_sched CPU stall events

Broadcom KB for high latency: 

High latency is observed on storage and virtual machines