os-vmware problems with ESXi 8

[Neuer_User]

Hello

I use opnsense on a protectli clone as a VM under ESXi, which so far seems to work fine. However, when I install the plugin os-vmware, I get frequent hard resets of the machine, typically 1-2 per day. The vmware.log looks like this:

Code: [Select]

2023-03-31T18:02:54.996Z In(05) vmx - MKSVMX: Vigor requested a screenshot
2023-03-31T18:02:54.997Z In(05) svga - MKSScreenShotMgr: Taking a screenshot
2023-03-31T20:53:32.316Z In(05) vcpu-0 - TOOLS Received tools.set.version rpc call, version = TOOLS_VERSION_NONE (uninstalled), type is unset
2023-03-31T20:53:32.316Z In(05) vcpu-0 - TOOLS Setting toolsVersionStatus = TOOLS_STATUS_NO_TOOLS
2023-03-31T20:53:32.316Z In(05) vcpu-0 - TOOLS setting legacy tools version to '0' type -1, manifest status is 7
2023-03-31T20:53:32.316Z In(05) vcpu-0 - Tools_SetVersionAndType: Updating the Tools Version in the disk
2023-03-31T20:53:32.331Z In(05) vcpu-0 - Tools_SetVersionAndType: Done updating the Tools Version in the disk
2023-03-31T20:53:32.331Z In(05) vcpu-0 - TOOLS using cached value 0 for isoImageExists (refreshCount=1, lastCount=1).
2023-03-31T20:53:32.331Z In(05) vcpu-0 - VMXVmdb_SetToolsVersionStatus: status value set to 'notAvailable', 'noTools', install impossible
2023-03-31T20:53:32.331Z No(00) vcpu-0 - ConfigDB: Setting toolsInstallManager.updateCounter = "3"
2023-03-31T20:53:32.333Z No(00) vcpu-0 - ConfigDB: Setting extendedConfigFile = "opnsense.vmxf"
2023-03-31T21:55:11.804Z In(05) vcpu-0 - CPU reset: soft (mode Emulation)
2023-03-31T21:55:11.804Z In(05) vcpu-1 - CPU reset: soft (mode HV)
2023-03-31T21:55:11.804Z In(05) vcpu-2 - CPU reset: soft (mode HV)
2023-03-31T21:55:11.804Z In(05) vcpu-3 - CPU reset: soft (mode HV)
2023-03-31T21:55:11.805Z In(05) vcpu-0 - SVGA: Unregistering IOSpace at 0x1070
2023-03-31T21:55:11.805Z In(05) vcpu-0 - SVGA: Unregistering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)
2023-03-31T21:55:11.805Z In(05) vcpu-0 - SVGA: FIFO is already mapped
2023-03-31T21:55:11.818Z In(05) vcpu-0 - PCIBridge4: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.818Z In(05) vcpu-0 - pciBridge4:1: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.818Z In(05) vcpu-0 - pciBridge4:2: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.818Z In(05) vcpu-0 - pciBridge4:3: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.819Z In(05) vcpu-0 - pciBridge4:4: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.819Z In(05) vcpu-0 - pciBridge4:5: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.819Z In(05) vcpu-0 - pciBridge4:6: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.819Z In(05) vcpu-0 - pciBridge4:7: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.819Z In(05) vcpu-0 - PCIBridge5: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.819Z In(05) vcpu-0 - pciBridge5:1: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.819Z In(05) vcpu-0 - pciBridge5:2: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.819Z In(05) vcpu-0 - pciBridge5:3: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.819Z In(05) vcpu-0 - pciBridge5:4: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.819Z In(05) vcpu-0 - pciBridge5:5: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.819Z In(05) vcpu-0 - pciBridge5:6: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.819Z In(05) vcpu-0 - pciBridge5:7: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.820Z In(05) vcpu-0 - PCIBridge6: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.820Z In(05) vcpu-0 - pciBridge6:1: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.820Z In(05) vcpu-0 - pciBridge6:2: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.820Z In(05) vcpu-0 - pciBridge6:3: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.820Z In(05) vcpu-0 - pciBridge6:4: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.820Z In(05) vcpu-0 - pciBridge6:5: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.820Z In(05) vcpu-0 - pciBridge6:6: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.820Z In(05) vcpu-0 - pciBridge6:7: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.820Z In(05) vcpu-0 - PCIBridge7: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.820Z In(05) vcpu-0 - pciBridge7:1: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.820Z In(05) vcpu-0 - pciBridge7:2: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.821Z In(05) vcpu-0 - pciBridge7:3: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.821Z In(05) vcpu-0 - pciBridge7:4: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.821Z In(05) vcpu-0 - pciBridge7:5: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.821Z In(05) vcpu-0 - pciBridge7:6: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.821Z In(05) vcpu-0 - pciBridge7:7: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T21:55:11.832Z In(05) vcpu-0 - Chipset: The guest has requested that the virtual machine be hard reset.
2023-03-31T21:55:11.836Z In(05) vcpu-0 - Destroying virtual dev for scsi0:0 vscsi=1136439756595205
2023-03-31T21:55:11.836Z In(05) vcpu-0 - VMMon_VSCSIStopVports: No such target on adapter
2023-03-31T21:55:11.838Z In(05) vcpu-0 - DEVICE: Resetting device 'ALL'.
2023-03-31T21:55:11.838Z In(05) vcpu-0 - USB: Per-Device Resetting device 0x1000000105572008
2023-03-31T21:55:12.297Z Wa(03) vcpu-0 - USBGL: DevID(1000000105572008): Failed to reset device. Error(0x16): Invalid argument.
2023-03-31T21:55:12.297Z Wa(03) vcpu-0 - USBGL: DevID(1000000105572008): Failed to reset port.
2023-03-31T21:55:12.297Z In(05) vcpu-0 - USB: Per-Device Resetting device 0x200000050e0f0003
or this:

Code: [Select]

