guestcontrol in terminated state right after using it on a just restored online snapshot

[Mayhem]

It seems that the guestcontrol interface goes into terminating state, right after an online snapshot has been restored of a VM (windows 10 image).

This is a problem I detected on a VM with 6.1.32 vbox guest additions installed. This problem is not present on a VM with 6.0.4 vbox guest additions installed.

Steps to reproduce:

1) load OVA (win10 OVA in my case)
2) start VM and create online snapshot
3) poweroff VM
4) restore online snapshot taken in step 2
5) start VM, now the VM will jumpstart into the (online) machine state as saved in step 2
6) execute a guestcontrol command from the host immediately after step 5

After step 6, the guestcontrol command returns with this kind of error: "VBoxManage.exe: error: Error starting guest session (current status is: terminated)"

The best way to reproduce the error is to automate the steps as it seems some race condition being the rootcause here. These were the simple steps I had in my batch script to reproduce the issue:

@echo off

set VM_NAME=win10_10.0.17_clean

echo restore snapshot on %VM_NAME%
"C:\Program Files\Oracle\VirtualBox\VBoxManage.exe" snapshot %VM_NAME% restore "online_snapshot"

echo start VM %VM_NAME%
"C:\Program Files\Oracle\VirtualBox\VBoxManage.exe" startvm %VM_NAME%

rem echo zzzzz
rem sleep 1

echo execute command via guest control interface
"C:\Program Files\Oracle\VirtualBox\VBoxManage.exe" guestcontrol %VM_NAME% run --putenv "USERNAME=user" --username user --password user  --wait-stdout --wait-stderr --timeout 600000 cmd.exe -- /C ipconfig

Executing this sequence on a VM with 6.1.32 vbox guest additions results in the mentioned 'terminated' state of the guestcontrol interface. There is not other way to get out of that, by just rebooting the VM. Otherwise, the guestcontrol interface remains in 'terminated' state.

If there is tiny sleep between step 5 & 6 (as can also be seen in the script) the issue is not there, and the command is executed succesfully.

So it seems some sort of race condition.

I have attached some logging. You will see that whenever the issue is there the logs show 'VERR_NOT_FOUND' errors:

NOK -->

00:00:09.268742 VMMDev: Guest Log: 14:01:20.520064 main     VBoxService 6.1.32 r149290 (verbosity: 0) win.amd64 (Jan 13 2022 19:13:21) release log
00:00:09.268766 VMMDev: Guest Log: 14:01:20.520064 main     Log opened 2022-06-27T14:01:20.520064800Z
00:00:09.268834 VMMDev: Guest Log: 14:01:20.522599 main     OS Product: Windows 10
00:00:09.268864 VMMDev: Guest Log: 14:01:20.522599 main     OS Release: 10.0.17763
00:00:09.268919 VMMDev: Guest Log: 14:01:20.522696 main     OS Service Pack: 
00:00:09.268946 VMMDev: Guest Log: 14:01:20.522696 main     Executable: C:\Windows\System32\VBoxService.exe
00:00:09.268953 VMMDev: Guest Log: 14:01:20.522696 main     Process ID: 5272
00:00:09.268957 VMMDev: Guest Log: 14:01:20.522696 main     Package type: WINDOWS_64BITS_GENERIC
00:00:09.268983 VMMDev: Guest Log: 14:01:20.522696 main     Hi, this is guest session ID=1
00:00:09.269316 VMMDev: Guest Log: 14:01:20.523084 main     vbglR3GuestCtrlDetectPeekGetCancelSupport: Supported (#1)
00:00:09.269585 VMMDev: Guest Log: 14:01:20.523084 main     Error: Failed to accept session 57 (client ID 1): VERR_NOT_FOUND
00:00:09.269628 VMMDev: Guest Log: 14:01:20.523084 main     Error: Setting message filterAdd=0x1 failed with rc=VERR_NOT_FOUND

In the VM with guest additions 6.0.4 these errors do not pop up and the logs look like this:

00:00:10.154777 VMMDev: Guest Log: 11:24:33.124468 main     VBoxService 6.0.4 r128413 (verbosity: 0) win.amd64 (Jan 25 2019 18:38:16) release log
00:00:10.154798 VMMDev: Guest Log: 11:24:33.124468 main     Log opened 2022-06-28T11:24:33.124468000Z
00:00:10.154834 VMMDev: Guest Log: 11:24:33.124468 main     OS Product: Windows 10
00:00:10.154862 VMMDev: Guest Log: 11:24:33.124468 main     OS Release: 10.0.17763
00:00:10.154888 VMMDev: Guest Log: 11:24:33.124468 main     OS Service Pack: 
00:00:10.154915 VMMDev: Guest Log: 11:24:33.124468 main     Executable: C:\Windows\System32\VBoxService.exe
00:00:10.154923 VMMDev: Guest Log: 11:24:33.124468 main     Process ID: 5212
00:00:10.154928 VMMDev: Guest Log: 11:24:33.124468 main     Package type: WINDOWS_64BITS_GENERIC
00:00:10.154957 VMMDev: Guest Log: 11:24:33.124468 main     Hi, this is guest session ID=1
00:00:10.155536 RTC: period=0x10 (16) 2048 Hz
00:00:10.155670 VMMDev: Guest Log: 11:24:33.140222 main     vbglR3GuestCtrlDetectPeekGetCancelSupport: Supported (#1)
00:00:10.171222 RTC: period=0x10 (16) 2048 Hz
00:00:10.186838 RTC: period=0x10 (16) 2048 Hz
00:00:10.188166 VMMDev: Guest Log: 11:24:33.171524 main     Session 1 is about to close ...
00:00:10.188261 VMMDev: Guest Log: 11:24:33.171524 main     Stopping all guest processes ...
00:00:10.188293 VMMDev: Guest Log: 11:24:33.171524 main     Closing all guest files ...
00:00:10.188324 VMMDev: Guest Log: 11:24:33.171524 main     Session 1 ended

For reproduction of the issue I am using Vbox version 6.1.32 with a VM using guest additions 6.1.32.