On Tue, May 17, 2022 at 05:43:02PM +0200, Martin Pieuchot wrote:
> Andrew, Alexander, could you test this and report back?
Panic "vref used where vget required" is still there. As usual it
needs a day to reproduce. This time I was running without the vref
history diff.
bluhm
> Index: kern/vfs_subr.c
> ===================================================================
> RCS file: /cvs/src/sys/kern/vfs_subr.c,v
> retrieving revision 1.315
> diff -u -p -r1.315 vfs_subr.c
> --- kern/vfs_subr.c 27 Mar 2022 16:19:39 -0000 1.315
> +++ kern/vfs_subr.c 17 May 2022 15:28:30 -0000
> @@ -459,6 +459,10 @@ getnewvnode(enum vtagtype tag, struct mo
> vp->v_flag = 0;
> vp->v_socket = NULL;
> }
> + /*
> + * Clean out any VM data associated with the vnode.
> + */
> + uvm_vnp_terminate(vp);
> cache_purge(vp);
> vp->v_type = VNON;
> vp->v_tag = tag;
[-- MARK -- Wed May 18 23:45:00 2022]
panic: vref used where vget required
Stopped at db_enter+0x24: lwz r11,12(r1)
TID PID UID PRFLAGS PFLAGS CPU COMMAND
264957 33761 21 0x2 0 0 c++
*197367 60221 0 0x14000 0x200 1K pagedaemon
db_enter() at db_enter+0x20
panic(92218b) at panic+0x158
vref(1e791340) at vref+0xac
uvm_vnp_uncache(e7ec3c50) at uvm_vnp_uncache+0x88
ffs_write(a8b89d11) at ffs_write+0x3b0
VOP_WRITE(1e791340,e7ec3c50,40,1ff3f00) at VOP_WRITE+0x48
uvn_io(a8b89d11,b12744,aa4808,ffffffff,e4010000) at uvn_io+0x264
uvn_put(5c9adf98,e7ec3dd4,1f0b8498,4ef8cb0) at uvn_put+0x64
uvm_pager_put(0,0,e7ec3d70,6810fc,2000000,80000000,0) at uvm_pager_put+0x15c
uvmpd_scan_inactive(0) at uvmpd_scan_inactive+0x224
uvmpd_scan() at uvmpd_scan+0x134
uvm_pageout(a8a37d41) at uvm_pageout+0x398
fork_trampoline() at fork_trampoline+0x14
end trace frame: 0x0, count: 2
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{1}> x/s version
version: OpenBSD 7.1-current (GENERIC.MP) #0: Tue May 17 22:51:12 CEST
2022\012
[email protected]:/usr/src/sys/arch/macppc/compile/GENERIC.MP\012
ddb{1}> show panic
*cpu1: vref used where vget required
ddb{1}> trace
db_enter() at db_enter+0x20
panic(92218b) at panic+0x158
vref(1e791340) at vref+0xac
uvm_vnp_uncache(e7ec3c50) at uvm_vnp_uncache+0x88
ffs_write(a8b89d11) at ffs_write+0x3b0
VOP_WRITE(1e791340,e7ec3c50,40,1ff3f00) at VOP_WRITE+0x48
uvn_io(a8b89d11,b12744,aa4808,ffffffff,e4010000) at uvn_io+0x264
uvn_put(5c9adf98,e7ec3dd4,1f0b8498,4ef8cb0) at uvn_put+0x64
uvm_pager_put(0,0,e7ec3d70,6810fc,2000000,80000000,0) at uvm_pager_put+0x15c
uvmpd_scan_inactive(0) at uvmpd_scan_inactive+0x224
uvmpd_scan() at uvmpd_scan+0x134
uvm_pageout(a8a37d41) at uvm_pageout+0x398
fork_trampoline() at fork_trampoline+0x14
end trace frame: 0x0, count: -13
ddb{1}> ps
PID TID PPID UID S FLAGS WAIT COMMAND
33761 264957 92741 21 7 0x2 c++
92741 312390 20513 21 3 0x10008a sigsusp sh
73333 85241 73592 21 2 0x2 c++
73592 395247 20513 21 3 0x10008a sigsusp sh
20513 387613 86722 21 3 0x10008a sigsusp make
86722 351373 19613 21 3 0x10008a sigsusp sh
19613 73018 69411 21 3 0x10008a sigsusp make
69411 381457 9957 21 3 0x10008a sigsusp sh
9957 35595 9308 21 3 0x10008a sigsusp make
9308 439208 50196 21 3 0x10008a sigsusp sh
50196 261987 21533 21 3 0x10008a sigsusp make
21533 134353 96184 21 3 0x10008a sigsusp sh
96184 127071 50665 21 3 0x10008a sigsusp make
50665 140826 82928 0 3 0x10008a sigsusp sh
82928 416743 39291 0 3 0x10008a sigsusp make
39291 450619 53019 0 3 0x10008a sigsusp make
53019 342216 5152 0 3 0x10008a sigsusp sh
5152 246225 75604 0 3 0x82 piperd perl
75604 321372 45770 0 3 0x10008a sigsusp ksh
45770 382402 53145 0 3 0x9a kqread sshd
19061 218044 1 0 3 0x100083 ttyin getty
77831 153734 1 0 3 0x100098 kqread cron
97917 207119 1 99 3 0x1100090 kqread sndiod
72318 229709 1 110 3 0x100090 kqread sndiod
99951 369454 60369 95 3 0x1100092 kqread smtpd
26631 442966 60369 103 3 0x1100092 kqread smtpd
29720 146017 60369 95 3 0x1100092 kqread smtpd
80957 314403 60369 95 3 0x100092 kqread smtpd
17022 361258 60369 95 3 0x1100092 kqread smtpd
7863 144172 60369 95 3 0x1100092 kqread smtpd
60369 51354 1 0 3 0x100080 kqread smtpd
28817 507320 1 0 3 0x100080 kqread snmpd
43747 396650 1 91 3 0x1000092 kqread snmpd
53145 60783 1 0 3 0x88 kqread sshd
68412 472833 0 0 3 0x14280 nfsidl nfsio
38965 50271 0 0 3 0x14280 nfsidl nfsio
63738 286868 0 0 3 0x14280 nfsidl nfsio
57519 133042 0 0 3 0x14280 nfsidl nfsio
75921 457932 1 0 3 0x100080 kqread ntpd
94001 320083 65951 83 3 0x100092 kqread ntpd
65951 487689 1 83 3 0x1100092 kqread ntpd
37425 490478 26923 74 3 0x1100092 bpf pflogd
26923 235516 1 0 3 0x80 netio pflogd
55101 407770 61472 73 3 0x1100090 kqread syslogd
61472 292170 1 0 3 0x100082 netio syslogd
98311 238756 1 0 3 0x100080 kqread resolvd
7735 159260 57978 77 3 0x100092 kqread dhcpleased
17714 1751 57978 77 3 0x100092 kqread dhcpleased
57978 519533 1 0 3 0x80 kqread dhcpleased
99605 489792 3147 115 3 0x100092 kqread slaacd
10939 121843 3147 115 3 0x100092 kqread slaacd
3147 261058 1 0 3 0x100080 kqread slaacd
23888 396060 0 0 3 0x14200 bored smr
69606 115821 0 0 3 0x40014200 idle1
90464 139264 0 0 2 0x14200 zerothread
11121 448555 0 0 3 0x14200 aiodoned aiodoned
19920 96295 0 0 3 0x14200 syncer update
16441 280085 0 0 3 0x14200 cleaner cleaner
68652 229682 0 0 3 0x14200 reaper reaper
*60221 197367 0 0 7 0x14200 pagedaemon
86451 457812 0 0 3 0x14200 usbtsk usbtask
20625 28313 0 0 3 0x14200 usbatsk usbatsk
23646 191020 0 0 3 0x14200 bored sensors
86355 202514 0 0 3 0x14200 bored softnet
65234 330900 0 0 3 0x14200 bored softnet
79127 169718 0 0 3 0x14200 bored softnet
61708 142055 0 0 3 0x14200 bored softnet
32773 70258 0 0 3 0x14200 bored systqmp
78908 287427 0 0 3 0x14200 bored systq
25355 302421 0 0 3 0x40014200 bored softclock
92573 461669 0 0 3 0x40014200 idle0
1 491684 0 0 3 0x82 wait init
0 0 -1 0 3 0x10200 scheduler swapper
ddb{1}> show uvm
Current UVM status:
pagesize=4096 (0x1000), pagemask=0xfff, pageshift=12
500881 VM pages: 167566 active, 181225 inactive, 1 wired, 50564 free (0 zero)
min 10% (25) anon, 10% (25) vnode, 5% (12) vtext
freemin=16696, free-target=22261, inactive-target=127400, wired-max=166960
faults=967713937, traps=0, intrs=1133287, ctxswitch=15084923 fpuswitch=3237978
softint=7838795, syscalls=1386451424, kmapent=10
fault counts:
noram=0, noanon=0, noamap=0, pgwait=0, pgrele=0
ok relocks(total)=628920(631617), anget(retries)=781661344(0),
amapcopy=60228565
neighbor anon/obj pg=68630878/137950795, gets(lock/unlock)=47508098/632729
cases: anon=779873451, anoncow=1787893, obj=42277567, prcopy=5226722,
przero=138548304
daemon and swap counts:
woke=7, revs=1, scans=33771, obscans=33508, anscans=0
busy=0, freed=33507, reactivate=263, deactivate=0
pageouts=1, pending=0, nswget=0
nswapdev=1
swpages=589823, swpginuse=0, swpgonly=0 paging=0
kernel pointers:
objs(kern)=0xab2090
ddb{1}> show register
r0 0x60f000 panic+0x15c
r1 0xe7ec3ae0
r2 0
r3 0xaad000 cpu_info+0x4c0
r4 0xaa0000 rnd_event_space+0x7c
r5 0x1
r6 0
r7 0xe7bb9000
r8 0
r9 0
r10 0x1b4fe6fe
r11 0x7f76d894
r12 0x69454aa _end+0x5e2d822
r13 0
r14 0
r15 0xe0415000
r16 0xffffffee
r17 0x243000 vfs_syncwait+0xb0
r18 0
r19 0x1000 tlbdsmsize+0xf18
r20 0
r21 0xe7ec3bb0
r22 0x1
r23 0x3000 tlbdsmsize+0x2f18
r24 0xe
r25 0x90 alisize+0x44
r26 0x1e791340
r27 0
r28 0
r29 0xaad2c0 cpu_info+0x780
r30 0x92218b pppdumpb.digits+0x2c0f
r31 0x12
lr 0x4121f8 db_enter+0x24
cr 0x48844022
xer 0x20000000
ctr 0x437b98 openpic_splx
iar 0x4121f8 db_enter+0x24
msr 0x9032 tlbdsmsize+0x8f4a
dar 0
dsisr 0
db_enter+0x24: lwz r11,12(r1)
