VM window freezes and process keeps running after manual savestate

[Philip Seeger]

There are several vms on this host, usually running in full screen mode. One vm has been experiencing this issue where the full screen vm window freezes, usually after the vm has been running for one or more days. I haven't noticed that issue with other vms, however, most other vms don't run for weeks.

When it happens, the vm window is not updated anymore. It doesn't show the vm anymore. Instead, it shows whatever was there on the screen earlier. If there was another window above the frozen window and that other window is closed, it's still shown in the frozen vm window. If I switch workspaces back and forth, when I switch back to the workspace with the frozen vm window, the vm window (which is in full screen mode) shows the previous workspace. For that reason, a screenshot wouldn't be helpful, as it would simply show whatever else was on the screen before the frozen vm window was activated.

This affects the vm window, i.e., the window that shows up when you start a vm in the VirtualBox gui. The affected vm itself is still running and can be accessed via ssh.

It is possible to suspend the vm using "vboxmanage controlvm [NAME] savestate", but the frozen vm window won't go away. It visually looks as if nothing had changed. The vm process keeps running after the vm is suspended:

user     985 27147 64 00:02 ?        08:10:26 /usr/lib/virtualbox/VirtualBox --comment Fedora-1 --startvm 5c908c7b-bf32-4965-be4d-a11f5abdbf04 --no-startvm-errormsgbox
user    7016     1  0 Apr04 ?        00:38:56 /usr/lib/virtualbox/VBoxXPCOMIPCD
user   27123     1  0 Apr10 ?        00:22:27 /usr/lib/virtualbox/VirtualBox
user   27147     1  0 Apr10 ?        00:47:51 /usr/lib/virtualbox/VBoxSVC --auto-shutdown

If this process (985 in this example) is killed, the frozen window disappears and VirtualBox marks the vm as "Aborted". The saved state is lost. I usually reset the vm to its last healthy state and start it again, which works fine every time. Until the vm window freezes again a few days later.

It's not clear what causes these freezes. I understand that this makes it very difficult to debug this, but I'm hoping this bug report helps someone else out there who is experiencing the same behavior.

Looking at the log (attached), it seems like two log entries are missing. These entries can be found at the end of the log files of other vms that were also suspended (without freeze):

12:07:58.276482 GUI: UIMediumEnumerator: Medium-enumeration finished!
12:07:58.551772 GUI: Passing request to close Runtime UI from machine-logic to UI session.

[Philip Seeger]

VBox.log of vm with frozen window

[Philip Seeger]

It just happened to another vm that was already running for several days and it happened while it was rendering a video file. The vm window was all black (full screen) when I unlocked the host computer (probably because the screensaver is just a black screen).

This is what happens when vboxmanage is used to resume a stuck vm that has just been suspended (resuming from the gui is not possible, the start button is disabled):

$ vboxmanage startvm Fedora-2
VBoxManage: error: The machine 'Fedora-2' is already locked by a session (or being locked or unlocked)
VBoxManage: error: Details: code VBOX_E_INVALID_OBJECT_STATE (0x80bb0007), component MachineWrap, interface IMachine, callee nsISupports
VBoxManage: error: Context: "LaunchVMProcess(a->session, sessionType.raw(), env.raw(), progress.asOutParam())" at line 589 of file VBoxManageMisc.cpp

Searching elsewhere, I found that some people suggest forcing the vm to stop, e.g., by killing the process. This obviously isn't a solution because it crashes the vm, losing the state. All work is lost and the virtual hdd could get corrupted.

However, a workaround seems to be to take a snapshot at this point before killing the vm. It can then be reverted to this snapshot.

[Frank Mehnert]

Of course killing the VM process is no solution. I would be glad to get a core dump of the VM process when it hangs after a savestate. Would be nice if you could compress and upload the core dump to a sever and if you could contact me via frank _dot_ mehnert _at_ oracle _dot_ com to tell me the URL. And please don't forget to provide the corresponding VBox.log file as well.

[Philip Seeger]

I'll remember to do that next time it happens. Thank you very much in advance, I appreciate it.

[Frank Mehnert]

