On 4.7.2017. 13:12, Hrvoje Popovski wrote:
> On 4.7.2017. 13:06, Hrvoje Popovski wrote:
>> On 4.7.2017. 12:33, Martin Pieuchot wrote:
>>> On 04/07/17(Tue) 01:49, Hrvoje Popovski wrote:
>>>> Hi all,
>>>>
>>>> with cvs tree (with or without bluhm@ uipc_syscalls patch) fetched few
>>>> minutes ago i'm getting panic below. would show witness be of any good?
>>>>
>>>>
>>>> Setup is quite standard, carp, pf, pfsync, isakmpd ....
>>>
>>> Thanks for the report. IPsec is here again, this time with pfsync.
>>>
>>>> # panic: kernel diagnostic assertion "_kernel_lock_held()" failed: file
>>>> "/usr/src/sys/netinet/ip_output.c", line 234
>>>
>>> Diff below should prevent and document the problem.
>>
>>
>> Yes, no more panic with this diff ...
>>
>> Thank you ...
>>
>>
>
>
> and i'm to quick ..
>
> here's panic when killing isakmpd on other box
>
> # panic: lock (kernel_lock) &kernel_lock not locked @
> /usr/src/sys/kern/kern_lock.c:82
> Stopped at db_enter+0x9: leave
> TID PID UID PRFLAGS PFLAGS CPU COMMAND
> 258791 23234 0 0x100002 0 2 logger
> 437405 70421 76 0x100012 0 3 tcpdump
> 227708 84289 73 0x100010 0 6 syslogd
> * 28487 40454 0 0x14000 0x200 4 pfpurge
> 165000 68771 0 0x14000 0x200 7 softnet
> 145173 9108 0 0x14000 0x200 1 systq
> db_enter(ffffffff8178040e,ffff80002a197ce0,10,ffff80002a197cc0,286,8) at
> db_ent
> er+0x9
> panic(ffffffff818d5cf8,ffffffff81b32340,ffffffff8185dd2e,ffff80002a182b18,fffff
> fff81af6ca8,c2a197e20) at panic+0x102
> witness_unlock(ffffffff81af6ca8,8,ffffffff8185dd2e,52,0,0) at
> witness_unlock+0x
> 30c
> ___mp_unlock(ffffffff81af6aa0,ffffffff8185dd2e,52,0,7,0) at
> ___mp_unlock+0x44
> pf_purge_thread(ffff80002a1828e8,8,ffff80002a1828e8,ffffffff8173ab30,0,0)
> at pf
> _purge_thread+0xc3
> end trace frame: 0x0, count: 10
> https://www.openbsd.org/ddb.html describes the minimum info required in bug
> reports. Insufficient info makes it difficult to find and fix bugs.
>
in attachment you can find ddb output ..
ddb{4}> ps
PID TID PPID UID S FLAGS WAIT COMMAND
69100 131206 76646 68 3 0x90 select isakmpd
76646 243167 1 0 3 0x80 netio isakmpd
2014 293161 92289 0 3 0x100083 ttyin ksh
92289 441450 10693 1000 3 0x10008b pause ksh
10693 54120 72477 1000 3 0x90 select sshd
72477 429788 99383 0 3 0x82 poll sshd
49117 113422 70421 0 3 0x100080 netio tcpdump
66022 486467 1 0 3 0x100083 ttyin ksh
89399 523261 1 0 3 0x100083 ttyin getty
21188 307375 1 0 3 0x100083 ttyin getty
82529 35200 1 0 3 0x100083 ttyin getty
3865 243938 1 0 3 0x100083 ttyin getty
84630 293032 1 0 3 0x100083 ttyin getty
23234 258791 22975 0 7 0x100002 logger
70421 437405 22975 76 7 0x100012 tcpdump
22975 404167 10700 0 3 0x10008a pause sh
10700 430573 3969 0 3 0x100090 piperd cron
3969 286159 1 0 3 0x100098 poll cron
6945 132545 88809 623 3 0x90 nanosleep zabbix_agentd
4459 66323 88809 623 3 0x90 select zabbix_agentd
50744 264167 88809 623 3 0x90 nanosleep zabbix_agentd
88809 293399 1 623 3 0x90 wait zabbix_agentd
42755 36825 47378 606 3 0x90 kqread ladvd
47378 349468 1 0 3 0x80 kqread ladvd
87011 463683 23134 95 3 0x100092 kqread smtpd
71836 164565 23134 103 3 0x100092 kqread smtpd
71034 523336 23134 95 3 0x100092 kqread smtpd
77470 116362 23134 95 3 0x100092 kqread smtpd
40997 68975 23134 95 3 0x100092 kqread smtpd
13769 399680 23134 95 3 0x100092 kqread smtpd
23134 1927 1 0 3 0x100080 kqread smtpd
58840 492911 1 77 3 0x100090 poll dhcpd
76034 189942 1 0 3 0x80 kqread snmpd
11521 294110 1 91 3 0x92 kqread snmpd
1594 270423 1 91 3 0x92 kqread snmpd
99383 253837 1 0 3 0x80 select sshd
2651 460468 19290 83 3 0x100092 poll ntpd
19290 470511 20041 83 3 0x100092 poll ntpd
20041 422594 1 0 3 0x100080 poll ntpd
59695 41766 78169 74 3 0x100090 bpf pflogd
78169 347785 1 0 3 0x100080 netio pflogd
84289 227708 71953 73 7 0x100010 syslogd
71953 208257 1 0 3 0x100082 netio syslogd
66262 173063 0 0 3 0x14200 pgzero zerothread
73107 440374 0 0 3 0x14200 aiodoned aiodoned
51435 277892 0 0 3 0x14200 syncer update
88351 298370 0 0 3 0x14200 cleaner cleaner
44771 426761 0 0 3 0x14200 reaper reaper
14211 63539 0 0 3 0x14200 pgdaemon pagedaemon
24483 132500 0 0 3 0x14200 bored crynlk
85151 409522 0 0 3 0x14200 bored crypto
*40454 28487 0 0 7 0x14200 pfpurge
95605 353568 0 0 3 0x14200 usbtsk usbtask
57385 175754 0 0 3 0x14200 usbatsk usbatsk
25375 92177 0 0 3 0x40014200 acpi0 acpi0
6167 139286 0 0 3 0x40014200 idle7
59370 398124 0 0 3 0x40014200 idle6
13093 292865 0 0 7 0x40014200 idle5
40820 388622 0 0 3 0x40014200 idle4
43799 304139 0 0 3 0x40014200 idle3
5292 206536 0 0 3 0x40014200 idle2
12108 181498 0 0 3 0x40014200 idle1
54097 490987 0 0 3 0x14200 bored sensors
68771 165000 0 0 7 0x14200 softnet
6431 173624 0 0 3 0x14200 bored systqmp
9108 145173 0 0 7 0x14200 systq
16744 36348 0 0 3 0x40014200 bored softclock
32746 59283 0 0 7 0x40014200 idle0
94613 95511 0 0 3 0x14200 bored sbar
1 254277 0 0 3 0x82 wait init
0 0 -1 0 3 0x10200 scheduler swapper
ddb{4}>
ddb{4}> mach ddbcpu 1
Stopped at db_enter+0x9: leave
db_enter(ffff80000003d000,ffff80002a14dbc8,ffff80002a14dbd8,10,ffff80002a14db88
,286) at db_enter+0x9
x86_ipi_handler(bf,ffffffff81af6ca8,ffffffff81af6aa8,0,ffffffff81af6ca8,0) at x
86_ipi_handler+0x85
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x1c
--- interrupt ---
___mp_lock(ffffffff81af6aa0,ffffffff817897d8,bf,8,ffffffff81af6aa0,ffffffff8178
97d8) at ___mp_lock+0x88
___mp_acquire_count(ffffffff81af6aa0,1,ffffffff817897d8,bf,0,0) at ___mp_acquir
e_count+0x51
msleep(ffffffff819f9020,ffffffff819f9038,20,ffffffff8197916f,0,ffff80002a14deb0
) at msleep+0x136
taskq_next_work(ffffffff819f9020,ffff80002a14deb0,ffffffff8105d380,1f0,0,ffff80
002a14deb0) at taskq_next_work+0x68
taskq_thread(ffffffff819f9020,8,ffffffff819f9020,ffffffff8174f280,0,0) at taskq
_thread+0x6e
end trace frame: 0x0, count: 7
ddb{1}> trace
db_enter(ffff80000003d000,ffff80002a14dbc8,ffff80002a14dbd8,10,ffff80002a14db88
,286) at db_enter+0x9
x86_ipi_handler(bf,ffffffff81af6ca8,ffffffff81af6aa8,0,ffffffff81af6ca8,0) at x
86_ipi_handler+0x85
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x1c
--- interrupt ---
___mp_lock(ffffffff81af6aa0,ffffffff817897d8,bf,8,ffffffff81af6aa0,ffffffff8178
97d8) at ___mp_lock+0x88
___mp_acquire_count(ffffffff81af6aa0,1,ffffffff817897d8,bf,0,0) at ___mp_acquir
e_count+0x51
msleep(ffffffff819f9020,ffffffff819f9038,20,ffffffff8197916f,0,ffff80002a14deb0
) at msleep+0x136
taskq_next_work(ffffffff819f9020,ffff80002a14deb0,ffffffff8105d380,1f0,0,ffff80
002a14deb0) at taskq_next_work+0x68
taskq_thread(ffffffff819f9020,8,ffffffff819f9020,ffffffff8174f280,0,0) at taskq
_thread+0x6e
end trace frame: 0x0, count: -8
ddb{1}>
ddb{1}> mach ddbcpu 2
Stopped at db_enter+0x9: leave
db_enter(ffff80000003f000,ffffffff8141e932,8a,10,ffff80002a2e6958,282) at db_en
ter+0x9
x86_ipi_handler(8a,ffffffff81af6ca8,ffffffff81af6ab0,0,8,ffffffff8190f43f) at x
86_ipi_handler+0x85
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x1c
--- interrupt ---
___mp_lock(ffffffff81af6aa0,ffffffff817897d8,8a,8,ffffffff81af6aa0,ffffffff8178
97d8) at ___mp_lock+0x82
___mp_acquire_count(ffffffff81af6aa0,1,ffffffff817897d8,8a,ffffff02d1300008,fff
fffff8199b73e) at ___mp_acquire_count+0x51
tsleep(ffffff02d1300008,110,ffffffff8199b73e,0,ffff80002a2e6d20,0) at tsleep+0x
138
pipe_read(ffffff02dde8a2c0,ffffff02dde8a2f0,ffff80002a2e6d20,ffffff032f7d3900,f
fffff02dde8a2c0,ffff80002a2e6eb0) at pipe_read+0xb6
dofilereadv(ffff80002a183ce0,0,ffffff02dde8a2c0,ffff80002a2e6de0,1,0) at dofile
readv+0x247
sys_read(ffff80002a183ce0,ffff80002a2e6e60,ffff80002a2e6eb0,45,1,ffff80002a2e6f
20) at sys_read+0x95
syscall() at syscall+0x29f
--- syscall (number 3) ---
end of kernel
end trace frame: 0x7f7ffffd3a88, count: 5
0x3c6b3c6f74a:
ddb{2}> trace
db_enter(ffff80000003f000,ffffffff8141e932,8a,10,ffff80002a2e6958,282) at db_en
ter+0x9
x86_ipi_handler(8a,ffffffff81af6ca8,ffffffff81af6ab0,0,8,ffffffff8190f43f) at x
86_ipi_handler+0x85
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x1c
--- interrupt ---
___mp_lock(ffffffff81af6aa0,ffffffff817897d8,8a,8,ffffffff81af6aa0,ffffffff8178
97d8) at ___mp_lock+0x82
___mp_acquire_count(ffffffff81af6aa0,1,ffffffff817897d8,8a,ffffff02d1300008,fff
fffff8199b73e) at ___mp_acquire_count+0x51
tsleep(ffffff02d1300008,110,ffffffff8199b73e,0,ffff80002a2e6d20,0) at tsleep+0x
138
pipe_read(ffffff02dde8a2c0,ffffff02dde8a2f0,ffff80002a2e6d20,ffffff032f7d3900,f
fffff02dde8a2c0,ffff80002a2e6eb0) at pipe_read+0xb6
dofilereadv(ffff80002a183ce0,0,ffffff02dde8a2c0,ffff80002a2e6de0,1,0) at dofile
readv+0x247
sys_read(ffff80002a183ce0,ffff80002a2e6e60,ffff80002a2e6eb0,45,1,ffff80002a2e6f
20) at sys_read+0x95
syscall() at syscall+0x29f
--- syscall (number 3) ---
end of kernel
end trace frame: 0x7f7ffffd3a88, count: -10
0x3c6b3c6f74a:
ddb{2}>
ddb{2}> mach ddbcpu 3
Stopped at db_enter+0x9: leave
db_enter(ffff800000040000,bf00000000,ffffffff81af6ca8,10,ffff80002a2e1808,282) a
t db_enter+0x9
x86_ipi_handler(ffff800000a5dc18,ffffffff817897d8,c3,9,0,0) at x86_ipi_handler+
0x85
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x1c
--- interrupt ---
__mtx_enter(ffff800000a5dc08,ffffffff817897d8,c3,bf,64,0) at __mtx_enter+0x30
msleep(ffff800000a5dc00,ffff800000a5dc08,11a,ffffffff81905ff0,64,ffffff02ddea7d
70) at msleep+0xfb
bpfread(61700,ffff80002a2e1d20,0,1a302aec2032f9a9,ffff80002a2e1d20,ffffff02ddea
7d70) at bpfread+0x23f
spec_read(ffff80002a2e1b80,2001,ffffff02dde8a670,ffffff02ddea7d70,8000,0) at sp
ec_read+0x301
VOP_READ(ffffff02ddea7d70,ffff80002a2e1d20,0,ffffff032f7d3900,1a302aec2032f9a9,
8000) at VOP_READ+0x4f
vn_read(ffffff02dde8a640,ffffff02dde8a670,ffff80002a2e1d20,ffffff032f7d3900,fff
fff02dde8a640,ffff80002a2e1eb0) at vn_read+0xaf
dofilereadv(ffff80002a1dbcf8,3,ffffff02dde8a640,ffff80002a2e1de0,1,0) at dofile
readv+0x247
sys_read(ffff80002a1dbcf8,ffff80002a2e1e60,ffff80002a2e1eb0,45,1,ffff80002a2e1f
20) at sys_read+0x95
syscall() at syscall+0x29f
--- syscall (number 3) ---
end of kernel
end trace frame: 0xf10b204000, count: 3
0xf18bf2174a:
ddb{3}> trace
db_enter(ffff800000040000,bf00000000,ffffffff81af6ca8,10,ffff80002a2e1808,282) a
t db_enter+0x9
x86_ipi_handler(ffff800000a5dc18,ffffffff817897d8,c3,9,0,0) at x86_ipi_handler+
0x85
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x1c
--- interrupt ---
__mtx_enter(ffff800000a5dc08,ffffffff817897d8,c3,bf,64,0) at __mtx_enter+0x30
msleep(ffff800000a5dc00,ffff800000a5dc08,11a,ffffffff81905ff0,64,ffffff02ddea7d
70) at msleep+0xfb
bpfread(61700,ffff80002a2e1d20,0,1a302aec2032f9a9,ffff80002a2e1d20,ffffff02ddea
7d70) at bpfread+0x23f
spec_read(ffff80002a2e1b80,2001,ffffff02dde8a670,ffffff02ddea7d70,8000,0) at sp
ec_read+0x301
VOP_READ(ffffff02ddea7d70,ffff80002a2e1d20,0,ffffff032f7d3900,1a302aec2032f9a9,
8000) at VOP_READ+0x4f
vn_read(ffffff02dde8a640,ffffff02dde8a670,ffff80002a2e1d20,ffffff032f7d3900,fff
fff02dde8a640,ffff80002a2e1eb0) at vn_read+0xaf
dofilereadv(ffff80002a1dbcf8,3,ffffff02dde8a640,ffff80002a2e1de0,1,0) at dofile
readv+0x247
sys_read(ffff80002a1dbcf8,ffff80002a2e1e60,ffff80002a2e1eb0,45,1,ffff80002a2e1f
20) at sys_read+0x95
syscall() at syscall+0x29f
--- syscall (number 3) ---
end of kernel
end trace frame: 0xf10b204000, count: -12
0xf18bf2174a:
ddb{3}>
ddb{3}> mach ddbcpu 5
Stopped at db_enter+0x9: leave
db_enter(ffff800000042000,ffffffff81b32548,ffff800000042000,10,ffff80002a177d28
,286) at db_enter+0x9
x86_ipi_handler(ffff800000042000,ffff80000001e700,ffff80000001b500,0,1c0,0) at x
86_ipi_handler+0x85
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x1c
--- interrupt ---
acpicpu_idle(ffff80002a12faa0,ffff800000042000,ffff800000042010,0,1a302aec2032f
9a9,286) at acpicpu_idle+0xec
cpu_idle_cycle(ffff800000042000,8,0,ffff800000042000,ffffffff810f8540,0) at cpu
_idle_cycle+0x10
end trace frame: 0x0, count: 10
ddb{5}> trace
db_enter(ffff800000042000,ffffffff81b32548,ffff800000042000,10,ffff80002a177d28
,286) at db_enter+0x9
x86_ipi_handler(ffff800000042000,ffff80000001e700,ffff80000001b500,0,1c0,0) at x
86_ipi_handler+0x85
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x1c
--- interrupt ---
acpicpu_idle(ffff80002a12faa0,ffff800000042000,ffff800000042010,0,1a302aec2032f
9a9,286) at acpicpu_idle+0xec
cpu_idle_cycle(ffff800000042000,8,0,ffff800000042000,ffffffff810f8540,0) at cpu
_idle_cycle+0x10
end trace frame: 0x0, count: -5
ddb{5}>
ddb{5}> mach ddbcpu 6
Stopped at db_enter+0x9: leave
db_enter(ffff800000044000,37,2,10,ffff80002a20f998,282) at db_enter+0x9
x86_ipi_handler(8a,ffffffff81af6ca8,ffffffff81af6ad0,0,ffff80002a20fa40,ffff800
000056048) at x86_ipi_handler+0x85
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x1c
--- interrupt ---
___mp_lock(ffffffff81af6aa0,ffffffff817897d8,8a,8,ffffffff81af6aa0,ffffffff8178
97d8) at ___mp_lock+0x88
___mp_acquire_count(ffffffff81af6aa0,1,ffffffff817897d8,8a,ffffff02d0951000,fff
fffff8194d9a2) at ___mp_acquire_count+0x51
tsleep(ffffff02d0951000,118,ffffffff8194d9a2,55b,0,40) at tsleep+0x138
kqueue_scan(ffffff02d0951000,40,16eaecf6b800,ffff80002a20fdd0,ffff80002a1d2f98,
ffff80002a20fde4) at kqueue_scan+0x15b
sys_kevent(ffff80002a1d2f98,ffff80002a20fe60,ffff80002a20feb0,45,48,1) at sys_k
event+0x2f6
syscall() at syscall+0x29f
--- syscall (number 72) ---
end of kernel
end trace frame: 0x16eaecf6b800, count: 6
0x16eb582d428a:
ddb{6}> trace
db_enter(ffff800000044000,37,2,10,ffff80002a20f998,282) at db_enter+0x9
x86_ipi_handler(8a,ffffffff81af6ca8,ffffffff81af6ad0,0,ffff80002a20fa40,ffff800
000056048) at x86_ipi_handler+0x85
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x1c
--- interrupt ---
___mp_lock(ffffffff81af6aa0,ffffffff817897d8,8a,8,ffffffff81af6aa0,ffffffff8178
97d8) at ___mp_lock+0x88
___mp_acquire_count(ffffffff81af6aa0,1,ffffffff817897d8,8a,ffffff02d0951000,fff
fffff8194d9a2) at ___mp_acquire_count+0x51
tsleep(ffffff02d0951000,118,ffffffff8194d9a2,55b,0,40) at tsleep+0x138
kqueue_scan(ffffff02d0951000,40,16eaecf6b800,ffff80002a20fdd0,ffff80002a1d2f98,
ffff80002a20fde4) at kqueue_scan+0x15b
sys_kevent(ffff80002a1d2f98,ffff80002a20fe60,ffff80002a20feb0,45,48,1) at sys_k
event+0x2f6
syscall() at syscall+0x29f
--- syscall (number 72) ---
end of kernel
end trace frame: 0x16eaecf6b800, count: -9
0x16eb582d428a:
ddb{6}>
ddb{6}> mach ddbcpu 7
Stopped at db_enter+0x9: leave
db_enter(ffff800000045000,80983100,bb01e0fc00000000,10,ffff80002a157c38,282) at
db_enter+0x9
x86_ipi_handler(0,20,ffff80000001a118,0,6e16d9ac00000210,0) at x86_ipi_handler+
0x85
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x1c
--- interrupt ---
__mp_lock_held(ffffffff81af6aa0,0,bb,0,10,ffff80002a157d70) at __mp_lock_held+0
x1b
msleep(ffff80000001a100,ffff80000001a118,20,ffffffff8197916f,0,ffff80002a157eb0
) at msleep+0xa8
taskq_next_work(ffff80000001a100,ffff80002a157eb0,ffffffff8105d380,0,0,ffff8000
2a157eb0) at taskq_next_work+0x68
taskq_thread(ffff80000001a100,8,ffff80000001a100,ffffffff8174f280,0,0) at taskq
_thread+0x6e
end trace frame: 0x0, count: 8
ddb{7}> trace
db_enter(ffff800000045000,80983100,bb01e0fc00000000,10,ffff80002a157c38,282) at
db_enter+0x9
x86_ipi_handler(0,20,ffff80000001a118,0,6e16d9ac00000210,0) at x86_ipi_handler+
0x85
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x1c
--- interrupt ---
__mp_lock_held(ffffffff81af6aa0,0,bb,0,10,ffff80002a157d70) at __mp_lock_held+0
x1b
msleep(ffff80000001a100,ffff80000001a118,20,ffffffff8197916f,0,ffff80002a157eb0
) at msleep+0xa8
taskq_next_work(ffff80000001a100,ffff80002a157eb0,ffffffff8105d380,0,0,ffff8000
2a157eb0) at taskq_next_work+0x68
taskq_thread(ffff80000001a100,8,ffff80000001a100,ffffffff8174f280,0,0) at taskq
_thread+0x6e
end trace frame: 0x0, count: -7
ddb{7}>
