On 21.11.2021. 23:36, Alexander Bluhm wrote:
> Updated tdb refcounting diff after merging with mvs@'s commit.
Hi,
after 24 hours hitting sasyncd setup one box panic
r620-2# panic: pool_do_get: tdb free list modified: page
0xffff8000012e0000; item addr 0
xffff8000012e2a88; offset 0x28=0xdead410f
Stopped at db_enter+0x10: popq %rbp
TID PID UID PRFLAGS PFLAGS CPU COMMAND
272153 56403 68 0x10 0 1 sasyncd
* 32102 91875 68 0x10 0 3 isakmpd
471006 1037 73 0x100010 0x80 0 syslogd
484026 49900 0 0x14000 0x200 4 softnet
106465 49485 0 0x14000 0x200 2 systq
db_enter() at db_enter+0x10
panic(ffffffff81ea6a83) at panic+0xbf
pool_do_get(ffffffff822bd5a0,9,ffff800022d80e34) at pool_do_get+0x35c
pool_get(ffffffff822bd5a0,9) at pool_get+0x93
tdb_alloc(0) at tdb_alloc+0x62
reserve_spi(0,100,ffffffff,ffff8000012c6254,ffff8000012c6238,32,73d60b71a1c10a4
9) at reserve_spi+0xff
pfkeyv2_send(fffffd8394d5f550,ffff8000012c5c80,50) at pfkeyv2_send+0x146a
pfkeyv2_output(fffffd800a5c5100,fffffd8394d5f550,0,0) at pfkeyv2_output+0x8a
pfkeyv2_usrreq(fffffd8394d5f550,9,fffffd800a5c5100,0,0,ffff800022cd5268)
at pfkeyv2_usrreq+0x1b0
sosend(fffffd8394d5f550,0,ffff800022d81480,0,0,0) at sosend+0x3a9
dofilewritev(ffff800022cd5268,7,ffff800022d81480,0,ffff800022d81580) at
dofilewritev+0x14d
sys_writev(ffff800022cd5268,ffff800022d81520,ffff800022d81580) at
sys_writev+0xd2
syscall(ffff800022d815f0) at syscall+0x3a9
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7ffffb2430, count: 1
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{3}>
ddb{3}> show tdb
0xffffffff8198ba60: 00000041 (unknown address family)->(unknown address
family)
:139 #1428429875 02c08348
ddb{3}> show all tdb
0xffff8000012e2a88: f5c0089f 192.168.42.112->192.168.42.100:50
#-559070961 0000
1000
ddb{3}> ps
PID TID PPID UID S FLAGS WAIT COMMAND
56403 272153 15076 68 7 0x10 sasyncd
15076 149191 1 0 3 0x80 kqread sasyncd
*91875 32102 21647 68 7 0x10 isakmpd
21647 46093 1 0 3 0x80 netio isakmpd
62911 252487 1 0 3 0x100083 ttyin ksh
27760 230059 1 0 3 0x100098 kqread cron
64991 237179 48935 95 3 0x100092 kqread smtpd
39524 451490 48935 103 3 0x100092 kqread smtpd
41945 372539 48935 95 3 0x100092 kqread smtpd
71764 444337 48935 95 3 0x100092 kqread smtpd
71639 125115 48935 95 3 0x100092 kqread smtpd
28372 471050 48935 95 3 0x100092 kqread smtpd
48935 320655 1 0 3 0x100080 kqread smtpd
82840 422286 1 0 3 0x88 kqread sshd
75675 375246 1 0 3 0x100080 kqread ntpd
3482 28773 19227 83 3 0x100092 kqread ntpd
19227 110748 1 83 3 0x100092 kqread ntpd
42341 280950 33183 74 3 0x100092 bpf pflogd
33183 127564 1 0 3 0x80 netio pflogd
1037 471006 30335 73 7 0x100090 syslogd
30335 62561 1 0 3 0x100082 netio syslogd
41504 427392 0 0 3 0x14200 bored smr
21187 243711 0 0 3 0x14200 pgzero zerothread
48815 395094 0 0 3 0x14200 aiodoned aiodoned
48275 488591 0 0 3 0x14200 syncer update
38791 457271 0 0 3 0x14200 cleaner cleaner
30177 510262 0 0 3 0x14200 reaper reaper
43460 5699 0 0 3 0x14200 pgdaemon pagedaemon
13390 114146 0 0 3 0x14200 usbtsk usbtask
75817 456494 0 0 3 0x14200 usbatsk usbatsk
49408 32535 0 0 3 0x40014200 acpi0 acpi0
34775 312507 0 0 7 0x40014200 idle5
48439 117613 0 0 3 0x40014200 idle4
36384 294756 0 0 3 0x40014200 idle3
91987 363872 0 0 3 0x40014200 idle2
91389 296087 0 0 3 0x40014200 idle1
7900 284285 0 0 3 0x14200 bored sensors
49900 484026 0 0 7 0x14200 softnet
31157 45925 0 0 3 0x14200 bored systqmp
49485 106465 0 0 7 0x14200 systq
52790 213052 0 0 3 0x40014200 bored softclock
88741 290928 0 0 3 0x40014200 idle0
1 245546 0 0 3 0x82 wait init
0 0 -1 0 3 0x10200 scheduler swapper
ddb{3}>
ddb{3}> show all pool
Name Size Requests Fail Releases Pgreq Pgrel Npage Hiwat Minpg
Maxpg Idle
pfsync 40 1969824535 0 1969824535 45 43 2 2 0
8 2
plcache 128 66 0 0 3 0 3 3 0
8 0
rtpcb 120 20 0 19 3 2 1 1 0
8 0
rtentry 112 46 0 3 2 0 2 2 0
8 0
unpcb 128 139 0 87 2 0 2 2 0
8 0
syncache 296 4 0 4 3 3 0 1 0
8 0
tcpqe 32 3 0 3 2 2 0 1 0
8 0
tcpcb 736 51 0 43 3 1 2 2 0
8 0
tdb 1088 199 0 198 65 64 1 1 0
8 0
pool(0xffffffff822bd5a0:tdb): page inconsistency: page
0xffff8000012e0000; 13 on list, 1 missing,
15 items per page
arp 88 16 0 2 1 0 1 1 0
8 0
ddb{3}> mach ddbcpu 0
Stopped at x86_ipi_db+0x12: leave
x86_ipi_db(ffffffff8215aff0) at x86_ipi_db+0x12
x86_ipi_handler() at x86_ipi_handler+0x80
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x23
__mp_acquire_count(ffffffff822b8120,2) at __mp_acquire_count+0x86
mi_switch() at mi_switch+0x299
sleep_finish(ffff800022d0eb30,1) at sleep_finish+0x11c
msleep(fffffd83afefee60,fffffd83afefee60,318,ffffffff81eae3c1,40e) at
msleep+0x
cc
kqueue_sleep(fffffd83afefee60,ffff800022d0eed8) at kqueue_sleep+0xbe
kqueue_scan(ffff800022d0ede8,8,ffff800022d0ece0,ffff800022d0eed8,ffff800022cdc0
10,ffff800022d0ef2c) at kqueue_scan+0xfc
sys_kevent(ffff800022cdc010,ffff800022d0ef90,ffff800022d0eff0) at
sys_kevent+0x
3ae
syscall(ffff800022d0f060) at syscall+0x3a9
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7ffffd0610, count: 3
ddb{0}> mach ddbcpu 1
Stopped at x86_ipi_db+0x12: leave
x86_ipi_db(ffff800022409ff0) at x86_ipi_db+0x12
x86_ipi_handler() at x86_ipi_handler+0x80
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x23
_kernel_lock() at _kernel_lock+0xa6
soo_ioctl(fffffd83b0941100,c020691b,ffff800022d27a90,ffff800022cd5508)
at soo_i
octl+0x150
sys_ioctl(ffff800022cd5508,ffff800022d27ba0,ffff800022d27c00) at
sys_ioctl+0x2c
4
syscall(ffff800022d27c70) at syscall+0x3a9
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7ffffd3e40, count: 7
ddb{1}>
ddb{1}> mach ddbcpu 2
Stopped at x86_ipi_db+0x12: leave
x86_ipi_db(ffff800022412ff0) at x86_ipi_db+0x12
x86_ipi_handler() at x86_ipi_handler+0x80
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x23
__mp_acquire_count(ffffffff822b8120,1) at __mp_acquire_count+0x80
msleep(ffffffff821641a8,ffffffff821641c0,20,ffffffff81e79176,0) at
msleep+0x11e
taskq_next_work(ffffffff821641a8,ffff800022c53f30) at taskq_next_work+0x61
taskq_thread(ffffffff821641a8) at taskq_thread+0xa6
end trace frame: 0x0, count: 8
ddb{2}>
ddb{2}> mach ddbcpu 3
Stopped at db_enter+0x10: popq %rbp
db_enter() at db_enter+0x10
panic(ffffffff81ea6a83) at panic+0xbf
pool_do_get(ffffffff822bd5a0,9,ffff800022d80e34) at pool_do_get+0x35c
pool_get(ffffffff822bd5a0,9) at pool_get+0x93
tdb_alloc(0) at tdb_alloc+0x62
reserve_spi(0,100,ffffffff,ffff8000012c6254,ffff8000012c6238,32,73d60b71a1c10a4
9) at reserve_spi+0xff
pfkeyv2_send(fffffd8394d5f550,ffff8000012c5c80,50) at pfkeyv2_send+0x146a
pfkeyv2_output(fffffd800a5c5100,fffffd8394d5f550,0,0) at pfkeyv2_output+0x8a
pfkeyv2_usrreq(fffffd8394d5f550,9,fffffd800a5c5100,0,0,ffff800022cd5268)
at pfk
eyv2_usrreq+0x1b0
sosend(fffffd8394d5f550,0,ffff800022d81480,0,0,0) at sosend+0x3a9
dofilewritev(ffff800022cd5268,7,ffff800022d81480,0,ffff800022d81580) at
dofilew
ritev+0x14d
sys_writev(ffff800022cd5268,ffff800022d81520,ffff800022d81580) at
sys_writev+0x
d2
syscall(ffff800022d815f0) at syscall+0x3a9
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7ffffb2430, count: 1
ddb{3}>
ddb{3}> mach ddbcpu 4
Stopped at x86_ipi_db+0x12: leave
x86_ipi_db(ffff800022424ff0) at x86_ipi_db+0x12
x86_ipi_handler() at x86_ipi_handler+0x80
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x23
ether_input(ffff800000087048,fffffd80a4f61e00) at ether_input+0x13f
if_input_process(ffff800000087048,ffff800022c60928) at if_input_process+0x6f
ifiq_process(ffff800000086b00) at ifiq_process+0x69
taskq_thread(ffff80000002f080) at taskq_thread+0x81
end trace frame: 0x0, count: 8
ddb{4}>
ddb{4}> mach ddbcpu 5
Stopped at x86_ipi_db+0x12: leave
x86_ipi_db(ffff80002242dff0) at x86_ipi_db+0x12
x86_ipi_handler() at x86_ipi_handler+0x80
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x23
acpicpu_idle() at acpicpu_idle+0x281
sched_idle(ffff80002242dff0) at sched_idle+0x27e
end trace frame: 0x0, count: 10
ddb{5}>
