[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20200402155723.534147ac@kicinski-fedora-PC1C0HJN>
Date: Thu, 2 Apr 2020 15:57:23 -0700
From: Jakub Kicinski <kuba@...nel.org>
To: Leon Romanovsky <leon@...nel.org>
Cc: "David S. Miller" <davem@...emloft.net>,
Leon Romanovsky <leonro@...lanox.com>,
Arjan van de Ven <arjan@...ux.intel.com>,
Cong Wang <xiyou.wangcong@...il.com>,
Jamal Hadi Salim <jhs@...atatu.com>,
Jiri Pirko <jiri@...nulli.us>, netdev@...r.kernel.org,
Itay Aveksis <itayav@...lanox.com>
Subject: Re: [PATCH net] net/sched: Don't print dump stack in event of
transmission timeout
On Thu, 2 Apr 2020 18:23:36 +0300 Leon Romanovsky wrote:
> From: Leon Romanovsky <leonro@...lanox.com>
>
> In event of transmission timeout, the drivers are given an opportunity
> to recover and continue to work after some in-house cleanups.
>
> Such event can be caused by HW bugs, wrong congestion configurations
> and many more other scenarios. In such case, users are interested to
> get a simple "NETDEV WATCHDOG ... " print, which points to the relevant
> netdevice in trouble.
>
> The dump stack printed later was added in the commit b4192bbd85d2
> ("net: Add a WARN_ON_ONCE() to the transmit timeout function") to give
> extra information, like list of the modules and which driver is involved.
>
> While the latter is already printed in "NETDEV WATCHDOG ... ", the list
> of modules rarely needed and can be collected later.
>
> So let's remove the WARN_ONCE() and make dmesg look more user-friendly in
> large cluster setups.
I'm of two minds about this. As much as printing a stack dump here is
not that useful indeed, it's certainly a good way of getting user's
attention. TX queue time outs should never happen, and there's a bunch
of log crawlers out there looking for kernel warnings.
Is there something special about IB here? The sender gets back
pressured into oblivion?
> [ 281.170584] ------------[ cut here ]------------
> [ 281.197120] NETDEV WATCHDOG: ib1 (mlx4_core): transmit queue 0 timed out
> [ 281.198521] WARNING: CPU: 0 PID: 0 at net/sched/sch_generic.c:442 dev_watchdog+0x232/0x240
> [ 281.200259] Modules linked in: bonding ipip tunnel4 geneve ip6_udp_tunnel udp_tunnel ip6_gre ip6_tunnel tunnel6 ip_gre gre ip_tunnel mlx4_en ptp pps_core mlx4_ib mlx4_core rdma_ucm ib_uverbs ib_ipoib ib_umad openvswitch nsh xt_MASQUERADE nf_conntrack_netlink nfnetlink iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 br_netfilter overlay ib_srp scsi_transport_srp rpcrdma ib_iser libiscsi scsi_transport_iscsi rdma_cm iw_cm ib_cm ib_core [last unloaded: mlx4_core]
> [ 281.208290] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.6.0-rc5-J14907-G268960df60ee #1
> [ 281.209954] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.12.1-0-ga5cab58e9a3f-prebuilt.qemu.org 04/01/2014
> [ 281.212281] RIP: 0010:dev_watchdog+0x232/0x240
> [ 281.213260] Code: 85 c0 75 e8 eb a5 4c 89 ef c6 05 dd 9c c4 00 01 e8 d3 b6 fb ff 44 89 e1 4c 89 ee 48 c7 c7 40 54 0b 82 48 89 c2 e8 10 f1 a0 ff <0f> 0b eb 86 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 48 c7 47
> [ 281.217078] RSP: 0018:ffffc90000003e70 EFLAGS: 00010282
> [ 281.218210] RAX: 0000000000000000 RBX: ffff8884521c3ce8 RCX: 0000000000000007
> [ 281.219709] RDX: 0000000000000007 RSI: 0000000000000086 RDI: ffff88846fc18230
> [ 281.221206] RBP: ffff88846daad440 R08: 0000000000000000 R09: 0000000000000249
> [ 281.222697] R10: 0000000000000774 R11: ffffc90000003d25 R12: 0000000000000000
> [ 281.224202] R13: ffff88846daad000 R14: ffff88846daad440 R15: 0000000000000082
> [ 281.225733] FS: 0000000000000000(0000) GS:ffff88846fc00000(0000) knlGS:0000000000000000
> [ 281.227472] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 281.228713] CR2: 00007efd12565000 CR3: 000000043cd3a002 CR4: 0000000000160eb0
> [ 281.230241] Call Trace:
> [ 281.230900] <IRQ>
> [ 281.231469] ? qdisc_put_unlocked+0x30/0x30
> [ 281.232437] call_timer_fn+0x30/0x130
> [ 281.233300] run_timer_softirq+0x18b/0x490
> [ 281.234229] ? timerqueue_add+0x96/0xb0
> [ 281.235119] ? enqueue_hrtimer+0x3d/0x90
> [ 281.236029] __do_softirq+0xdf/0x2e5
> [ 281.236864] irq_exit+0xa0/0xb0
> [ 281.237621] smp_apic_timer_interrupt+0x72/0x120
> [ 281.238652] apic_timer_interrupt+0xf/0x20
> [ 281.239581] </IRQ>
> [ 281.240147] RIP: 0010:default_idle+0x2d/0x150
> [ 281.241133] Code: 00 00 8b 05 3d 75 a7 00 41 54 55 65 8b 2d 6b e0 71 7e 53 85 c0 7f 29 8b 05 c8 97 f7 00 85 c0 7e 07 0f 00 2d 37 56 52 00 fb f4 <8b> 05 15 75 a7 00 65 8b 2d 46 e0 71 7e 85 c0 7f 7f 5b 5d 41 5c c3
> [ 281.244935] RSP: 0018:ffffffff82203ea0 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff13
> [ 281.246584] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000001
> [ 281.248082] RDX: 000000000010db42 RSI: ffffffff82203e40 RDI: 000000416d8a7440
> [ 281.249581] RBP: 0000000000000000 R08: 0000000000000001 R09: 00000041770da407
> [ 281.251069] R10: 0000000000000264 R11: 0000000000000000 R12: ffffffff82211840
> [ 281.252545] R13: 0000000000000000 R14: 0000000000000000 R15: ffffffff82211840
> [ 281.254036] do_idle+0x1ee/0x210
> [ 281.254809] cpu_startup_entry+0x19/0x20
> [ 281.255713] start_kernel+0x490/0x4af
> [ 281.257577] secondary_startup_64+0xa4/0xb0
> [ 281.259147] ---[ end trace 78f566c0214a2cb0 ]---
> [ 281.260866] ib1: transmit timeout: latency 1120 msecs
> [ 281.262730] ib1: queue stopped 1, tx_head 167838, tx_tail 167710
>
> Fixes: b4192bbd85d2 ("net: Add a WARN_ON_ONCE() to the transmit timeout function")
> Signed-off-by: Leon Romanovsky <leonro@...lanox.com>
> ---
> net/sched/sch_generic.c | 5 +++--
> 1 file changed, 3 insertions(+), 2 deletions(-)
>
> diff --git a/net/sched/sch_generic.c b/net/sched/sch_generic.c
> index 6c9595f1048a..c12530fe8b21 100644
> --- a/net/sched/sch_generic.c
> +++ b/net/sched/sch_generic.c
> @@ -439,8 +439,9 @@ static void dev_watchdog(struct timer_list *t)
>
> if (some_queue_timedout) {
> trace_net_dev_xmit_timeout(dev, i);
> - WARN_ONCE(1, KERN_INFO "NETDEV WATCHDOG: %s (%s): transmit queue %u timed out\n",
> - dev->name, netdev_drivername(dev), i);
> + pr_info_once("NETDEV WATCHDOG: %s (%s): transmit queue %u timed out\n",
I'd say pr_err_once(). Or dev_err_once().
> + dev->name,
> + netdev_drivername(dev), i);
> dev->netdev_ops->ndo_tx_timeout(dev, i);
> }
> if (!mod_timer(&dev->watchdog_timer,
> --
> 2.25.1
>
Powered by blists - more mailing lists