2023-03-30T07:37:39.993Z In(05) svga - MKSScreenShotMgr: Taking a screenshot
2023-03-30T07:38:40.044Z In(05) vmx - MKSVMX: Vigor requested a screenshot
2023-03-30T07:38:40.045Z In(05) svga - MKSScreenShotMgr: Taking a screenshot
2023-03-31T12:57:57.019Z In(05) vmx - GuestRpcSendTimedOut: message to toolbox timed out.
2023-03-31T12:57:57.019Z In(05) vmx - Tools: [AppStatus] Last heartbeat value 459578 (last received 8s ago)
2023-03-31T12:57:57.019Z In(05) vmx - TOOLS: appName=toolbox, oldStatus=1, status=2, guestInitiated=0.
2023-03-31T12:58:01.162Z In(05) vcpu-0 - CPU reset: soft (mode Emulation)
2023-03-31T12:58:01.162Z In(05) vcpu-2 - CPU reset: soft (mode HV)
2023-03-31T12:58:01.162Z In(05) vcpu-3 - CPU reset: soft (mode HV)
2023-03-31T12:58:01.162Z In(05) vcpu-1 - CPU reset: soft (mode HV)
2023-03-31T12:58:01.163Z In(05) vcpu-0 - SVGA: Unregistering IOSpace at 0x1070
2023-03-31T12:58:01.163Z In(05) vcpu-0 - SVGA: Unregistering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)
2023-03-31T12:58:01.163Z In(05) vcpu-0 - SVGA: FIFO is already mapped
2023-03-31T12:58:01.174Z In(05) vcpu-0 - PCIBridge4: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.174Z In(05) vcpu-0 - pciBridge4:1: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.174Z In(05) vcpu-0 - pciBridge4:2: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.175Z In(05) vcpu-0 - pciBridge4:3: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.175Z In(05) vcpu-0 - pciBridge4:4: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.175Z In(05) vcpu-0 - pciBridge4:5: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.175Z In(05) vcpu-0 - pciBridge4:6: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.175Z In(05) vcpu-0 - pciBridge4:7: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.175Z In(05) vcpu-0 - PCIBridge5: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.175Z In(05) vcpu-0 - pciBridge5:1: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.175Z In(05) vcpu-0 - pciBridge5:2: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.175Z In(05) vcpu-0 - pciBridge5:3: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.175Z In(05) vcpu-0 - pciBridge5:4: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.175Z In(05) vcpu-0 - pciBridge5:5: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.176Z In(05) vcpu-0 - pciBridge5:6: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.176Z In(05) vcpu-0 - pciBridge5:7: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.176Z In(05) vcpu-0 - PCIBridge6: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.176Z In(05) vcpu-0 - pciBridge6:1: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.176Z In(05) vcpu-0 - pciBridge6:2: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.176Z In(05) vcpu-0 - pciBridge6:3: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.176Z In(05) vcpu-0 - pciBridge6:4: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.176Z In(05) vcpu-0 - pciBridge6:5: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.176Z In(05) vcpu-0 - pciBridge6:6: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.176Z In(05) vcpu-0 - pciBridge6:7: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.176Z In(05) vcpu-0 - PCIBridge7: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.176Z In(05) vcpu-0 - pciBridge7:1: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.177Z In(05) vcpu-0 - pciBridge7:2: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.177Z In(05) vcpu-0 - pciBridge7:3: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.177Z In(05) vcpu-0 - pciBridge7:4: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.177Z In(05) vcpu-0 - pciBridge7:5: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.177Z In(05) vcpu-0 - pciBridge7:6: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.177Z In(05) vcpu-0 - pciBridge7:7: ISA/VGA decoding enabled (ctrl 0004)
2023-03-31T12:58:01.189Z In(05) vcpu-0 - Chipset: The guest has requested that the virtual machine be hard reset.
2023-03-31T12:58:01.190Z In(05) vcpu-0 - Destroying virtual dev for scsi0:0 vscsi=1136439756595204
2023-03-31T12:58:01.190Z In(05) vcpu-0 - VMMon_VSCSIStopVports: No such target on adapter
2023-03-31T12:58:01.194Z In(05) vcpu-0 - DEVICE: Resetting device 'ALL'.
2023-03-31T12:58:01.194Z In(05) vcpu-0 - USB: Per-Device Resetting device 0x1000000105572008
2023-03-31T12:58:01.647Z Wa(03) vcpu-0 - USBGL: DevID(1000000105572008): Failed to reset device. Error(0x16): Invalid argument.
2023-03-31T12:58:01.647Z Wa(03) vcpu-0 - USBGL: DevID(1000000105572008): Failed to reset port.
2023-03-31T12:58:01.647Z In(05) vcpu-0 - USB: Per-Device Resetting device 0x200000050e0f0003
2023-03-31T12:58:01.647Z In(05) vcpu-0 - Tools: ToolsRunningStatus_Reset, delayedRequest is 0x0
2023-03-31T12:58:01.647Z In(05) vcpu-0 - Tools: Changing running status: 1 => 0.
2023-03-31T12:58:01.647Z In(05) vcpu-0 - Tools: [RunningStatus] Last heartbeat value 459578 (last received 13s ago)

The main interesting line seems to be this:

Code: [Select]

vcpu-0 - Chipset: The guest has requested that the virtual machine be hard reset.
With os-vmware deinstalled the box is running without any issues for several days now. Anyone else with similar experience?

[benyamin]

Trying to make sense of your logs...

In the first log, the tools have crashed or are not installed. The status is 0 which is UNKNOWN.

In the second log, the status is 2 which is OLD, at least for the toolbox.

Perhaps check the version of tools installed. It should be 12.2.0_2.

Did you reboot after initial installation of the plugin?

Are you stunning the VM for any reason?

[Neuer_User]

Yes, the machine was rebootet. But additionally, it had rebooted around 1-2 times a day for about a week now, so approximately 10 reboots. This only stopped after I unistalled the os-vmware plugin. Since then the appliance is running for now four days without any issues. So I was wondering, if that could be related to the logs I attached

Are there other people using the os-vmware plugin with ESXi 8 successfully?

Are you stunning the VM for any reason?

Not that I would be aware of in any way. CPU usage is typically in the low 0-9%, with a few spikes to around 20-30%, and very rare 100% spikes (always only for a second or so). I am running Netflow and NgNTop, but nothing more.

Addendum: I forgot to mention that I am running OPNsense 23.1.4_1-amd64 (haven't updated to 23.1.5, maybe I should...)

[Neuer_User]

I will give it another try. I updated to 23.1.5-4 and also ESXi to 8.0c. I'll report back if I see again reboots.

[benyamin]

Perhaps check that open-vm-tools-nox11 version too. I'd normally check at the console / ssh with pkg, but it should also show up under packages once installed.

Stunning refers to quiescing the disk. The only other time I've seen something like this is when the disk takes too long to respond when being stunned and a hard reset occurs.

Yours seems to be more related to CPU resets. Perhaps more closely emulate the hardware profile, so if you have a dual core CPU and one socket, perhaps set the VM up to emulate that rather than trying to emulate more cores than you might have.

Are there other people using the os-vmware plugin with ESXi 8 successfully?

I migrated away from ESX last year so I'm unable to check without quite some work. Anyone else...?

[Neuer_User]

OK, so with the updated software the opnsense router worked for nearly 6 days. Then the same problem again. This is from VMWARE log:

Code: [Select]

2023-04-06T14:32:50.256Z In(05) vcpu-3 - E1000: e1000e-- tx queue 1 is enabled.
2023-04-06T14:32:50.256Z In(05) vcpu-3 - E1000: e1000e-- tx queue 1 is enabled.
2023-04-11T16:53:11.740Z In(05) vmx - GuestRpcSendTimedOut: message to toolbox timed out.
2023-04-11T16:53:11.740Z In(05) vmx - Tools: [AppStatus] Last heartbeat value 626418 (last received 11s ago)
2023-04-11T16:53:11.741Z In(05) vmx - TOOLS: appName=toolbox, oldStatus=1, status=2, guestInitiated=0.
2023-04-11T16:53:12.230Z In(05) vcpu-0 - CPU reset: soft (mode Emulation)
2023-04-11T16:53:12.230Z In(05) vcpu-1 - CPU reset: soft (mode HV)
2023-04-11T16:53:12.230Z In(05) vcpu-3 - CPU reset: soft (mode HV)
2023-04-11T16:53:12.230Z In(05) vcpu-2 - CPU reset: soft (mode HV)
2023-04-11T16:53:12.231Z In(05) vcpu-0 - SVGA: Unregistering IOSpace at 0x1070
2023-04-11T16:53:12.231Z In(05) vcpu-0 - SVGA: Unregistering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)
2023-04-11T16:53:12.231Z In(05) vcpu-0 - SVGA: FIFO is already mapped
2023-04-11T16:53:12.242Z In(05) vcpu-0 - PCIBridge4: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.242Z In(05) vcpu-0 - pciBridge4:1: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.242Z In(05) vcpu-0 - pciBridge4:2: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.242Z In(05) vcpu-0 - pciBridge4:3: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.242Z In(05) vcpu-0 - pciBridge4:4: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.242Z In(05) vcpu-0 - pciBridge4:5: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.243Z In(05) vcpu-0 - pciBridge4:6: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.243Z In(05) vcpu-0 - pciBridge4:7: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.243Z In(05) vcpu-0 - PCIBridge5: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.243Z In(05) vcpu-0 - pciBridge5:1: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.243Z In(05) vcpu-0 - pciBridge5:2: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.243Z In(05) vcpu-0 - pciBridge5:3: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.243Z In(05) vcpu-0 - pciBridge5:4: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.243Z In(05) vcpu-0 - pciBridge5:5: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.243Z In(05) vcpu-0 - pciBridge5:6: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.243Z In(05) vcpu-0 - pciBridge5:7: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.243Z In(05) vcpu-0 - PCIBridge6: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.244Z In(05) vcpu-0 - pciBridge6:1: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.244Z In(05) vcpu-0 - pciBridge6:2: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.244Z In(05) vcpu-0 - pciBridge6:3: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.244Z In(05) vcpu-0 - pciBridge6:4: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.244Z In(05) vcpu-0 - pciBridge6:5: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.244Z In(05) vcpu-0 - pciBridge6:6: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.244Z In(05) vcpu-0 - pciBridge6:7: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.244Z In(05) vcpu-0 - PCIBridge7: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.244Z In(05) vcpu-0 - pciBridge7:1: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.244Z In(05) vcpu-0 - pciBridge7:2: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.244Z In(05) vcpu-0 - pciBridge7:3: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.245Z In(05) vcpu-0 - pciBridge7:4: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.245Z In(05) vcpu-0 - pciBridge7:5: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.245Z In(05) vcpu-0 - pciBridge7:6: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.245Z In(05) vcpu-0 - pciBridge7:7: ISA/VGA decoding enabled (ctrl 0004)
2023-04-11T16:53:12.256Z In(05) vcpu-0 - Chipset: The guest has requested that the virtual machine be hard reset.
2023-04-11T16:53:12.258Z In(05) vcpu-0 - Destroying virtual dev for scsi0:0 vscsi=1136783353978881

