From mboxrd@z Thu Jan 1 00:00:00 1970 From: Cong Wang Subject: Re: [v5 Patch 1/3] netpoll: add generic support for bridge and bonding devices Date: Fri, 28 May 2010 10:47:01 +0800 Message-ID: <4BFF2EA5.9090008@redhat.com> References: <20100505081514.5157.83783.sendpatchset@localhost.localdomain> <20100527180545.GA2345@sysclose.org> Mime-Version: 1.0 Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Cc: linux-kernel@vger.kernel.org, Matt Mackall , netdev@vger.kernel.org, bridge@lists.linux-foundation.org, Andy Gospodarek , Neil Horman , Jeff Moyer , Stephen Hemminger , bonding-devel@lists.sourceforge.net, Jay Vosburgh , David Miller To: Flavio Leitner Return-path: Received: from mx1.redhat.com ([209.132.183.28]:56614 "EHLO mx1.redhat.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1755143Ab0E1Cnc (ORCPT ); Thu, 27 May 2010 22:43:32 -0400 In-Reply-To: <20100527180545.GA2345@sysclose.org> Sender: netdev-owner@vger.kernel.org List-ID: On 05/28/10 02:05, Flavio Leitner wrote: > > Hi guys! > > I finally could test this to see if an old problem reported on bugzilla[1] was > fixed now, but unfortunately it is still there. > > The ticket is private I guess, but basically the problem happens when bonding > driver tries to print something after it had taken the write_lock (monitor > functions, enslave/de-enslave), so the printk() will pass through netpoll, then > on bonding again which no matter what mode you use, it will try to read_lock() > the lock again. The result is a deadlock and the entire system hangs. This is true, I already fixed some similar issues. > > I manage to get a fresh backtrace with mode 1, see below: > > > [ 93.167079] Call Trace: > [ 93.167079] [] warn_slowpath_common+0x77/0x8f > [ 93.167079] [] warn_slowpath_fmt+0x3c/0x3e > [ 93.167079] [] ? _raw_read_trylock+0x11/0x4b > [ 93.167079] [] ? bond_start_xmit+0x12b/0x401 [bonding] > -> read_lock fails > [ 93.167079] [] bond_start_xmit+0x188/0x401 [bonding] > [ 93.167079] [] ? trace_hardirqs_off+0xd/0xf > [ 93.167079] [] netpoll_send_skb+0xbd/0x1f3 > [ 93.167079] [] netpoll_send_udp+0x1fe/0x20d > [ 93.167079] [] write_msg+0x89/0xcd [netconsole] > [ 93.167079] [] __call_console_drivers+0x67/0x79 > [ 93.167079] [] _call_console_drivers+0x59/0x5d > [ 93.167079] [] release_console_sem+0x121/0x1d7 > [ 93.167079] [] vprintk+0x35d/0x393 > [ 93.167079] [] ? add_timer+0x17/0x19 > [ 93.167079] [] ? queue_delayed_work_on+0xa2/0xa9 > [ 93.167079] [] printk+0x3c/0x44 > [ 93.167079] [] bond_select_active_slave+0x105/0x109 [bonding] > -> write_locked > [ 93.167079] [] bond_mii_monitor+0x479/0x4ed [bonding] > [ 93.167079] [] worker_thread+0x1ef/0x2e2 > > In this case, the message should be > "bonding: bond0: making interface eth0 the new active one" Hmm, you triggered a warning here, let me check the source code and try to reproduce it here. > > I did the following patch to discard the packet if it was IN_NETPOLL > and the read_lock() fails, so I could go ahead testing it: > > diff --git a/drivers/net/bonding/bond_main.c b/drivers/net/bonding/bond_main.c > index 5e12462..a3b8bad 100644 > --- a/drivers/net/bonding/bond_main.c > +++ b/drivers/net/bonding/bond_main.c > @@ -4258,8 +4258,19 @@ static int bond_xmit_activebackup(struct sk_buff *skb, struct net_device *bond_d > struct bonding *bond = netdev_priv(bond_dev); > int res = 1; > > - read_lock(&bond->lock); > - read_lock(&bond->curr_slave_lock); > + if (read_trylock(&bond->lock) == 0&& > + (bond_dev->flags& IFF_IN_NETPOLL)) { > + dev_kfree_skb(skb); > + return NETDEV_TX_OK; > + } > + > + if (read_trylock(&bond->curr_slave_lock) == 0&& > + (bond_dev->flags& IFF_IN_NETPOLL)) { > + read_unlock(&bond->lock); > + dev_kfree_skb(skb); > + return NETDEV_TX_OK; > + } > + > > if (!BOND_IS_OK(bond)) > goto out; > This looks like a workaround, not a fix. :) > > and I found another problem. The function netpoll_send_skb() checks > if the npinfo's queue length is zero and if it's not, it will queue > the packet to make sure it's in order and then schedule the thread > to run. Later, the thread wakes up running queue_process() which disables > interrupts before calling ndo_start_xmit(). However, dev_queue_xmit() > uses rcu_*_bh() and before return, it will enable the interrupts again, > spitting this: > > ------------[ cut here ]------------ > WARNING: at kernel/softirq.c:143 local_bh_enable+0x3c/0x86() > Hardware name: Precision WorkStation 490 > Modules linked in: netconsole bonding sunrpc ip6t_REJECT xt_tcpudp nf_conntrack_ipv6] > Pid: 17, comm: events/2 Not tainted 2.6.34-04700-gd938a70 #21 > Call Trace: > [] warn_slowpath_common+0x77/0x8f > [] warn_slowpath_null+0xf/0x11 > [] local_bh_enable+0x3c/0x86 > [] dev_queue_xmit+0x462/0x493 > [] bond_dev_queue_xmit+0x1bd/0x1e3 [bonding] > [] bond_start_xmit+0x158/0x37b [bonding] > -> interrupts disabled > [] queue_process+0x9d/0xf9 > [] worker_thread+0x19d/0x224 > [] ? queue_process+0x0/0xf9 > [] ? autoremove_wake_function+0x0/0x34 > [] ? worker_thread+0x0/0x224 > [] kthread+0x7a/0x82 > [] kernel_thread_helper+0x4/0x10 > [] ? kthread+0x0/0x82 > [] ? kernel_thread_helper+0x0/0x10 > ---[ end trace 74e3904503fdb632 ]--- > > kernel/softirq.c: > 141 static inline void _local_bh_enable_ip(unsigned long ip) > 142 { > 143 WARN_ON_ONCE(in_irq() || irqs_disabled()); > 144 #ifdef CONFIG_TRACE_IRQFLAGS > 145 local_irq_disable(); > 146 #endif > 147 /* > 148 * Are softirqs going to be turned on now: > 149 */ > > I am wondering if this was caused by the previous issue. > The git is updated up to: > d938a70 be2net: increase POST timeout for EEH recovery > > Two slave interfaces, bonding mode 1, netconsole over bond0. > > [1] https://bugzilla.redhat.com/show_bug.cgi?id=248374#c5 How did you reproduce this? I will check that BZ to see if I can find how to reproduce this. Thanks.