VirtualBox Manager Freezing Shortly After Launching Linux Guest

[harmonjeff]

I am having a problem where shortly after I launch a Linux guest, like within about 10 seconds, VirtualBox Manager freezes and the guest seems stuck. The windows with the Guest is moveable and I can still interact with it, but I can't interact with the VB Manager window at all. I wait and nothing happens so I close the Guest window by hitting the X in the corner, which makes Windows finally report it as an unresponsive application. I have to hit the X a second time to kill the Guest. Then the VB Manager window becomes active and I can interact with it again.

VirtualBox Version: 6.1.10-138449
Windows 10 1909

[harmonjeff]

The linux guest is an F5 BIGIP VE version 13 appliance. This happens just after it says "INFO: Allocating 4217 2048kB hugepages"

I have a CentOs 7 VM that works fine all the way through this running at the same time.

Here is what is shown in VBox.log:

00:00:20.722566 VMEmt: Halt method global1 (5)
00:00:20.722717 VMEmt: HaltedGlobal1 config: cNsSpinBlockThresholdCfg=50000
00:00:20.722739 Changing the VM state from 'CREATING' to 'CREATED'
00:00:20.724048 Changing the VM state from 'CREATED' to 'POWERING_ON'
00:00:20.724964 Changing the VM state from 'POWERING_ON' to 'RUNNING'
00:00:20.724976 Console: Machine state changed to 'Running'
00:00:20.735621 VMMDev: Guest Log: BIOS: VirtualBox 6.1.10
00:00:20.735753 PCI: Setting up resources and interrupts
00:00:20.737874 PIT: mode=2 count=0x10000 (65536) - 18.20 Hz (ch=0)
00:00:20.761563 Display::i_handleDisplayResize: uScreenId=0 pvVRAM=0000000000000000 w=720 h=400 bpp=0 cbLine=0x0 flags=0x0 origin=0,0
00:00:20.796532 VMMDev: Guest Log: CPUID EDX: 0x178bfbff
00:00:20.796677 PIIX3 ATA: Ctl#0: RESET, DevSel=0 AIOIf=0 CmdIf0=0x00 (-1 usec ago) CmdIf1=0x00 (-1 usec ago)
00:00:20.796726 PIIX3 ATA: Ctl#0: finished processing RESET
00:00:20.797338 VMMDev: Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63
00:00:20.802638 PIT: mode=2 count=0x48d3 (18643) - 64.00 Hz (ch=0)
00:00:20.851972 Display::i_handleDisplayResize: uScreenId=0 pvVRAM=000000000e220000 w=640 h=480 bpp=32 cbLine=0xA00 flags=0x0 origin=0,0
00:00:21.228632 GUI: UIMachineViewNormal::resendSizeHint: Restoring guest size-hint for screen 0 to 800x600
00:00:21.240721 GUI: 2D video acceleration is disabled
00:00:21.241130 GUI: HID LEDs sync is enabled
00:00:21.278820 GUI: UIMachineLogicNormal::sltCheckForRequestedVisualStateType: Requested-state=0, Machine-state=5
00:00:23.294677 Display::i_handleDisplayResize: uScreenId=0 pvVRAM=0000000000000000 w=720 h=400 bpp=0 cbLine=0x0 flags=0x0 origin=0,0
00:00:23.308635 PIT: mode=2 count=0x10000 (65536) - 18.20 Hz (ch=0)
00:00:23.309056 VMMDev: Guest Log: BIOS: Boot : bseqnr=1, bootseq=0231
00:00:23.309411 VMMDev: Guest Log: BIOS: Boot from Floppy 0 failed
00:00:23.309811 VMMDev: Guest Log: BIOS: Boot : bseqnr=2, bootseq=0023
00:00:23.310193 VMMDev: Guest Log: BIOS: CDROM boot failure code : 0002
00:00:23.310498 VMMDev: Guest Log: BIOS: Boot from CD-ROM failed
00:00:23.310878 VMMDev: Guest Log: BIOS: Boot : bseqnr=3, bootseq=0002
00:00:23.323415 VMMDev: Guest Log: BIOS: Booting from Hard Disk...
00:00:23.337120 PIIX3 ATA: Ctl#0: RESET, DevSel=0 AIOIf=0 CmdIf0=0xc4 (-1 usec ago) CmdIf1=0x00 (-1 usec ago)
00:00:23.337164 PIIX3 ATA: Ctl#0: finished processing RESET
00:00:23.341882 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=81
00:00:23.342472 VMMDev: Guest Log: int13_harddisk: function 08, unmapped device for ELDL=81
00:00:23.423359 Display::i_handleDisplayResize: uScreenId=0 pvVRAM=000000000e220000 w=640 h=480 bpp=0 cbLine=0x140 flags=0x0 origin=0,0
00:00:28.362358 Display::i_handleDisplayResize: uScreenId=0 pvVRAM=0000000000000000 w=720 h=400 bpp=0 cbLine=0x0 flags=0x0 origin=0,0
00:00:28.582426 VMMDev: Guest Log: BIOS: KBD: unsupported int 16h function 03
00:00:28.582829 VMMDev: Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000
00:00:28.587257 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=81
00:00:28.588488 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=81
00:00:28.598768 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=82
00:00:28.599347 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=82
00:00:28.599974 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=83
00:00:28.600543 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=83
00:00:28.601188 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=84
00:00:28.603175 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=84
00:00:28.606326 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=85
00:00:28.606879 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=85
00:00:28.607602 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=86
00:00:28.608190 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=86
00:00:28.608842 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=87
00:00:28.609460 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=87
00:00:28.610114 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=88
00:00:28.612657 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=88
00:00:28.613271 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=89
00:00:28.613858 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=89
00:00:28.614464 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8a
00:00:28.615040 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8a
00:00:28.615669 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8b
00:00:28.616251 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8b
00:00:28.616875 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8c
00:00:28.617453 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8c
00:00:28.618250 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8d
00:00:28.618889 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8d
00:00:28.619827 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8e
00:00:28.622391 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8e
00:00:28.622979 VMMDev: Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8f
00:00:28.623521 VMMDev: Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8f
00:00:28.715270 GUI: UIFrameBufferPrivate::performResize: Size=720x400, Using fallback buffer since no source bitmap is provided
00:00:29.118017 GIM: KVM: VCPU 0: Enabled system-time struct. at 0x000000029ffef000 - u32TscScale=0x92082577 i8TscShift=-1 uVersion=2 fFlags=0x1 uTsc=0x6d9e37957 uVirtNanoTS=0x1f43e2b75
00:00:29.118152 TM: Switching TSC mode from 'VirtTscEmulated' to 'RealTscOffset'
00:00:29.738025 GIM: KVM: Enabled wall-clock struct. at 0x0000000001cd7050 - u32Sec=1592489816 u32Nano=995654303 uVersion=2
00:00:29.809926 PIT: mode=2 count=0x4a9 (1193) - 1000.15 Hz (ch=0)
00:00:30.044656 APIC0: Switched mode to x2APIC
00:00:30.156975 PIT: mode=0 count=0x10000 (65536) - 18.20 Hz (ch=0)
00:00:30.160295 APIC1: Switched mode to x2APIC
00:00:30.160319 GIM: KVM: VCPU 1: Enabled system-time struct. at 0x000000029ffef040 - u32TscScale=0x92082577 i8TscShift=-1 uVersion=2 fFlags=0x1 uTsc=0x6d9e37957 uVirtNanoTS=0x1f43e2b75
00:00:30.163787 APIC2: Switched mode to x2APIC
00:00:30.163803 GIM: KVM: VCPU 2: Enabled system-time struct. at 0x000000029ffef080 - u32TscScale=0x92082577 i8TscShift=-1 uVersion=2 fFlags=0x1 uTsc=0x6d9e37957 uVirtNanoTS=0x1f43e2b75
00:00:30.167360 APIC3: Switched mode to x2APIC
00:00:30.167385 GIM: KVM: VCPU 3: Enabled system-time struct. at 0x000000029ffef0c0 - u32TscScale=0x92082577 i8TscShift=-1 uVersion=2 fFlags=0x1 uTsc=0x6d9e37957 uVirtNanoTS=0x1f43e2b75
00:00:31.293249 PIIX3 ATA: Ctl#0: RESET, DevSel=0 AIOIf=0 CmdIf0=0xc4 (-1 usec ago) CmdIf1=0x00 (-1 usec ago)
00:00:31.293322 PIIX3 ATA: Ctl#0: finished processing RESET

