Vms sometimes boot, sometimes don't

[Alex80]

Hi All!

I have a Linux Fedora 32 based server, where I installed the VirtualBox 6.2.
I made more vms with Fedora 32 in the VirtualBox, and everything works fine until yesterday.
I don't really knows what happened, what changed, but the virtual machines not really wants to boot. Sometimes they boot, sometimes don't.

Here are some ends of vms log file at the times when the virtual machines didn't boot:

1)

Code: Select all

00:00:09.273357 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8b
00:00:09.273576 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8c
00:00:09.273780 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8c
00:00:09.273997 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8d
00:00:09.274200 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8d
00:00:09.274419 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8e
00:00:09.274623 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8e
00:00:09.274840 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8f
00:00:09.275043 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8f
00:00:09.429184 GIM: KVM: VCPU  0: Enabled system-time struct. at 0x000000059b601000 - u32TscScale=0x9c250e03 i8TscShift=-1 uVersion=2 fFlags=0x1 uTsc=0x6a0efedbb uVirtNanoTS=0x20589d6e3
00:00:09.429206 TM: Switching TSC mode from 'Dynamic' to 'RealTscOffset'
00:00:09.757505 GIM: KVM: Enabled wall-clock struct. at 0x000000059b600000 - u32Sec=1591722595 u32Nano=858028000 uVersion=2
00:00:09.764461 PIT: mode=2 count=0x4a9 (1193) - 1000.15 Hz (ch=0)
00:00:09.764631 APIC0: Switched mode to x2APIC
00:00:09.766276 IEM: wrmsr(0x3a,0x0`00000001) -> #GP(0)
00:00:09.766329 IEM: rdmsr(0x4e) -> #GP(0)
00:00:09.873683 PIT: mode=0 count=0x10000 (65536) - 18.20 Hz (ch=0)
00:00:10.381354 OHCI: Software reset
00:00:10.711242 AHCI#0: Reset the HBA
00:00:10.711260 VD#0: Cancelling all active requests
00:00:10.711686 AHCI#0: Port 0 reset
00:00:10.712247 EHCI: Hardware reset
00:00:10.712320 EHCI: USB Operational
00:00:10.712622 PIIX3 ATA: Ctl#1: RESET, DevSel=0 AIOIf=0 CmdIf0=0xa0 (-1 usec ago) CmdIf1=0x00 (-1 usec ago)
00:00:10.712705 PIIX3 ATA: Ctl#1: finished processing RESET

2)

Code: Select all

00:00:09.231913 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8d
00:00:09.232116 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8d
00:00:09.232333 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8e
00:00:09.232537 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8e
00:00:09.232754 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8f
00:00:09.232957 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8f
00:00:09.383886 GIM: KVM: VCPU  0: Enabled system-time struct. at 0x000000003b601000 - u32TscScale=0x9c250e03 i8TscShift=-1 uVersion=2 fFlags=0x1 uTsc=0x696d974ad uVirtNanoTS=0x20275d23b
00:00:09.383908 TM: Switching TSC mode from 'Dynamic' to 'RealTscOffset'
00:00:09.490818 GIM: KVM: Enabled wall-clock struct. at 0x000000003b600000 - u32Sec=1591724346 u32Nano=942368000 uVersion=2
00:00:09.497406 PIT: mode=2 count=0x4a9 (1193) - 1000.15 Hz (ch=0)
00:00:09.497567 APIC0: Switched mode to x2APIC
00:00:09.498698 IEM: wrmsr(0x3a,0x0`00000001) -> #GP(0)
00:00:09.498747 IEM: rdmsr(0x4e) -> #GP(0)
00:00:09.605922 PIT: mode=0 count=0x10000 (65536) - 18.20 Hz (ch=0)
00:00:09.759820 OHCI: Software reset
00:00:10.093834 AHCI#0: Reset the HBA
00:00:10.093854 VD#0: Cancelling all active requests
00:00:10.094281 AHCI#0: Port 0 reset
00:00:10.094862 EHCI: Hardware reset
00:00:10.094946 EHCI: USB Operational
00:00:10.095647 PIIX3 ATA: Ctl#1: RESET, DevSel=0 AIOIf=0 CmdIf0=0xa0 (-1 usec ago) CmdIf1=0x00 (-1 usec ago)
00:00:10.095734 PIIX3 ATA: Ctl#1: finished processing RESET

