Skip site navigation (1)Skip section navigation (2)
Date:      Thu, 2 May 2019 13:11:06 +0200
From:      Roger Pau =?utf-8?B?TW9ubsOp?= <roger.pau@citrix.com>
To:        Kyle Evans <kevans@FreeBSD.org>
Cc:        <src-committers@freebsd.org>, <svn-src-all@freebsd.org>, <svn-src-head@freebsd.org>
Subject:   Re: svn commit: r346670 - head/sys/net
Message-ID:  <20190502111106.pfosaq73kgo6g33j@Air-de-Roger.citrite.net>
In-Reply-To: <201904251244.x3PCi8g0096201@repo.freebsd.org>
References:  <201904251244.x3PCi8g0096201@repo.freebsd.org>

next in thread | previous in thread | raw e-mail | index | archive | help
On Thu, Apr 25, 2019 at 12:44:08PM +0000, Kyle Evans wrote:
> Author: kevans
> Date: Thu Apr 25 12:44:08 2019
> New Revision: 346670
> URL: https://svnweb.freebsd.org/changeset/base/346670
>=20
> Log:
>   tun/tap: close race between destroy/ioctl handler
>  =20
>   It seems that there should be a better way to handle this, but this see=
ms to
>   be the more common approach and it should likely get replaced in all of=
 the
>   places it happens... Basically, thread 1 is in the process of destroyin=
g the
>   tun/tap while thread 2 is executing one of the ioctls that requires the
>   tun/tap mutex and the mutex is destroyed before the ioctl handler can
>   acquire it.
>  =20
>   This is only one of the races described/found in PR 233955.
>  =20
>   PR:		233955
>   Reviewed by:	ae
>   MFC after:	2 weeks
>   Differential Revision:	https://reviews.freebsd.org/D20027

This has caused a regression when booting. I reliably get the
following panic when booting on several different boxes:

Apr 26 16:23:57.662653 panic: mtx_lock() of spin mutex (null) @ /usr/home/o=
sstest/build.135317.build-amd64-freebsd/freebsd/sys/kern/subr_bus.c:620
Apr 26 16:23:57.674650 cpuid =3D 2
Apr 26 16:23:57.686653 time =3D 1
Apr 26 16:23:57.686720 KDB: stack backtrace:
Apr 26 16:23:57.686797 db_trace_self_wrapper() at db_trace_self_wrapper+0x2=
b/frame 0xfffffe003abe8710
Apr 26 16:23:57.686879 vpanic() at vpanic+0x19d/frame 0xfffffe003abe8760
Apr 26 16:23:57.698637 panic() at panic+0x43/frame 0xfffffe003abe87c0
Apr 26 16:23:57.698700 __mtx_lock_flags() at __mtx_lock_flags+0x145/frame 0=
xfffffe003abe8810
Apr 26 16:23:57.710640 devctl_queue_data_f() at devctl_queue_data_f+0x6a/fr=
ame 0xfffffe003abe8840
Apr 26 16:23:57.722625 g_dev_taste() at g_dev_taste+0x463/frame 0xfffffe003=
abe8a00
Apr 26 16:23:57.722690 g_load_class() at g_load_class+0x1bc/frame 0xfffffe0=
03abe8a30
Apr 26 16:23:57.734638 g_run_events() at g_run_events+0x197/frame 0xfffffe0=
03abe8a70
Apr 26 16:23:57.734704 fork_exit() at fork_exit+0x84/frame 0xfffffe003abe8a=
b0
Apr 26 16:23:57.746655 fork_trampoline() at fork_trampoline+0xe/frame 0xfff=
ffe003abe8ab0
Apr 26 16:23:57.746721 --- trap 0, rip =3D 0, rsp =3D 0, rbp =3D 0 ---
Apr 26 16:23:57.758797 KDB: enter: panic
Apr 26 16:23:57.758913 [ thread pid 13 tid 100029 ]
Apr 26 16:23:57.758943 Stopped at      kdb_enter+0x3b: movq    $0,kdb_why
Apr 26 16:23:57.770557 db>=20

The full serial log of the host booting:

