Bug 254412 - emulators/virtualbox-ose-additions - Boot time crash - Sleeping thread owns a non-sleepable lock
Summary: emulators/virtualbox-ose-additions - Boot time crash - Sleeping thread owns a...
Status: New
Alias: None
Product: Ports & Packages
Classification: Unclassified
Component: Individual Port(s) (show other bugs)
Version: Latest
Hardware: amd64 Any
: --- Affects Only Me
Assignee: Virtualbox Team (Nobody)
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2021-03-19 23:46 UTC by David R. Bergstein
Modified: 2021-06-24 19:39 UTC (History)
3 users (show)

See Also:
bugzilla: maintainer-feedback? (vbox)


Attachments
panic with guest additions 6.2.2 in a 13.0-RELEASE-p1 guest (53.46 KB, text/plain)
2021-05-31 18:08 UTC, Graham Perrin
no flags Details
Screenshot: panic-free with the guest limited to a single processor (23.04 KB, image/png)
2021-05-31 19:25 UTC, Graham Perrin
no flags Details
panic with guest additions 5.2.44_3 in a 13.0-RELEASE-p2 guest (86.73 KB, text/plain)
2021-06-24 19:39 UTC, Graham Perrin
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description David R. Bergstein 2021-03-19 23:46:19 UTC
I have been seeing this boot time crash on an intermittent basis on a 
virtualbox running FreeBSD-13.0-RC2.  The information below was extracted from a recent crash dump:

drb-freebsd-13.localdomain dumped core - see /var/crash/vmcore.4

Thu Mar 18 20:58:47 EDT 2021

FreeBSD drb-freebsd-13.localdomain 13.0-RC2 FreeBSD 13.0-RC2 #0 
releng/13.0-n244684-13c22f74953: Fri Mar 12 04:05:19 UTC 2021 
root@releng1.nyi.freebsd.org:/usr/obj/usr/src/amd64.amd64/sys/GENERIC amd64

panic: sleeping thread

GNU gdb (GDB) 10.1 [GDB v10.1 for FreeBSD]
Copyright (C) 2020 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later 
<http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-portbld-freebsd13.0".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<https://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
 ??? <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /boot/kernel/kernel...
Reading symbols from /usr/lib/debug//boot/kernel/kernel.debug...

Unread portion of the kernel message buffer:
---<<BOOT>>---
Copyright (c) 1992-2021 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
 ??? The Regents of the University of California. All rights reserved.
FreeBSD is a registered trademark of The FreeBSD Foundation.
FreeBSD 13.0-RC2 #0 releng/13.0-n244684-13c22f74953: Fri Mar 12 04:05:19 
UTC 2021
root@releng1.nyi.freebsd.org:/usr/obj/usr/src/amd64.amd64/sys/GENERIC amd64
FreeBSD clang version 11.0.1 (git@github.com:llvm/llvm-project.git 
llvmorg-11.0.1-0-g43ff75f2c3fe)
VT(vga): text 80x25
CPU: Intel(R) Core(TM) i7 CPU???????? 950? @ 3.07GHz (3103.68-MHz 
K8-class CPU)
 ? Origin="GenuineIntel"? Id=0x106a5? Family=0x6? Model=0x1a Stepping=5
Features=0x1783fbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR,SSE,SSE2,HTT>
 ? Features2=0x180201<SSE3,SSSE3,SSE4.1,SSE4.2>
 ? AMD Features=0x28100800<SYSCALL,NX,RDTSCP,LM>
 ? AMD Features2=0x1<LAHF>
 ? Structured Extended Features3=0x10000000<L1DFL>
 ? TSC: P-state invariant