Again the exact same message "The guest has requested that the virtual machine be hard reset."

I also logged all messages from opnsense on a remote syslog server. There is nothing in there. The reset came out of the blue for opnsense.

If there is no fix for that, I will 1.) observe the behaviour for another couple of days/weeks (depending on what happens). then 2.) will deactivate os-vmware again and see if that fixes the problem once and forever, and 3.) if nothing helps, then install Proxmox instead of esxi. 

[benyamin]

You might try recreating the virtual hardware too...

I presume you are using PVSCSI, VMXNET3 and virtual HW version 20.

What OS did you select for the VM?

What physical CPU is in your clone? Is it a quad-core?

You may also want to keep an eye on memory usage in case there is a leak.

[Neuer_User]

Thanks for your help, Ben.

I am very new to esxi, so I am not really much familiar with it yet. (Been a proxmox user before.)

The physical hardware is a HUNSN RJ03 with a N5105 celeron CPU, 16GB RAM and a 256 GB M2. SSD. The virtual HW uses a four core processor with four threads (so identical to the host CPU), 8GB RAM, a LSI Logic Parallel SCSI controller and three e1000 virtual NICs.

I still have no idea why these hard resets happen. This night there was another one. Again there is no message in remote syslog. The vmware log has again the same entries (so a tools timeout). I don't know, if there really is a problem in the virtual machine or if that is a software bug in the vmware-tools package.

I guess the next test should be without the vmware-tools package and see, if there will be some real issues after a couple of days (which would have initiated the vmware-tools hard reset) or if the machine continues working without problems.

[benyamin]

At a glance, you aren't using the recommended virtual hardware. You should definetely be using PVSCSI and VMXNET3. This could be a result of not using the correct Guest OS Family and Version when you created the VM. iirc, Guest OS Family should be set to "Other" and the Version should be equivalent to FreeBSD 13 (64-bit). For reference, the relevant compatibility guide can be found here.

Also, have you checked logs at var/log/vmware-<service>.log where <service> is one of vmsvc, vmusr or toolboxcmd. If no logs are present, you might need to enable debug logging per this VMware article. The cause of any vmware-tools initiated reset will likely be found in these logs.

[Neuer_User]

Thanks for the lots of good information. For me as a total newbie for esxi that is very helpful.

I modified the virtual hardware now so to use PVSCSI and VMXNET3 drivers. (The switch to the different nic drivers actually was a pain in the ..., as simply switching to them on the esxi interface made them completely dysfunctional and a switching back to e1000e just gave an "invalid config" message. I needed to remove the interfaces and then create new ones. Now it is working.) Guest OS Family was already set to "FreeBSD 13 (64bit)".

The performance seems to be somewhat worse now with the vmxnet drivers than with the e1000 drivers but still sufficient. I will now give it some time to see if I get hard resets again. If yes, I will then add the vmware.conf file (which is missing on opnsense) so that it starts logging debug info.

[Neuer_User]

 

Ok, that was faster than expected. Hard reset happened already, now even with fully "recommended" HW settings. And a second hard reset only 7 min later. Same vmware.log entries. Here is the first reset:

Code: [Select]