=1B[01;01He820: 0000000095fff000 0`0000000/boot/config: -hn -S115200/=08-=
=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08=
/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=
=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08=
-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=
=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08=
\=08|=08/=08-=08\=08|=08/=08-=08\=08Consoles: serial port =20
Apr 26 16:23:50.318505 BIOS drive C: is disk0
Apr 26 16:23:50.318505 BIOS drive D: is disk1
Apr 26 16:23:50.330486 |=08/=08BIOS 632kB/2316028kB available memory
Apr 26 16:23:50.366512=20
Apr 26 16:23:50.366512 FreeBSD/x86 bootstrap loader, Revision 1.1
Apr 26 16:23:50.366512 -=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08=
\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=
=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08=
|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=
=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08=
/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=
=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08=
-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=
=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08=
\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08Loading /boot/defaults/loader.conf
Apr 26 16:23:50.414528 Loading /boot/device.hints
Apr 26 16:23:50.426510 /=08-=08\=08|=08/=08-=08Loading /boot/loader.conf
Apr 26 16:23:50.426510 \=08|=08/=08-=08Loading /boot/loader.conf.local
Apr 26 16:23:50.438526 \=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08=
|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=
=08\=08Loading kernel...
Apr 26 16:23:50.450532 |=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08=
/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=
=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08=
-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08/boot/kerne=
l/kernel text=3D0x16e4c29 -=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=
=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08=
/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=
=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08=
-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08data=3D0x1d65a8=
+0x819948 /=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=
=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08=
|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=
=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08=
/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=
=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08syms=3D[0x8+0x183c48\=08|=08=
/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=
=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08=
-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=
=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08=
\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08+0x8+0x1a1479-=08\=08|=08]
Apr 26 16:23:51.626609 Loading configured modules...
Apr 26 16:23:51.638619 /=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08=
-=08\=08|=08can't find '/boot/entropy'
Apr 26 16:23:51.638679 /=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08=
-=08\=08/mfsroot |=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=
=088000000 2       \=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08=
/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=
=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08=
-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=
=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08=
\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=
=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08=
|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=
=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08=
/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=
=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08=
-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=
=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08=
\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=
=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08=
|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=
=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08=
/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=
=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08=
-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=
=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08=
\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=
=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08=
|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=
=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08=
/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=
=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08=
-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=
=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08=
\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=
=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08=
|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=
=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08=
/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=
=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08=
-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=
=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08=
\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=
=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08=
|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=
=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08/=08-=08\=08|=08=
/=08-=08\=08|=08/=08-=08                \=08|=08/=08-=08\=08|=08/=08-=08\=
=08|=08/=08-=08size=3D0x171c8000
Apr 26 16:23:53.846620=20
Apr 26 16:23:53.846671=20
Booting [/boot/kernel/kernel]...              =20
Apr 26 16:23:53.846719 GDB: no debug ports present
Apr 26 16:23:54.530540 KDB: debugger backends: ddb
Apr 26 16:23:54.530540 KDB: current backend: ddb
Apr 26 16:23:54.530540 ---<<BOOT>>---
Apr 26 16:23:54.530540 Table 'FACP' at 0x95ff7000
Apr 26 16:23:54.542628 Table 'UEFI' at 0x95ffd000
Apr 26 16:23:54.542683 Table 'UEFI' at 0x95ffc000
Apr 26 16:23:54.542726 Table 'ASF!' at 0x95ffb000
Apr 26 16:23:54.554635 Table 'ASPT' at 0x95ffa000
Apr 26 16:23:54.554696 Table 'BOOT' at 0x95ff9000
Apr 26 16:23:54.554743 Table 'DBGP' at 0x95ff8000
Apr 26 16:23:54.554792 Table 'HPET' at 0x95ff6000
Apr 26 16:23:54.566627 Table 'APIC' at 0x95ff5000
Apr 26 16:23:54.566689 APIC: Found table at 0x95ff5000
Apr 26 16:23:54.566738 APIC: Using the MADT enumerator.
Apr 26 16:23:54.566787 Copyright (c) 1992-2019 The FreeBSD Project.
Apr 26 16:23:54.578639 Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 19=
91, 1992, 1993, 1994
Apr 26 16:23:54.578706 	The Regents of the University of California. All ri=
ghts reserved.
Apr 26 16:23:54.590645 FreeBSD is a registered trademark of The FreeBSD Fou=
ndation.
Apr 26 16:23:54.590710 FreeBSD 13.0-CURRENT 4284b348ee3(HEAD) GENERIC amd64
Apr 26 16:23:54.602637 FreeBSD clang version 8.0.0 (tags/RELEASE_800/final =
356365) (based on LLVM 8.0.0)
Apr 26 16:23:54.614600 WARNING: WITNESS option enabled, expect reduced perf=
ormance.
Apr 26 16:23:54.614665 Table 'FACP' at 0x95ff7000
Apr 26 16:23:54.614715 Table 'UEFI' at 0x95ffd000
Apr 26 16:23:54.614762 Table 'UEFI' at 0x95ffc000
Apr 26 16:23:54.626589 Table 'ASF!' at 0x95ffb000
Apr 26 16:23:54.626643 Table 'ASPT' at 0x95ffa000
Apr 26 16:23:54.626690 Table 'BOOT' at 0x95ff9000
Apr 26 16:23:54.626736 Table 'DBGP' at 0x95ff8000
Apr 26 16:23:54.638647 Table 'HPET' at 0x95ff6000
Apr 26 16:23:54.638729 Table 'APIC' at 0x95ff5000
Apr 26 16:23:54.638779 Table 'MCFG' at 0x95ff4000
Apr 26 16:23:54.638826 Table 'SLIC' at 0x95ff3000
Apr 26 16:23:54.650634 Table 'SSDT' at 0x95fdc000
Apr 26 16:23:54.650695 Table 'SPMI' at 0x95fda000
Apr 26 16:23:54.650743 Table 'SSDT' at 0x95fd9000
Apr 26 16:23:54.650790 Table 'SSDT' at 0x95fd8000
Apr 26 16:23:54.650837 Table 'SSDT' at 0x95fd4000
Apr 26 16:23:54.662635 Table 'SPCR' at 0x95ff2000
Apr 26 16:23:54.662696 Table 'DMAR' at 0x95fd3000
Apr 26 16:23:54.662744 Table 'SSDT' at 0x95fd2000
Apr 26 16:23:54.662791 Table 'FPDT' at 0x95fd1000
Apr 26 16:23:54.674633 Table 'HEST' at 0x95fd0000
Apr 26 16:23:54.674694 Table 'ERST' at 0x95fce000
Apr 26 16:23:54.674742 Table 'BERT' at 0x95fcd000
Apr 26 16:23:54.674789 Table 'EINJ' at 0x95fcc000
Apr 26 16:23:54.674836 ACPI: No SRAT table found
Apr 26 16:23:54.686618 PPIM 0: PA=3D0xa0000, VA=3D0xffffffff99a10000, size=
=3D0x10000, mode=3D0
Apr 26 16:23:54.722627 pmap: large map 8 PML4 slots (4096 Gb)
Apr 26 16:23:54.734614 VT(vga): resolution 640x480
Apr 26 16:23:54.734676 Preloaded elf kernel "/boot/kernel/kernel" at 0xffff=
ffff998dd000.
Apr 26 16:23:54.746630 Preloaded mfs_root "/mfsroot" at 0xffffffff998e61f0.
Apr 26 16:23:54.746696 Table 'FACP' at 0x95ff7000
Apr 26 16:23:54.746745 FACP: Found table at 0x95ff7000
Apr 26 16:23:54.758587 Calibrating TSC clock ... TSC clock: 3092899860 Hz
Apr 26 16:23:55.754490 CPU: Intel(R) Xeon(R) CPU E3-1220 v3 @ 3.10GHz (3092=
=2E90-MHz K8-class CPU)
Apr 26 16:23:55.766650   Origin=3D"GenuineIntel"  Id=3D0x306c3  Family=3D0x=
6  Model=3D0x3c  Stepping=3D3
Apr 26 16:23:55.778636   Features=3D0xbfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,M=
CE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,S=
SE2,SS,HTT,TM,PBE>
Apr 26 16:23:55.790589   Features2=3D0x7ffafbff<SSE3,PCLMULQDQ,DTES64,MON,D=
S_CPL,VMX,SMX,EST,TM2,SSSE3,SDBG,FMA,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2AP=
IC,MOVBE,POPCNT,TSCDLT,AESNI,XSAVE,OSXSAVE,AVX,F16C,RDRAND>
Apr 26 16:23:55.802661   AMD Features=3D0x2c100800<SYSCALL,NX,Page1GB,RDTSC=
P,LM>
Apr 26 16:23:55.814629   AMD Features2=3D0x21<LAHF,ABM>
Apr 26 16:23:55.814690   Structured Extended Features=3D0x2fbb<FSGSBASE,TSC=
ADJ,BMI1,HLE,AVX2,SMEP,BMI2,ERMS,INVPCID,RTM,NFPUSG>
Apr 26 16:23:55.826639   XSAVE Features=3D0x1<XSAVEOPT>
Apr 26 16:23:55.826700   VT-x: Basic Features=3D0xda0400<SMM,INS/OUTS,TRUE>
Apr 26 16:23:55.826753         Pin-Based Controls=3D0x7f<ExtINT,NMI,VNMI,Pr=
eTmr>
Apr 26 16:23:55.838605         Primary Processor Controls=3D0xfff9fffe<INTW=
IN,TSCOff,HLT,INVLPG,MWAIT,RDPMC,RDTSC,CR3-LD,CR3-ST,CR8-LD,CR8-ST,TPR,NMIW=
IN,MOV-DR,IO,IOmap,MTF,MSRmap,MONITOR,PAUSE>
Apr 26 16:23:55.850662         Secondary Processor Controls=3D0x7cff<APIC,E=
PT,DT,RDTSCP,x2APIC,VPID,WBINVD,UG,PAUSE-loop,RDRAND,INVPCID,VMFUNC,VMCS>
Apr 26 16:23:55.862645         Exit Controls=3D0xda0400<PAT-LD,EFER-SV,PTMR=
-SV>
Apr 26 16:23:55.874646         Entry Controls=3D0xda0400
Apr 26 16:23:55.874708         EPT Features=3D0x6334141<XO,PW4,UC,WB,2M,1G,=
INVEPT,AD,single,all>
Apr 26 16:23:55.886587         VPID Features=3D0xf01<INVVPID,individual,sin=
gle,all,single-globals>
Apr 26 16:23:55.886598   TSC: P-state invariant, performance statistics
Apr 26 16:23:55.898658 Data TLB: 2 MByte or 4 MByte pages, 4-way set associ=
ative, 32 entries and a separate array with 1 GByte pages, 4-way set associ=
ative, 4 entries
Apr 26 16:23:55.910639 Data TLB: 4 KB pages, 4-way set associative, 64 entr=
ies
Apr 26 16:23:55.910704 Instruction TLB: 2M/4M pages, fully associative, 8 e=
ntries
Apr 26 16:23:55.922634 Instruction TLB: 4KByte pages, 8-way set associative=
, 128 entries
Apr 26 16:23:55.922701 64-Byte prefetching
Apr 26 16:23:55.922749 Shared 2nd-Level TLB: 4 KByte/2MByte pages, 8-way as=
sociative, 1024 entries
Apr 26 16:23:55.934645 L2 cache: 256 kbytes, 8-way associative, 64 bytes/li=
ne
Apr 26 16:23:55.946629 real memory  =3D 8589934592 (8192 MB)
Apr 26 16:23:55.946692 Physical memory chunk(s):
Apr 26 16:23:55.946742 0x0000000000010000 - 0x000000000009cfff, 577536 byte=
s (141 pages)
Apr 26 16:23:55.958641 0x0000000000103000 - 0x00000000001fffff, 1036288 byt=
es (253 pages)
Apr 26 16:23:55.958736 0x0000000019a00000 - 0x000000008d6befff, 1942745088 =
bytes (474303 pages)
Apr 26 16:23:55.970634 0x0000000095fff000 - 0x0000000095ffffff, 4096 bytes =
(1 pages)
Apr 26 16:23:55.970700 0x0000000100000000 - 0x0000000250b8efff, 5649264640 =
bytes (1379215 pages)
Apr 26 16:23:55.982625 avail memory =3D 7548768256 (7199 MB)
Apr 26 16:23:55.994570 Table 'FACP' at 0x95ff7000
Apr 26 16:23:56.006636 Table 'UEFI' at 0x95ffd000
Apr 26 16:23:56.006696 Table 'UEFI' at 0x95ffc000
Apr 26 16:23:56.006743 Table 'ASF!' at 0x95ffb000
Apr 26 16:23:56.006790 Table 'ASPT' at 0x95ffa000
Apr 26 16:23:56.018651 Table 'BOOT' at 0x95ff9000
Apr 26 16:23:56.018712 Table 'DBGP' at 0x95ff8000
Apr 26 16:23:56.018760 Table 'HPET' at 0x95ff6000
Apr 26 16:23:56.018807 Table 'APIC' at 0x95ff5000
Apr 26 16:23:56.018854 Table 'MCFG' at 0x95ff4000
Apr 26 16:23:56.030634 Table 'SLIC' at 0x95ff3000
Apr 26 16:23:56.030694 Table 'SSDT' at 0x95fdc000
Apr 26 16:23:56.030741 Table 'SPMI' at 0x95fda000
Apr 26 16:23:56.030788 Table 'SSDT' at 0x95fd9000
Apr 26 16:23:56.042642 Table 'SSDT' at 0x95fd8000
Apr 26 16:23:56.042702 Table 'SSDT' at 0x95fd4000
Apr 26 16:23:56.042750 Table 'SPCR' at 0x95ff2000
Apr 26 16:23:56.042797 Table 'DMAR' at 0x95fd3000
Apr 26 16:23:56.054632 DMAR: Found table at 0x95fd3000
Apr 26 16:23:56.054694 MADT: Found CPU APIC ID 0 ACPI ID 1: enabled
Apr 26 16:23:56.054746 SMP: Added CPU 0 (AP)
Apr 26 16:23:56.054793 MADT: Found CPU APIC ID 2 ACPI ID 2: enabled
Apr 26 16:23:56.066632 SMP: Added CPU 2 (AP)
Apr 26 16:23:56.066691 MADT: Found CPU APIC ID 4 ACPI ID 3: enabled
Apr 26 16:23:56.066742 SMP: Added CPU 4 (AP)
Apr 26 16:23:56.066788 MADT: Found CPU APIC ID 6 ACPI ID 4: enabled
Apr 26 16:23:56.078725 SMP: Added CPU 6 (AP)
Apr 26 16:23:56.078760 MADT: Found CPU APIC ID 0 ACPI ID 5: disabled
Apr 26 16:23:56.078817 MADT: Found CPU APIC ID 0 ACPI ID 6: disabled
Apr 26 16:23:56.090547 MADT: Found CPU APIC ID 0 ACPI ID 7: disabled
Apr 26 16:23:56.090547 MADT: Found CPU APIC ID 0 ACPI ID 8: disabled
Apr 26 16:23:56.102520 Event timer "LAPIC" quality 600
Apr 26 16:23:56.102520 ACPI APIC Table: <DELL   PE_SC3  >
Apr 26 16:23:56.102520 Package ID shift: 4
Apr 26 16:23:56.102520 L3 cache ID shift: 4
Apr 26 16:23:56.102520 L2 cache ID shift: 1
Apr 26 16:23:56.114479 L1 cache ID shift: 1
Apr 26 16:23:56.114479 Core ID shift: 1
Apr 26 16:23:56.114479 INTR: Adding local APIC 2 as a target
Apr 26 16:23:56.150539 INTR: Adding local APIC 4 as a target
Apr 26 16:23:56.150539 INTR: Adding local APIC 6 as a target
Apr 26 16:23:56.150539 FreeBSD/SMP: Multiprocessor System Detected: 4 CPUs
Apr 26 16:23:56.162543 FreeBSD/SMP: 1 package(s) x 4 core(s)
Apr 26 16:23:56.162543 Package HW ID =3D 0
Apr 26 16:23:56.162543 	Core HW ID =3D 0
Apr 26 16:23:56.174555 		CPU0 (BSP): APIC ID: 0
Apr 26 16:23:56.174555 	Core HW ID =3D 1
Apr 26 16:23:56.174555 		CPU1 (AP): APIC ID: 2
Apr 26 16:23:56.174555 	Core HW ID =3D 2
Apr 26 16:23:56.174555 		CPU2 (AP): APIC ID: 4
Apr 26 16:23:56.174555 	Core HW ID =3D 3
Apr 26 16:23:56.186544 		CPU3 (AP): APIC ID: 6
Apr 26 16:23:56.186544 APIC: CPU 0 has ACPI ID 1
Apr 26 16:23:56.186544 APIC: CPU 1 has ACPI ID 2
Apr 26 16:23:56.186544 APIC: CPU 2 has ACPI ID 3
Apr 26 16:23:56.186544 APIC: CPU 3 has ACPI ID 4
Apr 26 16:23:56.198550 x86bios:  IVT 0x000000-0x0004ff at 0xfffff80000000000
Apr 26 16:23:56.198550 x86bios: SSEG 0x09c000-0x09cfff at 0xfffffe0002eb1000
Apr 26 16:23:56.210547 x86bios: EBDA 0x09f000-0x09ffff at 0xfffff8000009f000
Apr 26 16:23:56.210547 x86bios:  ROM 0x0a0000-0x0fefff at 0xfffff800000a0000
Apr 26 16:23:56.210547 lapic0: CMCI unmasked
Apr 26 16:23:56.222548 Pentium Pro MTRR support enabled
Apr 26 16:23:56.222611 __stack_chk_init: WARNING: Initializing stack protec=
tion with non-random cookies!
Apr 26 16:23:56.234649 __stack_chk_init: WARNING: This severely limits the =
benefit of -fstack-protector!
Apr 26 16:23:56.234725 VIMAGE (virtualized network stack) enabled
Apr 26 16:23:56.246632 ULE: setup cpu 0
Apr 26 16:23:56.246709 ULE: setup cpu 1
Apr 26 16:23:56.246757 ULE: setup cpu 2
Apr 26 16:23:56.246803 ULE: setup cpu 3
Apr 26 16:23:56.246850 ACPI: RSDP 0x00000000000FE020 000024 (v02 DELL  )
Apr 26 16:23:56.258620 ACPI: XSDT 0x0000000095FCF188 0000E4 (v01 DELL   PE_=
SC3   00000001      01000013)
Apr 26 16:23:56.258689 ACPI: FACP 0x0000000095FF7000 00010C (v05 DELL   PE_=
SC3   00000001 DELL 00040000)
Apr 26 16:23:56.270640 ACPI: DSDT 0x0000000095FDF000 012335 (v01 DELL   PE_=
SC3   00000000 DELL 00040000)
Apr 26 16:23:56.282635 ACPI: FACS 0x0000000095FBD000 000040
Apr 26 16:23:56.282698 ACPI: UEFI 0x0000000095FFD000 000236 (v01 DELL   PE_=
SC3   00000001 DELL 00040000)
Apr 26 16:23:56.294635 ACPI: UEFI 0x0000000095FFC000 000042 (v01 DELL   PE_=
SC3   00000000 DELL 00040000)
Apr 26 16:23:56.294705 ACPI: ASF! 0x0000000095FFB000 0000A5 (v32 DELL   PE_=
SC3   00000001 DELL 00040000)
Apr 26 16:23:56.306597 ACPI: ASPT 0x0000000095FFA000 000034 (v07 DELL   PE_=
SC3   00000001 DELL 00040000)
Apr 26 16:23:56.318581 ACPI: BOOT 0x0000000095FF9000 000028 (v01 DELL   PE_=
SC3   00000001 DELL 00040000)
Apr 26 16:23:56.318581 ACPI: DBGP 0x0000000095FF8000 000034 (v01 DELL   PE_=
SC3   00000001 DELL 00040000)
Apr 26 16:23:56.330620 ACPI: HPET 0x0000000095FF6000 000038 (v01 DELL   PE_=
SC3   00000001 DELL 00040000)
Apr 26 16:23:56.342636 ACPI: APIC 0x0000000095FF5000 000092 (v03 DELL   PE_=
SC3   00000001 DELL 00040000)
Apr 26 16:23:56.342704 ACPI: MCFG 0x0000000095FF4000 00003C (v01 DELL   PE_=
SC3   00000001 DELL 00040000)
Apr 26 16:23:56.354639 ACPI: SLIC 0x0000000095FF3000 000176 (v01 DELL   PE_=
SC3   00000001 DELL 00040000)
Apr 26 16:23:56.366687 ACPI: SSDT 0x0000000095FDC000 002028 (v01 DELL   PE_=
SC3   00001000 DELL 00040000)
Apr 26 16:23:56.366756 ACPI: SPMI 0x0000000095FDA000 000040 (v05 DELL   PE_=
SC3   00000001 DELL 00040000)
Apr 26 16:23:56.378647 ACPI: SSDT 0x0000000095FD9000 000533 (v01 DELL   PE_=
SC3   00003000 DELL 00040000)
Apr 26 16:23:56.390638 ACPI: SSDT 0x0000000095FD8000 000ACE (v01 DELL   PE_=
SC3   00003000 DELL 00040000)
Apr 26 16:23:56.390709 ACPI: SSDT 0x0000000095FD4000 003492 (v01 DELL   PE_=
SC3   00003000 DELL 00040000)
Apr 26 16:23:56.402647 ACPI: SPCR 0x0000000095FF2000 000050 (v01 DELL   PE_=
SC3   00000001 DELL 00040000)
Apr 26 16:23:56.414633 ACPI: DMAR 0x0000000095FD3000 000080 (v01 DELL   PE_=
SC3   00000001 DELL 00040000)
Apr 26 16:23:56.414701 ACPI: SSDT 0x0000000095FD2000 000514 (v01 DELL   PE_=
SC3   00001000 DELL 00040000)
Apr 26 16:23:56.426646 ACPI: FPDT 0x0000000095FD1000 000044 (v01 DELL   PE_=
SC3   00000001 DELL 00040000)
Apr 26 16:23:56.438643 ACPI: HEST 0x0000000095FD0000 0000A8 (v01 DELL   PE_=
SC3   00000001 DELL 00040000)
Apr 26 16:23:56.438711 ACPI: ERST 0x0000000095FCE000 000230 (v01 DELL   PE_=
SC3   00000001 DELL 00040000)
Apr 26 16:23:56.450651 ACPI: BERT 0x0000000095FCD000 000030 (v01 DELL   PE_=
SC3   00000001 DELL 00040000)
Apr 26 16:23:56.462631 ACPI: EINJ 0x0000000095FCC000 000150 (v01 DELL   PE_=
SC3   00000001 DELL 00040000)
Apr 26 16:23:56.462700 MADT: Found IO APIC ID 2, Interrupt 0 at 0xfec00000
Apr 26 16:23:56.474535 ioapic0: ver 0x20 maxredir 0x17
Apr 26 16:23:56.474568 ioapic0: Routing external 8259A's -> intpin 0
Apr 26 16:23:56.474596 MADT: Interrupt override: source 0, irq 2
Apr 26 16:23:56.486634 ioapic0: Routing IRQ 0 -> intpin 2
Apr 26 16:23:56.486696 MADT: Interrupt override: source 9, irq 9
Apr 26 16:23:56.486748 ioapic0: intpin 9 trigger: level
Apr 26 16:23:56.498651 lapic: Routing NMI -> LINT1
Apr 26 16:23:56.498713 lapic: LINT1 trigger: edge
Apr 26 16:23:56.498761 lapic: LINT1 polarity: high
Apr 26 16:23:56.498809 ioapic0 <Version 2.0> irqs 0-23 on motherboard
Apr 26 16:23:56.510592 lapic: Divisor 2, Frequency 49885486 Hz
Apr 26 16:23:57.506602 lapic: deadline tsc mode, Frequency 3092899860 Hz
Apr 26 16:23:57.518669 cpu0 BSP:
Apr 26 16:23:57.518727      ID: 0x00000000   VER: 0x01060015 LDR: 0x0000000=
1 DFR: 0x00000000 x2APIC: 1
Apr 26 16:23:57.530597   lint0: 0x00010700 lint1: 0x00000400 TPR: 0x0000000=
0 SVR: 0x000011ff
Apr 26 16:23:57.530611   timer: 0x000100ef therm: 0x00010000 err: 0x000000f=
0 pmc: 0x00010400
Apr 26 16:23:57.542651    cmci: 0x000000f2
Apr 26 16:23:57.542714 lapic4: CMCI unmasked
Apr 26 16:23:57.542762 SMP: AP CPU #2 Launched!
Apr 26 16:23:57.542809 cpu2 AP:
Apr 26 16:23:57.554629      ID: 0x00000004   VER: 0x01060015 LDR: 0x0000001=
0 DFR: 0x00000000 x2APIC: 1
Apr 26 16:23:57.554698   lint0: 0x00010700 lint1: 0x00000400 TPR: 0x0000000=
0 SVR: 0x000011ff
Apr 26 16:23:57.566634   timer: 0x000100ef therm: 0x00010000 err: 0x000000f=
0 pmc: 0x00010400
Apr 26 16:23:57.566701    cmci: 0x000000f2
Apr 26 16:23:57.566748 lapic6: CMCI unmasked
Apr 26 16:23:57.578636 SMP: AP CPU #3 Launched!
Apr 26 16:23:57.578697 cpu3 AP:
Apr 26 16:23:57.578741      ID: 0x00000006   VER: 0x01060015 LDR: 0x0000004=
0 DFR: 0x00000000 x2APIC: 1
Apr 26 16:23:57.590638   lint0: 0x00010700 lint1: 0x00000400 TPR: 0x0000000=
0 SVR: 0x000011ff
Apr 26 16:23:57.590703   timer: 0x000100ef therm: 0x00010000 err: 0x000000f=
0 pmc: 0x00010400
Apr 26 16:23:57.602644    cmci: 0x000000f2
Apr 26 16:23:57.602702 lapic2: CMCI unmasked
Apr 26 16:23:57.602749 SMP: AP CPU #1 Launched!
Apr 26 16:23:57.602798 cpu1 AP:
Apr 26 16:23:57.614625      ID: 0x00000002   VER: 0x01060015 LDR: 0x0000000=
4 DFR: 0x00000000 x2APIC: 1
Apr 26 16:23:57.614693   lint0: 0x00010700 lint1: 0x00000400 TPR: 0x0000000=
0 SVR: 0x000011ff
Apr 26 16:23:57.626628   timer: 0x000100ef therm: 0x00010000 err: 0x000000f=
0 pmc: 0x00010400
Apr 26 16:23:57.626694    cmci: 0x000000f2
Apr 26 16:23:57.638631 SMP: passed TSC synchronization test
Apr 26 16:23:57.638694 TSC timecounter discards lower 1 bit(s)
Apr 26 16:23:57.638744 Timecounter "TSC-low" frequency 1546449930 Hz qualit=
y 1000
Apr 26 16:23:57.650643 snd_md0: Preload)e u=3D0x00ff800f0 [512] d=3D0743070=
07cbyt e[32at c=3D0x00000f3f82 [10248]
Apr 26 16:23:57.650713 feeder_register: snd_unit=3D-1 snd_maxautovchans=3D1=
6 latency=3D5 feeder_rate_min=3D1 feeder_rate_max=3D2016000 feeder_rate_rou=
nd=3D25
Apr 26 16:23:57.662653 panic: mtx_lock() of spin mutex (null) @ /usr/home/o=
sstest/build.135317.build-amd64-freebsd/freebsd/sys/kern/subr_bus.c:620
Apr 26 16:23:57.674650 cpuid =3D 2
Apr 26 16:23:57.686653 time =3D 1
Apr 26 16:23:57.686720 KDB: stack backtrace:
Apr 26 16:23:57.686797 db_trace_self_wrapper() at db_trace_self_wrapper+0x2=
b/frame 0xfffffe003abe8710
Apr 26 16:23:57.686879 vpanic() at vpanic+0x19d/frame 0xfffffe003abe8760
Apr 26 16:23:57.698637 panic() at panic+0x43/frame 0xfffffe003abe87c0
Apr 26 16:23:57.698700 __mtx_lock_flags() at __mtx_lock_flags+0x145/frame 0=
xfffffe003abe8810
Apr 26 16:23:57.710640 devctl_queue_data_f() at devctl_queue_data_f+0x6a/fr=
ame 0xfffffe003abe8840
Apr 26 16:23:57.722625 g_dev_taste() at g_dev_taste+0x463/frame 0xfffffe003=
abe8a00
Apr 26 16:23:57.722690 g_load_class() at g_load_class+0x1bc/frame 0xfffffe0=
03abe8a30
Apr 26 16:23:57.734638 g_run_events() at g_run_events+0x197/frame 0xfffffe0=
03abe8a70
Apr 26 16:23:57.734704 fork_exit() at fork_exit+0x84/frame 0xfffffe003abe8a=
b0
Apr 26 16:23:57.746655 fork_trampoline() at fork_trampoline+0xe/frame 0xfff=
ffe003abe8ab0
Apr 26 16:23:57.746721 --- trap 0, rip =3D 0, rsp =3D 0, rbp =3D 0 ---
Apr 26 16:23:57.758797 KDB: enter: panic
Apr 26 16:23:57.758913 [ thread pid 13 tid 100029 ]
Apr 26 16:23:57.758943 Stopped at      kdb_enter+0x3b: movq    $0,kdb_why
Apr 26 16:23:57.770557 db>=20

The automatic bisector has pointed as this commit as the culprit, you
can see the full bisection at:

https://lists.xenproject.org/archives/html/xen-devel/2019-04/msg02061.html

And an example of a failed test at:

https://lists.xenproject.org/archives/html/xen-devel/2019-05/msg00104.html
http://logs.test-lab.xenproject.org/osstest/logs/135458/

Thanks, Roger.



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20190502111106.pfosaq73kgo6g33j>