On 24.12.2021. 0:55, Alexander Bluhm wrote:
> I think we can remove the ipsec_in_use workaround now. The IPsec
> path is protected with the kernel lock.
>
> There are some issues left:
> - npppd l2pt ipsecflowinfo is not MP safe
> - the acquire SA feature is not MP safe
> - Hrvoje has seen a panic with sasync
>
> If you use one of these, the diff below should trigger crashes faster.
> If you use only regular IPsec or forwarding, I hope it is stable.
Hi,
after hitting sasyncd setup with this diff for some time i've run
ipsecctl -sa just to see what's going on and box panic
r620-1# ipsecctl -sa
uvm_fault(0xffffffff82200c18, 0x417, 0, 2) -> e
kernel: page fault trap, code=0
Stopped at pfsync_delete_tdb+0x84: movq %rcx,0x8(%rsi)
TID PID UID PRFLAGS PFLAGS CPU COMMAND
290490 40316 0 0x3 0 3 ipsecctl
10869 22801 68 0x10 0 5 sasyncd
504041 13202 68 0x10 0x80 1 isakmpd
476980 6400 0 0x100000 0 2 ntpd
224100 72648 0 0x14000 0x200 4 reaper
* 75659 10211 0 0x14000 0x40000200 0K softclock
pfsync_delete_tdb(ffff8000012e8008) at pfsync_delete_tdb+0x84
tdb_free(ffff8000012e8008) at tdb_free+0x67
tdb_timeout(ffff8000012e8008) at tdb_timeout+0x7e
softclock_thread(ffff8000fffff260) at softclock_thread+0x13b
end trace frame: 0x0, count: 11
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}>
ddb{0}> show reg
rdi 0x4
rsi 0x40f
rbp 0xffff800022c4e390
rbx 0
rdx 0xffff8000006b39e8
rcx 0xffffffffffffffff
rax 0xffffffffffffffff
r8 0x1f
r9 0
r10 0xbaf844ce8eec335d
r11 0xb9858c0c287d2c4d
r12 0xffff8000006b3000
r13 0xffffffff821c5e60 timeout_proc
r14 0xffff8000012e8008
r15 0xffff8000006b39f8
rip 0xffffffff8131a254 pfsync_delete_tdb+0x84
cs 0x8
rflags 0x10286 __ALIGN_SIZE+0xf286
rsp 0xffff800022c4e360
ss 0x10
pfsync_delete_tdb+0x84: movq %rcx,0x8(%rsi)
ddb{0}>
ddb{0}> show all tdb
0xffff8000012e8008: f9f247f0 192.168.42.100->192.168.42.112:50 #0 000d1040
0xffff8000012e8428: 959c114b 192.168.42.112->192.168.42.100:50 #2 00001002
0xffff8000012e8848: b7eb65bc 192.168.42.113->192.168.42.100:50 #2 00001002
0xffff8000012e9ce8: 55495192 192.168.42.100->192.168.42.113:50 #3 000d1002
ddb{0}>
ddb{0}> show tdb /f 0xffff8000012e8008
tdb at 0xffff8000012e8008
hnext: 0x0
dnext: 0x0
snext: 0x0
inext: 0x0
onext: 0x0
xform: 0x0
refcnt: 0
encalgxform: 0xffffffff81f36090
authalgxform: 0xffffffff81f36380
compalgxform: 0x0
flags: d1040<DELETED,TUNNELING,USEDTUNNEL,PFSYNC,PFSYNC_RPL>
seq: 8
exp_allocations: 0
soft_allocations: 0
cur_allocations: 0
exp_bytes: 0
soft_bytes: 0
cur_bytes: 1272048336570
exp_timeout: 1200
soft_timeout: 1080
established: 1640372736
first_use: 1640372754
soft_first_use: 0
exp_first_use: 0
last_used: 1640419926
last_marked: 0
cryptoid: 0
tdb_spi: f9f247f0
amxkeylen: 20
emxkeylen: 20
ivlen: 8
sproto: 50
wnd: 16
satype: 2
updates: 158
dst: 192.168.42.112
src: 192.168.42.100
amxkey: 0x0
emxkey: 0x0
rpl: 5256398086
ids: 0xffff8000012d8800
ids_swapped: 0
mtu: 0
mtutimeout: 0
udpencap_port: 0
tag: 0
tap: 0
rdomain: 0
rdomain_post: 0
ddb{0}>
PID TID PPID UID S FLAGS WAIT COMMAND
40316 290490 5050 0 7 0x3 ipsecctl
22801 10869 51239 68 7 0x10 sasyncd
51239 39174 1 0 3 0x80 kqread sasyncd
13202 504041 43160 68 7 0x90 isakmpd
43160 53413 1 0 3 0x80 netio isakmpd
5050 12722 1 0 3 0x10008b sigsusp ksh
64387 345990 1 0 3 0x100098 poll cron
58819 219224 16427 95 3 0x100092 kqread smtpd
67207 340852 16427 103 3 0x100092 kqread smtpd
97983 457473 16427 95 3 0x100092 kqread smtpd
6608 99059 16427 95 3 0x100092 kqread smtpd
91670 313820 16427 95 3 0x100092 kqread smtpd
7571 97218 16427 95 3 0x100092 kqread smtpd
16427 464572 1 0 3 0x100080 kqread smtpd
66627 364623 1 0 3 0x88 poll sshd
6400 476980 1 0 7 0x100000 ntpd
15200 447105 93293 83 3 0x100092 poll ntpd
93293 59596 1 83 2 0x100012 ntpd
46409 262850 63547 74 3 0x100092 bpf pflogd
63547 127229 1 0 3 0x80 netio pflogd
72530 73213 4587 73 3 0x100090 kqread syslogd
4587 512426 1 0 3 0x100082 netio syslogd
17655 381404 0 0 3 0x14200 bored smr
73757 204335 0 0 3 0x14200 pgzero zerothread
10290 119553 0 0 3 0x14200 aiodoned aiodoned
87569 15096 0 0 3 0x14200 syncer update
90413 144932 0 0 3 0x14200 cleaner cleaner
72648 224100 0 0 7 0x14200 reaper
65898 277187 0 0 3 0x14200 pgdaemon pagedaemon
72836 339003 0 0 3 0x14200 usbtsk usbtask
57295 478285 0 0 3 0x14200 usbatsk usbatsk
9904 80675 0 0 3 0x40014200 acpi0 acpi0
60370 374031 0 0 3 0x40014200 idle5
66091 260777 0 0 3 0x40014200 idle4
44655 171688 0 0 3 0x40014200 idle3
12526 257304 0 0 3 0x40014200 idle2
46398 213841 0 0 3 0x40014200 idle1
37584 47737 0 0 3 0x14200 bored sensors
60719 433549 0 0 3 0x14200 bored softnet
7704 416964 0 0 3 0x14200 bored softnet
31937 522056 0 0 3 0x14200 bored softnet
79009 468497 0 0 3 0x14200 bored softnet
3925 227725 0 0 3 0x14200 bored systqmp
44335 71027 0 0 3 0x14200 bored systq
*10211 75659 0 0 7 0x40014200 softclock
88062 62748 0 0 3 0x40014200 idle0
1 493056 0 0 3 0x82 wait init
0 0 -1 0 3 0x10200 scheduler swapper
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
__mp_acquire_count(ffffffff821f1760,3) at __mp_acquire_count+0x92
mi_switch() at mi_switch+0x299
sleep_finish(ffff800022d970f0,1) at sleep_finish+0x11c
msleep(fffffd83b0aeeda8,fffffd83b0aeeda8,318,ffffffff81ead720,1771) at
msleep+0xcc
kqueue_sleep(fffffd83b0aeeda8,ffff800022d97600) at kqueue_sleep+0xbe
kqueue_scan(ffff800022d973a0,8,ffff800022d972a0,ffff800022d97600,ffff8000ffff42
b0,ffff800022d9756c) at kqueue_scan+0xfc
dopselect(ffff8000ffff42b0,17,624934c5f70,623ea8556f0,0,ffff800022d97600,b25bc6
5c0b9e131b,ffff8000ffff42b0) at dopselect+0x415
sys_pselect(ffff8000ffff42b0,ffff800022d97670,ffff800022d976c0) at
sys_pselect+0xdb
syscall(ffff800022d97730) at syscall+0x374
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7ffffc88c0, count: 2
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
_kernel_lock() at _kernel_lock+0xb2
selwakeup(fffffd83b37dfbf8) at selwakeup+0x11
uipc_usrreq(fffffd83b37df8c0,8,0,0,0,ffff8000ffff4d30) at uipc_usrreq+0x470
soreceive(fffffd83b37df8c0,ffff800022d51480,ffff800022d51430,0,ffff800022d51470
,ffff800022d515dc,419d63b6f434ec76) at soreceive+0xc0d
recvit(ffff8000ffff4d30,3,ffff800022d515b0,0,ffff800022d51690) at
recvit+0x200
sys_recvmsg(ffff8000ffff4d30,ffff800022d51640,ffff800022d51690) at
sys_recvmsg+0xd4
syscall(ffff800022d51700) at syscall+0x374
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7ffffd8390, count: 4
ddb{2}>
ddb{2}> mach ddbcpu 3
Stopped at x86_ipi_db+0x12: leave
x86_ipi_db(ffff80002241bff0) 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+0xa0
syscall(ffff800022d0ddc0) at syscall+0x278
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7ffffcf2e0, count: 9
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
_kernel_lock() at _kernel_lock+0xab
uvm_unmap_detach(ffff800022cb4568,1) at uvm_unmap_detach+0xc5
uvm_map_teardown(fffffd83ae059228) at uvm_map_teardown+0x1cb
uvmspace_free(fffffd83ae059228) at uvmspace_free+0x5a
reaper(ffff8000ffff87e8) at reaper+0x15d
end trace frame: 0x0, count: 7
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
_kernel_lock() at _kernel_lock+0xb2
syscall(ffff800022d578a0) at syscall+0x278
Xsyscall() at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7ffffeaad0, count: 9
ddb{5}>