[harmonjeff]

I turned off Host I/O Cache on the IDE controller and it got a little further into the boot process as far as what is shown in the guest window, but it froze at about the same time point. Now the guest has this in the window:

Checking all file systems.
[/sbin/fsck.ext4 (1) -- /] fsck.ext4 -a /dev/mapper/vg--db--vda--set.1.root
set.1./: clean, 5870/112640 files, 293431/450560 blocks
[/sbin/fsck.ext4 (1) -- /shared fsck.ext4 -a /dev/mapper/vg--db--vda--dat.share

I don't think the issue has to do with exactly what the guest is doing.

[harmonjeff]

Rolled back to VB version 6.1.6-137129 and the VM is starting up as it should and the VB Manager doesn't freeze. Guest is doing SELinux policy relabeling so I haven't had it boot all the way up yet.

[harmonjeff]

Yep, full boot up working perfectly with version 6.1.6-137129 (Qt5.6.2). Totally clean with no freezing of the VB Manager window. Seems like something changed with VB 6.1.8 and beyond that makes the F5 VE not work. Any ideas on information I can gather to help with troubleshooting?

[mpack]

Partial logs are not useful I'm afraid. Zip the entire log and attach it to a post.

[harmonjeff]

Partial logs are not useful I'm afraid. Zip the entire log and attach it to a post.

OK, I'll have to update to the most current version again.

[harmonjeff]

Logs from 6.1.10 attached

VB_6-1-10_F5VEFreezingVBManager.zip

(16.89 KiB) Downloaded 9 times

[harmonjeff]

And here are the logs from 6.1.6

VBox_6-1-6.zip

(16.62 KiB) Downloaded 4 times

[mpack]

You have allocated 4 cores (out of 4 available), leaving none for the host. I would reduce this to 2.

I doubt that "'Linux 2.6 (64 bit)" accurately identifies the guest OS. What exactly is the guest OS?

Unfortunately the log is truncated to a point shortly after the boot begins, meaning it was grabbed while the VM was still open and is still not useful.

p.s. I only need one log from the VM having problems. I don't need historical logs.

[harmonjeff]

# uname -a
Linux localhost 3.10.0-862.14.4.el7.ve.x86_64 #1 SMP Sat May 9 07:49:51 PDT 2020 x86_64 x86_64 x86_64 GNU/Linux

# cat /etc/*release
CentOS Linux release 7.3.1611 (Core)
BIG-IP release 14.1.2.5 (Final)
NAME="CentOS Linux"
VERSION="7 (Core)"
ID="centos"
ID_LIKE="rhel fedora"
VERSION_ID="7"
PRETTY_NAME="CentOS Linux 7 (Core)"
ANSI_COLOR="0;31"
CPE_NAME="cpe:/o:centos:centos:7"
HOME_URL="https://www.centos.org/"
BUG_REPORT_URL="https://bugs.centos.org/"

CENTOS_MANTISBT_PROJECT="CentOS-7"
CENTOS_MANTISBT_PROJECT_VERSION="7"
REDHAT_SUPPORT_PRODUCT="centos"
REDHAT_SUPPORT_PRODUCT_VERSION="7"

CentOS Linux release 7.3.1611 (Core)

I'll have to upgrade and get to the problem again. So what you want is for me to start the VM, have it be a problem and then poweroff the VM?

[harmonjeff]

Lower the vCPU count from 4 to 2 made it work. Thanks, I should have thought of that. Everything looks good on version 6.1.10 now.