2023-04-17T06:47:50.338Z In(05) vcpu-0 - VMXNET3 user: Ethernet1 Driver Info: version = 65536 gosBits = 2 gosType = 4, gosVer = 0, gosMisc = 0
2023-04-17T06:47:50.338Z In(05) vcpu-0 - VMXNET3 user: Activate request succeeds for device 1.
2023-04-17T12:24:44.966Z In(05) vmx - GuestRpcSendTimedOut: message to toolbox timed out.
2023-04-17T12:24:44.966Z In(05) vmx - Tools: [AppStatus] Last heartbeat value 90444 (last received 8s ago)
2023-04-17T12:24:44.966Z In(05) vmx - TOOLS: appName=toolbox, oldStatus=1, status=2, guestInitiated=0.
2023-04-17T12:24:45.209Z In(05) vcpu-0 - CPU reset: soft (mode Emulation)
2023-04-17T12:24:45.209Z In(05) vcpu-1 - CPU reset: soft (mode HV)
2023-04-17T12:24:45.209Z In(05) vcpu-3 - CPU reset: soft (mode HV)
2023-04-17T12:24:45.209Z In(05) vcpu-2 - CPU reset: soft (mode HV)
2023-04-17T12:24:45.211Z In(05) vcpu-0 - SVGA: Unregistering IOSpace at 0x1070
2023-04-17T12:24:45.211Z In(05) vcpu-0 - SVGA: Unregistering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)
2023-04-17T12:24:45.211Z In(05) vcpu-0 - SVGA: FIFO is already mapped
...
2023-04-17T12:24:45.692Z In(05) vcpu-0 - Tools: ToolsRunningStatus_Reset, delayedRequest is 0x0
2023-04-17T12:24:45.692Z In(05) vcpu-0 - Tools: Changing running status: 1 => 0.
2023-04-17T12:24:45.692Z In(05) vcpu-0 - Tools: [RunningStatus] Last heartbeat value 90444 (last received 9s ago)
2023-04-17T12:24:45.692Z In(05) vcpu-0 - GuestLib Generated SessionId 15800366821342947488
2023-04-17T12:24:45.693Z In(05) vcpu-0 - GuestRpc: Reinitializing Channel 0(toolbox)
2023-04-17T12:24:45.693Z In(05) vcpu-0 - GuestMsg: Channel 0, Cannot unpost because the previous post is already completed
2023-04-17T12:24:45.693Z In(05) vcpu-0 - Tools: [AppStatus] Last heartbeat value 90444 (last received 9s ago)
2023-04-17T12:24:45.693Z In(05) vcpu-0 - TOOLS: appName=toolbox, oldStatus=2, status=0, guestInitiated=0.
2023-04-17T12:24:45.693Z In(05) vcpu-0 - TOOLS: appName=toolbox-dnd, oldStatus=0, status=0, guestInitiated=0.
2023-04-17T12:24:45.693Z In(05) vcpu-0 - VMXNET3 user: UPT support is not requested
2023-04-17T12:24:45.694Z In(05) vcpu-0 - Ethernet2 MAC Address: 00:0c:29:fe:1a:84
2023-04-17T12:24:45.694Z In(05) vcpu-0 - VMXNET3 user: Ethernet2 RSS fields requested by vmx: 3
2023-04-17T12:24:45.694Z In(05) vcpu-0 - VMXNET3 user: UPT support is not requested
2023-04-17T12:24:45.694Z In(05) vcpu-0 - Ethernet1 MAC Address: 00:0c:29:fe:1a:7a
2023-04-17T12:24:45.694Z In(05) vcpu-0 - VMXNET3 user: Ethernet1 RSS fields requested by vmx: 3
2023-04-17T12:24:45.694Z In(05) vcpu-0 - VMXNET3 user: UPT support is not requested
2023-04-17T12:24:45.694Z In(05) vcpu-0 - Ethernet0 MAC Address: 00:0c:29:fe:1a:70
2023-04-17T12:24:45.694Z In(05) vcpu-0 - VMXNET3 user: Ethernet0 RSS fields requested by vmx: 3
2023-04-17T12:24:45.694Z In(05) vcpu-0 - UHCI: HCReset
2023-04-17T12:24:45.694Z In(05) vcpu-0 - Checkpoint_Unstun: vm stopped for 458828 us
2023-04-17T12:24:45.695Z In(05) vcpu-0 - CPU reset: hard (mode Emulation)
2023-04-17T12:24:45.695Z In(05) vcpu-1 - CPU reset: hard (mode Emulation)
2023-04-17T12:24:45.695Z In(05) vcpu-3 - CPU reset: hard (mode Emulation)
2023-04-17T12:24:45.695Z In(05) vcpu-2 - CPU reset: hard (mode Emulation)
2023-04-17T12:24:45.696Z In(05) vcpu-0 - PVSCSI: scsi0: switching to async
2023-04-17T12:24:45.696Z In(05) vcpu-0 - Creating virtual dev for 'scsi0:0'.
2023-04-17T12:24:45.696Z In(05) vcpu-0 - DumpDiskInfo: scsi0:0 createType=11, capacity = 16777216, numLinks = 4
2023-04-17T12:24:45.696Z In(05) vcpu-0 - , allocationType = 2
2023-04-17T12:24:45.696Z In(05) vcpu-0 -
2023-04-17T12:24:45.696Z In(05) vcpu-0 - SCSIDiskESXPopulateVDevDesc: Using FS backend
2023-04-17T12:24:45.696Z In(05) vcpu-0 - DISKUTIL: scsi0:0 : geometry=1044/255/63
2023-04-17T12:24:45.696Z In(05) vcpu-0 - SCSIFilterESXAttachCBRCInt: CBRC not enabled or opened without filters,skipping CBRC           filter attach.
2023-04-17T12:24:45.696Z In(05) vcpu-0 - SCSIFilterESXAttachCBRCInt: Invalidating all hashes for this digest
2023-04-17T12:24:45.697Z In(05) vcpu-0 - SCSIFilterSBDAttachCBRC: device scsi0:0 is not SBD. Skipping CBRC attach SBD way.
2023-04-17T12:24:45.697Z In(05) vcpu-0 - DataSetsMgrSync: Reconnect dataSets store after checkpoint.
2023-04-17T12:24:45.697Z In(05) vcpu-0 - CPT: vm was stunned for 461410 us
2023-04-17T12:24:45.700Z In(05) vcpu-0 - OpNotificationMgr_RemoveAllApps: Attempting to remove registered apps during warm or cold reboot
...
2023-04-17T12:24:46.032Z In(05) vcpu-1 - CPU reset: soft (mode Emulation)
2023-04-17T12:24:46.033Z In(05) vcpu-2 - CPU reset: soft (mode Emulation)
2023-04-17T12:24:46.034Z In(05) vcpu-3 - CPU reset: soft (mode Emulation)
...
2023-04-17T12:24:52.526Z In(05) vcpu-2 - UHCI: HCReset
2023-04-17T12:24:52.626Z In(05) vcpu-2 - VMXNET3 user: UPT support is not requested
2023-04-17T12:24:52.626Z In(05) vcpu-2 - Ethernet2 MAC Address: 00:0c:29:fe:1a:84
2023-04-17T12:24:52.626Z In(05) vcpu-2 - VMXNET3 user: Ethernet2 RSS fields requested by vmx: 3
2023-04-17T12:24:52.626Z In(05) vcpu-2 - VMXNET3 user: Supported set 0x000000ff, configured set 0x00000001
2023-04-17T12:24:52.626Z In(05) vcpu-2 - Ethernet2 MAC Address: 00:0c:29:fe:1a:84
2023-04-17T12:24:52.626Z In(05) vcpu-2 - Ethernet2 MAC Address: 00:0c:29:fe:1a:84
2023-04-17T12:24:52.695Z In(05) vcpu-2 - PVSCSI: ReqRing: 1024 entries, eSz=128, 32 pages
2023-04-17T12:24:52.695Z In(05) vcpu-2 - PVSCSI: CmpRing: 4096 entries, eSz=32, 32 pages
2023-04-17T12:24:52.695Z In(05) vcpu-2 - PVSCSI: MsgRing: 32 entries, eSz=128, 1 pages
2023-04-17T12:24:52.695Z In(05) vcpu-2 - PVSCSI: scsi0: switching to sync
2023-04-17T12:24:52.695Z In(05) vcpu-2 - PVSCSI: scsi0: init reqCallThresholdCapable 1
2023-04-17T12:24:52.740Z In(05) vcpu-2 - VMXNET3 user: UPT support is not requested
2023-04-17T12:24:52.740Z In(05) vcpu-2 - Ethernet0 MAC Address: 00:0c:29:fe:1a:70
2023-04-17T12:24:52.740Z In(05) vcpu-2 - VMXNET3 user: Ethernet0 RSS fields requested by vmx: 3
2023-04-17T12:24:52.740Z In(05) vcpu-2 - VMXNET3 user: Supported set 0x000000ff, configured set 0x00000001
2023-04-17T12:24:52.740Z In(05) vcpu-2 - Ethernet0 MAC Address: 00:0c:29:fe:1a:70
2023-04-17T12:24:52.740Z In(05) vcpu-2 - Ethernet0 MAC Address: 00:0c:29:fe:1a:70
2023-04-17T12:24:52.798Z In(05) vcpu-1 - VMXNET3 user: UPT support is not requested
2023-04-17T12:24:52.798Z In(05) vcpu-1 - Ethernet1 MAC Address: 00:0c:29:fe:1a:7a
2023-04-17T12:24:52.799Z In(05) vcpu-1 - VMXNET3 user: Ethernet1 RSS fields requested by vmx: 3
2023-04-17T12:24:52.799Z In(05) vcpu-1 - VMXNET3 user: Supported set 0x000000ff, configured set 0x00000001
2023-04-17T12:24:52.799Z In(05) vcpu-1 - Ethernet1 MAC Address: 00:0c:29:fe:1a:7a
2023-04-17T12:24:52.799Z In(05) vcpu-1 - Ethernet1 MAC Address: 00:0c:29:fe:1a:7a
2023-04-17T12:24:56.307Z In(05) vcpu-0 - Tools: Tools heartbeat timeout.
2023-04-17T12:24:56.307Z In(05) vcpu-0 - Tools: Running status rpc handler: 0 => 0.
2023-04-17T12:24:58.391Z Wa(03) vmx - USBGL: DevID(1000000105572008): Failed to reset device. Error(0x16): Invalid argument.
2023-04-17T12:24:58.391Z Wa(03) vmx - USBGL: DevID(1000000105572008): Failed to reset port.
2023-04-17T12:24:58.565Z In(05) vmx - USBGL: DevID(1000000105572008): Claimed device interface(0) successfully.
2023-04-17T12:25:08.283Z Wa(03) vcpu-0 - Balloon: Start: vmmemctl reset balloon
2023-04-17T12:25:11.793Z In(05) vcpu-3 - VMXNET3 user: UPT support is not requested
2023-04-17T12:25:11.793Z In(05) vcpu-3 - Ethernet0 MAC Address: 00:0c:29:fe:1a:70
2023-04-17T12:25:11.793Z In(05) vcpu-3 - VMXNET3 user: Ethernet0 RSS fields requested by vmx: 3
2023-04-17T12:25:11.799Z In(05) vcpu-3 - VMXNET3 user: Activate device 0.
2023-04-17T12:25:11.799Z In(05) vcpu-3 - VMXNET3 user: Ethernet0 Driver Info: version = 65536 gosBits = 2 gosType = 4, gosVer = 0, gosMisc = 0
2023-04-17T12:25:11.799Z In(05) vcpu-3 - VMXNET3 user: Activate request succeeds for device 0.
2023-04-17T12:25:11.823Z In(05) vcpu-0 - VMXNET3 user: Quiesce device 0.
2023-04-17T12:25:11.823Z In(05) vcpu-0 - VMXNET3 user: UPT support is not requested
2023-04-17T12:25:11.823Z In(05) vcpu-0 - Ethernet0 MAC Address: 00:0c:29:fe:1a:70
2023-04-17T12:25:11.823Z In(05) vcpu-0 - VMXNET3 user: Ethernet0 RSS fields requested by vmx: 3
2023-04-17T12:25:11.827Z In(05) vcpu-0 - VMXNET3 user: Activate device 0.
2023-04-17T12:25:11.831Z In(05) vcpu-0 - VMXNET3 user: Ethernet0 Driver Info: version = 65536 gosBits = 2 gosType = 4, gosVer = 0, gosMisc = 0
2023-04-17T12:25:11.831Z In(05) vcpu-0 - VMXNET3 user: Activate request succeeds for device 0.
2023-04-17T12:25:11.832Z In(05) vcpu-0 - VMXNET3 user: Quiesce device 0.
2023-04-17T12:25:11.832Z In(05) vcpu-0 - VMXNET3 user: UPT support is not requested
2023-04-17T12:25:11.832Z In(05) vcpu-0 - Ethernet0 MAC Address: 00:0c:29:fe:1a:70
2023-04-17T12:25:11.833Z In(05) vcpu-0 - VMXNET3 user: Ethernet0 RSS fields requested by vmx: 3
2023-04-17T12:25:11.837Z In(05) vcpu-0 - VMXNET3 user: Activate device 0.
2023-04-17T12:25:11.864Z In(05) vcpu-0 - VMXNET3 user: Ethernet0 Driver Info: version = 65536 gosBits = 2 gosType = 4, gosVer = 0, gosMisc = 0
2023-04-17T12:25:11.864Z In(05) vcpu-0 - VMXNET3 user: Activate request succeeds for device 0.
2023-04-17T12:25:11.894Z In(05) vcpu-0 - VMXNET3 user: Quiesce device 0.
2023-04-17T12:25:11.894Z In(05) vcpu-0 - VMXNET3 user: UPT support is not requested
2023-04-17T12:25:11.894Z In(05) vcpu-0 - Ethernet0 MAC Address: 00:0c:29:fe:1a:70
2023-04-17T12:25:11.894Z In(05) vcpu-0 - VMXNET3 user: Ethernet0 RSS fields requested by vmx: 3
2023-04-17T12:25:11.898Z In(05) vcpu-0 - VMXNET3 user: Activate device 0.
2023-04-17T12:25:11.899Z In(05) vcpu-0 - VMXNET3 user: Ethernet0 Driver Info: version = 65536 gosBits = 2 gosType = 4, gosVer = 0, gosMisc = 0
2023-04-17T12:25:11.899Z In(05) vcpu-0 - VMXNET3 user: Activate request succeeds for device 0.
2023-04-17T12:25:11.900Z In(05) vcpu-0 - VMXNET3 user: Quiesce device 0.
2023-04-17T12:25:11.900Z In(05) vcpu-0 - VMXNET3 user: UPT support is not requested
2023-04-17T12:25:11.900Z In(05) vcpu-0 - Ethernet0 MAC Address: 00:0c:29:fe:1a:70
2023-04-17T12:25:11.900Z In(05) vcpu-0 - VMXNET3 user: Ethernet0 RSS fields requested by vmx: 3
2023-04-17T12:25:11.908Z In(05) vcpu-0 - VMXNET3 user: Activate device 0.
2023-04-17T12:25:11.931Z In(05) vcpu-0 - VMXNET3 user: Ethernet0 Driver Info: version = 65536 gosBits = 2 gosType = 4, gosVer = 0, gosMisc = 0
2023-04-17T12:25:11.931Z In(05) vcpu-0 - VMXNET3 user: Activate request succeeds for device 0.
2023-04-17T12:25:11.951Z In(05) vcpu-3 - VMXNET3 user: UPT support is not requested
2023-04-17T12:25:11.951Z In(05) vcpu-3 - Ethernet2 MAC Address: 00:0c:29:fe:1a:84
2023-04-17T12:25:11.951Z In(05) vcpu-3 - VMXNET3 user: Ethernet2 RSS fields requested by vmx: 3
2023-04-17T12:25:11.954Z In(05) vcpu-3 - VMXNET3 user: Activate device 2.
2023-04-17T12:25:11.954Z In(05) vcpu-3 - VMXNET3 user: Ethernet2 Driver Info: version = 65536 gosBits = 2 gosType = 4, gosVer = 0, gosMisc = 0
2023-04-17T12:25:11.954Z In(05) vcpu-3 - VMXNET3 user: Activate request succeeds for device 2.
2023-04-17T12:25:12.032Z In(05) vcpu-3 - VMXNET3 user: UPT support is not requested
2023-04-17T12:25:12.032Z In(05) vcpu-3 - Ethernet1 MAC Address: 00:0c:29:fe:1a:7a
2023-04-17T12:25:12.032Z In(05) vcpu-3 - VMXNET3 user: Ethernet1 RSS fields requested by vmx: 3
2023-04-17T12:25:12.037Z In(05) vcpu-3 - VMXNET3 user: Activate device 1.
2023-04-17T12:25:12.037Z In(05) vcpu-3 - VMXNET3 user: Ethernet1 Driver Info: version = 65536 gosBits = 2 gosType = 4, gosVer = 0, gosMisc = 0
2023-04-17T12:25:12.037Z In(05) vcpu-3 - VMXNET3 user: Activate request succeeds for device 1.
2023-04-17T12:25:30.205Z In(05) vcpu-1 - GuestStore: gstored access is disabled.
2023-04-17T12:25:30.206Z In(05) vcpu-1 - ToolsGetAppInfoEnabledFromConfigStore: Returning the cached value: '1'.
2023-04-17T12:25:30.208Z In(05) vcpu-1 - DEVSWAP: GuestOS does not require LSI adapter swap.
2023-04-17T12:25:30.208Z In(05) vcpu-1 - Guest: toolbox: Version: 12.2.0.41219 (build-21223074)
2023-04-17T12:25:30.208Z Wa(03) vcpu-1 - GuestRpc: application toolbox, changing channel 65535 -> 0
2023-04-17T12:25:30.208Z In(05) vcpu-1 - GuestRpc: Channel 0, guest application toolbox.
2023-04-17T12:25:30.208Z In(05) vcpu-1 - Tools: [AppStatus] Last heartbeat value 90444 (last received 53s ago)
2023-04-17T12:25:30.208Z In(05) vcpu-1 - TOOLS: appName=toolbox, oldStatus=0, status=1, guestInitiated=0.
2023-04-17T12:25:30.214Z In(05) vcpu-3 - TOOLS soft reset detected.
2023-04-17T12:25:30.214Z In(05) vcpu-3 - Vix: [mainDispatch.c:4129]: VMAutomationReportPowerStateChange: Reporting power state change (opcode=2, err=0).
2023-04-17T12:25:30.215Z In(05) vcpu-3 - TOOLS Received tools.set.version rpc call, version = TOOLS_VERSION_UNMANAGED, type is unknown
2023-04-17T12:25:30.215Z In(05) vcpu-3 - TOOLS Setting toolsVersionStatus = TOOLS_STATUS_UNMANAGED
2023-04-17T12:25:30.215Z In(05) vcpu-3 - Tools_SetVersionAndType did nothing; new tools version (2147483647) and type (0) match old Tools version and type
2023-04-17T12:25:30.215Z In(05) vcpu-3 - TOOLS Setting autoupgrade-checked FALSE.
2023-04-17T12:25:30.308Z In(05) vcpu-0 - Tools: Running status rpc handler: 0 => 1.
2023-04-17T12:25:30.308Z In(05) vcpu-0 - Tools: Changing running status: 0 => 1.
2023-04-17T12:25:30.308Z In(05) vcpu-0 - Tools: [RunningStatus] Last heartbeat value 90445 (last received 0s ago)
2023-04-17T12:25:30.370Z In(05) vcpu-2 - Vix: [mainDispatch.c:4129]: VMAutomationReportPowerStateChange: Reporting power state change (opcode=2, err=0).
2023-04-17T12:25:30.370Z In(05) vcpu-2 - TOOLS Received tools.set.version rpc call, version = TOOLS_VERSION_UNMANAGED, type is unknown
2023-04-17T12:25:30.370Z In(05) vcpu-2 - TOOLS Setting toolsVersionStatus = TOOLS_STATUS_UNMANAGED
2023-04-17T12:25:30.370Z In(05) vcpu-2 - Tools_SetVersionAndType did nothing; new tools version (2147483647) and type (0) match old Tools version and type
2023-04-17T12:26:00.205Z In(05) vcpu-0 - GuestInfo: HostinfoDetailedDataHeader version: 1
2023-04-17T12:26:00.206Z No(00) vcpu-0 - ConfigDB: Setting guestInfo.detailed.data = <not printed>