real memory? = 9126805504 (8704 MB)
avail memory = 8285257728 (7901 MB)
Event timer "LAPIC" quality 100
ACPI APIC Table: <VBOX?? VBOXAPIC>
FreeBSD/SMP: Multiprocessor System Detected: 4 CPUs
FreeBSD/SMP: 1 package(s) x 4 cache groups x 1 core(s)
random: unblocking device.
ioapic0: MADT APIC ID 4 != hw id 0
ioapic0 <Version 2.0> irqs 0-23
Launching APs: 2 1 3
Timecounter "TSC-low" frequency 1551839460 Hz quality 1000
KTLS: Initialized 4 threads
random: entropy device external interface
[ath_hal] loaded
WARNING: Device "kbd" is Giant locked and may be deleted before FreeBSD 
14.0.
kbd1 at kbdmux0
000.000058 [4350] netmap_init?????????????? netmap: loaded module
mlx5en: Mellanox Ethernet driver 3.6.0 (December 2020)
nexus0
vtvga0: <VT VGA driver>
cryptosoft0: <software crypto>
aesni0: No AES or SHA support.
acpi0: <VBOX VBOXXSDT>
acpi0: Power Button (fixed)
acpi0: Sleep Button (fixed)
cpu0: <ACPI CPU> on acpi0
attimer0: <AT timer> port 0x40-0x43,0x50-0x53 on acpi0
Timecounter "i8254" frequency 1193182 Hz quality 0
Event timer "i8254" frequency 1193182 Hz quality 100
Timecounter "ACPI-fast" frequency 3579545 Hz quality 900
acpi_timer0: <32-bit timer at 3.579545MHz> port 0x4008-0x400b on acpi0
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
pci0: <ACPI PCI bus> on pcib0
isab0: <PCI-ISA bridge> at device 1.0 on pci0
isa0: <ISA bus> on isab0
atapci0: <Intel PIIX4 UDMA33 controller> port 
0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0xd000-0xd00f at device 1.1 on pci0
ata0: <ATA channel> at channel 0 on atapci0
ata1: <ATA channel> at channel 1 on atapci0
vgapci0: <VGA-compatible display> mem 0xe0000000-0xefffffff irq 18 at 
device 2.0 on pci0
vgapci0: Boot video device
em0: <Intel(R) PRO/1000 Network Connection> port 0xd010-0xd017 mem 
0xf0000000-0xf001ffff irq 19 at device 3.0 on pci0
em0: Using 1024 TX descriptors and 1024 RX descriptors
<6>em0: Ethernet address: 08:00:27:dd:d4:fc
<6>em0: netmap queues/slots: TX 1/1024, RX 1/1024
pcm0: <Intel ICH (82801AA)> port 0xd100-0xd1ff,0xd200-0xd23f irq 21 at 
device 5.0 on pci0
pcm0: <SigmaTel STAC9700/83/84 AC97 Codec>
ohci0: <Apple KeyLargo/Intrepid USB controller> mem 
0xf0804000-0xf0804fff irq 22 at device 6.0 on pci0
usbus0 on ohci0
usbus0: 12Mbps Full Speed USB v1.0
pci0: <bridge> at device 7.0 (no driver attached)
ehci0: <Intel 82801FB (ICH6) USB 2.0 controller> mem 
0xf0805000-0xf0805fff irq 19 at device 11.0 on pci0
usbus1: EHCI version 1.0
usbus1 on ehci0
usbus1: 480Mbps High Speed USB v2.0
acpi_acad0: <AC Adapter> on acpi0
atkbdc0: <Keyboard controller (i8042)> port 0x60,0x64 irq 1 on acpi0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
kbd0 at atkbd0
atkbd0: [GIANT-LOCKED]
psm0: <PS/2 Mouse> irq 12 on atkbdc0
psm0: [GIANT-LOCKED]
WARNING: Device "psm" is Giant locked and may be deleted before FreeBSD 
14.0.
psm0: model IntelliMouse Explorer, device ID 4
orm0: <ISA Option ROMs> at iomem 0xc0000-0xc7fff,0xe2000-0xe2fff pnpid 
ORM0000 on isa0
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff pnpid 
PNP0900 on isa0
atrtc0: <AT realtime clock> at port 0x70 irq 8 on isa0
atrtc0: registered as a time-of-day clock, resolution 1.000000s
Event timer "RTC" frequency 32768 Hz quality 0
atrtc0: non-PNP ISA device will be removed from GENERIC in FreeBSD 14.
Timecounters tick every 10.000 msec
ZFS filesystem version: 5
ZFS storage pool version: features support (5000)
Trying to mount root from zfs:zroot/ROOT/default []...
Root mount waiting for: CAM usbus0 usbus1
ugen0.1: <Apple OHCI root HUB> at usbus0
uhub0 on usbus0
ugen1.1: <Intel EHCI root HUB> at usbus1
uhub0: <Apple OHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus0
uhub1 on usbus1
uhub1: <Intel EHCI root HUB, class 9/0, rev 2.00/1.00, addr 1> on usbus1
ada0 at ata0 bus 0 scbus0 target 0 lun 0
ada0: <VBOX HARDDISK 1.0> ATA8-ACS device
ada0: Serial Number VBb8450cb8-277eed0b
ada0: 33.300MB/s transfers (UDMA2, PIO 65536bytes)
ada0: 61440MB (125829120 512 byte sectors)
cd0 at ata1 bus 0 scbus1 target 0 lun 0
cd0: <VBOX CD-ROM 1.0> Removable CD-ROM SCSI device
cd0: Serial Number VB2-01700376
cd0: 33.300MB/s transfers (UDMA2, ATAPI 12bytes, PIO 65534bytes)
cd0: Attempt to query device size failed: NOT READY, Medium not present
uhub0: 12 ports with 12 removable, self powered
Root mount waiting for: usbus1
Root mount waiting for: usbus1
Root mount waiting for: usbus1
Root mount waiting for: usbus1
uhub1: 12 ports with 12 removable, self powered
<118>Setting hostuuid: 56767ad9-d311-7b42-9f7f-db26ca8d9b82.
<118>Setting hostid: 0x10458f66.
<118>Starting file system checks:
<118>no pools available to import
<118>Mounting local filesystems:.
<118>Setting hostname: drb-freebsd-13.localdomain.
<118>ELF ldconfig path: /lib /usr/lib /usr/lib/compat /usr/local/lib 
/usr/local/lib/compat/pkg /usr/local/lib/compat/pkg /usr/local/lib/gcc10 
/usr/local/lib/gcc9 /usr/local/lib/mysql /usr/local/lib/mysql/plugin 
/usr/local/lib/perl5/5.32/mach/CORE /usr/local/lib/qt5 
/usr/local/lib/samba4 /usr/local/lib/signon 
/usr/local/lib/signon/extensions /usr/local/llvm10/lib
<118>32-bit compatibility ldconfig path: /usr/lib32
<118>Setting up harvesting: 
[UMA],[FS_ATIME],SWI,INTERRUPT,NET_NG,[NET_ETHER],NET_TUN,MOUSE,KEYBOARD,ATTACH,CACHED
<118>Feeding entropy: .
vboxguest0 port 0xd020-0xd03f mem 
0xf0400000-0xf07fffff,0xf0800000-0xf0803fff irq 20 at device 4.0 on pci0
Sleeping thread (tid 100521, pid 174) owns a non-sleepable lock
KDB: stack backtrace of thread 100521:
#0 0xffffffff80c16291 at mi_switch+0xc1
#1 0xffffffff8293cf37 at rtR0SemEventMultiBsdWait+0x297
#2 0xffffffff8291d36a at vgdrvHgcmAsyncWaitCallbackWorker+0x14a
#3 0xffffffff8291e49b at VbglR0HGCMInternalConnect+0x11b
#4 0xffffffff8291ad33 at VGDrvCommonIoCtl+0xb53
#5 0xffffffff82919af6 at VGDrvCommonProcessOptionsFromHost+0x146
#6 0xffffffff8291d9f8 at vgdrvFreeBSDAttach+0x1d8
#7 0xffffffff80c462ad at device_attach+0x3dd
#8 0xffffffff80c45eb1 at device_probe_and_attach+0x41
#9 0xffffffff8085b966 at pci_driver_added+0xf6
#10 0xffffffff80c43d29 at devclass_driver_added+0x39
#11 0xffffffff80c43cad at devclass_add_driver+0x13d
#12 0xffffffff80be6964 at module_register_init+0xa4
#13 0xffffffff80bd8667 at linker_load_module+0xbc7
#14 0xffffffff80bd9e4b at kern_kldload+0xbb
#15 0xffffffff80bd9f7b at sys_kldload+0x5b
#16 0xffffffff8108aa8c at amd64_syscall+0x10c
#17 0xffffffff810618be at fast_syscall_common+0xf8
panic: sleeping thread
cpuid = 0
time = 1616100801
KDB: stack backtrace:
#0 0xffffffff80c57105 at kdb_backtrace+0x65
#1 0xffffffff80c09cd1 at vpanic+0x181
#2 0xffffffff80c09b43 at panic+0x43
#3 0xffffffff80c6e526 at propagate_priority+0x296
#4 0xffffffff80c6f0c3 at turnstile_wait+0x313
#5 0xffffffff80be7b9c at __mtx_lock_sleep+0x17c
#6 0xffffffff80c256bf at softclock_call_cc+0xff
#7 0xffffffff80c25b89 at softclock+0x79
#8 0xffffffff80bcae0d at ithread_loop+0x24d
#9 0xffffffff80bc7c0e at fork_exit+0x7e
#10 0xffffffff8106201e at fork_trampoline+0xe
Uptime: 8s
Dumping 364 out of 8152 MB:..5%..14%..22%..31%..44%..53%..62%..71%..84%..93%

