4.3.16: should "savestate" be aborting the vm?

This is for discussing general topics about how to use VirtualBox.

4.3.16: should "savestate" be aborting the vm?

Postby neilo » 18. Sep 2014, 01:38

Using a fresh install of 4.3.16 on Windows 7 Pro SP1, I find that

    $ VBoxManage.exe controlvm <uuid> savestate

leaves the VM in an aborted state. In Logs/VBox.log I see the following:

    $ grep "VM state" VBox.log
    00:00:00.972364 Changing the VM state from 'CREATING' to 'CREATED'.
    00:00:00.977306 Changing the VM state from 'CREATED' to 'POWERING_ON'.
    00:00:00.998114 Changing the VM state from 'POWERING_ON' to 'RUNNING'.
    00:02:28.626006 Changing the VM state from 'RUNNING' to 'SUSPENDING'.
    00:02:28.722622 Changing the VM state from 'SUSPENDING' to 'SUSPENDED'.
    00:02:28.728527 Changing the VM state from 'SUSPENDED' to 'SAVING'.
    00:02:30.033601 SSM: Successfully saved the VM state to 'C:\Users\xxxxx\VirtualBox VMs\trusty64_default_1410996474733_91815\Snapshots\2014-09-17T23-30-27-735
    155700Z.sav'
    00:02:30.033612 Changing the VM state from 'SAVING' to 'SUSPENDED'.
    00:02:30.033687 Changing the VM state from 'SUSPENDED' to 'POWERING_OFF'.
    00:02:30.033801 Changing the VM state from 'POWERING_OFF' to 'OFF'.
    00:02:30.034611 Changing the VM state from 'OFF' to 'DESTROYING'.
    00:02:30.040039 Changing the VM state from 'DESTROYING' to 'TERMINATED'.

If I then show the vm state

    $ VBoxManage.exe showvminfo <uuid>| grep State
    State: saved (since 2014-09-17T23:30:29.069000000)

I see state is saved, but this invocation of VBoxManage.exe crashes. If I immediately run it again

    $ VBoxManage.exe showvminfo <uuid>| grep State
    State: aborted (since 2014-09-17T23:33:05.833000000)

The state is now "aborted". That isn't the expected behavior, is it?
neilo
 
Posts: 4
Joined: 18. Sep 2014, 01:23

Re: 4.3.16: should "savestate" be aborting the vm?

Postby scottgus1 » 18. Sep 2014, 13:45

This may just be terminology in the log, or it may be a glitch.

Does your guest save-state and restart properly, despite the log messages? If so, the messages may just be issues with how the log is written, or everything may be working properly.

Regarding the change in operation with Vboxmanage, try it without grep and read through it for the "State" line. Maybe the piping is at fault, or maybe it's another issue.
Human government is like that crazy uncle who hides a quarter in his fist behind his back, then asks you to guess which fist the quarter is in...
No matter which side you choose, Left or Right, both Sides are empty.
scottgus1
 
Posts: 4037
Joined: 30. Dec 2009, 20:14
Primary OS: MS Windows 10
VBox Version: PUEL
Guest OSses: Win7

Re: 4.3.16: should "savestate" be aborting the vm?

Postby mpack » 18. Sep 2014, 14:52

Since I don't see how a Windows Host is relevant to the question asked, I'll move this topic to "Using VirtualBox".
mpack
Site Moderator
 
Posts: 29553
Joined: 4. Sep 2008, 17:09
Primary OS: MS Windows 10
VBox Version: PUEL
Guest OSses: Mostly XP

Re: 4.3.16: should "savestate" be aborting the vm?

Postby neilo » 18. Sep 2014, 18:29

@mpack - sure, thanks. I wasn't sure which forum to use.

@scottgus1 -

Nothing to do with the "| grep State", same result if I don't grep and instead manually inspect the full output. Again, note that "vboxmanage showvminfo <uuid>" crashes on the first invocation after savestate, and then doesn't crash thereafter.

Finally, I confirmed the guest does not restart properly after savestate, here is the error:

    $ /c/Program\ Files/Oracle/VirtualBox/VBoxManage.exe startvm 1ad06baf-f276-4f8a-9d07-86ba0ada29e0
    Waiting for VM "1ad06baf-f276-4f8a-9d07-86ba0ada29e0" to power on...
    VBoxManage.exe: error: The virtual machine 'trusty64_default_1411056660085_30660' has terminated unexpectedly during startup with exit code 1 (0x1). More details may be available in 'C:\Users\nokamoto\VirtualBox VMs\trusty64_default_1411056660085_30660\Logs\VBoxStartup.log'
    VBoxManage.exe: error: Details: code E_FAIL (0x80004005), component Machine, interface IMachine