And here the second one seven minutes later:

Code: [Select]

2023-04-17T12:32:46.727Z In(05) vcpu-0 - CPU reset: soft (mode Emulation)
2023-04-17T12:32:46.727Z In(05) vcpu-1 - CPU reset: soft (mode HV)
2023-04-17T12:32:46.727Z In(05) vcpu-3 - CPU reset: soft (mode HV)
2023-04-17T12:32:46.727Z In(05) vcpu-2 - CPU reset: soft (mode HV)
2023-04-17T12:32:46.728Z In(05) vcpu-0 - SVGA: Unregistering IOSpace at 0x1070
2023-04-17T12:32:46.728Z In(05) vcpu-0 - SVGA: Unregistering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)
2023-04-17T12:32:46.728Z In(05) vcpu-0 - SVGA: FIFO is already mapped
...
2023-04-17T12:32:46.753Z In(05) vcpu-0 - Chipset: The guest has requested that the virtual machine be hard reset.
2023-04-17T12:32:46.754Z In(05) vcpu-0 - Destroying virtual dev for scsi0:0 vscsi=1589730605015058
2023-04-17T12:32:46.754Z In(05) vcpu-0 - VMMon_VSCSIStopVports: No such target on adapter
2023-04-17T12:32:46.755Z In(05) vcpu-0 - DEVICE: Resetting device 'ALL'.
2023-04-17T12:32:46.755Z In(05) vcpu-0 - USB: Per-Device Resetting device 0x1000000105572008
2023-04-17T12:32:47.213Z Wa(03) vcpu-0 - USBGL: DevID(1000000105572008): Failed to reset device. Error(0x16): Invalid argument.
2023-04-17T12:32:47.213Z Wa(03) vcpu-0 - USBGL: DevID(1000000105572008): Failed to reset port.
2023-04-17T12:32:47.213Z In(05) vcpu-0 - USB: Per-Device Resetting device 0x200000050e0f0003
2023-04-17T12:32:47.213Z In(05) vcpu-0 - Tools: ToolsRunningStatus_Reset, delayedRequest is 0x0
2023-04-17T12:32:47.213Z In(05) vcpu-0 - Tools: Changing running status: 1 => 0.
2023-04-17T12:32:47.213Z In(05) vcpu-0 - Tools: [RunningStatus] Last heartbeat value 90869 (last received 12s ago)
2023-04-17T12:32:47.213Z In(05) vcpu-0 - GuestLib Generated SessionId 576637647794113200
2023-04-17T12:32:47.213Z In(05) vcpu-0 - GuestRpc: Reinitializing Channel 0(toolbox)
2023-04-17T12:32:47.213Z In(05) vcpu-0 - GuestMsg: Channel 0, Cannot unpost because the previous post is already completed
2023-04-17T12:32:47.213Z In(05) vcpu-0 - Tools: [AppStatus] Last heartbeat value 90869 (last received 12s ago)
2023-04-17T12:32:47.213Z In(05) vcpu-0 - TOOLS: appName=toolbox, oldStatus=1, status=0, guestInitiated=0.
2023-04-17T12:32:47.214Z In(05) vcpu-0 - VMXNET3 user: UPT support is not requested
2023-04-17T12:32:47.214Z In(05) vcpu-0 - Ethernet2 MAC Address: 00:0c:29:fe:1a:84
2023-04-17T12:32:47.214Z In(05) vcpu-0 - VMXNET3 user: Ethernet2 RSS fields requested by vmx: 3
2023-04-17T12:32:47.214Z In(05) vcpu-0 - VMXNET3 user: UPT support is not requested
2023-04-17T12:32:47.214Z In(05) vcpu-0 - Ethernet1 MAC Address: 00:0c:29:fe:1a:7a
2023-04-17T12:32:47.214Z In(05) vcpu-0 - VMXNET3 user: Ethernet1 RSS fields requested by vmx: 3
2023-04-17T12:32:47.214Z In(05) vcpu-0 - VMXNET3 user: UPT support is not requested
2023-04-17T12:32:47.214Z In(05) vcpu-0 - Ethernet0 MAC Address: 00:0c:29:fe:1a:70
2023-04-17T12:32:47.214Z In(05) vcpu-0 - VMXNET3 user: Ethernet0 RSS fields requested by vmx: 3
2023-04-17T12:32:47.214Z In(05) vcpu-0 - UHCI: HCReset
2023-04-17T12:32:47.214Z In(05) vcpu-0 - Checkpoint_Unstun: vm stopped for 461772 us
2023-04-17T12:32:47.215Z In(05) vcpu-0 - CPU reset: hard (mode Emulation)
2023-04-17T12:32:47.215Z In(05) vcpu-1 - CPU reset: hard (mode Emulation)
2023-04-17T12:32:47.215Z In(05) vcpu-2 - CPU reset: hard (mode Emulation)
2023-04-17T12:32:47.215Z In(05) vcpu-3 - CPU reset: hard (mode Emulation)
2023-04-17T12:32:47.217Z In(05) vcpu-0 - PVSCSI: scsi0: switching to async
2023-04-17T12:32:47.217Z In(05) vcpu-0 - Creating virtual dev for 'scsi0:0'.
2023-04-17T12:32:47.217Z In(05) vcpu-0 - DumpDiskInfo: scsi0:0 createType=11, capacity = 16777216, numLinks = 4
2023-04-17T12:32:47.217Z In(05) vcpu-0 - , allocationType = 2
2023-04-17T12:32:47.217Z In(05) vcpu-0 -
2023-04-17T12:32:47.217Z In(05) vcpu-0 - SCSIDiskESXPopulateVDevDesc: Using FS backend
2023-04-17T12:32:47.217Z In(05) vcpu-0 - DISKUTIL: scsi0:0 : geometry=1044/255/63
2023-04-17T12:32:47.217Z In(05) vcpu-0 - SCSIFilterESXAttachCBRCInt: CBRC not enabled or opened without filters,skipping CBRC           filter attach.
2023-04-17T12:32:47.217Z In(05) vcpu-0 - SCSIFilterESXAttachCBRCInt: Invalidating all hashes for this digest
2023-04-17T12:32:47.217Z In(05) vcpu-0 - SCSIFilterSBDAttachCBRC: device scsi0:0 is not SBD. Skipping CBRC attach SBD way.
2023-04-17T12:32:47.217Z In(05) vcpu-0 - DataSetsMgrSync: Reconnect dataSets store after checkpoint.
2023-04-17T12:32:47.217Z In(05) vcpu-0 - CPT: vm was stunned for 464645 us
2023-04-17T12:32:47.222Z In(05) vcpu-0 - OpNotificationMgr_RemoveAllApps: Attempting to remove registered apps during warm or cold reboot
...
2023-04-17T12:32:47.709Z In(05) vcpu-0 - DISKUTIL: scsi0:0 : geometry=1044/255/63
2023-04-17T12:32:47.709Z In(05) vcpu-0 - DISKUTIL: scsi0:0 : capacity=16777216 logical sector size=512
2023-04-17T12:32:47.775Z In(05) vcpu-1 - CPU reset: soft (mode Emulation)
2023-04-17T12:32:47.776Z In(05) vcpu-2 - CPU reset: soft (mode Emulation)
2023-04-17T12:32:47.777Z In(05) vcpu-3 - CPU reset: soft (mode Emulation)
2023-04-17T12:32:47.784Z In(05) vcpu-0 - BIOS-UUID is 56 4d 78 4d e5 4c 52 06-67 da 1c ed 57 fe 1a 70
2023-04-17T12:32:54.206Z In(05) vcpu-1 - CPU reset: soft (mode Emulation)
2023-04-17T12:32:54.216Z In(05) vcpu-2 - CPU reset: soft (mode Emulation)
2023-04-17T12:32:54.226Z In(05) vcpu-3 - CPU reset: soft (mode Emulation)
2023-04-17T12:32:54.317Z In(05) vcpu-0 - Tools: Tools heartbeat timeout.
2023-04-17T12:32:54.318Z In(05) vcpu-0 - Tools: Running status rpc handler: 0 => 0.
...
2023-04-17T12:32:54.440Z In(05) vcpu-2 - UHCI: Global Reset
2023-04-17T12:32:54.551Z In(05) vcpu-2 - UHCI: HCReset
2023-04-17T12:32:54.654Z In(05) vcpu-2 - VMXNET3 user: UPT support is not requested
2023-04-17T12:32:54.654Z In(05) vcpu-2 - Ethernet2 MAC Address: 00:0c:29:fe:1a:84
2023-04-17T12:32:54.654Z In(05) vcpu-2 - VMXNET3 user: Ethernet2 RSS fields requested by vmx: 3
2023-04-17T12:32:54.654Z In(05) vcpu-2 - VMXNET3 user: Supported set 0x000000ff, configured set 0x00000001
2023-04-17T12:32:54.654Z In(05) vcpu-2 - Ethernet2 MAC Address: 00:0c:29:fe:1a:84
2023-04-17T12:32:54.654Z In(05) vcpu-2 - Ethernet2 MAC Address: 00:0c:29:fe:1a:84
2023-04-17T12:32:54.723Z In(05) vcpu-2 - PVSCSI: ReqRing: 1024 entries, eSz=128, 32 pages
2023-04-17T12:32:54.723Z In(05) vcpu-2 - PVSCSI: CmpRing: 4096 entries, eSz=32, 32 pages
2023-04-17T12:32:54.723Z In(05) vcpu-2 - PVSCSI: MsgRing: 32 entries, eSz=128, 1 pages
2023-04-17T12:32:54.723Z In(05) vcpu-2 - PVSCSI: scsi0: switching to sync
2023-04-17T12:32:54.723Z In(05) vcpu-2 - PVSCSI: scsi0: init reqCallThresholdCapable 1
2023-04-17T12:32:54.768Z In(05) vcpu-2 - VMXNET3 user: UPT support is not requested
2023-04-17T12:32:54.768Z In(05) vcpu-2 - Ethernet0 MAC Address: 00:0c:29:fe:1a:70
2023-04-17T12:32:54.768Z In(05) vcpu-2 - VMXNET3 user: Ethernet0 RSS fields requested by vmx: 3
2023-04-17T12:32:54.768Z In(05) vcpu-2 - VMXNET3 user: Supported set 0x000000ff, configured set 0x00000001
2023-04-17T12:32:54.768Z In(05) vcpu-2 - Ethernet0 MAC Address: 00:0c:29:fe:1a:70
2023-04-17T12:32:54.768Z In(05) vcpu-2 - Ethernet0 MAC Address: 00:0c:29:fe:1a:70
2023-04-17T12:32:54.842Z In(05) vcpu-1 - VMXNET3 user: UPT support is not requested
2023-04-17T12:32:54.842Z In(05) vcpu-1 - Ethernet1 MAC Address: 00:0c:29:fe:1a:7a
2023-04-17T12:32:54.842Z In(05) vcpu-1 - VMXNET3 user: Ethernet1 RSS fields requested by vmx: 3
2023-04-17T12:32:54.842Z In(05) vcpu-1 - VMXNET3 user: Supported set 0x000000ff, configured set 0x00000001
2023-04-17T12:32:54.842Z In(05) vcpu-1 - Ethernet1 MAC Address: 00:0c:29:fe:1a:7a
2023-04-17T12:32:54.842Z In(05) vcpu-1 - Ethernet1 MAC Address: 00:0c:29:fe:1a:7a
2023-04-17T12:33:00.417Z Wa(03) vmx - USBGL: DevID(1000000105572008): Failed to reset device. Error(0x16): Invalid argument.
2023-04-17T12:33:00.417Z Wa(03) vmx - USBGL: DevID(1000000105572008): Failed to reset port.
2023-04-17T12:33:00.585Z In(05) vmx - USBGL: DevID(1000000105572008): Claimed device interface(0) successfully.
2023-04-17T12:33:10.352Z Wa(03) vcpu-0 - Balloon: Start: vmmemctl reset balloon
2023-04-17T12:33:13.814Z In(05) vcpu-1 - VMXNET3 user: UPT support is not requested
2023-04-17T12:33:13.814Z In(05) vcpu-1 - Ethernet0 MAC Address: 00:0c:29:fe:1a:70
2023-04-17T12:33:13.815Z In(05) vcpu-1 - VMXNET3 user: Ethernet0 RSS fields requested by vmx: 3
2023-04-17T12:33:13.819Z In(05) vcpu-1 - VMXNET3 user: Activate device 0.
2023-04-17T12:33:13.819Z In(05) vcpu-1 - VMXNET3 user: Ethernet0 Driver Info: version = 65536 gosBits = 2 gosType = 4, gosVer = 0, gosMisc = 0
2023-04-17T12:33:13.819Z In(05) vcpu-1 - VMXNET3 user: Activate request succeeds for device 0.
2023-04-17T12:33:13.839Z In(05) vcpu-2 - VMXNET3 user: Quiesce device 0.
2023-04-17T12:33:13.839Z In(05) vcpu-2 - VMXNET3 user: UPT support is not requested
2023-04-17T12:33:13.839Z In(05) vcpu-2 - Ethernet0 MAC Address: 00:0c:29:fe:1a:70
2023-04-17T12:33:13.839Z In(05) vcpu-2 - VMXNET3 user: Ethernet0 RSS fields requested by vmx: 3
2023-04-17T12:33:13.843Z In(05) vcpu-2 - VMXNET3 user: Activate device 0.
2023-04-17T12:33:13.851Z In(05) vcpu-2 - VMXNET3 user: Ethernet0 Driver Info: version = 65536 gosBits = 2 gosType = 4, gosVer = 0, gosMisc = 0
2023-04-17T12:33:13.851Z In(05) vcpu-2 - VMXNET3 user: Activate request succeeds for device 0.
2023-04-17T12:33:13.853Z In(05) vcpu-2 - VMXNET3 user: Quiesce device 0.
2023-04-17T12:33:13.853Z In(05) vcpu-2 - VMXNET3 user: UPT support is not requested
2023-04-17T12:33:13.853Z In(05) vcpu-2 - Ethernet0 MAC Address: 00:0c:29:fe:1a:70
2023-04-17T12:33:13.853Z In(05) vcpu-2 - VMXNET3 user: Ethernet0 RSS fields requested by vmx: 3
2023-04-17T12:33:13.859Z In(05) vcpu-2 - VMXNET3 user: Activate device 0.
2023-04-17T12:33:13.884Z In(05) vcpu-2 - VMXNET3 user: Ethernet0 Driver Info: version = 65536 gosBits = 2 gosType = 4, gosVer = 0, gosMisc = 0
2023-04-17T12:33:13.884Z In(05) vcpu-2 - VMXNET3 user: Activate request succeeds for device 0.
2023-04-17T12:33:13.913Z In(05) vcpu-0 - VMXNET3 user: Quiesce device 0.
2023-04-17T12:33:13.913Z In(05) vcpu-0 - VMXNET3 user: UPT support is not requested
2023-04-17T12:33:13.913Z In(05) vcpu-0 - Ethernet0 MAC Address: 00:0c:29:fe:1a:70
2023-04-17T12:33:13.914Z In(05) vcpu-0 - VMXNET3 user: Ethernet0 RSS fields requested by vmx: 3
2023-04-17T12:33:13.917Z In(05) vcpu-0 - VMXNET3 user: Activate device 0.
2023-04-17T12:33:13.918Z In(05) vcpu-0 - VMXNET3 user: Ethernet0 Driver Info: version = 65536 gosBits = 2 gosType = 4, gosVer = 0, gosMisc = 0
2023-04-17T12:33:13.918Z In(05) vcpu-0 - VMXNET3 user: Activate request succeeds for device 0.
2023-04-17T12:33:13.919Z In(05) vcpu-0 - VMXNET3 user: Quiesce device 0.
2023-04-17T12:33:13.920Z In(05) vcpu-0 - VMXNET3 user: UPT support is not requested
2023-04-17T12:33:13.920Z In(05) vcpu-0 - Ethernet0 MAC Address: 00:0c:29:fe:1a:70
2023-04-17T12:33:13.920Z In(05) vcpu-0 - VMXNET3 user: Ethernet0 RSS fields requested by vmx: 3
2023-04-17T12:33:13.923Z In(05) vcpu-0 - VMXNET3 user: Activate device 0.
2023-04-17T12:33:13.950Z In(05) vcpu-0 - VMXNET3 user: Ethernet0 Driver Info: version = 65536 gosBits = 2 gosType = 4, gosVer = 0, gosMisc = 0
2023-04-17T12:33:13.950Z In(05) vcpu-0 - VMXNET3 user: Activate request succeeds for device 0.
2023-04-17T12:33:13.969Z In(05) vcpu-2 - VMXNET3 user: UPT support is not requested
2023-04-17T12:33:13.969Z In(05) vcpu-2 - Ethernet2 MAC Address: 00:0c:29:fe:1a:84
2023-04-17T12:33:13.969Z In(05) vcpu-2 - VMXNET3 user: Ethernet2 RSS fields requested by vmx: 3
2023-04-17T12:33:13.972Z In(05) vcpu-2 - VMXNET3 user: Activate device 2.
2023-04-17T12:33:13.972Z In(05) vcpu-2 - VMXNET3 user: Ethernet2 Driver Info: version = 65536 gosBits = 2 gosType = 4, gosVer = 0, gosMisc = 0
2023-04-17T12:33:13.972Z In(05) vcpu-2 - VMXNET3 user: Activate request succeeds for device 2.
2023-04-17T12:33:14.058Z In(05) vcpu-1 - VMXNET3 user: UPT support is not requested
2023-04-17T12:33:14.058Z In(05) vcpu-1 - Ethernet1 MAC Address: 00:0c:29:fe:1a:7a
2023-04-17T12:33:14.058Z In(05) vcpu-1 - VMXNET3 user: Ethernet1 RSS fields requested by vmx: 3
2023-04-17T12:33:14.065Z In(05) vcpu-1 - VMXNET3 user: Activate device 1.
2023-04-17T12:33:14.065Z In(05) vcpu-1 - VMXNET3 user: Ethernet1 Driver Info: version = 65536 gosBits = 2 gosType = 4, gosVer = 0, gosMisc = 0
2023-04-17T12:33:14.065Z In(05) vcpu-1 - VMXNET3 user: Activate request succeeds for device 1.
2023-04-17T12:33:32.434Z In(05) vcpu-3 - GuestStore: gstored access is disabled.
2023-04-17T12:33:32.434Z In(05) vcpu-3 - ToolsGetAppInfoEnabledFromConfigStore: Returning the cached value: '1'.
2023-04-17T12:33:32.434Z In(05) vcpu-3 - DEVSWAP: GuestOS does not require LSI adapter swap.
2023-04-17T12:33:32.434Z In(05) vcpu-3 - Guest: toolbox: Version: 12.2.0.41219 (build-21223074)
2023-04-17T12:33:32.434Z Wa(03) vcpu-3 - GuestRpc: application toolbox, changing channel 65535 -> 0
2023-04-17T12:33:32.434Z In(05) vcpu-3 - GuestRpc: Channel 0, guest application toolbox.
2023-04-17T12:33:32.434Z In(05) vcpu-3 - Tools: [AppStatus] Last heartbeat value 90869 (last received 58s ago)
2023-04-17T12:33:32.434Z In(05) vcpu-3 - TOOLS: appName=toolbox, oldStatus=0, status=1, guestInitiated=0.
2023-04-17T12:33:32.439Z In(05) vcpu-3 - TOOLS soft reset detected.
2023-04-17T12:33:32.439Z In(05) vcpu-3 - Vix: [mainDispatch.c:4129]: VMAutomationReportPowerStateChange: Reporting power state change (opcode=2, err=0).
2023-04-17T12:33:32.440Z In(05) vcpu-3 - TOOLS Received tools.set.version rpc call, version = TOOLS_VERSION_UNMANAGED, type is unknown
2023-04-17T12:33:32.440Z In(05) vcpu-3 - TOOLS Setting toolsVersionStatus = TOOLS_STATUS_UNMANAGED
2023-04-17T12:33:32.440Z In(05) vcpu-3 - Tools_SetVersionAndType did nothing; new tools version (2147483647) and type (0) match old Tools version and type
2023-04-17T12:33:32.440Z In(05) vcpu-3 - TOOLS Setting autoupgrade-checked FALSE.
2023-04-17T12:33:33.318Z In(05) vcpu-0 - Tools: Running status rpc handler: 0 => 1.
2023-04-17T12:33:33.318Z In(05) vcpu-0 - Tools: Changing running status: 0 => 1.
2023-04-17T12:33:33.318Z In(05) vcpu-0 - Tools: [RunningStatus] Last heartbeat value 90870 (last received 0s ago)
2023-04-17T12:33:33.423Z In(05) vcpu-0 - Vix: [mainDispatch.c:4129]: VMAutomationReportPowerStateChange: Reporting power state change (opcode=2, err=0).
2023-04-17T12:33:33.424Z In(05) vcpu-0 - TOOLS Received tools.set.version rpc call, version = TOOLS_VERSION_UNMANAGED, type is unknown
2023-04-17T12:33:33.424Z In(05) vcpu-0 - TOOLS Setting toolsVersionStatus = TOOLS_STATUS_UNMANAGED
2023-04-17T12:33:33.424Z In(05) vcpu-0 - Tools_SetVersionAndType did nothing; new tools version (2147483647) and type (0) match old Tools version and type
2023-04-17T12:34:02.439Z In(05) vcpu-1 - GuestInfo: HostinfoDetailedDataHeader version: 1
2023-04-17T12:34:02.440Z No(00) vcpu-1 - ConfigDB: Setting guestInfo.detailed.data = <not printed>

