Differential D49212
route: protect against unattached if_afdata Authored by franco_opnsense.org on Mon, Mar 3, 10:21 AM. Tags None Referenced Files
Details For pppoe/ng interfaces sometimes we enter ip6_tryforward() with While here remove the RT_LINK_IS_UP macro since nothing outside PR: 285129
Diff Detail
Event TimelineComment Actions I think we need to understand the underlying problem better: adding these extra checks to the data path is something to be avoided, and most likely they only make an existing race smaller rather than eliminating it. Is the interface being torn down? Can you dump the ifnet structure and see from the vmcore if a different CPU was running if_detach_internal()? /usr/libexec/kgdb/acttrace.py should help with this; crashinfo(8) runs it automatically. Looking at if_detach_internal(), it calls rt_flushifroutes(), then deletes afdata, and there's no synchronization (e.g., NET_EPOCH_WAIT) with the data path. That's probably the real bug, assuming that this crash happens during interface teardown. Comment Actions Last bits in dmesg, perhaps unrelated: ng0: changing name to 'pppoe0' ovpnc1: link state changed to UP ifp dump: (kgdb) p *nifp
$1 = {if_link = {cstqe_next = 0x0}, if_clones = {le_next = 0x0, le_prev = 0x0}, if_groups = {cstqh_first = 0x0,
cstqh_last = 0xfffff80051e6f018}, if_alloctype = 53 '5', if_numa_domain = 255 '\377', if_softc = 0xfffff8006588fa00,
if_llsoftc = 0x0, if_l2com = 0x0, if_dname = 0xffffffff834773c9 "ng", if_dunit = 0, if_index = 15, if_idxgen = 4,
if_xname = "pppoe0\000\000\000\000\000\000\000\000\000", if_description = 0xfffff8002675c530 "AQUISS (opt1)", if_flags = 2132112,
if_drv_flags = 0, if_capabilities = 0, if_capabilities2 = 0, if_capenable = 0, if_capenable2 = 0, if_linkmib = 0x0, if_linkmiblen = 0,
if_refcount = 4, if_type = 53 '5', if_addrlen = 0 '\000', if_hdrlen = 0 '\000', if_link_state = 0 '\000', if_mtu = 1500,
if_metric = 0, if_baudrate = 64000, if_hwassist = 0, if_epoch = 4321, if_lastchange = {tv_sec = 1740916734, tv_usec = 199361},
if_snd = {ifq_head = 0x0, ifq_tail = 0x0, ifq_len = 0, ifq_maxlen = 50, ifq_mtx = {lock_object = {
lo_name = 0xfffff80051e6f058 "pppoe0", lo_flags = 16973824, lo_data = 0, lo_witness = 0x0}, mtx_lock = 0}, ifq_drv_head = 0x0,
ifq_drv_tail = 0x0, ifq_drv_len = 0, ifq_drv_maxlen = 50, altq_type = 0, altq_flags = 1, altq_disc = 0x0,
altq_ifp = 0xfffff80051e6f000, altq_enqueue = 0x0, altq_dequeue = 0x0, altq_request = 0x0, altq_tbr = 0x0, altq_cdnr = 0x0},
if_linktask = {ta_link = {stqe_next = 0x0}, ta_pending = 0, ta_priority = 0 '\000', ta_flags = 0 '\000',
ta_func = 0xffffffff80d00d60 <do_link_state_change>, ta_context = 0xfffff80051e6f000}, if_addmultitask = {ta_link = {
stqe_next = 0x0}, ta_pending = 0, ta_priority = 0 '\000', ta_flags = 0 '\000', ta_func = 0xffffffff80d01080 <if_siocaddmulti>,
ta_context = 0xfffff80051e6f000}, if_addr_lock = {lock_object = {lo_name = 0xffffffff812b77d6 "if_addr_lock", lo_flags = 16973824,
lo_data = 0, lo_witness = 0x0}, mtx_lock = 0}, if_addrhead = {cstqh_first = 0x0, cstqh_last = 0xfffff80051e6f1c0},
if_multiaddrs = {cstqh_first = 0x0, cstqh_last = 0xfffff80051e6f1d0}, if_amcount = 0, if_addr = 0xfffff80023d0c900, if_hw_addr = 0x0,
if_broadcastaddr = 0x0, if_afdata_lock = {lock_object = {lo_name = 0xffffffff813524c5 "if_afdata", lo_flags = 16973824, lo_data = 0,
lo_witness = 0x0}, mtx_lock = 0}, if_afdata = {0x0 <repeats 44 times>}, if_afdata_initialized = 0, if_fib = 0,
if_vnet = 0xfffff80004174c00, if_home_vnet = 0xfffff80004174c00, if_vlantrunk = 0x0, if_bpf = 0xffffffff8147fc68 <dead_bpf_if>,
if_pcount = 0, if_bridge = 0x0, if_lagg = 0x0, if_pf_kif = 0x0, if_carp = 0x0, if_label = 0x0, if_netmap = 0x0,
if_output = 0xffffffff80d04460 <ifdead_output>, if_input = 0xffffffff80d04480 <ifdead_input>, if_bridge_input = 0x0,
if_bridge_output = 0x0, if_bridge_linkstate = 0x0, if_start = 0xffffffff80d04490 <ifdead_start>,
if_ioctl = 0xffffffff80d044a0 <ifdead_ioctl>, if_init = 0x0, if_resolvemulti = 0xffffffff80d044b0 <ifdead_resolvemulti>,
if_qflush = 0xffffffff80d044d0 <ifdead_qflush>, if_transmit = 0xffffffff80d044e0 <ifdead_transmit>, if_reassign = 0x0,
if_get_counter = 0xffffffff80d04500 <ifdead_get_counter>, if_requestencap = 0xffffffff80d012d0 <if_requestencap_default>,
if_counters = {0xfffffe00f2c331d8, 0xfffffe00f2c33b38, 0xfffffe00f2c33ab0, 0xfffffe00f2c33ab8, 0xfffffe00ecfce710, 0xfffffe00ecfce708,
0xfffffe00f2c33948, 0xfffffe00ecf36d80, 0xfffffe00ecf36d88, 0xfffffe00ecf36d90, 0xfffffe00ecf36d08, 0xfffffe00ecf3a3a0},
if_hw_tsomax = 65518, if_hw_tsomaxsegcount = 35, if_hw_tsomaxsegsize = 2048,
if_snd_tag_alloc = 0xffffffff80d04510 <ifdead_snd_tag_alloc>, if_ratelimit_query = 0xffffffff80d04520 <ifdead_ratelimit_query>,
if_ratelimit_setup = 0x0, if_pcp = 255 '\377', if_debugnet_methods = 0x0, if_epoch_ctx = {data = {0x0, 0x0}}, if_ispare = {0, 0, 0, 0}}CPUS: (kgdb) Tracing command "kernel", '\000' <repeats 13 times> pid 0 tid 100011 (CPU 0)
#0 __curthread () at /usr/src/sys/amd64/include/pcpu_aux.h:57
#1 doadump (textdump=textdump@entry=0)
at /usr/src/sys/kern/kern_shutdown.c:405
#2 0xffffffff8049d3ea in db_dump (dummy=<optimized out>,
dummy2=<optimized out>, dummy3=<optimized out>, dummy4=<optimized out>)
at /usr/src/sys/ddb/db_command.c:591
#3 0xffffffff8049d1ed in db_command (last_cmdp=<optimized out>,
cmd_table=<optimized out>, dopager=false)
at /usr/src/sys/ddb/db_command.c:504
#4 0xffffffff8049d336 in db_command_script (
command=command@entry=0xffffffff81bbf6d3 <db_recursion_data+3> "dump")
at /usr/src/sys/ddb/db_command.c:569
#5 0xffffffff804a25a8 in db_script_exec (scriptname=<optimized out>,
warnifnotfound=warnifnotfound@entry=0) at /usr/src/sys/ddb/db_script.c:302
#6 0xffffffff804a24b5 in db_script_kdbenter (eventname=<optimized out>)
at /usr/src/sys/ddb/db_script.c:325
#7 0xffffffff804a0571 in db_trap (type=<optimized out>, code=<optimized out>)
at /usr/src/sys/ddb/db_main.c:267
#8 0xffffffff80c14388 in kdb_trap (type=type@entry=3, code=code@entry=0,
tf=tf@entry=0xfffffe0003796650) at /usr/src/sys/kern/subr_kdb.c:790
#9 0xffffffff81100839 in trap (frame=0xfffffe0003796650)
at /usr/src/sys/amd64/amd64/trap.c:608
#10 <signal handler called>
#11 kdb_enter (why=<optimized out>, msg=<optimized out>)
at /usr/src/sys/kern/subr_kdb.c:556
#12 0xffffffff80bc2e12 in vpanic (fmt=0xffffffff8127db5c "%s",
ap=ap@entry=0xfffffe0003796880) at /usr/src/sys/kern/kern_shutdown.c:955
#13 0xffffffff80bc2ec3 in panic (fmt=0xffffffff81d82b38 <cnputs_mtx+24> "")
at /usr/src/sys/kern/kern_shutdown.c:891
#14 0xffffffff811012cb in trap_fatal (frame=0xfffffe0003796960, eva=16)
at /usr/src/sys/amd64/amd64/trap.c:952
#15 0xffffffff81101327 in trap_pfault (frame=<optimized out>,
usermode=<optimized out>, signo=<optimized out>, ucode=<optimized out>)
at /usr/src/sys/amd64/amd64/trap.c:760
#16 <signal handler called>
#17 0xffffffff80e0f6fc in ip6_tryforward (m=0xfffff80053520d00)
at /usr/src/sys/netinet6/ip6_fastfwd.c:194
#18 0xffffffff80e11ab9 in ip6_input (m=0xfffff80053520d00)
at /usr/src/sys/netinet6/ip6_input.c:737
#19 0xffffffff80d2362e in netisr_dispatch_src (proto=proto@entry=6,
source=source@entry=0, m=0xfffff80053520d00)
at /usr/src/sys/net/netisr.c:1152
#20 0xffffffff80d23a0f in netisr_dispatch (proto=1374089216, proto@entry=6,
m=0xfffff80026ed9c78) at /usr/src/sys/net/netisr.c:1243
#21 0xffffffff80d05019 in ether_demux (ifp=ifp@entry=0xfffff8000491c800,
m=0xfffff80053520d00) at /usr/src/sys/net/if_ethersubr.c:960
#22 0xffffffff80d067c9 in ether_input_internal (ifp=0xfffff8000491c800,
m=0xfffff80053520d00) at /usr/src/sys/net/if_ethersubr.c:718
#23 ether_nh_input (m=<optimized out>) at /usr/src/sys/net/if_ethersubr.c:748
#24 0xffffffff80d2362e in netisr_dispatch_src (proto=proto@entry=5,
source=source@entry=0, m=0xfffff80053520d00)
at /usr/src/sys/net/netisr.c:1152
#25 0xffffffff80d23a0f in netisr_dispatch (proto=1374089216, proto@entry=5,
m=0xfffff80026ed9c78) at /usr/src/sys/net/netisr.c:1243
#26 0xffffffff80d05515 in ether_input (ifp=0xfffff8000491c800,
m=<optimized out>) at /usr/src/sys/net/if_ethersubr.c:865
#27 0xffffffff80d1f0e3 in iflib_rxeof (rxq=rxq@entry=0xfffff80004c4f000,
budget=<optimized out>) at /usr/src/sys/net/iflib.c:3084
#28 0xffffffff80d18dba in _task_fn_rx (context=0xfffff80004c4f000)
at /usr/src/sys/net/iflib.c:4158
#29 0xffffffff80c1246e in gtaskqueue_run_locked (
queue=queue@entry=0xfffff800044f3d00)
at /usr/src/sys/kern/subr_gtaskqueue.c:369
#30 0xffffffff80c121d3 in gtaskqueue_thread_loop (
arg=arg@entry=0xfffffe0003fb5008)
at /usr/src/sys/kern/subr_gtaskqueue.c:545
#31 0xffffffff80b75602 in fork_exit (
callout=0xffffffff80c12100 <gtaskqueue_thread_loop>,
arg=0xfffffe0003fb5008, frame=0xfffffe0003796f40)
at /usr/src/sys/kern/kern_fork.c:1164
#32 <signal handler called>
Tracing command "idle\000l", '\000' <repeats 13 times> pid 11 tid 100004 (CPU 1)
#0 cpustop_handler () at /usr/src/sys/x86/x86/mp_x86.c:1527
#1 0xffffffff810c6888 in ipi_nmi_handler ()
at /usr/src/sys/x86/x86/mp_x86.c:1484
#2 0xffffffff811005c7 in trap (frame=0xfffffe0003db1f30)
at /usr/src/sys/amd64/amd64/trap.c:237
#3 <signal handler called>
#4 acpi_cpu_c1 () at /usr/src/sys/x86/x86/cpu_machdep.c:247
#5 0xffffffff804c4752 in acpi_cpu_idle (sbt=<optimized out>)
at /usr/src/sys/dev/acpica/acpi_cpu.c:1157
#6 0xffffffff810bbb30 in cpu_idle_acpi (sbt=274192962)
at /usr/src/sys/x86/x86/cpu_machdep.c:590
#7 0xffffffff810bbc16 in cpu_idle (busy=0)
at /usr/src/sys/x86/x86/cpu_machdep.c:679
#8 0xffffffff80bf8e84 in sched_idletd (dummy=dummy@entry=0x0)
at /usr/src/sys/kern/sched_ule.c:3061
#9 0xffffffff80b75602 in fork_exit (
callout=0xffffffff80bf8950 <sched_idletd>, arg=0x0,
frame=0xfffffe0003769f40) at /usr/src/sys/kern/kern_fork.c:1164
#10 <signal handler called>
#11 0x0019c00122300014 in ?? ()
Backtrace stopped: Cannot access memory at address 0x481980e8
Tracing command "idle\000l", '\000' <repeats 13 times> pid 11 tid 100005 (CPU 2)
#0 cpustop_handler () at /usr/src/sys/x86/x86/mp_x86.c:1527
#1 0xffffffff810c6888 in ipi_nmi_handler ()
at /usr/src/sys/x86/x86/mp_x86.c:1484
#2 0xffffffff811005c7 in trap (frame=0xfffffe0003dc0f30)
at /usr/src/sys/amd64/amd64/trap.c:237
#3 <signal handler called>
#4 acpi_cpu_c1 () at /usr/src/sys/x86/x86/cpu_machdep.c:247
#5 0xffffffff804c4752 in acpi_cpu_idle (sbt=<optimized out>)
at /usr/src/sys/dev/acpica/acpi_cpu.c:1157
#6 0xffffffff810bbb30 in cpu_idle_acpi (sbt=432877283)
at /usr/src/sys/x86/x86/cpu_machdep.c:590
#7 0xffffffff810bbc16 in cpu_idle (busy=0)
at /usr/src/sys/x86/x86/cpu_machdep.c:679
#8 0xffffffff80bf8e84 in sched_idletd (dummy=dummy@entry=0x0)
at /usr/src/sys/kern/sched_ule.c:3061
#9 0xffffffff80b75602 in fork_exit (
callout=0xffffffff80bf8950 <sched_idletd>, arg=0x0,
frame=0xfffffe0003764f40) at /usr/src/sys/kern/kern_fork.c:1164
#10 <signal handler called>
Tracing command "idle\000l", '\000' <repeats 13 times> pid 11 tid 100006 (CPU 3)
#0 cpustop_handler () at /usr/src/sys/x86/x86/mp_x86.c:1527
#1 0xffffffff810c6888 in ipi_nmi_handler ()
at /usr/src/sys/x86/x86/mp_x86.c:1484
#2 0xffffffff811005c7 in trap (frame=0xfffffe0003dcff30)
at /usr/src/sys/amd64/amd64/trap.c:237
#3 <signal handler called>
#4 acpi_cpu_c1 () at /usr/src/sys/x86/x86/cpu_machdep.c:247
#5 0xffffffff804c4752 in acpi_cpu_idle (sbt=<optimized out>)
at /usr/src/sys/dev/acpica/acpi_cpu.c:1157
#6 0xffffffff810bbb30 in cpu_idle_acpi (sbt=373828983)
at /usr/src/sys/x86/x86/cpu_machdep.c:590
#7 0xffffffff810bbc16 in cpu_idle (busy=0)
at /usr/src/sys/x86/x86/cpu_machdep.c:679
#8 0xffffffff80bf8e84 in sched_idletd (dummy=dummy@entry=0x0)
at /usr/src/sys/kern/sched_ule.c:3061
#9 0xffffffff80b75602 in fork_exit (
callout=0xffffffff80bf8950 <sched_idletd>, arg=0x0,
frame=0xfffffe000375ff40) at /usr/src/sys/kern/kern_fork.c:1164
#10 <signal handler called>Comment Actions In if_flags I see that IFF_DYING is set, which suggests that my theory explains the crash. I think this should be reproducible with a test setup that 1) creates and tears down a PPPoE interface in a loop, 2) tries to send traffic over some route assigned to the interface. Would you be willing to try that? As for a solution, we can call NET_EPOCH_WAIT() after purging routes in if_detach_internal(), though that's something of a band-aid. The general pattern in if_detach_internal() should be to first remove the ifnet from globally visible data structures, then block and drain readers, then tear down the structure. Comment Actions Does NET_EPOCH_WAIT() and NET_EPOCH_ENTER() establish a happens-before order ? i.e., thread A: foo = "bar"; NET_EPOCH_WAIT(); thread B: NET_EPOCH_ENTER(); MPASS(foo == "bar"); If that works, I'd proposal moving if_down(ifp) up, prior to NET_EPOCH_WAIT(), as the ether_input_internal() is in net epoch, and checks the status of the interface before passing the mbuf to upper layer. static void ether_input_internal(struct ifnet *ifp, struct mbuf *m) { struct ether_header *eh; u_short etype; if ((ifp->if_flags & IFF_UP) == 0) { m_freem(m); return; } ... +++ if_down(ifp); /* * At this point we know the interface still was on the ifnet list * and we removed it so we are in a stable state. */ NET_EPOCH_WAIT(); /* * Ensure all pending EPOCH(9) callbacks have been executed. This * fixes issues about late destruction of multicast options * which lead to leave group calls, which in turn access the * belonging ifnet structure: */ NET_EPOCH_DRAIN_CALLBACKS(); /* * In any case (destroy or vmove) detach us from the groups * and remove/wait for pending events on the taskq. * XXX-BZ in theory an interface could still enqueue a taskq change? */ if_delgroups(ifp); taskqueue_drain(taskqueue_swi, &ifp->if_linktask); taskqueue_drain(taskqueue_swi, &ifp->if_addmultitask); --- if_down(ifp); Probably we also want to invoke EVENTHANDLER_INVOKE(ifnet_departure_event, ifp); earlier. Comment Actions I think the root cause is, thread A NET_EPOCH_WAIT() does not block thread B's NET_EPOCH_ENTER(). Well the net epoch does protect the liveness of ifp, but it does not guard ifp's state from been changed. For example the two threads execute in the following sequence, Thread A: NET_EPOCH_WAIT() NET_EPOCH_DRAIN_CALLBACKS if_delgroups taskqueue_drain Thread B: NET_EPOCH_ENTER ether_input_internal() /* (ifp->if_flags & IFF_UP) != 0 */ Thread A: if_down(ifp); if_purgeaddrs(ifp) in_ifdetach in6_ifdetach if_purgemaddrs EVENTHANDLER_INVOKE(ifnet_departure_event, ifp) rt_flushifroutes ifp->if_afdata_initialized = 0; ifp->if_afdata[dp->dom_family] = NULL Thread B: ip6_input() /* ifp->if_afdata[dp->dom_family] == NULL, panic() */ Comment Actions Previous work D45690 by @takahiro.kurosawa_gmail.com . That is IMHO brute force and may relief the issue, but the net stack will have to check the unstable state of ifp a lot. Comment Actions I'm happy to pass an alternative patch on to the affected users, but I'm unable to reproduce this locally. Comment Actions I had a look at the implementation of epoch_wait_preempt() and epoch_enter_preempt(). epoch_wait_preempt calls ck_epoch_synchronize_wait() which has memory barrier ck_pr_fence_memory(), and epoch_enter_preempt() calls ck_epoch_begin() which has memory barrier, ck_pr_fence_atomic_load() or ck_pr_fence_memory(). So I think the happens-before order, NET_EPOCH_WAIT() -> NET_EPOCH_ENTER() is true. I'm preparing the test and the patch. Hopefully this long standing issue will be fixed perfectly.
Comment Actions Right, the whole point is to avoid blocking latency-sensitive readers. I think deferring freeing of afdata also makes sense as a solution. Comment Actions Right, it is the same bug. I have started a branch where we completely get rid of notion of initialized/non-initialized if_afdata[]. Also we get rid of the array, because this array has only two members initialized (IPv4 and IPv6) but blows up struct ifnet to span several cache lines. @gallatin actually demonstrated that this has a measurable impact. I wish we had a stress test to trigger the bug, that would help me a lot to prove that my branch actually fixes the problem. Comment Actions Happy to see this progress. Do you think removing RT_LINK_IS_UP without adding the additional conditional would be a useful cleanup nonetheless? Half the code uses NH_IS_VALID, the other RT_LINK_IS_UP and all of it is within NH scope nowadays. Comment Actions Thank you for woking on this!
Comment Actions Thanks for the review. I added https://reviews.freebsd.org/D49353 based on your comments. | |||||||||||||||||||||||||||||||||||||||||