<p>I could get a chance to get the backtrace from serial port. I didnt do the kgdb session yet.<br>
To iterate, the crash occurs on TFO server on mips platform.</p>
<p>The call trace looks like this <br>
[ 1024.530000] Call Trace: [ 1024.530000] [<801fc7f4>] reqsk_fastopen_remove+0x30/0x17c [ 1024.530000] [<8024a36c>] tcp_rcv_state_process+0x7b4/0xc28 [ 1024.530000] [<802516ec>] tcp_v4_do_rcv+0x21c/0x274 [ 1024.530000] [<80253c74>] tcp_v4_rcv+0x5b4/0x974 [ 1024.530000] [<802320f0>] ip_local_deliver_finish+0x168/0x29c [ 1024.530000] [<80207100>] __netif_receive_skb+0x63c/0x6c0 [ 1024.530000] [<c060b2e8>] ieee80211_deliver_skb+0x1b8/0x220 [mac80211] [ 1024.530000] [<c060cc70>] ieee80211_rx_handlers.part.12+0x1654/0x23e0 [mac80211] [ 1024.530000] [<c060e468>] ieee80211_prepare_and_rx_handle+0xa6c/0xaf0 [mac80211] [ 1024.530000] [<c060ecfc>] ieee80211_rx+0x810/0x8d8 [mac80211] [ 1024.530000] [<c078651c>] ath_rx_tasklet+0xf4c/0x10a4 [ath9k] [ 1024.530000] [<c078437c>] ath9k_tasklet+0x104/0x174 [ath9k] [ 1024.530000] [<800793b8>] tasklet_action+0x78/0xc8 [ 1024.530000] [<80078c08>] __do_softirq+0xb0/0x184 [ 1024.530000] [<80078d8c>] do_softirq+0x48/0x68 [ 1024.530000] [<80078fa8>] irq_exit+0x4c/0x7c [ 1024.530000] [<8006330c>] ret_from_irq+0x0/0x4 [ 1024.530000] [ 1024.530000] Code: 8e510208 30d300ff 2c420001 <00028036> 0c01e2a7 ac80048c 8e220008 2442ffff ae220008 [ 1024.940000] ---[ end trace a47ff22dd20a96c1 ]---[ 1024.950000] Kernel panic - not syncing: Fatal exception in interrupt</p>
<p>I suspect this is the line responsible for this crash</p>
<p>void reqsk_fastopen_remove(struct sock *sk, struct request_sock *req, bool reset) { struct sock *lsk = tcp_rsk(req)->listener; struct fastopen_queue *fastopenq = inet_csk(lsk)->icsk_accept_ queue.fastopenq;</p>
<p>>>>>> BUG_ON(!spin_is_locked(&sk-> sk_lock.slock) && !sock_owned_by_user(sk));</p>
<p>tcp_sk(sk)->fastopen_rsk = NULL; spin_lock_bh(&fastopenq->lock); fastopenq->qlen--; tcp_rsk(req)->listener = NULL;<br></p>
<p>Please see more details here<br>
<a href="http://www.bufferbloat.net/issues/418#change-1706">http://www.bufferbloat.net/issues/418#change-1706</a></p>
<p>Thanks,<br>
Ketan</p>
<p>On Jan 6, 2013 12:43 AM, "Ketan Kulkarni" <<a href="mailto:ketkulka@gmail.com">ketkulka@gmail.com</a>> wrote:<br>
><br>
> Disabling ECN on cero box has no effect.<br>
> The box crashed with with ECN disabled.<br>
> Also tried enabling ECN on x86 and it didnt crash in either case. The<br>
> tcpdump on cero lo is updated at -<br>
> <a href="https://www.bufferbloat.net/issues/418#change-1703">https://www.bufferbloat.net/issues/418#change-1703</a><br>
> It is exactly similar to the previously attached "lo_capture.txt" but<br>
> with ECN disabled.<br>
><br>
> I might try getting serial cable on Sunday to get the crash details.<br>
> Till then probably I cannot provide the crash logs as logread/dmesg<br>
> does not print anything.<br>
><br>
> Thanks,<br>
> Ketan<br>
><br>
> On Sat, Jan 5, 2013 at 8:32 AM, Ketan Kulkarni <<a href="mailto:ketkulka@gmail.com">ketkulka@gmail.com</a>> wrote:<br>
> > Without TFO all worked fine.<br>
> > The problem is when tfo server is on cero box.<br>
> > I will try both ECN on on laptop and disabling ECN on cero with TFO on. Will<br>
> > report the behavior seen.<br>
> ><br>
> > Thanks,<br>
> > Ketan.<br>
> ><br>
> > On Jan 5, 2013 7:50 AM, "Yuchung Cheng" <<a href="mailto:ycheng@google.com">ycheng@google.com</a>> wrote:<br>
> >><br>
> >> On Fri, Jan 4, 2013 at 5:59 PM, Ketan Kulkarni <<a href="mailto:ketkulka@gmail.com">ketkulka@gmail.com</a>> wrote:<br>
> >> > Well, I was trying polipo server on cero box and httping from laptop. On<br>
> >> > both the boxes I set 3 in tcp_fastopen.<br>
> >> ><br>
> >> > The panic is seen only when server is on cero box.<br>
> >> > If I run server on my laptop and httping from cero all TFO connections<br>
> >> > are<br>
> >> > successful.<br>
> >> > So I doubt its the only problem is SYN+DATA.<br>
> >> Just to confirm: you meant the problem is SYN/data processing on the<br>
> >> server side?<br>
> >><br>
> >> Maybe we hit some ECN / TFO bug. Some crash log would be great. Thanks<br>
> >> for trying TFO!<br>
> >><br>
> >> ><br>
> >> > Unfortunately I don't have the serial cable right now, and logread or<br>
> >> > dmesg<br>
> >> > didn't print any logs before the cero router restarted.<br>
> >> ><br>
> >> > Attached is the tcpdump capture on lo when client and server both run on<br>
> >> > cero box.<br>
> >> > HTH!<br>
> >> ><br>
> >> > If you (or anyone) can suggest more diagnostics, I will be glad to<br>
> >> > provide.<br>
> >> ><br>
> >> > On Jan 5, 2013 2:49 AM, "Jerry Chu" <<a href="mailto:hkchu@google.com">hkchu@google.com</a>> wrote:<br>
> >> >><br>
> >> >> +ycheng<br>
> >> >><br>
> >> >><br>
> >> >> On Fri, Jan 4, 2013 at 1:11 PM, Dave Taht <<a href="mailto:dave.taht@gmail.com">dave.taht@gmail.com</a>> wrote:<br>
> >> >>><br>
> >> >>> Hmm. I would lean towards there being an issue with the new (freshly<br>
> >> >>> ported forward to 3.7.1) unaligned checksum code for mips based on<br>
> >> >>> what you say here. Or an offload...<br>
> >> >>><br>
> >> >>> As for the 239.x multicast issue, hmm... separate issue entirely.<br>
> >> >>> Probably...<br>
> >> >>><br>
> >> >>> And then there's TFO. I note that in order to use it properly you need<br>
> >> >>> to turn it on in proc. Last I remember that was<br>
> >> >>><br>
> >> >>> echo 3 > /proc/sys/net/ipv4/tcp_fastopen<br>
> >> >><br>
> >> >><br>
> >> >> Correct - to enable the normal use of TFO for both client and server.<br>
> >> >> There are other flags for advanced usage:<br>
> >> >> /* Bit Flags for sysctl_tcp_fastopen */<br>
> >> >> #define TFO_CLIENT_ENABLE 1<br>
> >> >> #define TFO_SERVER_ENABLE 2<br>
> >> >> #define TFO_CLIENT_NO_COOKIE 4 /* Send data-in-SYN w/o cookie */<br>
> >> >><br>
> >> >> /* Process SYN data but skip cookie validation */<br>
> >> >> #define TFO_SERVER_COOKIE_NOT_CHKED 0x100<br>
> >> >> /* Accept SYN data w/o any cookie option */<br>
> >> >> #define TFO_SERVER_COOKIE_NOT_REQD 0x200<br>
> >> >><br>
> >> >> /* Force enable TFO on all listeners, i.e., not requiring the<br>
> >> >> * TCP_FASTOPEN socket option. SOCKOPT1/2 determine how to set<br>
> >> >> max_qlen.<br>
> >> >> */<br>
> >> >> #define TFO_SERVER_WO_SOCKOPT1 0x400<br>
> >> >> #define TFO_SERVER_WO_SOCKOPT2 0x800<br>
> >> >> /* Always create TFO child sockets on a TFO listener even when<br>
> >> >> * cookie/data not present. (For testing purpose!)<br>
> >> >> */<br>
> >> >> #define TFO_SERVER_ALWAYS 0x1000<br>
> >> >><br>
> >> >>><br>
> >> >>> However that's an old memory and there is this tcp_fastopen_key file I<br>
> >> >>> don't know anything about yet (this is such bleeding edge stuff!)<br>
> >> >>><br>
> >> >>> ... and with tcp_fastopen disabled things should still work right...<br>
> >> >>> so I'm thinking something else is busted in the stack.<br>
> >> >>><br>
> >> >>> I've also observed a dns slowdown in what I've been testing but hadn't<br>
> >> >>> dug into packet dumps. (and was assuming, until now, it was due to me<br>
> >> >>> fiddling with ULAs inside the network) Thanks for digging this deep!<br>
> >> >>><br>
> >> >>> I never said this first attempt at 3.7 for cero was going to be<br>
> >> >>> perfect, but we've entered a new age of subtle problems here.<br>
> >> >>><br>
> >> >>> I strongly suggest nobody else try this dev build as a default gw, and<br>
> >> >>> that the TFO folk ignore the noise for now.<br>
> >> >><br>
> >> >><br>
> >> >> SG.<br>
> >> >><br>
> >> >> Jerry<br>
> >> >><br>
> >> >>><br>
> >> >>><br>
> >> >>> I just got a 3.7.1 box built on x86_64 so as to a/b some captures.<br>
> >> >>> Regrettably I'm short on time through the weekend...<br>
> >> >>><br>
> >> >>> On Fri, Jan 4, 2013 at 12:42 PM, Maciej Soltysiak<br>
> >> >>> <<a href="mailto:maciej@soltysiak.com">maciej@soltysiak.com</a>><br>
> >> >>> wrote:<br>
> >> >>> > I am seeing something strange here, with polipo related to TFO but<br>
> >> >>> > also<br>
> >> >>> > DNS.<br>
> >> >>> > When I just took 3.7.1-1 and set my windows 7 laptop to use<br>
> >> >>> > gw.home.lan:8123<br>
> >> >>> > as http proxy it didn't work. What I observed was:<br>
> >> >>> > A) after quite a while polipo's response to browser was 504 Host<br>
> >> >>> > <a href="http://www.osnews.com">www.osnews.com</a> lookup failed: Timeout<br>
> >> >>> > b) this error in ssh console: Host <a href="http://osnews.com">osnews.com</a> lookup failed: Timeout<br>
> >> >>> > (131072)<br>
> >> >>> > c) Disabling TFO by adding option useTCPFastOpen 'false' to config<br>
> >> >>> > 'polipo'<br>
> >> >>> > 'general' works around the problem<br>
> >> >>> > d) Alternatively, you can keep TFO enabled in polipo but change<br>
> >> >>> > option<br>
> >> >>> > 'dnsUseGethostbyname' from 'reluctantly' to 'true' (!)<br>
> >> >>> > This is very weird, because TFO is TCP and the DNS queries fired off<br>
> >> >>> > by<br>
> >> >>> > polipo are UDP:<br>
> >> >>> > root@OpenWrt:/tmp/log# tcpdump -n -v -vv -vvv -x -X -s 1500 -i lo<br>
> >> >>> > 20:21:56.160245 IP (tos 0x0, ttl 64, id 50129, offset 0, flags [DF],<br>
> >> >>> > proto<br>
> >> >>> > UDP (17), length 60)<br>
> >> >>> > 127.0.0.1.47304 > 127.0.0.1.53: [bad udp cksum 0xfe3b -> 0xd17f!]<br>
> >> >>> > 55396+ A?<br>
> >> >>> > <a href="http://www.osnews.com">www.osnews.com</a>. (32)<br>
> >> >>> > 0x0000: 4500 003c c3d1 4000 4011 78dd 7f00 0001 E..<..@.@.x.....<br>
> >> >>> > 0x0010: 7f00 0001 b8c8 0035 0028 fe3b d864 0100 .......5.(.;.d..<br>
> >> >>> > 0x0020: 0001 0000 0000 0000 0377 7777 066f 736e .........www.osn<br>
> >> >>> > 0x0030: 6577 7303 636f 6d00 0001 0001 ews.com.....<br>
> >> >>> > 20:21:56.160319 IP (tos 0x0, ttl 64, id 50130, offset 0, flags [DF],<br>
> >> >>> > proto<br>
> >> >>> > UDP (17), length 60)<br>
> >> >>> > 127.0.0.1.47304 > 127.0.0.1.53: [bad udp cksum 0xfe3b -> 0xd164!]<br>
> >> >>> > 55396+<br>
> >> >>> > AAAA? <a href="http://www.osnews.com">www.osnews.com</a>. (32)<br>
> >> >>> > 0x0000: 4500 003c c3d2 4000 4011 78dc 7f00 0001 E..<..@.@.x.....<br>
> >> >>> > 0x0010: 7f00 0001 b8c8 0035 0028 fe3b d864 0100 .......5.(.;.d..<br>
> >> >>> > 0x0020: 0001 0000 0000 0000 0377 7777 066f 736e .........www.osn<br>
> >> >>> > 0x0030: 6577 7303 636f 6d00 001c 0001 ews.com.....<br>
> >> >>> > 20:21:56.169942 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF],<br>
> >> >>> > proto<br>
> >> >>> > UDP<br>
> >> >>> > (17), length 123)<br>
> >> >>> > 127.0.0.1.53 > 127.0.0.1.47304: [bad udp cksum 0xfe7a -> 0x5f73!]<br>
> >> >>> > 55396<br>
> >> >>> > q:<br>
> >> >>> > A? <a href="http://www.osnews.com">www.osnews.com</a>. 1/2/0 <a href="http://www.osnews.com">www.osnews.com</a>. [29m3s] A 74.86.31.159 ns:<br>
> >> >>> > <a href="http://osnews.com">osnews.com</a>. [29m3s] NS <a href="http://ns2.swelter.net">ns2.swelter.net</a>., <a href="http://osnews.com">osnews.com</a>. [29m3s] NS<br>
> >> >>> > <a href="http://ns1.swelter.net">ns1.swelter.net</a>. (95)<br>
> >> >>> > 0x0000: 4500 007b 0000 4000 4011 3c70 7f00 0001 E..{..@.@.<p....<br>
> >> >>> > 0x0010: 7f00 0001 0035 b8c8 0067 fe7a d864 8180 .....5...g.z.d..<br>
> >> >>> > 0x0020: 0001 0001 0002 0000 0377 7777 066f 736e .........www.osn<br>
> >> >>> > 0x0030: 6577 7303 636f 6d00 0001 0001 c00c 0001 ews.com.........<br>
> >> >>> > 0x0040: 0001 0000 06cf 0004 4a56 1f9f c010 0002 ........JV......<br>
> >> >>> > 0x0050: 0001 0000 06cf 0011 036e 7332 0773 7765 .........ns2.swe<br>
> >> >>> > 0x0060: 6c74 6572 036e 6574 00c0 1000 0200 0100 lter.net........<br>
> >> >>> > 0x0070: 0006 cf00 0603 6e73 31c0 40 ......ns1.@<br>
> >> >>> > 20:21:56.173901 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF],<br>
> >> >>> > proto<br>
> >> >>> > UDP<br>
> >> >>> > (17), length 135)<br>
> >> >>> > 127.0.0.1.53 > 127.0.0.1.47304: [bad udp cksum 0xfe86 -> 0x8ecb!]<br>
> >> >>> > 55396<br>
> >> >>> > q:<br>
> >> >>> > AAAA? <a href="http://www.osnews.com">www.osnews.com</a>. 1/2/0 <a href="http://www.osnews.com">www.osnews.com</a>. [54m44s] AAAA<br>
> >> >>> > 2607:f0d0:1002:62::3 ns: <a href="http://osnews.com">osnews.com</a>. [29m3s] NS <a href="http://ns1.swelter.net">ns1.swelter.net</a>.,<br>
> >> >>> > <a href="http://osnews.com">osnews.com</a>. [29m3s] NS <a href="http://ns2.swelter.net">ns2.swelter.net</a>. (107)<br>
> >> >>> > 0x0000: 4500 0087 0000 4000 4011 3c64 7f00 0001 E.....@.@.<d....<br>
> >> >>> > 0x0010: 7f00 0001 0035 b8c8 0073 fe86 d864 8180 .....5...s...d..<br>
> >> >>> > 0x0020: 0001 0001 0002 0000 0377 7777 066f 736e .........www.osn<br>
> >> >>> > 0x0030: 6577 7303 636f 6d00 001c 0001 c00c 001c ews.com.........<br>
> >> >>> > 0x0040: 0001 0000 0cd4 0010 2607 f0d0 1002 0062 ........&......b<br>
> >> >>> > 0x0050: 0000 0000 0000 0003 c010 0002 0001 0000 ................<br>
> >> >>> > 0x0060: 06cf 0011 036e 7331 0773 7765 6c74 6572 .....ns1.swelter<br>
> >> >>> > 0x0070: 036e 6574 00c0 1000 0200 0100 0006 cf00 .net............<br>
> >> >>> > 0x0080: 0603 6e73 32c0 4c ..ns2.L<br>
> >> >>> > This is the only DNS traffic I saw during the attempts. The tcpdumps<br>
> >> >>> > have<br>
> >> >>> > udp bad checksum but when I disabled TFO in polipo, the UDP where<br>
> >> >>> > still<br>
> >> >>> > bad<br>
> >> >>> > checksum but they worked.<br>
> >> >>> > Really weird.<br>
> >> >>> > p.s. UPNP still works for port forwarding negotiation as it did in<br>
> >> >>> > 3.6.11-4<br>
> >> >>> > I still couldn't get the UPNP/SSDP broadcasts (udp to<br>
> >> >>> > 239.255.255.250)<br>
> >> >>> > to<br>
> >> >>> > being forwarded between se00 and sw00/sw10. Last time it worked was<br>
> >> >>> > ~3.3.8.<br>
> >> >>> > I'm starting not to question why it doesn't work, I'm starting to<br>
> >> >>> > wonder why<br>
> >> >>> > it did work then ;-)<br>
> >> >>> > Regards,<br>
> >> >>> > Maciej<br>
> >> >>> > On Fri, Jan 4, 2013 at 6:33 PM, Dave Taht <<a href="mailto:dave.taht@gmail.com">dave.taht@gmail.com</a>><br>
> >> >>> > wrote:<br>
> >> >>> >><br>
> >> >>> >> On Fri, Jan 4, 2013 at 9:27 AM, Eric Dumazet <<a href="mailto:edumazet@google.com">edumazet@google.com</a>><br>
> >> >>> >> wrote:<br>
> >> >>> >> > Sorry, could you give us a copy of the panic stack trace ?<br>
> >> >>> >><br>
> >> >>> >> I will get a serial console up on a wndr3800 by sunday. (sorry,<br>
> >> >>> >> just<br>
> >> >>> >> landed in california, am in disarray)<br>
> >> >>> >><br>
> >> >>> >> The latest dev build of cero for the wndr3800 and wndr3700v2 is at:<br>
> >> >>> >><br>
> >> >>> >> <a href="http://snapon.lab.bufferbloat.net/~cero2/cerowrt/wndr/3.7.1-1/">http://snapon.lab.bufferbloat.net/~cero2/cerowrt/wndr/3.7.1-1/</a><br>
> >> >>> >><br>
> >> >>> >> --<br>
> >> >>> >> Dave Täht<br>
> >> >>> >><br>
> >> >>> >> Fixing bufferbloat with cerowrt:<br>
> >> >>> >> <a href="http://www.teklibre.com/cerowrt/subscribe.html">http://www.teklibre.com/cerowrt/subscribe.html</a><br>
> >> >>> >> _______________________________________________<br>
> >> >>> >> Cerowrt-devel mailing list<br>
> >> >>> >> <a href="mailto:Cerowrt-devel@lists.bufferbloat.net">Cerowrt-devel@lists.bufferbloat.net</a><br>
> >> >>> >> <a href="https://lists.bufferbloat.net/listinfo/cerowrt-devel">https://lists.bufferbloat.net/listinfo/cerowrt-devel</a><br>
> >> >>> ><br>
> >> >>> ><br>
> >> >>><br>
> >> >>><br>
> >> >>><br>
> >> >>> --<br>
> >> >>> Dave Täht<br>
> >> >>><br>
> >> >>> Fixing bufferbloat with cerowrt:<br>
> >> >>> <a href="http://www.teklibre.com/cerowrt/subscribe.html">http://www.teklibre.com/cerowrt/subscribe.html</a><br>
> >> >><br>
> >> >><br>
> >> ><br>
</p>