From owner-freebsd-pf@FreeBSD.ORG Mon Jun 4 06:41:30 2012 Return-Path: Delivered-To: freebsd-pf@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [69.147.83.52]) by hub.freebsd.org (Postfix) with ESMTP id 7A8CD1065672; Mon, 4 Jun 2012 06:41:30 +0000 (UTC) (envelope-from Joerg.Pulz@frm2.tum.de) Received: from mailhost.frm2.tum.de (mailhost.frm2.tum.de [129.187.179.12]) by mx1.freebsd.org (Postfix) with ESMTP id A88B98FC12; Mon, 4 Jun 2012 06:41:29 +0000 (UTC) Received: from mailhost.frm2.tum.de (localhost [127.0.0.1]) by mailhost.frm2.tum.de (8.14.4/8.14.4) with ESMTP id q546eNVA050547; Mon, 4 Jun 2012 08:40:23 +0200 (CEST) (envelope-from Joerg.Pulz@frm2.tum.de) X-Virus-Scanned: at mailhost.frm2.tum.de Received: from hades.admin.frm2 (hades.admin.frm2 [172.25.1.10]) (authenticated bits=0) by mailhost.frm2.tum.de (8.14.4/8.14.4) with ESMTP id q546eJmj050542 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NOT); Mon, 4 Jun 2012 08:40:20 +0200 (CEST) (envelope-from Joerg.Pulz@frm2.tum.de) Date: Mon, 4 Jun 2012 08:40:16 +0200 (CEST) From: Joerg Pulz To: Daniel Hartmeier , =?ISO-8859-15?Q?Ermal_Lu=E7i?= In-Reply-To: Message-ID: References: <201205271830.q4RIU9fA039893@freefall.freebsd.org> <20120529064910.GA12508@insomnia.benzedrine.cx> MIME-Version: 1.0 Content-Type: MULTIPART/MIXED; BOUNDARY="3469798045-1136351326-1338792020=:89783" X-Greylist: Sender succeeded SMTP AUTH, not delayed by milter-greylist-4.2.6 (mailhost.frm2.tum.de [129.187.179.12]); Mon, 04 Jun 2012 08:40:20 +0200 (CEST) Cc: bug-followup@freebsd.org, freebsd-pf@freebsd.org Subject: Re: kern/168190: [pf] panic when using pf and route-to (maybe: bad fragment handling?) X-BeenThere: freebsd-pf@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: "Technical discussion and general questions about packet filter \(pf\)" List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 04 Jun 2012 06:41:30 -0000 This message is in MIME format. The first part should be readable text, while the remaining parts are likely unreadable without MIME-aware tools. --3469798045-1136351326-1338792020=:89783 Content-Type: TEXT/PLAIN; charset=UTF-8; format=flowed Content-Transfer-Encoding: 8BIT -----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 On Fri, 1 Jun 2012, Ermal Luçi wrote: > On Fri, Jun 1, 2012 at 10:25 AM, Joerg Pulz wrote: >> -----BEGIN PGP SIGNED MESSAGE----- >> Hash: SHA1 >> >> >> On Tue, 29 May 2012, Daniel Hartmeier wrote: >> >>> On Sun, May 27, 2012 at 06:30:09PM +0000, Joerg Pulz wrote: >>> >>>>  i've seen 12 more "pf_route: m0->m_len < sizeof(struct ip)" messages >>>> since the system is running after adding your patch, but no panic. >>>>  Is there another place in the code where i can add an additional check? >>> >>> >>> Yes, the following patch adds more checks to pf. >> >> >> Daniel, >> >> after several days waiting for a panic since i applied your new patch, it >> finally happend last night. >> >> Below is the kgdb(1) output. I tried to print as much as possible to give >> you the most informations. >> >> Hope this helps to find the cuase of the trouble or at least to get a bit >> closer. >> >> #### kgdb.out_len >> pf_test() at pf_test+0x259 >> pf_check_out() at pf_check_out+0x71 >> pfil_run_hooks() at pfil_run_hooks+0x113 >> >> ip_output() at ip_output+0x6de >> ip_forward() at ip_forward+0x19e > > It is quite strange that you do not have a pfil_run_hooks() here as well! > Maybe you are running ipsec, if so i would expect that to show in the trace!? > > Can you describe the setup you have in more detail to understand what > interactions are happening with the stack? Ermal, for detailed information please take a look at PR: kern/168190 Everything is described there. Meanwhile, i got five more panics. Four of them look exactly like the first one: panic: pf_test: 1: m->m_pkthdr.len 176, m->m_len 0 and the last one shows: panic: pf_test: 1: m->m_pkthdr.len 310, m->m_len 0 All panics with "m->m_pkthdr.len 176, m->m_len 0" show "bge0" as ifname, which is the external interface. The last panic with "m->m_pkthdr.len 310, m->m_len 0" shows "bge1" as ifname, which is the internal interface. All dumps look like the first one, only interface counters, addresses (memory and involved src and dst) differ. For the sake of completeness, here is the output of the last dump. Any further ideas? Kind regards Joerg #### kgdb.out_len6 GNU gdb 6.1.1 [FreeBSD] Copyright 2004 Free Software Foundation, Inc. GDB is free software, covered by the GNU General Public License, and you are welcome to change it and/or distribute copies of it under certain conditions. Type "show copying" to see the conditions. There is absolutely no warranty for GDB. Type "show warranty" for details. This GDB was configured as "amd64-marcel-freebsd"... Unread portion of the kernel message buffer: panic: pf_test: 1: m->m_pkthdr.len 310, m->m_len 0 cpuid = 0 KDB: stack backtrace: db_trace_self_wrapper() at db_trace_self_wrapper+0x2a kdb_backtrace() at kdb_backtrace+0x37 panic() at panic+0x182 pf_test() at pf_test+0x259 pf_check_out() at pf_check_out+0x71 pfil_run_hooks() at pfil_run_hooks+0x113 ip_output() at ip_output+0x6de ip_forward() at ip_forward+0x19e ip_input() at ip_input+0x680 swi_net() at swi_net+0x15a intr_event_execute_handlers() at intr_event_execute_handlers+0x66 ithread_loop() at ithread_loop+0xaf fork_exit() at fork_exit+0x12a fork_trampoline() at fork_trampoline+0xe - --- trap 0, rip = 0, rsp = 0xffffff8000241d00, rbp = 0 --- KDB: enter: panic Dumping 714 out of 4077 MB:..3%..12%..21%..32%..41%..52%..61%..72%..81%..92% Reading symbols from /boot/kernel/geom_mirror.ko...Reading symbols from /boot/kernel/geom_mirror.ko.symbols...done. done. Loaded symbols for /boot/kernel/geom_mirror.ko Reading symbols from /boot/kernel/ipmi.ko...Reading symbols from /boot/kernel/ipmi.ko.symbols...done. done. Loaded symbols for /boot/kernel/ipmi.ko #0 doadump (textdump=0) at pcpu.h:224 224 __asm("movq %%gs:0,%0" : "=r" (td)); (kgdb) up 10 #10 0xffffffff80326737 in pf_test (dir=2, ifp=0xfffffe0003002000, m0=0xffffff80002418e8, eh=0x0, inp=0x0) at /usr/src/sys/contrib/pf/net/pf.c:6725 6725 panic("pf_test: 1: m->m_pkthdr.len %d, m->m_len %d", (kgdb) list 6720 goto done; 6721 } 6722 6723 if (m->m_pkthdr.len < sizeof(struct ip) || 6724 m->m_len < sizeof(struct ip)) 6725 panic("pf_test: 1: m->m_pkthdr.len %d, m->m_len %d", 6726 (int)m->m_pkthdr.len, (int)m->m_len); 6727 6728 #ifdef __FreeBSD__ 6729 if (m->m_flags & M_SKIP_FIREWALL) { (kgdb) p *m $1 = {m_hdr = {mh_next = 0xfffffe0005a80800, mh_nextpkt = 0x0, mh_data = 0xfffffe001a8bb174 "E", mh_len = 0, mh_flags = 66, mh_type = 1, pad = "­ÞÞÀ­Þ"}, M_dat = {MH = {MH_pkthdr = {rcvif = 0xfffffe0003001800, header = 0x0, len = 310, flowid = 0, csum_flags = 768, csum_data = 26821, tso_segsz = 0, PH_vt = {vt_vtag = 0, vt_nrecs = 0}, tags = {slh_first = 0xfffffe00058bc580}}, MH_dat = {MH_ext = { ext_buf = 0x3765016c0045
, ext_free = 0x376501360045, ext_arg1 = 0x4e79875d91110437, ext_arg2 = 0x3601004557b3bb81, ext_size = 3584, ref_cnt = 0x240119ac05079b0a, ext_type = -239336701}, MH_databuf = "E\000l\001e7\000\000E\0006\001e7\000\0007\004\021\221]\207yN\201»³WE\000\0016\000\016\000\000\177\001zÜ\n\233\a\005¬\031\001$\003\003¼ñ\000\000\000\000E\000\001\032\f\213\000\000>\021°k¬\031\001$\n\233\a\005\0005öf\001\006«û\200[\201\200\000\001\000\001\000\003\000\006ÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­Þ"}}, M_databuf = "\000\030\000\003\000þÿÿ\000\000\000\000\000\000\000\0006\001\000\000\000\000\000\000\000\003\000\000Åh\000\000\000\000\000\000ÞÀ­Þ\200Å\213\005\000þÿÿE\000l\001e7\000\000E\0006\001e7\000\0007\004\021\221]\207yN\201»³WE\000\0016\000\016\000\000\177\001zÜ\n\233\a\005¬\031\001$\003\003¼ñ\000\000\000\000E\000\001\032\f\213\000\000>\021°k¬\031\001$\n\233\a\005\0005öf\001\006«û\200[\201\200\000\001\000\001\000\003\000\006ÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­ÞÞÀ­Þ"...}} (kgdb) p *ifp $2 = {if_softc = 0xffffff80007b1000, if_l2com = 0xfffffe000300ba40, if_vnet = 0x0, if_link = {tqe_next = 0xfffffe0003001000, tqe_prev = 0xfffffe0003001818}, if_xname = "bge1", '\0' , if_dname = 0xfffffe00028f0758 "bge", if_dunit = 1, if_refcount = 1, if_addrhead = {tqh_first = 0xfffffe0003009800, tqh_last = 0xfffffe00059236b8}, if_pcount = 0, if_carp = 0x0, if_bpf = 0xfffffe00050a4880, if_index = 6, if_index_reserved = 0, if_vlantrunk = 0x0, if_flags = 34819, if_capabilities = 524443, if_capenable = 524443, if_linkmib = 0x0, if_linkmiblen = 0, if_data = { ifi_type = 6 '\006', ifi_physical = 0 '\0', ifi_addrlen = 6 '\006', ifi_hdrlen = 18 '\022', ifi_link_state = 2 '\002', ifi_spare_char1 = 0 '\0', ifi_spare_char2 = 0 '\0', ifi_datalen = 152 '\230', ifi_mtu = 1500, ifi_metric = 0, ifi_baudrate = 1000000000, ifi_ipackets = 354876, ifi_ierrors = 0, ifi_opackets = 141821, ifi_oerrors = 0, ifi_collisions = 0, ifi_ibytes = 106681967, ifi_obytes = 12317395, ifi_imcasts = 169195, ifi_omcasts = 0, ifi_iqdrops = 0, ifi_noproto = 0, ifi_hwassist = 3, ifi_epoch = 1, ifi_lastchange = {tv_sec = 1338708223, tv_usec = 13051}}, if_multiaddrs = {tqh_first = 0xfffffe0005926b40, tqh_last = 0xfffffe00058b8d00}, if_amcount = 0, if_output = 0xffffffff8073d2f5 , if_input = 0xffffffff8073c8cb , if_start = 0xffffffff803c2b67 , if_ioctl = 0xffffffff803c8d9a , if_init = 0xffffffff803c8d54 , if_resolvemulti = 0xffffffff8073c28d , if_qflush = 0xffffffff807350b2 , if_transmit = 0xffffffff80734f7e , if_reassign = 0, if_home_vnet = 0x0, if_addr = 0xfffffe0003009800, if_llsoftc = 0x0, if_drv_flags = 64, if_snd = {ifq_head = 0x0, ifq_tail = 0x0, ifq_len = 0, ifq_maxlen = 511, ifq_drops = 0, ifq_mtx = {lock_object = { lo_name = 0xfffffe0003002028 "bge1", lo_flags = 16973824, lo_data = 0, lo_witness = 0xffffff80006cf480}, mtx_lock = 4}, ifq_drv_head = 0x0, ifq_drv_tail = 0x0, ifq_drv_len = 0, ifq_drv_maxlen = 511, altq_type = 0, altq_flags = 1, altq_disc = 0x0, altq_ifp = 0xfffffe0003002000, altq_enqueue = 0, altq_dequeue = 0, altq_request = 0, altq_clfier = 0x0, altq_classify = 0, altq_tbr = 0x0, altq_cdnr = 0x0}, if_broadcastaddr = 0xffffffff80ad06c0 "ÿÿÿÿÿÿ", if_bridge = 0x0, if_label = 0x0, if_prefixhead = {tqh_first = 0x0, tqh_last = 0xfffffe0003002278}, if_afdata = {0x0, 0x0, 0xfffffe0005821a00, 0x0 , 0xfffffe0005815880, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, if_afdata_initialized = 2, if_afdata_lock = { lock_object = {lo_name = 0xffffffff80acf95a "if_afdata", lo_flags = 69402624, lo_data = 0, lo_witness = 0xffffff80006cf400}, rw_lock = 1}, if_linktask = {ta_link = {stqe_next = 0x0}, ta_pending = 0, ta_priority = 0, ta_func = 0xffffffff80737559 , ta_context = 0xfffffe0003002000}, if_addr_mtx = {lock_object = { lo_name = 0xffffffff80ac1a20 "if_addr_mtx", lo_flags = 16973824, lo_data = 0, lo_witness = 0xffffff80006c8b80}, mtx_lock = 4}, if_clones = {le_next = 0x0, le_prev = 0x0}, if_groups = { tqh_first = 0xfffffe0005065ae0, tqh_last = 0xfffffe0005065ae8}, if_pf_kif = 0xfffffe0005888300, if_lagg = 0x0, if_description = 0x0, if_fib = 0, if_alloctype = 6 '\006', if_cspare = "\000\000", if_ispare = {0, 0, 0, 0}, if_pspare = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}} (kgdb) p pd $3 = {lookup = {done = 0, uid = 0, gid = 0, pid = 0}, tot_len = 0, hdr = { tcp = 0x0, udp = 0x0, icmp = 0x0, icmp6 = 0x0, any = 0x0}, nat_rule = 0x0, eh = 0x0, src = 0x0, dst = 0x0, sport = 0x0, dport = 0x0, pf_mtag = 0xfffffe001a43dbd8, p_len = 0, ip_sum = 0x0, proto_sum = 0x0, flags = 0, af = 0 '\0', proto = 0 '\0', tos = 0 '\0', dir = 0 '\0', sidx = 0 '\0', didx = 0 '\0'} (kgdb) p pf_status $4 = {counters = {634320, 0, 0, 0, 0, 0, 0, 0, 320, 0, 6, 0, 0, 0, 0}, lcounters = {0, 0, 0, 0, 0, 0, 0}, fcounters = {719058, 4120, 4008}, scounters = {0, 0, 0}, pcounters = {{{0, 0, 0}, {0, 0, 0}}, {{0, 0, 0}, {0, 0, 0}}}, bcounters = {{0, 0}, {0, 0}}, stateid = 5749708040966246424, running = 1, states = 112, src_nodes = 0, since = 1338708224, debug = 1, hostid = 4123334744, ifname = '\0' , pf_chksum = "quÎ\205<0­ hº\021»¾vi\203"} (kgdb) p pf_status.running $5 = 1 (kgdb) up #11 0xffffffff8032cc7b in pf_check_out (arg=) at /usr/src/sys/contrib/pf/net/pf_ioctl.c:4184 4184 chk = pf_test(PF_OUT, ifp, m, NULL, inp); (kgdb) list 4179 h = mtod(*m, struct ip *); 4180 HTONS(h->ip_len); 4181 HTONS(h->ip_off); 4182 } 4183 CURVNET_SET(ifp->if_vnet); 4184 chk = pf_test(PF_OUT, ifp, m, NULL, inp); 4185 CURVNET_RESTORE(); 4186 if (chk && *m) { 4187 m_freem(*m); 4188 *m = NULL; (kgdb) up #12 0xffffffff8074adcf in pfil_run_hooks (ph=) at /usr/src/sys/net/pfil.c:89 89 rv = (*pfh->pfil_func)(pfh->pfil_arg, &m, ifp, dir, (kgdb) list 84 KASSERT(ph->ph_nhooks >= 0, ("Pfil hook count dropped < 0")); 85 for (pfh = pfil_hook_get(dir, ph); pfh != NULL; 86 pfh = TAILQ_NEXT(pfh, pfil_link)) { 87 if (pfh->pfil_func != NULL) { 88 ASSERT_HOST_BYTE_ORDER(m); 89 rv = (*pfh->pfil_func)(pfh->pfil_arg, &m, ifp, dir, 90 inp); 91 if (rv != 0 || m == NULL) 92 break; 93 ASSERT_HOST_BYTE_ORDER(m); (kgdb) p *pfh $6 = {pfil_link = {tqe_next = 0x0, tqe_prev = 0xfffffe0005821b00}, pfil_func = 0xffffffff8032cc0a , pfil_arg = 0x0} (kgdb) up #13 0xffffffff80776b3a in ip_output (m=0xfffffe001a8bb100, opt=) at /usr/src/sys/netinet/ip_output.c:512 512 error = pfil_run_hooks(&V_inet_pfil_hook, &m, ifp, PFIL_OUT, inp); (kgdb) list 507 goto passout; 508 509 /* Run through list of hooks for output packets. */ 510 odst.s_addr = ip->ip_dst.s_addr; 511 ASSERT_HOST_BYTE_ORDER(m); 512 error = pfil_run_hooks(&V_inet_pfil_hook, &m, ifp, PFIL_OUT, inp); 513 if (error != 0 || m == NULL) 514 goto done; 515 516 ip = mtod(m, struct ip *); (kgdb) p *ip $7 = {ip_hl = 5 '\005', ip_v = 4 '\004', ip_tos = 0 '\0', ip_len = 13825, ip_id = 3584, ip_off = 0, ip_ttl = 127 '\177', ip_p = 1 '\001', ip_sum = 56442, ip_src = {s_addr = 84384522}, ip_dst = {s_addr = 604051884}} (kgdb) p flags $8 = 1 (kgdb) p mtu $9 = 1500 (kgdb) p *ia $10 = {ia_ifa = {ifa_addr = 0xfffffe000592f338, ifa_dstaddr = 0xfffffe000592f348, ifa_netmask = 0xfffffe000592f358, if_data = {ifi_type = 0 '\0', ifi_physical = 0 '\0', ifi_addrlen = 0 '\0', ifi_hdrlen = 0 '\0', ifi_link_state = 0 '\0', ifi_spare_char1 = 0 '\0', ifi_spare_char2 = 0 '\0', ifi_datalen = 0 '\0', ifi_mtu = 0, ifi_metric = 0, ifi_baudrate = 0, ifi_ipackets = 6077, ifi_ierrors = 0, ifi_opackets = 2883, ifi_oerrors = 0, ifi_collisions = 0, ifi_ibytes = 823732, ifi_obytes = 309266, ifi_imcasts = 0, ifi_omcasts = 0, ifi_iqdrops = 0, ifi_noproto = 0, ifi_hwassist = 0, ifi_epoch = 0, ifi_lastchange = {tv_sec = 0, tv_usec = 0}}, ifa_ifp = 0xfffffe0003002000, ifa_link = {tqe_next = 0xfffffe0005923600, tqe_prev = 0xfffffe00030098b8}, ifa_rtrequest = 0, ifa_flags = 5, ifa_refcnt = 7, ifa_metric = 0, ifa_claim_addr = 0, ifa_mtx = { lock_object = {lo_name = 0xffffffff80ad4634 "ifaddr", lo_flags = 16973824, lo_data = 0, lo_witness = 0xffffff80006c8980}, mtx_lock = 4}}, ia_subnet = 2887319808, ia_subnetmask = 4294967040, ia_hash = {le_next = 0x0, le_prev = 0xfffffe000587ff70}, ia_link = { tqe_next = 0x0, tqe_prev = 0xfffffe00058e1d28}, ia_addr = { sin_len = 16 '\020', sin_family = 2 '\002', sin_port = 0, sin_addr = { s_addr = 2533431724}, sin_zero = "\000\000\000\000\000\000\000"}, ia_dstaddr = {sin_len = 16 '\020', sin_family = 2 '\002', sin_port = 0, sin_addr = {s_addr = 4278262188}, sin_zero = "\000\000\000\000\000\000\000"}, ia_sockmask = { sin_len = 7 '\a', sin_family = 2 '\002', sin_port = 0, sin_addr = { s_addr = 16777215}, sin_zero = "\000\000\000\000\000\000\000"}} (kgdb) p *dst $11 = {sin_len = 16 '\020', sin_family = 2 '\002', sin_port = 0, sin_addr = { s_addr = 604051884}, sin_zero = "\000\000\000\000\000\000\000"} (kgdb) #### kgdb.out_len6 - -- The beginning is the most important part of the work. -Plato -----BEGIN PGP SIGNATURE----- Version: GnuPG v2.0.18 (FreeBSD) iD8DBQFPzFhTSPOsGF+KA+MRAtVJAJ4oHrqC8Y4O0q0vHjgnhJ7wrVlE7ACfSkc0 6juyQmrvcT+m74JdfH30tlE= =ayEo -----END PGP SIGNATURE----- --3469798045-1136351326-1338792020=:89783--