3) Started with inserted Fedora 32 install media (iso):

Code: Select all

00:00:06.866297 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8d
00:00:06.866514 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8e
00:00:06.866716 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8e
00:00:06.866935 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8f
00:00:06.867137 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8f
00:00:06.876335 Display::i_handleDisplayResize: uScreenId=0 pvVRAM=0000000000000000 w=720 h=400 bpp=0 cbLine=0x0 flags=0x0 origin=0,0
00:00:07.024566 GIM: KVM: VCPU  0: Enabled system-time struct. at 0x000000041e601000 - u32TscScale=0x9c250e03 i8TscShift=-1 uVersion=2 fFlags=0x1 uTsc=0x4c0b68899 uVirtNanoTS=0x173156a6f
00:00:07.024602 TM: Switching TSC mode from 'Dynamic' to 'RealTscOffset'
00:00:07.355180 GIM: KVM: Enabled wall-clock struct. at 0x000000041e600000 - u32Sec=1591724467 u32Nano=81655460 uVersion=2
00:00:07.361780 PIT: mode=2 count=0x4a9 (1193) - 1000.15 Hz (ch=0)
00:00:07.361941 APIC0: Switched mode to x2APIC
00:00:07.363584 IEM: wrmsr(0x3a,0x0`00000001) -> #GP(0)
00:00:07.363637 IEM: rdmsr(0x4e) -> #GP(0)
00:00:07.470769 PIT: mode=0 count=0x10000 (65536) - 18.20 Hz (ch=0)
00:00:07.978246 OHCI: Software reset
00:00:11.620381 AHCI#0: Reset the HBA
00:00:11.620401 VD#0: Cancelling all active requests
00:00:11.620856 AHCI#0: Port 0 reset
00:00:11.621457 EHCI: Hardware reset
00:00:11.621534 EHCI: USB Operational
00:00:11.621814 PIIX3 ATA: Ctl#1: RESET, DevSel=0 AIOIf=0 CmdIf0=0xa0 (-1 usec ago) CmdIf1=0x00 (-1 usec ago)
00:00:11.621915 PIIX3 ATA: Ctl#1: finished processing RESET

It's very weird.. what's going on?

I attached full log one of vms. I hope somebody could help me.
Thanks in advance!

[scottgus1]

The guest log posted is incomplete, it either came from a complete failure in Virtualbox on the host, or the guest Virtualbox window was still open.

Start the guest from full normal shutdown, not save-state. Run until you see the problem happen, then shut down the guest from within the guest OS if possible. If not possible, close the Virtualbox window for the guest with the Power Off option set.

Right-click the guest in the main Virtualbox window's guest list, choose Show Log. Save the far left tab's log, zip it, and post the zip file, using the forum's Upload Attachment tab.

It would be best to provide a log from a guest that fails to boot and another log from the same guest when it boots and shuts down properly.

[Alex80]

Hi scottgus1,

thanks for your reply.
I attached the logs from a good and a bad case.

tesztjoinhoz-2020-06-10-10-09-31.log - it fails to boot, close the Virtualbox window for the guest with the Power Off option set.
tesztjoinhoz-2020-06-10-10-13-11.log - it boots and shuts down properly.

[Alex80]

Hi scottgus1,

Were you able to view the logs? Did you find any problems?

[mpack]

I would start by updating both VirtualBox and the Guest Additions. The latter especially are still on the 6.0.0 version, by definition the buggiest possible in the v6 branch.

I'd also allocate two cores to the VM, and increase graphics RAM to 128MB.

[scottgus1]

I too see the failure to continue running after

00:00:10.139538 PIIX3 ATA: Ctl#1: RESET, DevSel=0 AIOIf=0 CmdIf0=0xa0 (-1 usec ago) CmdIf1=0x00 (-1 usec ago)
00:00:10.139589 PIIX3 ATA: Ctl#1: finished processing RESET

But what I also see is that the failure-after-reset guest continues processing Virtualbox commands and log entries and closes properly after the user requests to close the Virtualbox window:

00:00:10.139538 PIIX3 ATA: Ctl#1: RESET, DevSel=0 AIOIf=0 CmdIf0=0xa0 (-1 usec ago) CmdIf1=0x00 (-1 usec ago)
00:00:10.139589 PIIX3 ATA: Ctl#1: finished processing RESET
00:01:39.748165 GUI: Request to close active machine-window.
00:01:39.754530 Changing the VM state from 'RUNNING' to 'SUSPENDING'
00:01:39.757213 AIOMgr: Endpoint for file '/vbox/vms/tesztjoinhoz/tesztjoinhoz.vdi' (flags 000c0781) created successfully
00:01:39.844311 PDMR3Suspend: 89 742 454 ns run time
00:01:39.844342 Changing the VM state from 'SUSPENDING' to 'SUSPENDED'
00:01:39.844357 Console: Machine state changed to 'Paused'
00:01:43.954942 GUI: Request for close-action to power VM off.
00:01:43.954977 GUI: Passing request to power VM off from machine-logic to UI session.
00:01:43.954987 GUI: Powering VM down on UI session power off request...
00:01:43.955422 Console: Machine state changed to 'Stopping'
00:01:43.956129 Console::powerDown(): A request to power off the VM has been issued (mMachineState=Stopping, InUninit=0)
00:01:43.956684 Changing the VM state from 'SUSPENDED' to 'POWERING_OFF'

The other good-boot log shows the guest OS continuing after the RESET line.

This shows me that the issue resides in the guests or on the host PC somehow, not in Virtualbox itself. I may be wrong, but from the info posted I cannot see what might be wrong from a Virtualbox standpoint.

One suggestion in the future, be sure to take the log after the guest Virtualbox window is fully closed. Your first log also stops at "PIIX3 ATA: Ctl#1: finished processing RESET", but the other logs posted later indicate Virtualbox does continue processing. The log in the first post was taken while the guest OS had seized but before the Virtualbox window was closed. Your log snippets in the

Code: Select all

 tags also suffer from the same problem.

One other possibility. You state your host PC OS as Fedora 32. If I recall correctly, Fedora 32 did not exist when Virtualbox 6.1.6 came out. Maybe a Virtualbox upgrade is in order. Also, check on Mpack's thoughts on the Guest Additions. 6.0.0 GAs are really old.

[Alex80]

After the updating both VirtualBox and the Guest Additions, it seems that every guests work fine.

The version of Guest Additions was 6.1.6, not 6.0.0

vbox2.jpg (76.74 KiB) Viewed 2223 times

However, I see that the version number is 6.0.0 was in the log. After the update the version hasn't changed in the log:
00:00:15.651073 VMMDev: Guest Additions information report: Version 6.0.0 r127566 '6.0.0'

Probably, is it a log bug?

Thank you guys!

[mpack]

Probably, is it a log bug?

Nope.

Short answer: the log doesn't lie. If it reports an unexpected GAs version, then you didn't install the GAs.

Also the dialog box you picture is telling you about the host extension pack, which has nothing to do with the GAs.

[Alex80]

you didn't install the GAs.

I'm sorry, I mixed the GAs with the Extension Pack.

[scottgus1]

After the updating both VirtualBox and the Guest Additions, it seems that every guests work fine.

Good! Glad you're up and running.