__curthread () at /usr/src/sys/amd64/include/pcpu_aux.h:55
55??? ??? __asm("movq %%gs:%P1,%0" : "=r" (td) : "n" (offsetof(struct pcpu,
(kgdb) #0? __curthread () at /usr/src/sys/amd64/include/pcpu_aux.h:55
#1? doadump (textdump=<optimized out>) at 
/usr/src/sys/kern/kern_shutdown.c:399
#2? 0xffffffff80c098c6 in kern_reboot (howto=260)
 ??? at /usr/src/sys/kern/kern_shutdown.c:486
#3? 0xffffffff80c09d40 in vpanic (fmt=<optimized out>, ap=<optimized out>)
 ??? at /usr/src/sys/kern/kern_shutdown.c:919
#4? 0xffffffff80c09b43 in panic (fmt=<unavailable>)
 ??? at /usr/src/sys/kern/kern_shutdown.c:843
#5? 0xffffffff80c6e526 in propagate_priority (td=0xfffffe00c2c0be00)
 ??? at /usr/src/sys/kern/subr_turnstile.c:251
#6? 0xffffffff80c6f0c3 in turnstile_wait (ts=ts@entry=0xfffff800035b9540,
 ??? owner=<optimized out>, owner@entry=0xfffffe00c2c0be00, 
queue=queue@entry=0)
 ??? at /usr/src/sys/kern/subr_turnstile.c:808
#7? 0xffffffff80be7b9c in __mtx_lock_sleep (c=0xffffffff81802718 
<Giant+24>,
 ??? v=<optimized out>) at /usr/src/sys/kern/kern_mutex.c:664
#8? 0xffffffff80c256bf in softclock_call_cc (
 ??? c=0xffffffff81d1b700 <default_kbd_state+40>,
 ??? cc=cc@entry=0xffffffff81ca8200 <cc_cpu>, direct=direct@entry=0)
 ??? at /usr/src/sys/kern/kern_timeout.c:658