and here are the last few lines of VBoxStartup.log:
    778.8d8: supR3HardenedScreenImage/NtCreateSection: cache hit (VINF_SUCCESS) on \Device\HarddiskVolume2\Program Files\Oracle\VirtualBox\QtGuiVBox4.dll
    778.8d8: \Device\HarddiskVolume2\Windows\winsxs\amd64_microsoft.windows.common-controls_6595b64144ccf1df_5.82.7601.18201_none_a4d3b9377117c3df\comctl32.dll: Owner is not trusted installer (01 02 00 00 00 00 00 05 20 00 00 00 20 02 00 00)
    778.8d8: supHardenedWinVerifyImageByHandle: -> -5667 (\Device\HarddiskVolume2\Windows\winsxs\amd64_microsoft.windows.common-controls_6595b64144ccf1df_5.82.7601.18201_none_a4d3b9377117c3df\comctl32.dll)
    778.8d8: Error (rc=0):
    778.8d8: supR3HardenedScreenImage/NtCreateSection: rc=Unknown Status -5667 (0xffffe9dd) fImage=1 fProtect=0xf fAccess=0x10 \Device\HarddiskVolume2\Windows\winsxs\amd64_microsoft.windows.common-controls_6595b64144ccf1df_5.82.7601.18201_none_
    a4d3b9377117c3df\comctl32.dll: supHardenedWinVerifyImageByHandle: TrustedInstaller is not the owner of '\Device\HarddiskVolume2\Windows\winsxs\amd64_microsoft.windows.common-controls_6595b64144ccf1df_5.82.7601.18201_none_a4d3b9377117c3df\comctl32.dll'.
    778.8d8: supR3HardenedMonitor_LdrLoadDll: returns rcNt=0xc0000190 'C:\Program Files\Oracle\VirtualBox\VirtualBox.dll'
    778.8d8: Fatal error:
    778.8d8: supR3HardenedMainGetTrustedMain: LoadLibrary "C:\Program Files\Oracle\VirtualBox/VirtualBox.dll" failed, rc=1790
    20b4.19f4: supR3HardenedWinDoReSpawn(2): Quitting: ExitCode=0x1 rcNt=0x0
    510.13e4: supR3HardenedWinDoReSpawn(1): Quitting: ExitCode=0x1 rcNt=0x0
neilo
 
Posts: 4
Joined: 18. Sep 2014, 01:23

Re: 4.3.16: should "savestate" be aborting the vm?

Postby scottgus1 » 18. Sep 2014, 20:19

All those "supR3HardenedWinDoReSpawn"s mentioned in the log snippet make me wonder if this issue is part of the anti-invasion hardening the developers have been working on. See https://forums.virtualbox.org/viewtopic.php?f=6&t=62615 for 4.3.14 and https://forums.virtualbox.org/viewtopic.php?f=6&t=63556 for 4.3.16, the version you're using.

I wonder if rolling back to 4.3.12 (don't forget the extension pack) would make the problem go away? If you can test that way and the issue does resolve, then send some info on the bugtracker, and use a full log.

(after editing the last sentence to include the comment about the extension pack, it also sparks me to ask if your present version and extension pack match?)
Human government is like that crazy uncle who hides a quarter in his fist behind his back, then asks you to guess which fist the quarter is in...
No matter which side you choose, Left or Right, both Sides are empty.
scottgus1
 
Posts: 4037
Joined: 30. Dec 2009, 20:14
Primary OS: MS Windows 10
VBox Version: PUEL
Guest OSses: Win7

Re: 4.3.16: should "savestate" be aborting the vm?

Postby neilo » 18. Sep 2014, 20:44

4.3.12 definitely does not have this symptom -- that's the version I was using day before yesterday. So yes I could revert to that, and I plan to revert as soon as it seems we've extracted enough debugging information to help the developers.

I have never explicitly installed the extension pack for this or any prior version, if that helps.
neilo
 
Posts: 4
Joined: 18. Sep 2014, 01:23

Re: 4.3.16: should "savestate" be aborting the vm?

Postby neilo » 18. Sep 2014, 21:00

build 4.3.17-96101 also has these symptoms.

I'll try posting to the "Windows 4.3.16 specifically for errors due to security" thread, and see what develops there.
neilo
 
Posts: 4
Joined: 18. Sep 2014, 01:23


Return to Using VirtualBox

Who is online

Users browsing this forum: No registered users and 15 guests