Synopsis: Kernel panic while recompiling the base system on 7.2-current
Category: kernel sparc64
Environment:
System : OpenBSD 7.2
Details : OpenBSD 7.2-current (GENERIC.MP) #9: Mon Nov 7 01:33:54 WIB 2022
k@openbsd:/sys/arch/sparc64/compile/GENERIC.MP
Architecture: OpenBSD.sparc64
Machine : sparc64
Description:
This occurs when I'm updating a 7.2-current installation.
When recompiling the base system after installing an updated kernel,
the kernel panics in the middle of the compilation session.
The install is on a 8 vcore, 8 GiB memory LDOM on a Sun T5120.
How-To-Repeat:
Recompile kernel & base system as usual:
# cd /sys/arch/$(machine)/compile/GENERIC.MP
# make obj
# make config
# make -j8 && make install
# reboot
# cd /usr/src
# make -j8 obj
# make -j8 build # Panics in the middle of this command
Fix:
dmesg:
OpenBSD 7.2-current (GENERIC.MP) #9: Mon Nov 7 01:33:54 WIB 2022
k@openbsd:/sys/arch/sparc64/compile/GENERIC.MP
real mem = 8589934592 (8192MB)
avail mem = 8408670208 (8019MB)
random: good seed from bootblocks
mpath0 at root
scsibus0 at mpath0: 256 targets
mainbus0 at root: SPARC Enterprise T5120
cpu0 at mainbus0: SUNW,UltraSPARC-T2 (rev 0.0) @ 1165.379 MHz
cpu1 at mainbus0: SUNW,UltraSPARC-T2 (rev 0.0) @ 1165.379 MHz
cpu2 at mainbus0: SUNW,UltraSPARC-T2 (rev 0.0) @ 1165.379 MHz
cpu3 at mainbus0: SUNW,UltraSPARC-T2 (rev 0.0) @ 1165.379 MHz
cpu4 at mainbus0: SUNW,UltraSPARC-T2 (rev 0.0) @ 1165.379 MHz
cpu5 at mainbus0: SUNW,UltraSPARC-T2 (rev 0.0) @ 1165.379 MHz
cpu6 at mainbus0: SUNW,UltraSPARC-T2 (rev 0.0) @ 1165.379 MHz
cpu7 at mainbus0: SUNW,UltraSPARC-T2 (rev 0.0) @ 1165.379 MHz
vbus0 at mainbus0
"flashprom" at vbus0 not configured
vrng0 at vbus0
cbus0 at vbus0
vdsk0 at cbus0 chan 0x2: ivec 0x4, 0x5
scsibus1 at vdsk0: 1 targets
sd0 at scsibus1 targ 0 lun 0: <SUN, Virtual Disk, 1.1>
sd0: 40960MB, 512 bytes/sector, 83886080 sectors
vdsk1 at cbus0 chan 0x3: ivec 0x6, 0x7
scsibus2 at vdsk1: 1 targets
cd0 at scsibus2 targ 0 lun 0: <SUN, Virtual Disk, 1.1>
vnet0 at cbus0 chan 0x4: ivec 0x8, 0x9, address 00:14:4f:f9:6a:75
vcons0 at vbus0: ivec 0x111: console
vrtc0 at vbus0
vscsi0 at root
scsibus3 at vscsi0: 256 targets
softraid0 at root
scsibus4 at softraid0: 256 targets
bootpath: /virtual-devices@100,0/channel-devices@200,0/disk@0,0
root on sd0a (f7061d976cd07cad.a) swap on sd0b dump on sd0b
WARNING: / was not properly unmounted
usbdevs:
usbdevs: no USB controllers found
cp: /var/db/acpi/*: No such file or directory
b64encode: *: No such file or directory
pcidump:
acpidump:
ddb log:
mode = 0100660, inum = 441884, fs = /usr/obj
panic: ffs_valloc: dup alloc
Stopped at db_enter+0x8: nop
TID PID UID PRFLAGS PFLAGS CPU COMMAND
463321 83767 21 0x100003 0 2 as
92098 92219 21 0x100003 0 5 cc1
258938 85141 21 0x100003 0 4 as
422498 22643 21 0x100003 0 0 cc1
165247 67024 21 0x100003 0 6 as
*211105 14170 21 0x100003 0 7K cc1
299542 30294 21 0x100003 0 1 cc1
458544 71411 0 0x14000 0x200 3 kmthread
ffs_inode_alloc(4000bfc94a0, 81b0, 4000ccfc380, 4007af57f00,
fffffffffffffffe, 4007b497ba0) at ffs_inode_alloc+0x3b4
ufs_makeinode(81b0, 4000bf5e8d0, 4007b497ba0, 4007b497bd0, 4000cad5a80,
800) at ufs_makeinode+0x5c
ufs_create(4007b497908, 4007b497b70, 80000, 4007b497810, 2000, 8000) at
ufs_create+0x3c
VOP_CREATE(4000bf5e8d0, 4007b497ba0, 19ad988, 4007b4979f8, 4007b497918,
19ad988) at VOP_CREATE+0x44
vn_open(4007b4979f8, 602, 1b0, 0, ffffffffffffff9c, fffffffffffbe2d7) at
vn_open+0x2fc
doopenat(4007b497b70, ffffffffffffff9c, fffffffffffbe2d7, 601, 1b0,
4007b497df0) at doopenat+0x16c
syscall(4007b497ed0, 405, 2f11928a8, 2f11928ac, 0, 0) at syscall+0x388
syscall_setup(fffffffffffbe2d7, 601, 1b6, 0, 400, 200) at syscall_setup+0x134
https://www.openbsd.org/ddb.html describes the minimum info required in bug
reports. Insufficient info makes it difficult to find and fix bugs.
ddb{7}> show panic
*cpu7: ffs_valloc: dup alloc
ddb{7}> mach ddbcpu 0
Stopped at __mp_lock+0x68: ld [%o0 + 0x800], %g1
sparc_intr_retry(1c8d160, 2c8adf658, 5, 100, 1ff, 6) at sparc_intr_retry+0x5c
intr_handler(2017ec8, 4000cd04300, 100f191, 100, 1ff, 2025e4000) at
intr_handler+0x74
sparc_intr_retry(1c8d160, 4007b413b84, 4007b1a5cf0, 28a732300, 0, 6) at
sparc_intr_retry+0x5c
trapsignal(4000cae6dc0, 5, 0, 1, 266798, 1) at trapsignal+0xe8
trap(4007b1a5ed0, 101, 266798, 820012, 6c3560, 128f40) at trap+0x500
Lslowtrap_reenter(0, 0, 0, 0, 28aaba228, 13) at Lslowtrap_reenter+0xf8
ddb{0}> mach ddbcpu 1
panic: trap type 0x114 (*trap): ppc=13fb26c npc=13fb270
pstate=820006<PRIV,IE>
Stopped at __mp_lock+0x64: rd %ccr, %g0
trap(4007b2d7ed0, 101, 47499c, 44820012, 800, 1) at trap+0x500
Lslowtrap_reenter(220903b00, 2208f6100, 1bc, b, 8e4578, 127) at
Lslowtrap_reenter+0xf8
ddb{1}> mach ddbcpu 2
Stopped at db_enter+0x8: nop
trap(4007b50b9b0, 111, 13fb26c, 820006, 0, 0) at trap+0x328
Lslowtrap_reenter(1c8d160, 4007a3a3684, 4007b50bcf0, 0, 0, 6) at
Lslowtrap_reenter+0xf8
trapsignal(4000c7d9310, 5, 0, 1, 91d9e00ff8, 1) at trapsignal+0xe8
trap(4007b50bed0, 101, 91d9e00ff8, 99820002, 9115b8e000, 1) at trap+0x500
Lslowtrap_reenter(91b502d000, 0, 0, 0, 0, 0) at Lslowtrap_reenter+0xf8
ddb{2}> mach ddbcpu 3
Stopped at pool_do_put+0x130: brnz,pt %g1, hid_get_byte+0x20
pool_put(1c877b8, 4007abb6380, 4007abb6380, 0, 101323, 2000) at pool_put+0x50
uvm_unmap_detach(40079d73c78, 0, 4b2, 4007b50e000, 4007b510000, 101323) at
uvm_unmap_detach+0x80
uvm_map(1c721f0, 40079d73da8, 2000, 40079d73c78, 0, 0) at uvm_map+0x74c
uvm_km_thread(1323, 1cac028, 10028, 2000, 40079d73e10, 101323) at
uvm_km_thread+0x15c
proc_trampoline(0, 0, 0, 0, 0, 0) at proc_trampoline+0x14
ddb{3}> mach ddbcpu 4
Stopped at __mp_lock+0x70: bne,pt __mp_lock+0x5c
trap(4007b4ffed0, 101, 69f3521004, 44820002, 6a40a6e000, 1) at trap+0x500
Lslowtrap_reenter(6a40a6c000, 40, 0, 699efcbf80, 0, 0) at
Lslowtrap_reenter+0xf8
ddb{4}> mach ddbcpu 5
Stopped at db_enter+0x8: nop
trap(4007b5079b0, 114, 13fb26c, 820006, 6940fa, 2a9962510) at trap+0x328
Lslowtrap_reenter(1c8d160, 4007b412e04, 4007b507cf0, 65cd60, 2a9955600, 6)
at Lslowtrap_reenter+0xf8
trapsignal(4007b4bc930, 5, 0, 1, 29bcee160, 911188) at trapsignal+0xe8
trap(4007b507ed0, 101, 29bcee160, 820012, 55, 238) at trap+0x500
Lslowtrap_reenter(2a9996540, 2ee4bf515, 1605f0, 2a9994d88, 29c02e228, 7) at
Lslowtrap_reenter+0xf8
ddb{5}> mach ddbcpu 6
Stopped at __mp_lock+0x6c: subcc %g3, %g1, %g0
syscall(4007b49bed0, 56, e147401730, e147401734, 0, 0) at syscall+0x45c
syscall_setup(ffffffffffff4058, 2c, a3be282bfb2be9a, df33810c60,
ffffffffffff40a4, ffffffffffff3f30) at syscall_setup+0x134
ddb{6}> mach ddbcpu 7
Stopped at __mp_lock+0x5c: rd %ccr, %g0
hardclock(401a9f97ec8, 56913eac8b7f, 8, 1535b0e, 1, 1013120) at hardclock+0x178
sys_tickintr(401a9f97ec8, 568cd0883fff, 8, 4007b496d40, 0, 1cc6688) at
sys_tickintr+0x4c
intr_handler(401a9f97ec8, 401a9f987e8, 127458f, 0, 1535b28, 4007b496e98) at
intr_handler+0x50
sparc_intr_retry(1c19f50, 81b0, 6be1c, 4000cf770d4, 100, 401a9f98964) at
sparc_intr_retry+0x5c
db_enter_ddb(1cc5000, 1cc5958, 130, 4000d0a18c0, 0, 5) at db_enter_ddb+0xbc
db_ktrap(101, 4007b497200, 1, 0, 4007b497490, 0) at db_ktrap+0x104
trap(4007b497200, 101, 1535b24, 820006, 0, 73) at trap+0x2cc
Lslowtrap_reenter(1d, 401a9f98964, 1942eb0, 4007b497558, 0, 0) at
Lslowtrap_reenter+0xf8
panic(1942eb0, 81b0, 6be1c, 4000cf770d4, 100, 401a9f98964) at panic+0xcc
ffs_inode_alloc(4000bfc94a0, 81b0, 4000ccfc380, 4007af57f00,
fffffffffffffffe, 4007b497ba0) at ffs_inode_alloc+0x3b4
ufs_makeinode(81b0, 4000bf5e8d0, 4007b497ba0, 4007b497bd0, 4000cad5a80,
800) at ufs_makeinode+0x5c
ufs_create(4007b497908, 4007b497b70, 80000, 4007b497810, 2000, 8000) at
ufs_create+0x3c
VOP_CREATE(4000bf5e8d0, 4007b497ba0, 19ad988, 4007b4979f8, 4007b497918,
19ad988) at VOP_CREATE+0x44
vn_open(4007b4979f8, 602, 1b0, 0, ffffffffffffff9c, fffffffffffbe2d7) at
vn_open+0x2fc
ddb{7}> ps
PID TID PPID UID S FLAGS WAIT COMMAND
83767 463321 62684 21 7 0x100003 as
92219 92098 62684 21 7 0x100003 cc1
62684 80548 3524 21 3 0x100083 wait cc
3524 19743 38965 21 3 0x10008b sigsusp sh
85141 258938 63414 21 7 0x100003 as
63414 15986 67106 21 3 0x100083 wait cc
67106 202184 38965 21 3 0x10008b sigsusp sh
16815 444267 67572 21 3 0x100083 piperd as
27447 478487 67572 21 2 0x100003 cc1
67572 505126 27486 21 3 0x100083 wait cc
27486 265628 38965 21 3 0x10008b sigsusp sh
64353 351005 40309 21 3 0x100083 piperd as
22643 422498 40309 21 7 0x100003 cc1
40309 33368 11270 21 3 0x100083 wait cc
11270 34385 38965 21 3 0x10008b sigsusp sh
67024 165247 39340 21 7 0x100003 as
*14170 211105 39340 21 7 0x100003 cc1
39340 281959 50917 21 3 0x100083 wait cc
50917 388318 38965 21 3 0x10008b sigsusp sh
40245 172617 48202 21 3 0x100083 piperd as
38977 165274 48202 21 2 0x100003 cc1
94327 210308 98352 21 3 0x100083 piperd as
1479 481832 98352 21 2 0x100003 cc1
23383 18920 13330 21 3 0x100083 piperd as
30294 299542 13330 21 7 0x100003 cc1
98352 82959 2733 21 3 0x100083 wait cc
48202 224810 25982 21 3 0x100083 wait cc
25982 142858 38965 21 3 0x10008b sigsusp sh
13330 402593 15882 21 3 0x100083 wait cc
2733 246850 38965 21 3 0x10008b sigsusp sh
15882 522787 38965 21 3 0x10008b sigsusp sh
38965 69758 70115 21 3 0x10008b sigsusp make
70115 249017 60027 21 3 0x10008b sigsusp sh
60027 49938 1756 21 3 0x10008b sigsusp make
1756 252280 31031 21 3 0x10008b sigsusp sh
31031 355014 18571 21 3 0x10008b sigsusp make
18571 221300 29879 21 3 0x10008b sigsusp sh
29879 345816 23003 21 3 0x10008b sigsusp make
23003 369331 18071 0 3 0x10008b sigsusp sh
18071 282085 67412 0 3 0x10008b sigsusp make
67412 257027 684 0 3 0x10008b sigsusp make
76037 152213 85764 0 3 0x100083 kqread tmux
684 166722 9801 0 3 0x10008b sigsusp ksh
9801 518136 1 0 3 0x100080 kqread tmux
85764 212337 6264 1000 3 0x10008b sigsusp ksh
6264 521919 9782 1000 3 0x98 kqread sshd
9782 401204 34215 0 3 0x92 kqread sshd
1125 189667 1 0 3 0x100083 ttyin getty
59091 128632 1 0 3 0x100098 kqread cron
10946 34940 1 99 3 0x1100090 kqread sndiod
3782 509000 1 110 3 0x100090 kqread sndiod
98853 203490 79443 95 3 0x1100092 kqread smtpd
86454 258307 79443 103 3 0x1100092 kqread smtpd
7208 427701 79443 95 3 0x1100092 kqread smtpd
69129 223824 79443 95 3 0x100092 kqread smtpd
25705 7076 79443 95 3 0x1100092 kqread smtpd
93748 408551 79443 95 3 0x1100092 kqread smtpd
79443 286221 1 0 3 0x100080 kqread smtpd
34215 198919 1 0 3 0x88 kqread sshd
41743 189446 1 0 3 0x100080 kqread ntpd
62525 285868 74807 83 3 0x100092 kqread ntpd
74807 416834 1 83 3 0x1100092 kqread ntpd
77998 240596 94598 74 3 0x1100092 bpf pflogd
94598 181384 1 0 3 0x80 netio pflogd
50691 127913 29981 73 3 0x1100090 kqread syslogd
29981 52123 1 0 3 0x100082 netio syslogd
30587 376350 1 0 3 0x100080 kqread resolvd
2175 74624 20751 77 3 0x100092 kqread dhcpleased
96355 422850 20751 77 3 0x100092 kqread dhcpleased
20751 412539 1 0 3 0x80 kqread dhcpleased
41298 206843 33283 115 3 0x100092 kqread slaacd
18423 104963 33283 115 3 0x100092 kqread slaacd
33283 275308 1 0 3 0x100080 kqread slaacd
37117 345771 0 0 3 0x14200 bored smr
23538 367353 0 0 2 0x14200 zerothread
3609 157834 0 0 3 0x14200 aiodoned aiodoned
20785 261230 0 0 3 0x14200 syncer update
4946 49536 0 0 3 0x14200 cleaner cleaner
38408 104283 0 0 3 0x14200 reaper reaper
2842 210797 0 0 3 0x14200 pgdaemon pagedaemon
15256 339019 0 0 3 0x40014200 idle7
53867 122048 0 0 3 0x40014200 idle6
31194 389962 0 0 3 0x40014200 idle5
9033 47302 0 0 3 0x40014200 idle4
12466 415341 0 0 3 0x40014200 idle3
23747 128832 0 0 3 0x40014200 idle2
15147 420967 0 0 3 0x40014200 idle1
73827 207892 0 0 3 0x14200 bored softnet
2483 129409 0 0 3 0x14200 bored softnet
11337 486019 0 0 2 0x14200 softnet
73956 156521 0 0 3 0x14200 bored softnet
72802 196484 0 0 3 0x14200 bored systqmp
46995 430726 0 0 3 0x14200 bored systq
55376 195873 0 0 3 0x40014200 bored softclock
79331 260499 0 0 3 0x40014200 idle0
71411 458544 0 0 7 0x14200 kmthread
1 9429 0 0 3 0x82 wait init
0 0 -1 0 3 0x10200 scheduler swapper
ddb{7}> show uvm
Current UVM status:
pagesize=8192 (0x2000), pagemask=0x1fff, pageshift=13
1026492 VM pages: 23460 active, 32040 inactive, 1 wired, 748218 free (88328
zero)
min 10% (25) anon, 10% (25) vnode, 5% (12) vtext
freemin=34216, free-target=45621, inactive-target=0, wired-max=342164
faults=47088255, traps=49184167, intrs=19378453, ctxswitch=3238840
fpuswitch=71355
softint=568357, syscalls=29389526, kmapent=13
fault counts:
noram=0, noanon=0, noamap=0, pgwait=0, pgrele=0
ok relocks(total)=48046(48046), anget(retries)=15561668(0), amapcopy=6079778
neighbor anon/obj pg=2571090/15718620, gets(lock/unlock)=10287227/48592
cases: anon=14287548, anoncow=1274120, obj=9160784, prcopy=1125897,
przero=21239906
daemon and swap counts:
woke=0, revs=0, scans=0, obscans=0, anscans=0
busy=0, freed=0, reactivate=0, deactivate=0
pageouts=0, pending=0, nswget=0
nswapdev=1
swpages=263063, swpginuse=0, swpgonly=0 paging=0
kernel pointers:
objs(kern)=0x1c719a0
ddb{7}> show bcstats
Current Buffer Cache status:
numbufs 102637 busymapped 3, delwri 139
kvaslots 25662 avail kva slots 25659
bufpages 205264, dmapages 205264, dirtypages 278
pendingreads 0, pendingwrites 1
highflips 0, highflops 0, dmaflips 0
objdump and crash line information:
/sys/ufs/ffs/ffs_alloc.c:405
30a8: 11 00 00 00 sethi %hi(0), %o0
30a8: R_SPARC_H44 .rodata.str1.8+0x2d0
30ac: 90 12 20 00 mov %o0, %o0 ! 0 <ffs_hashalloc>
30ac: R_SPARC_M44 .rodata.str1.8+0x2d0
30b0: 91 2a 30 0c sllx %o0, 0xc, %o0
30b4: 40 00 00 00 call 30b4 <ffs_inode_alloc+0x3b4>
30b4: R_SPARC_WDISP30 panic
30b8: 90 12 20 00 mov %o0, %o0
30b8: R_SPARC_L44 .rodata.str1.8+0x2d0
30bc: 01 00 00 00 nop
Which resolves to this source line:
405 panic("ffs_valloc: dup alloc");
Or, with the surrounding if clause:
402 if (DIP(ip, mode)) {
403 printf("mode = 0%o, inum = %u, fs = %s\n",
404 DIP(ip, mode), ip->i_number, fs->fs_fsmnt);
405 panic("ffs_valloc: dup alloc");
406 }