#9? 0xffffffff80c25b89 in softclock (arg=0xffffffff81ca8200 <cc_cpu>)
 ??? at /usr/src/sys/kern/kern_timeout.c:816
#10 0xffffffff80bcae0d in intr_event_execute_handlers (p=<optimized out>,
 ??? ie=0xfffff8000364a700) at /usr/src/sys/kern/kern_intr.c:1168
#11 ithread_execute_handlers (p=<optimized out>, ie=0xfffff8000364a700)
 ??? at /usr/src/sys/kern/kern_intr.c:1181
#12 ithread_loop (arg=arg@entry=0xfffff80003657d20)
 ??? at /usr/src/sys/kern/kern_intr.c:1269
#13 0xffffffff80bc7c0e in fork_exit (
 ??? callout=0xffffffff80bcabc0 <ithread_loop>, arg=0xfffff80003657d20,
 ??? frame=0xfffffe00835e8d40) at /usr/src/sys/kern/kern_fork.c:1069
#14 <signal handler called>
(kgdb)
Comment 1 Jethro Nederhof 2021-03-21 05:54:32 UTC
Also seeing this on a 14-CURRENT guest, using virtualbox-ose-additions 6.1.18 from pkg. Host is Windows 10 with VirtualBox Version 6.1.18 r142142 with both the VMSVGA and VBoxSVGA display adaptors if that matters.

Disabling vboxguest_load="YES" (and vboxservice_load) in rc.conf, if I boot fully and wait a bit, it seems to work okay about 50% of the time if I manually start it with:

$ sudo service vboxguest onestart

I can then onestart vboxservice and everything seems to work OK as expected.

The other 50% it goes straight to ddb with the same "Sleeping thread (tid ######, pid ###) owns a non-sleepable lock" error and stack trace as comment #1. So intermittent not just at boot-time.
Comment 2 David R. Bergstein 2021-03-23 10:47:31 UTC
Just had anther crash with the error above at boot time, this time on FreeBSD 13.0-RC3.
Comment 3 parv 2021-03-24 23:17:34 UTC
I can confirm that this happens in 12-STABLE (n232872-af0cea80104) too. Sometimes on reboot; other times from a cold boot.
Comment 4 parv 2021-03-25 21:07:58 UTC
On every (re)boot FreeBSD was seeing panic with (Windows host & VirtualBOx 6.1.18) vbox-ose-additions 6.1.18; then restarting by itself normally. Got tiring fast.

I have reverted to VirutalBox 5.2.44 on Windows; and to -additions-legacy on FreeBSD. Let me know please if something I could try with 6.1.18 version components.
Comment 5 Graham Perrin 2021-05-31 14:23:08 UTC
Windows 10 21H1 host, 6.1.22. 

