From mboxrd@z Thu Jan 1 00:00:00 1970 From: Yuchung Cheng Subject: Re: IPv6 kernel warning Date: Mon, 7 Oct 2013 13:00:56 -0700 Message-ID: References: <20130920131153.GF12758@n2100.arm.linux.org.uk> <20130920160830.GA4241@marquez.int.rhx>

Mime-Version: 1.0 Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: 7BIT Cc: Michele Baldessari , Russell King - ARM Linux , netdev , Neal Cardwell , Nandita Dukkipati To: dormando Return-path: Received: from mail-ie0-f179.google.com ([209.85.223.179]:37585 "EHLO mail-ie0-f179.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1752270Ab3JGUBS convert rfc822-to-8bit (ORCPT ); Mon, 7 Oct 2013 16:01:18 -0400 Received: by mail-ie0-f179.google.com with SMTP id e14so17582226iej.10 for ; Mon, 07 Oct 2013 13:01:17 -0700 (PDT) In-Reply-To: Sender: netdev-owner@vger.kernel.org List-ID: On Mon, Oct 7, 2013 at 12:56 PM, dormando wrote: > On Mon, 7 Oct 2013, Yuchung Cheng wrote: > >> On Mon, Oct 7, 2013 at 11:13 AM, dormando wrote: >> > >> > > > >> > > > there's been multiple reports about this one: >> > > > https://bugzilla.redhat.com/show_bug.cgi?id=989251 >> > > > http://bugzilla.kernel.org/show_bug.cgi?id=60779 >> > > > >> > > > Could you try Yuchung's debug patch? >> > > > http://www.spinics.net/lists/netdev/msg250193.html >> > > Yes it looks like the same bug. Please try that patch to help identify >> > > this elusive bug. >> > > >> > >> > Hi! >> > >> > We get this one a few times a day in production. Here's a warning with >> > your debug trace in the line immediately following: >> > (I censored a few things) >> > >> > [125311.721950] ------------[ cut here ]------------ >> > [125311.721961] WARNING: at net/ipv4/tcp_input.c:2776 tcp_fastretrans_alert+0xb58/0xc80() >> > [125311.721962] Modules linked in: bridge ip_vs macvlan coretemp crc32_pclmul ghash_clmulni_intel gpio_ich ipmi_watchdog microcode ipmi_devintf sb_edac lpc_ich edac_core mfd_core ipmi_si ipmi_msghandler iptable_nat nf_nat_ipv4 nf_nat ixgbe igb mdio i2c_algo_bit ptp pps_core >> > [125311.721981] CPU: 11 PID: 0 Comm: swapper/11 Not tainted 3.10.13 #1 >> > [125311.721982] Hardware name: Supermicro XXXXXXXXXXX, BIOS 1.1 10/03/2012 >> > [125311.721984] ffffffff81a82007 ffff88407fc63958 ffffffff816bb9cc ffff88407fc63998 >> > [125311.721986] ffffffff8104b940 00ff8840ad904f82 ffff883b8a165b00 0000000000004120 >> > [125311.721989] 0000000000000001 0000000000000019 0000000000000000 ffff88407fc639a8 >> > [125311.721991] Call Trace: >> > [125311.721992] [] dump_stack+0x19/0x1d >> > [125311.722002] [] warn_slowpath_common+0x70/0xa0 >> > [125311.722005] [] warn_slowpath_null+0x1a/0x20 >> > [125311.722007] [] tcp_fastretrans_alert+0xb58/0xc80 >> > [125311.722011] [] tcp_ack+0x6df/0xe90 >> > [125311.722016] [] ? ipt_do_table+0x22a/0x680 >> > [125311.722018] [] ? tcp_validate_incoming+0x63/0x320 >> > [125311.722021] [] tcp_rcv_established+0x2cc/0x810 >> > [125311.722023] [] tcp_v4_do_rcv+0x254/0x4f0 >> > [125311.722025] [] tcp_v4_rcv+0x5fc/0x750 >> > [125311.722027] [] ? ip_rcv+0x350/0x350 >> > [125311.722032] [] ? nf_hook_slow+0x7d/0x160 >> > [125311.722034] [] ? ip_rcv+0x350/0x350 >> > [125311.722036] [] ip_local_deliver_finish+0xce/0x250 >> > [125311.722037] [] ip_local_deliver+0x4c/0x80 >> > [125311.722039] [] ip_rcv_finish+0x119/0x360 >> > [125311.722040] [] ip_rcv+0x230/0x350 >> > [125311.722046] [] __netif_receive_skb_core+0x477/0x600 >> > [125311.722049] [] __netif_receive_skb+0x27/0x70 >> > [125311.722051] [] process_backlog+0xf4/0x1e0 >> > [125311.722053] [] net_rx_action+0xf5/0x250 >> > [125311.722056] [] __do_softirq+0xef/0x270 >> > [125311.722058] [] irq_exit+0x95/0xa0 >> > [125311.722062] [] do_IRQ+0x66/0xe0 >> > [125311.722065] [] common_interrupt+0x6a/0x6a >> > [125311.722065] [] ? default_idle+0x21/0xc0 >> > [125311.722082] [] arch_cpu_idle+0xf/0x20 >> > [125311.722086] [] cpu_startup_entry+0xb3/0x230 >> > [125311.722091] [] start_secondary+0x1dc/0x1e3 >> > [125311.722093] ---[ end trace e77cd5ba583fcbe9 ]--- >> > [125311.722096] 355.355.1.355:22496 F0x4120 S1 s7 IF25+17-1-24f0 ur57 rr3 rt0 um0 hs23120 nxt23120 >> > >> > It's been happening with all 3.10 kernels, and the one above is .13 as >> > stated in the trace. >> >> Thanks! could you post the output of `sysctl -a |grep tcp`? >> >> I suspect tcp_process_tlp_ack() should not revert state to Open >> directly, but calling tcp_try_keep_open() instead, similar to all the >> undo processing in the tcp_fastretrans_alert(): after >> tcp_end_cwnd_reduction(), the process (E) falls back to check other >> stats before moving to CA_Open. >> >> >> index 9c62257..9012b42 100644 >> --- a/net/ipv4/tcp_input.c >> +++ b/net/ipv4/tcp_input.c >> @@ -3314,7 +3314,7 @@ static void tcp_process_tlp_ack(struct sock *sk, u32 ack, >> tcp_init_cwnd_reduction(sk, true); >> tcp_set_ca_state(sk, TCP_CA_CWR); >> tcp_end_cwnd_reduction(sk); >> - tcp_set_ca_state(sk, TCP_CA_Open); >> + tcp_try_keep_open(sk); >> NET_INC_STATS_BH(sock_net(sk), >> LINUX_MIB_TCPLOSSPROBERECOVERY); >> } >> > > Should I apply this and see if the warning stops? I'd like to hear what the authors of TLP think. In the mean time could you help us collect more evidence by disabling TLP with sysctl net.ipv4.tcp_early_retrans=2 and see if the problem still occurs? (it should not). thanks > > net.ipv4.tcp_abort_on_overflow = 0 > net.ipv4.tcp_adv_win_scale = 1 > net.ipv4.tcp_allowed_congestion_control = cubic reno > net.ipv4.tcp_app_win = 31 > net.ipv4.tcp_available_congestion_control = cubic reno westwood > net.ipv4.tcp_base_mss = 512 > net.ipv4.tcp_challenge_ack_limit = 100 > net.ipv4.tcp_congestion_control = cubic > net.ipv4.tcp_dma_copybreak = 262144 > net.ipv4.tcp_dsack = 1 > net.ipv4.tcp_early_retrans = 3 > net.ipv4.tcp_ecn = 2 > net.ipv4.tcp_fack = 1 > net.ipv4.tcp_fastopen = 0 > net.ipv4.tcp_fastopen_key = 009dc92c-82e3e514-d440ed23-c49b1a89 > net.ipv4.tcp_fin_timeout = 5 > net.ipv4.tcp_frto = 0 > net.ipv4.tcp_keepalive_intvl = 75 > net.ipv4.tcp_keepalive_probes = 9 > net.ipv4.tcp_keepalive_time = 1800 > net.ipv4.tcp_limit_output_bytes = 131072 > net.ipv4.tcp_low_latency = 0 > net.ipv4.tcp_max_orphans = 2000000 > net.ipv4.tcp_max_ssthresh = 0 > net.ipv4.tcp_max_syn_backlog = 65536 > net.ipv4.tcp_max_tw_buckets = 2000000 > net.ipv4.tcp_mem = 6188001 8250670 12376002 > net.ipv4.tcp_moderate_rcvbuf = 1 > net.ipv4.tcp_mtu_probing = 0 > net.ipv4.tcp_no_metrics_save = 1 > net.ipv4.tcp_orphan_retries = 0 > net.ipv4.tcp_reordering = 3 > net.ipv4.tcp_retrans_collapse = 1 > net.ipv4.tcp_retries1 = 3 > net.ipv4.tcp_retries2 = 15 > net.ipv4.tcp_rfc1337 = 0 > net.ipv4.tcp_rmem = 4096 87380 16777216 > net.ipv4.tcp_sack = 1 > net.ipv4.tcp_slow_start_after_idle = 0 > net.ipv4.tcp_stdurg = 0 > net.ipv4.tcp_syn_retries = 6 > net.ipv4.tcp_synack_retries = 5 > net.ipv4.tcp_syncookies = 1 > net.ipv4.tcp_thin_dupack = 0 > net.ipv4.tcp_thin_linear_timeouts = 0 > net.ipv4.tcp_timestamps = 1 > net.ipv4.tcp_tso_win_divisor = 3 > net.ipv4.tcp_tw_recycle = 0 > net.ipv4.tcp_tw_reuse = 0 > net.ipv4.tcp_user_cwnd_max = 20 > net.ipv4.tcp_window_scaling = 1 > net.ipv4.tcp_wmem = 4096 65536 16777216 > net.ipv4.tcp_workaround_signed_windows = 0 > net.ipv4.vs.secure_tcp = 0 >