I've received your core dump from a 5.1.22 VM session. Thanks, you can delete it. Am I correct that this core dump is from a VM session where you observed a VM hang and then tried to save the VM state? I don't have the corresponding log file but AFAICS there are only a couple of threads running in this process, in particular some threads are missing.

Would it be possible to get another core dump of such a VM when the VM is frozen (you say "the VM window is not updated anymore") but before you try to save the VM state? Also next time it would be nice to have the corresponding VBox.log file together with the core dump.

Thanks!

[Philip Seeger]

Yes, this vm got stuck and I took a snapshot (successfully; using the VirtualBox Manager gui) before I killed the vm process. While the vm window was stuck, the vm state was shown as "Running" (gui). After killing the vm process, the state was "Aborted" (btw. I've had many crashes where the state did not switch to "Aborted" indicating a crash so that status seems rare, but that's off topic).

The next "vm window freeze" should happen in just a few weeks. I'll kill that vm without taking a snapshot and provide the core dump.

[Philip Seeger]

It happened again (a bit earlier than expected). I killed the vm process without taking a snapshot beforehand. Afterwards, I checked the log file and found something interesting at the end of the file that wasn't there last time.

24:33:08.721488 GUI: UIMachineViewFullscreen::adjustGuestScreenSize: Adjust guest-screen size if necessary.
24:33:08.738428 GUI: UIMiniToolBar::sltAdjust: Resize window to: 1280x1024
24:33:08.738454 GUI: UIMiniToolBar::sltAdjust: Move window to: 0x0
24:33:08.739228 GUI: UIMiniToolBar::sltAdjust: Resize window to: 1280x1024
24:33:08.739252 GUI: UIMiniToolBar::sltAdjust: Move window to: 0x0

[Philip Seeger]

"Move window to: 0x0"

[Frank Mehnert]

Thanks for the core dump and the VBox.log file. So far didn't spot anything interesting. Both guest CPUs are happily executing code and I don't see any thread deadlock. The "Resize window to" / "Move window to" messages are normal. Also the GUI thread looks normal.

Just to double-check: When this "freeze" happens then you are in fullscreen mode, correct? Are you still able to open the VM menu (HostKey+Home)? I assume so because you reported earlier that you took a snapshot when this happened before -- but taking a snapshot would be also possible using VBoxManage etc, therefore I need to double-check.

[Philip Seeger]

In response to the last comment:

It usually happens in fullscreen mode, yes. This is simply because I tend to have most of my vms running in fullscreen mode at all times. But see below.

It's good that you're asking - no, I'm not able to do anything. I can't open the vm menu and when I move the mouse to the top, the toolbar does not appear either. The window is dead and the fact that it's "transparent" (for the lack of a better term) can lead to confusion if you don't know that what looks like your desktop is actually a frozen VirtualBox window.

I probably used vboxmanage once or twice to take a snapshot of a frozen vm. I definitely used it a few times to suspend it (savestate). The last few times, I used the VirtualBox Manager gui, which is still able to work with frozen vms except it can't start them (start button disabled).

Today, new freeze:

It happened again. This time, a backup script suspended the vms before I could take a core dump (I have one, but it's after suspending and taking a snapshot). 3 vms were affected, which indicates that this happens randomly. It's happening a lot recently, which makes working with VirtualBox difficult.

This time, one of the frozen vms was not running in fullscreen mode. That means that it has a window border and title, but otherwise it behaved just like the other frozen vms (I didn't try Host + Home this time, but I'm sure it would not have worked). I made a screenshot with this frozen vm on the right and another frozen vm in fullscreen mode on the left. Note that it's not black because the guest system turned off the screen, that's not the case. It's black because the host's screen was black (screensaver) before I saw this. Switching workspaces, which are blue in this case, made the window blue. That's what I mean by "transparent".

One of the affected vms has this at the end of the log (keep in mind that my backup script suspended the vm, but the window didn't go away):

129:57:02.506550 Changing the VM state from 'DESTROYING' to 'TERMINATED'
129:57:02.509531 Console: Machine state changed to 'Saved'
129:57:02.509687 GUI: Request to close Runtime UI because VM is powered off already.
129:57:02.509708 GUI: Passing request to close Runtime UI from machine-logic to UI session.

[Philip Seeger]

Frozen vm in fullscreen mode left; other frozen vm right