13.0-RELEASE-p1 guest, UFS, 6.1.22 additions:

* first boot after updating the system and pkg upgrade, 
  panic-free

* restarted, a panic, I didn't note the details

* a few subsequent restarts, panic-free

* I edited /etc/rc.conf to enable crash dumps but then 
  dumps did not occur because my edition was lost 
  (this, presumably, would not happen with ZFS)

* after repeat edition of /etc/rc.conf and installation of 
  devel/gdb I got a crash dump but still, can't get 
  what's required from the dump :-(
Comment 6 Graham Perrin 2021-05-31 18:08:04 UTC
Created attachment 225420 [details]
panic with guest additions 6.2.2 in a 13.0-RELEASE-p1 guest
Comment 7 Graham Perrin 2021-05-31 19:25:39 UTC
Created attachment 225426 [details]
Screenshot: panic-free with the guest limited to a single processor

(In reply to Graham Perrin from comment #5)

Tested with a different 13.0-RELEASE-p1 guest (booting from ZFS instead of UFS) on the same Windows host. 

As far as I can tell, kernel panics are: 


a) _highly_ reproducible when the guest uses 
   all available processors, with /etc/rc.conf set to 
   vboxguest_enable="NO"
   vboxservice_enable="NO"

   – at ttyv1, login as root then 
       kldload vboxguest
     kldunload vboxguest
       kldload vboxguest
     kldunload vboxguest
       kldload vboxguest
     kldunload vboxguest
     
     … et cetera, until a panic occurs


b) _never_ reproducible when the guest is limited to 
   one (1) processor, or booted in safe mode

   – with one processor, I was able to repeatedly run 
     the one-line command below.

kldload vboxguest && kldunload vboxguest && kldload vboxguest && kldunload vboxguest && kldload vboxguest && kldunload vboxguest
Comment 8 Graham Perrin 2021-06-01 23:26:17 UTC
This bug 254412 is probably a duplicate of bug 236917, 

> emulators/virtualbox-ose: Sleeping thread owns a non-sleepable lock kernel panic

– I'll continue there. 


(In reply to parv from comment #4)

> …  reverted to VirutalBox 5.2.44 on Windows; …

Consider the panic with 5.2.44_4 at bug 236917 comment 3
Comment 9 parv 2021-06-01 23:50:50 UTC
(In reply to Graham Perrin from comment #8)

I want to note that PR #236917 is about emulators/virtualbox-ose 5.2.44. I am concerned with use of emulators/virtualbox-ose-additions 6.1 when VirutalBox 6.1 virtual machine runs on Windows. Both could have the same/similar reason for the bug.
Comment 10 Graham Perrin 2021-06-06 04:25:38 UTC
Sincere apologies from me (at bug 236917 comment 9) for confusing the two bugs. 

It took _way_ too long for me to realise my mistake. 

Shouting this at myself: 

there, 236917 = panics of FreeBSD HOSTS
 here, 254412 = panics of FreeBSD GUESTS
Comment 11 Graham Perrin 2021-06-06 06:06:30 UTC
(In reply to Graham Perrin from comment #6)

Quoting John Baldwin: 

> … the breakage is somewhere in this code: 
> 
> Sleeping thread (tid 100099, pid 155) owns a non-sleepable lock
> KDB: stack backtrace of thread 100099:
> #0 0xffffffff80c166f1 at mi_switch+0xc1
> #1 0xffffffff8233cf37 at rtR0SemEventMultiBsdWait+0x297
> #2 0xffffffff8231d36a at vgdrvHgcmAsyncWaitCallbackWorker+0x14a
> #3 0xffffffff8231e49b at VbglR0HGCMInternalConnect+0x11b
> #4 0xffffffff8231ad33 at VGDrvCommonIoCtl+0xb53
> #5 0xffffffff82319af6 at VGDrvCommonProcessOptionsFromHost+0x146
> #6 0xffffffff8231d9f8 at vgdrvFreeBSDAttach+0x1d8
> #7 0xffffffff80c4670d at device_attach+0x3dd
Comment 12 Graham Perrin 2021-06-24 19:39:32 UTC
Created attachment 226041 [details]
panic with guest additions 5.2.44_3 in a 13.0-RELEASE-p2 guest

(In reply to parv from comment #4)

> I have reverted to VirutalBox 5.2.44 on Windows; and to 
> -additions-legacy on FreeBSD. …

Maybe (far) less likely to occur with legacy but still, with virtualbox-ose-additions-legacy-5-2.44_3, it's possible to produce this panic.