On Wed, Apr 13, 2022 at 02:16:51PM +0200, Sebastien Marie wrote:
Andrew,
Here a new diff which will record a bit more information.
It keep track of the last 10 v_usecount changes with:
- pid and ps_comm
- usecount value (before and after)
- stacktrace
We will need:
- the vnode_history (without offsets)
- the panic and the backtrace of it
Thank you. Built a kernel with your new diff, reproduced the panic,
here are the results:
uvn_io: start: 0xfffffd831161b918, type VREG, use 0, write 0, hold 0, flags
(VXLOCK)
tag VT_UFS, ino 14694933, on dev 4, 30 flags 0x100, effnlinks 1, nlink 1
mode 0100644, owner 858, group 1000, size 284752156
==> vnode_history_print 0xfffffd831161b918, next=7
[0] qbittorrent-nox[63709] usecount 1>2
#0 uvn_attach
#1 uvn_mmapfile
#2 sys_mmap
#3 syscall
#4 Xsyscall
[1] qbittorrent-nox[63709] usecount 2>1
#0 vput
#1 vn_closefiles
#2 fdrop
#3 closef
#4 fdfree
#5 exit1
#6 single_thread_check_locked
#7 userret
#8 syscall
#9 Xsyscall
[2] reaper[82712] usecount 1>0
#0 vrele
#1 uvm_unmap_detach
#2 uvm_map_teardown
#3 uvmspace_free
#4 reaper
#5 proc_trampoline
[3] qbittorrent-nox[59800] usecount 0>1
#0 vget
#1 ufs_ihashget
#2 ffs_vget
#3 ufs_lookup
#4 VOP_LOOKUP
#5 vfs_lookup
#6 namei
#7 dofstatat
#8 syscall
#9 Xsyscall
[4] qbittorrent-nox[59800] usecount 1>0
#0 vput
#1 dofstatat
#2 syscall
#3 Xsyscall
[5] qbittorrent-nox[59800] usecount 0>1
#0 vget
#1 ufs_ihashget
#2 ffs_vget
#3 ufs_lookup
#4 VOP_LOOKUP
#5 vfs_lookup
#6 namei
#7 dofstatat
#8 syscall
#9 Xsyscall
[6] qbittorrent-nox[59800] usecount 1>0
#0 vput
#1 dofstatat
#2 syscall
#3 Xsyscall
uvn_io: start: 0xfffffd8388982e90, type VREG, use 0, write 0, hold 0, flags
(VBIOONFREELIST)
tag VT_UFS, ino 14695187, on dev 4, 30 flags 0x100, effnlinks 1, nlink 1
mode 0100644, owner 858, group 1000, size 5026060
==> vnode_history_print 0xfffffd8388982e90, next=7
[0] qbittorrent-nox[59800] usecount 1>2
#0 uvn_attach
#1 uvm_mmapfile
#2 sys_mmap
#3 syscall
#4 Xsyscall
[1] qbittorrent-nox[59800] usecount 2>1
#0 vput
#1 vn_closefile
#2 fdrop
#3 closef
#4 fdfree
#5 exit1
#6 single_thread_check_locked
#7 userret
#8 intr_user_exit
[2] reaper[82712] usecount 1>0
#0 vrele
#1 uvm_unmap
#2 uvm_map_teardown
#3 uvmspace_free
#4 reaper
#5 proc_trampoline
[3] qbittorrent-nox[49910] usecount 0>1
#0 vget
#1 cache_lookup
#2 ufs_lookup
#3 VOP_LOOKUP
#4 vfs_lookup
#5 namei
#6 dofstatat
#7 syscall
#8 Xsyscall
[4] qbittorrent-nox[49910] usecount 1>0
#0 vput
#1 dofstatat
#2 syscall
#3 Xsyscall
[5] qbittorrent-nox[49910] usecount 0>1
#0 vget
#1 ufs_ihashget
#2 ffs_vget
#3 ufs_lookup
#4 VOP_LOOKUP
#5 vfs_lookup
#6 namei
#7 dofstatat
#8 syscall
#9 Xsyscall
[6] qbittorrent-nox[49910] usecount 1>0
#0 vput
#1 dofstatat
#2 syscall
#3 Xsyscall
vn_lock: v_usecount == 0: 0xfffffd8388982e90, type VREG, use 0, write 0, hold
0, flags (VBIOONFREELIST)
tag VT_UFS, ino 14695187, on dev 4, 30 flags 0x100, effnlink 1, nlink 1
mode 0100644, owner 858, group 1000, size 5026060
==> vnode_history_print 0xfffffd8388982e90, next=7
[0] qbittorrent-nox[59800] usecount 1>2
#0 uvn_attach
#1 uvm_mmapfile
#2 sys_mmap
#3 syscall
#4 Xsyscall
[1] qbittorrent-nox[59800] usecount 2>1
#0 vput
#1 vn_closefile
#2 fdrop
#3 closef
#4 fdfree
#5 exit1
#6 single_thread_check_locked
#7 userret
#8 intr_user_exit
[2] reaper[82712] usecount 1>0
#0 vrele
#1 uvm_unmap_detach
#2 uvm_map_teardown
#3 uvmspace_free
#4 reaper
#5 proc_trampoline
[3] qbittorrent-nox[49910] usecount 0>1
#0 vget
#1 cache_lookup
#2 ufs_lookup
#3 VOP_LOOKUP
#4 vfs_lookup
#5 namei
#6 dofstatat
#7 syscall
#8 Xsyscall
[4] qbittorrent-nox[49910] usecount 1>0
#0 vput
#1 dofstatat
#2 syscall
#3 Xsyscall
[5] qbittorrent-nox[49910] usecount 0>1
#0 vget
#1 ufs_ihashget
#2 ffs_vget
#3 ufs_lookup
#4 VOP_LOOKUP
#5 vfs_lookup
#6 namei
#7 dofstatat
#8 syscall
#9 Xsyscall
[6] qbittorrent-nox[49910] usecount 1>0
#0 vput
#1 dofstatat
#2 syscall
#3 Xsyscall
panic: vn_lock: v_usecount == 0
Stopped at: db_enter+0x10: popq %rbp
TID PID UID PRFLAGS PFLAGS CPU COMMAND
366946 49910 858 0 0 3 qbittorrent-nox
169963 49910 858 0 0x4000000 2 qbittorrent-nox
*378217 10953 0 0x14000 0x200 1K pagedaemon
db_enter() at db_enter+0x10
panic(ffffffff81fc2e7d) at panic+0xbf
vn_lock(fffffd8388982e90, 81) at vn_lock+0x18d
uvn_io(fffffd8387e01840,ffff8000255b0380,1,90,1) at uvn_io+0x209
uvm_pager_put(fffffd8387e01840,fffffd8108c22400,ffff8000255b0488,ffff8000255b04a4,90,0,d7e57deb274bc411)
\
\ at uvm_pager_put+0xf7
uvmpd_scan_inactive(ffffffff82350e40) at uvmpd_scan_inactive_0x187
uvmpd_scan() at uvmpd_scan+0xdb
uvm_pageout(ffff8000ffff42b0) at uvm_pageout+0x365
end trace frame: 0x0, count: 7
but keep also photos.
You can find a bit more information in the images since I didn't
reprint everything.
http://46.23.91.227:8098/2_panic_0.jpg
http://46.23.91.227:8098/2_panic_1.jpg
http://46.23.91.227:8098/2_panic_2.jpg
http://46.23.91.227:8098/2_panic_3.jpg
http://46.23.91.227:8098/2_panic_4.jpg
http://46.23.91.227:8098/2_panic_5.jpg
http://46.23.91.227:8098/2_panic_6.jpg
http://46.23.91.227:8098/2_panic_7.jpg
http://46.23.91.227:8098/2_panic_8.jpg
http://46.23.91.227:8098/2_panic_9.jpg
http://46.23.91.227:8098/2_panic_10.jpg
http://46.23.91.227:8098/2_panic_11.jpg
http://46.23.91.227:8098/2_panic_12.jpg
http://46.23.91.227:8098/2_panic_13.jpg
http://46.23.91.227:8098/2_panic_14.jpg
http://46.23.91.227:8098/2_panic_15.jpg
http://46.23.91.227:8098/2_panic_16.jpg
http://46.23.91.227:8098/2_panic_17.jpg
http://46.23.91.227:8098/2_panic_18.jpg
http://46.23.91.227:8098/2_panic_19.jpg
http://46.23.91.227:8098/2_panic_20.jpg
http://46.23.91.227:8098/2_panic_21.jpg
Just in case: the pid of qbittorrent changes because its process
periodically crashes during 'recheck'. Shortly before a kernel panic,
qbittorrent's crash rate usually increases. I suspect that this may
also be related to the increasing number of page faults.
--
Wbr, Andrew Krasavin
