Hi,
I've just upgraded via bsd.rd to the 31st of July snapshot and the
crash is still 100% reproductible, please see below.
Syscall 28 is sendmsg so I'm pretty sure that the crash happens the
very first time unbound tries to send a DNS request via the PPPoE
interface. I'm using very similar PF & unbound configs on another
machine and I don't see any issues there. This APU3 box where I see
the crashes is the only one with a PPPoE interface.
Any help to troubleshoot this further is greatly appreciated.
root@APU3 ~ $ sysctl kern.version
kern.version=OpenBSD 6.1-current (GENERIC.MP) #29: Mon Jul 31 16:03:57 MDT 2017
dera...@amd64.openbsd.org:/usr/src/sys/arch/amd64/compile/GENERIC.MP
root@APU3 ~ $ ls -lsah /sbin/pfctl
1184 -r-xr-xr-x 1 root bin 562K Aug 1 00:54 /sbin/pfctl
root@APU3 ~ $ ls -lsah /usr/sbin/unbound
1504 -r-xr-xr-x 1 root bin 725K Aug 1 00:55 /usr/sbin/unbound
root@APU3 ~ $ uptime
9:19AM up 9 mins, 2 users, load averages: 0.05, 0.06, 0.01
root@APU3 ~ $ ifconfig pppoe0
pppoe0: flags=8851<UP,POINTOPOINT,RUNNING,SIMPLEX,MULTICAST> mtu 1492
description: XXXXX Internet Access
index 17 priority 0 llprio 3
dev: em0 state: session
sid: 0xfb0 PADI retries: 1 PADR retries: 0 time: 152d 05:19:04
sppp: phase network authproto pap authname "YYYYYYYYYYYYYY"
groups: pppoe OUTSIDE egress
status: active
inet6 fe80::200:0:bc19:6932%pppoe0 -> prefixlen 64 scopeid 0x11
inet 256.256.256.256 --> 257.257.257.257 netmask 0xffffffff
root@APU3 ~ $ pfctl -s rules | egrep -i ppp
match out on pppoe0 inet proto udp all nat-to (pppoe0) round-robin
match out on pppoe0 inet proto tcp all nat-to (pppoe0) round-robin
match out on pppoe0 inet proto icmp all nat-to (pppoe0) round-robin
pass out on pppoe0 inet proto udp from 0.0.0.0 to any
pass out on pppoe0 inet proto tcp from 0.0.0.0 to any flags S/SA
pass out on pppoe0 inet proto icmp from 0.0.0.0 to any
pass out on pppoe0 inet proto udp from <LOCAL_NETS> to any
pass out on pppoe0 inet proto tcp from <LOCAL_NETS> to any flags S/SA
pass out on pppoe0 inet proto icmp from <LOCAL_NETS> to any
pass in on pppoe0 inet proto tcp from ! <INET_BOGONS> to 0.0.0.0 port = 8080
keep state (source-track rule, max-src-conn 10, max-src-conn-rate 10/5,
overload <BRUTEFORCE> flush global, src.track 5) rdr-to 1.2.3.4
block drop in on pppoe0 inet from no-route to any
block drop in on pppoe0 inet from urpf-failed to any
root@APU3 ~ $ rcctl stop unbound
unbound(ok)
root@APU3 ~ $ pfctl -f /etc/pf.conf
root@APU3 ~ $ pfctl -s rules | egrep -i ppp
match out on pppoe0 inet proto udp all nat-to (pppoe0) round-robin
match out on pppoe0 inet proto tcp all nat-to (pppoe0) round-robin
match out on pppoe0 inet proto icmp all nat-to (pppoe0) round-robin
pass out on pppoe0 inet proto udp from 256.256.256.256 to any
pass out on pppoe0 inet proto tcp from 256.256.256.256 to any flags S/SA
pass out on pppoe0 inet proto icmp from 256.256.256.256 to any
pass out on pppoe0 inet proto udp from <LOCAL_NETS> to any
pass out on pppoe0 inet proto tcp from <LOCAL_NETS> to any flags S/SA
pass out on pppoe0 inet proto icmp from <LOCAL_NETS> to any
pass in on pppoe0 inet proto tcp from ! <INET_BOGONS> to 256.256.256.256 port =
8080 keep state (source-track rule, max-src-conn 10, max-src-conn-rate 10/5,
overload <BRUTEFORCE> flush global, src.track 5) rdr-to 1.2.3.4
block drop in on pppoe0 inet from no-route to any
block drop in on pppoe0 inet from urpf-failed to any
root@APU3 ~ $ rcctl start unbound
unbound(ok)
root@APU3 ~ $ WARNING: SPL NOT LOWERED ON SYSCALL 28 19 EXIT a042fe00 7
Stopped at Xsyscall+0x1d5: movl $0,%gs:0x4e0
ddb{1}>
ddb{1}> trace
Xsyscall(c31fbeffa00,c3231757380,c32d41f9b1f,0,1c,c321b7e7000) at Xsyscall+0x1d5
(null)(c320aa35e00,c32b3118e00,c31fbeffa00,c320aa35e30,0,c3231757380) at
0xc2ff21663a7
(null)(c31fbeffa00,c324dd88800,c324dd88800,c2ff216d5c0,c320aa35e00,a2c109991f039405)
at 0xc2ff216c588
(null)(c31fbeffa00,c31fbeffa00,c324dd88850,c324dd88800,c324dd88800,1781f039405)
at 0xc2ff216c398
(null)(c32b3118e00,c32a3be8ca0,a2c109991f039405,17800000000,c32a3be8ca0,10) at
0xc2ff216dcdf
(null)(10,c32b0d06398,0,c32b0d06080,c32b0d08558,a2c109991f039405) at
0xc2ff216e0cf
(null)(10,c32b0d078b8,c32b0d06298,c32b0d06080,0,801000000000) at 0xc2ff2110954
(null)(c32b0d06080,1,c32b0d06080,c32b0d06298,1,a2c109991f039405) at
0xc2ff217189f
(null)(c32b0d06030,c32b0d06080,0,c3287fc5200,4,a2c109991f039405) at
0xc2ff216f8d2
(null)(100,1,73d4,7f7ffffc3890,1,c3287fc5218) at 0xc2ff2135cbc
(null)(0,7f7ffffc3890,c325bdfb0e0,7f7ffffc3a08,c325bdfb000,a2c109991f039405) at
0xc2ff21355a0
(null)(3,7f7ffffc3a10,c3299506c00,0,c324ad77a00,a2c109991f039405) at
0xc2ff210fd14
(null)(c324ad74110,c32c727d048,c3248f5bd60,a2c109991f039405,c32c727d040,9bcfdc32b0015bc4)
at 0xc2ff2166ba6
(null)(c321e347000,1,e861,0,c2ff2281214,9bcfdc32b0015bc4) at 0xc32c70748d5
(null)(c2ff2281214,c3248f5cf80,c2ff2166211,7f7ffffc3c10,c321e347000,1) at
0xc2ff2166211
(null)(c321e347000,7f7ffffc3e3f,0,c3299506800,1,c324ad3b000) at 0xc2ff21046f8
(null)(c320d512000,3,0,7f7ffffc3d30,7f7ffffc3d38,a2c109991f039405) at
0xc2ff210ddd3
(null)(0,0,0,c2ff21010d0,c2ff2101124,7f7ffffc3d20) at 0xc2ff2101124
end trace frame: 0x0, count: -18
ddb{1}>
ddb{1}> show all procs /n
PID TID PPID UID S FLAGS WAIT COMMAND
60855 137480 69955 0 3 0x100083 nanosleep sleep
* 7693 453850 1 53 7 0x10 unbound
69955 14566 1 0 3 0x100089 pause sh
33333 331599 78678 1000 3 0x100083 ttyin ksh
78678 338753 41833 1000 3 0x90 select sshd
41833 39252 40240 0 3 0x92 poll sshd
32608 393924 1 0 3 0x100083 ttyin ksh
1499 206189 1 0 3 0x100098 poll cron
45863 335368 1 0 3 0x80 nanosleep collectd
45863 241788 1 0 3 0x4000080 fsleep collectd
45863 247444 1 0 3 0x4000080 fsleep collectd
45863 52264 1 0 3 0x4000080 fsleep collectd
45863 482143 1 0 3 0x4000080 fsleep collectd
45863 190426 1 0 3 0x4000080 fsleep collectd
45863 76525 1 0 3 0x4000080 fsleep collectd
45863 476219 1 0 3 0x4000080 fsleep collectd
45863 343934 1 0 3 0x4000080 fsleep collectd
45863 195954 1 0 3 0x4000080 fsleep collectd
45863 333794 1 0 3 0x4000080 fsleep collectd
68054 355831 1 577 3 0x90 poll openvpn
85120 396287 7944 95 3 0x100092 kqread smtpd
76111 192394 7944 103 3 0x100092 kqread smtpd
99511 404639 7944 95 3 0x100092 kqread smtpd
25702 463676 7944 95 3 0x100092 kqread smtpd
83929 6587 7944 95 3 0x100092 kqread smtpd
65544 515369 7944 95 3 0x100092 kqread smtpd
7944 242004 1 0 3 0x100080 kqread smtpd
46250 71230 1 77 3 0x100090 poll dhcpd
40240 275373 1 0 3 0x80 select sshd
93502 387522 40730 83 3 0x100092 poll ntpd
40730 88004 8417 83 3 0x100092 poll ntpd
8417 311120 1 0 3 0x100080 poll ntpd
81760 424335 97650 74 3 0x100090 bpf pflogd
97650 324727 1 0 3 0x80 netio pflogd
99708 516374 94949 73 7 0x100090 syslogd
94949 483041 1 0 3 0x100082 netio syslogd
39715 141848 25185 115 3 0x100092 kqread slaacd
69857 38925 25185 115 3 0x100092 kqread slaacd
25185 8549 1 0 3 0x80 kqread slaacd
72455 330353 0 0 3 0x14200 pgzero zerothread
5416 43026 0 0 3 0x14200 aiodoned aiodoned
16092 48096 0 0 3 0x14200 syncer update
66474 145955 0 0 3 0x14200 cleaner cleaner
61609 510514 0 0 3 0x14200 reaper reaper
92080 239404 0 0 3 0x14200 pgdaemon pagedaemon
27031 232921 0 0 3 0x14200 bored crynlk
8655 193834 0 0 3 0x14200 bored crypto
78189 36557 0 0 3 0x14200 pftm pfpurge
10281 493463 0 0 3 0x14200 bored sensors
23749 435096 0 0 3 0x14200 mmctsk sdmmc0
319 229128 0 0 3 0x14200 usbtsk usbtask
92006 310596 0 0 3 0x14200 usbatsk usbatsk
91388 419810 0 0 3 0x40014200 acpi0 acpi0
13027 445825 0 0 7 0x40014200 idle3
86346 324240 0 0 3 0x40014200 idle2
33377 473579 0 0 3 0x40014200 idle1
86612 372417 0 0 3 0x14200 bored softnet
91674 66300 0 0 3 0x14200 bored systqmp
95212 272582 0 0 3 0x14200 bored systq
56972 130113 0 0 3 0x40014200 bored softclock
58764 136829 0 0 7 0x40014200 idle0
81273 324028 0 0 3 0x14200 bored sbar
1 305559 0 0 3 0x82 wait init
0 0 -1 0 3 0x10200 scheduler swapper
ddb{1}>
ddb{1}> show all procs /o
TID PID UID PRFLAGS PFLAGS CPU COMMAND
*453850 7693 53 0x10 0 1 unbound
516374 99708 73 0x100010 0x80 2 syslogd
ddb{1}>
ddb{1}> boot reboot
panic: kernel diagnostic assertion "_kernel_lock_held()" failed: file
"/usr/src/sys/net/rtsock.c", line 374
Starting stack trace...
panic(0,ffffff00df77f900,ffff800022250e50,ffff8000000bd000,ffffff0009828018,ffff800022250ad0)
at panic+0x11b
__assert(ffffffff810c4da4,ffff800022250b60,0,ffffff00df77f900,ffff800022250e50,ffff8000000bd000)
at __assert+0x24
rtm_report(ffffffff81a9b560,ffff800022250bd8,c31fbeffa00,ffff800022250e50,ffff8000000bd000,0)
at rtm_report
if_down(ffff8000000bd000,0,ffffffff812f0d90,ffff800022250bc0,ffffffff81a9b560,ffff800022250bd8)
at if_down+0x90
if_downall(ffffffff81ac7800,4804,c7218b6358b30eee,ffffffff81ac7800,ffff800022250e50,ffff800022250c78)
at if_downall+0x51
boot(4804,0,ffffffff8105b926,ffff800022250c30,ffffffff81ac7800,4804) at
boot+0x76
reboot(0,1,ffffffff812620bb,ffff800022250c50,4804,0) at reboot+0x4b
db_boot_reboot_cmd(ffffffff812d262e,ffff800022250c60,0,1,ffffffff812620bb,ffff800022250c50)
at db_boot_reboot_cmd+0xe
db_command(1,0,0,c7218b6358b30eee,ffffffff812c22ea,ffff800022250d10) at
db_command+0x28d
db_command_loop(0,c7218b6358b30eee,ffffffff812d2971,1,0,c31fbeffa00) at
db_command_loop+0x86
db_trap(7,c7218b6358b30eee,813b6725,ffff800022250db0,ffffffff816d2734,ffff800022250db0)
at db_trap+0x134
db_ktrap(ffff800022115418,ffff800022250e50,ffff80002224c000,1,ffffffff813de3e4,ffff800022250de0)
at db_ktrap+0xe4
trap() at trap+0x3f4
--- trap (number 1) ---
end of kernel
end trace frame: 0x7f7ffffc2e80, count: 244
Xsyscall+0x1d5:
End of stack trace.
syncing disks...
