On Wed, Apr 27, 2022 at 09:16:48AM +0200, Sebastien Marie wrote:
> Here a new diff (sorry for the delay) which add a new vnode_history_record()
> point inside uvn_detach() (when 'uvn' object has UVM_VNODE_CANPERSIST flag
> sets).
[-- MARK -- Thu Apr 28 14:10:00 2022]
uvn_io: start: 0x23ae1400, type VREG, use 0, write 0, hold 0, flags
(VBIOONFREELIST)
tag VT_UFS, ino 495247, on dev 0, 10 flags 0x100, effnlink 1, nlink 1
mode 0100660, owner 21, group 21, size 13647873
==> vnode_history_print 0x23ae1400, next=6
[3] c++[44194] usecount 2>1
#0 0x626946ec
[4] reaper[10898] usecount 1>1
#0 entropy_pool0+0xf54
[5] reaper[10898] usecount 1>0
#0 splx+0x30
#1 0xfffffffc
#2 vrele+0x5c
#3 uvn_detach+0x160
#4 uvm_unmap_detach+0x1a4
#5 uvm_map_teardown+0x184
#6 uvmspace_free+0x60
#7 uvm_exit+0x30
#8 reaper+0x138
#9 fork_trampoline+0x14
vn_lock: v_usecount == 0: 0x23ae1400, type VREG, use 0, write 0, hold 0, flags
(VBIOONFREELIST)
tag VT_UFS, ino 495247, on dev 0, 10 flags 0x100, effnlink 1, nlink 1
mode 0100660, owner 21, group 21, size 13647873
==> vnode_history_print 0x23ae1400, next=6
[3] c++[44194] usecount 2>1
#0 0x626946ec
[4] reaper[10898] usecount 1>1
#0 entropy_pool0+0xf54
[5] reaper[10898] usecount 1>0
#0 splx+0x30
#1 0xfffffffc
#2 vrele+0x5c
#3 uvn_detach+0x160
#4 uvm_unmap_detach+0x1a4
#5 uvm_map_teardown+0x184
#6 uvmspace_free+0x60
#7 uvm_exit+0x30
#8 reaper+0x138
#9 fork_trampoline+0x14
panic: vn_lock: v_usecount == 0
Stopped at db_enter+0x24: lwz r11,12(r1)
TID PID UID PRFLAGS PFLAGS CPU COMMAND
*259468 43813 0 0x14000 0x200 0K pagedaemon
146649 72608 0 0x14000 0x200 1 systq
db_enter() at db_enter+0x20
panic(9466c5) at panic+0x158
vn_lock(49535400,b0000) at vn_lock+0x1c4
uvn_io(accff0,af022c,e7ebbc50,7c22f4,e4010000) at uvn_io+0x254
uvn_put(bab343e0,e7ebbdd4,23a0f150,408ef30) at uvn_put+0x64
uvm_pager_put(0,0,e7ebbd70,38ec28,2000000,80000000,0) at uvm_pager_put+0x15c
uvmpd_scan_inactive(0) at uvmpd_scan_inactive+0x224
uvmpd_scan() at uvmpd_scan+0x158
uvm_pageout(468f7e26) at uvm_pageout+0x398
fork_trampoline() at fork_trampoline+0x14
end trace frame: 0x0, count: 5
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{0}> x/s version
version: OpenBSD 7.1-current (GENERIC.MP) #0: Wed Apr 27 12:15:54 CEST
2022\012
[email protected]:/usr/src/sys/arch/macppc/compile/GENERIC.MP\012
ddb{0}> show panic
*cpu0: vn_lock: v_usecount == 0
ddb{0}> trace
db_enter() at db_enter+0x20
panic(9466c5) at panic+0x158
vn_lock(49535400,b0000) at vn_lock+0x1c4
uvn_io(accff0,af022c,e7ebbc50,7c22f4,e4010000) at uvn_io+0x254
uvn_put(bab343e0,e7ebbdd4,23a0f150,408ef30) at uvn_put+0x64
uvm_pager_put(0,0,e7ebbd70,38ec28,2000000,80000000,0) at uvm_pager_put+0x15c
uvmpd_scan_inactive(0) at uvmpd_scan_inactive+0x224
uvmpd_scan() at uvmpd_scan+0x158
uvm_pageout(468f7e26) at uvm_pageout+0x398
fork_trampoline() at fork_trampoline+0x14
end trace frame: 0x0, count: -10
ddb{0}> show register
r0 0x456398 panic+0x15c
r1 0xe7ebbb60
r2 0
r3 0xaddd20 cpu_info
r4 0xa90000 cac_weights_oland+0x4a0
r5 0x1
r6 0
r7 0xe7bb9000
r8 0
r9 0x91c6bb pppdumpb.digits
r10 0x14
r11 0xad435544
r12 0x40f2b95b
r13 0
r14 0xaeccf0 bcstats
r15 0xb0e060 uvmexp
r16 0
r17 0
r18 0
r19 0xb0000 tlbdsmsize+0xaff18
r20 0x1000 tlbdsmsize+0xf18
r21 0x1000 tlbdsmsize+0xf18
r22 0xa84c34 netlock
r23 0xe4010000
r24 0x23a0f168
r25 0x23a0f16c
r26 0x927da8 pppdumpb.digits+0xb6ed
r27 0
r28 0
r29 0xaddfe0 cpu_info+0x2c0
r30 0x9466c5 cy_pio_rec+0x11ddb
r31 0xb0e18c uvmexp+0x12c
lr 0x7600f4 db_enter+0x24
cr 0x48228204
xer 0x20000000
ctr 0x619c94 openpic_splx
iar 0x7600f4 db_enter+0x24
msr 0x9032 tlbdsmsize+0x8f4a
dar 0
dsisr 0
db_enter+0x24: lwz r11,12(r1)
ddb{0}> ps
PID TID PPID UID S FLAGS WAIT COMMAND
58038 126472 17568 21 2 0x2 c++
17568 326369 64325 21 3 0x10008a sigsusp sh
95069 60222 81300 21 2 0x2 c++
81300 287425 64325 21 3 0x10008a sigsusp sh
64325 247079 67416 21 3 0x10008a sigsusp make
67416 6273 21897 21 3 0x10008a sigsusp sh
21897 133219 63094 21 3 0x10008a sigsusp make
63094 445339 47647 21 3 0x10008a sigsusp sh
47647 139403 22159 21 3 0x10008a sigsusp make
22159 248738 24095 21 3 0x10008a sigsusp sh
24095 477366 14646 21 3 0x10008a sigsusp make
14646 111329 55744 21 3 0x10008a sigsusp sh
55744 368522 3397 21 3 0x10008a sigsusp make
3397 349572 99598 0 3 0x10008a sigsusp sh
99598 510186 86505 0 3 0x10008a sigsusp make
86505 213806 29713 0 3 0x10008a sigsusp make
29713 76615 11666 0 3 0x10008a sigsusp sh
11666 158413 30424 0 3 0x82 piperd perl
30424 233250 56724 0 3 0x10008a sigsusp ksh
56724 160537 53570 0 3 0x9a kqread sshd
43167 359893 1 0 3 0x100083 ttyin getty
51231 209123 1 0 3 0x100098 kqread cron
87445 494154 1 99 3 0x1100090 kqread sndiod
89492 391745 1 110 3 0x100090 kqread sndiod
21093 368083 75019 95 3 0x1100092 kqread smtpd
40296 398818 75019 103 3 0x1100092 kqread smtpd
82127 519318 75019 95 3 0x1100092 kqread smtpd
74259 357906 75019 95 3 0x100092 kqread smtpd
97590 312389 75019 95 3 0x1100092 kqread smtpd
92988 113001 75019 95 3 0x1100092 kqread smtpd
75019 80125 1 0 3 0x100080 kqread smtpd
37946 138518 1 0 3 0x100080 kqread snmpd
71898 8160 1 91 3 0x1000092 kqread snmpd
53570 142931 1 0 3 0x88 kqread sshd
13547 352036 0 0 3 0x14280 nfsidl nfsio
93359 256712 0 0 3 0x14280 nfsidl nfsio
99320 244583 0 0 3 0x14280 nfsidl nfsio
99404 470578 0 0 3 0x14280 nfsidl nfsio
94723 402108 1 0 3 0x100080 kqread ntpd
87109 202362 18301 83 3 0x100092 kqread ntpd
18301 178821 1 83 3 0x1100092 kqread ntpd
25826 90316 88878 74 3 0x1100092 bpf pflogd
88878 169873 1 0 3 0x80 netio pflogd
67646 415264 29673 73 3 0x1100090 kqread syslogd
29673 131302 1 0 3 0x100082 netio syslogd
43975 246540 1 0 3 0x100080 kqread resolvd
60928 460407 76093 77 3 0x100092 kqread dhcpleased
32901 208280 76093 77 3 0x100092 kqread dhcpleased
76093 141437 1 0 3 0x80 kqread dhcpleased
3303 506731 83319 115 3 0x100092 kqread slaacd
60565 119229 83319 115 3 0x100092 kqread slaacd
83319 126543 1 0 3 0x100080 kqread slaacd
47737 152547 0 0 3 0x14200 bored smr
50370 511329 0 0 3 0x40014200 idle1
69972 513033 0 0 2 0x14200 zerothread
39569 93722 0 0 3 0x14200 aiodoned aiodoned
40874 17307 0 0 3 0x14200 syncer update
37441 523480 0 0 3 0x14200 cleaner cleaner
10898 320555 0 0 3 0x14200 reaper reaper
*43813 259468 0 0 7 0x14200 pagedaemon
71868 345423 0 0 3 0x14200 usbtsk usbtask
61581 429532 0 0 3 0x14200 usbatsk usbatsk
69683 484078 0 0 3 0x14200 bored sensors
94439 356344 0 0 2 0x14200 softnet
46479 452477 0 0 3 0x14200 bored systqmp
72608 146649 0 0 7 0x14200 systq
85677 99390 0 0 3 0x40014200 bored softclock
65104 388708 0 0 3 0x40014200 idle0
1 106514 0 0 3 0x82 wait init
0 0 -1 0 3 0x10200 scheduler swapper
ddb{0}> show uvm
Current UVM status:
pagesize=4096 (0x1000), pagemask=0xfff, pageshift=12
500885 VM pages: 178426 active, 175323 inactive, 1 wired, 38117 free (0 zero)
min 10% (25) anon, 10% (25) vnode, 5% (12) vtext
freemin=16696, free-target=22261, inactive-target=125047, wired-max=166961
faults=969500145, traps=0, intrs=1175044, ctxswitch=14677435 fpuswitch=3183257
softint=8147873, syscalls=1385962033, kmapent=10
fault counts:
noram=0, noanon=0, noamap=0, pgwait=0, pgrele=0
ok relocks(total)=631514(634290), anget(retries)=781457689(0),
amapcopy=60280584
neighbor anon/obj pg=68714025/140990784, gets(lock/unlock)=49417680/635237
cases: anon=779698748, anoncow=1758941, obj=42721120, prcopy=6692837,
przero=138628499
daemon and swap counts:
woke=4, revs=1, scans=21657, obscans=21405, anscans=0
busy=0, freed=21404, reactivate=252, deactivate=0
pageouts=1, pending=0, nswget=0
nswapdev=1
swpages=589823, swpginuse=0, swpgonly=0 paging=0
kernel pointers:
objs(kern)=0xaa30c8