I will see, if I can enable debig logging for the vmware tools. But to me, it seems that this vmware-tools is somewhat buggy and maybe it stops sending the heartbeat, so esxi resets the machine.

[Neuer_User]

So, more bad news: After turing on debugging and having a hard reset again this night, there is no usable information in any of the created log files. All just show that the reset came out of the blue. ESXi again claims a missing heartbeat and therefore resets the vm.

I will first go back to a snapshot taken a few days ago (all these hard reset have apparently corrupted the rrd db). Then I will remove the vmware-plugin and see if the machine then runs fine or shows any other issues.

[Supermule]

I'll bet you its CPU related.

Do you have option to run a XEON instead??

[Neuer_User]

I'll bet you its CPU related.

Do you have option to run a XEON instead??

What do you mean? The "virtual CPU"? The host is running without any issues and is not restarting or doing anything weird. So, there does not seem to be any CPU issue for ESXi. Only the VM is being hard reset by ESXi pretty often.

Or do you mean that the opnsense kernel in the VM doesn't work nicely with the intel N5105 cpu and crashes or something like that? There is nothing in any log, but I'm not sure that one would see any entry. In such a case, I guess it should be possible to change the presented CPU features to the guest system somewhere?

Concerning other HW: No, I exactly purchased this appliance for this usage. I do have three small mini servers (running proxmox), but they only have two nics each and are actually strongly in use.

[benyamin]

Whilst certainly not on the VMware HCL, Jasper Lake CPUs should work. I presume you have VT-x enabled in the BIOS (I presume this because I doubt ESXi would install without it).

The best way to confirm whether or not this is an opnsense issue would be to setup a fresh FreeBSD or HardenedBSD VM with OVT (open-vm-tools) installed and see if the issue is reproducible. You could also try a Windows VM to be sure. If the issue is reproducible with other VMs, the VMware forums are probably your best bet to finding a solution. If the issue only exists in opnsense, I would recommend re-installation on a fresh VM with a new disk device, and pursuing the issue further in this forum, or the general forum, or on GitHub (at a guess this repository).

Your mention of snapshots gives me some pause; you might instead consider using a monolithic flat disk, i.e. a fully allocated disk. You might remember we previously spoke about stunning, which can occur during various disk snapshot and other underlying sparse disk operations. This can cause a variety of timeouts to occur.

That being said, I predict that using Proxmox and the QEMU Guest Agent inside your VM would likely work without this issue. Some might argue that it's also less likely to be compromised given the recent blackhat focus on ESX.