r8169: Fix rtl8169_rx_interrupt()
in [Kernel]
|
Prev: rcu: make rcu_read_lock_bh_held() allow for disabled BH
Next: drivers/serial/sunsab.c: adjust the constant used to initialize the interrupt_mask0 fields
From: Eric Dumazet on 16 Mar 2010 11:10 Le mardi 16 mars 2010 à 17:00 +0200, Sergey Senozhatsky a écrit : > Nope! > Here it is: > > > [17250.998293] ------------[ cut here ]------------ > [17250.998305] WARNING: at net/sched/sch_generic.c:255 dev_watchdog+0xc1/0x125() > [17250.998308] Hardware name: F3JC > [17250.998312] NETDEV WATCHDOG: eth0 (r8169): transmit queue 0 timed out > [17250.998315] Modules linked in: pktgen ppp_async crc_ccitt ipv6 ppp_generic slhc snd_hwdep snd_hda_codec_si3054 snd_hda_codec_realtek sdhci_pci sdhci asus_laptop sparse_keymap > mmc_core led_class snd_hda_intel snd_hda_codec snd_pcm snd_timer snd_page_alloc rng_core sg evdev i2c_i801 snd soundcore psmouse r8169 serio_raw mii uhci_hcd ehci_hcd sr_mod > usbcore cdrom sd_mod ata_piix > [17250.998371] Pid: 3985, comm: kpktgend_0 Tainted: G W 2.6.34-rc1-dbg-git6-r8169 #46 > [17250.998375] Call Trace: > [17250.998383] [<c102e353>] warn_slowpath_common+0x65/0x7c > [17250.998388] [<c126b654>] ? dev_watchdog+0xc1/0x125 > [17250.998393] [<c102e39e>] warn_slowpath_fmt+0x24/0x27 > [17250.998398] [<c126b654>] dev_watchdog+0xc1/0x125 > [17250.998405] [<c1036bbb>] ? run_timer_softirq+0x120/0x1eb > [17250.998411] [<c1036c11>] run_timer_softirq+0x176/0x1eb > [17250.998416] [<c1036bbb>] ? run_timer_softirq+0x120/0x1eb > [17250.998421] [<c126b593>] ? dev_watchdog+0x0/0x125 > [17250.998426] [<c1032df9>] __do_softirq+0x8d/0x117 > [17250.998431] [<c1032eae>] do_softirq+0x2b/0x43 > [17250.998436] [<c1032fd3>] irq_exit+0x38/0x75 > [17250.998442] [<c1014e75>] smp_apic_timer_interrupt+0x66/0x74 > [17250.998448] [<c12c812a>] apic_timer_interrupt+0x36/0x3c > [17250.998457] [<c1185d18>] ? do_raw_spin_trylock+0x28/0x37 > [17250.998464] [<c12c7101>] _raw_spin_lock+0x2f/0x58 > [17250.998472] [<f80855ca>] ? spin_lock+0x8/0xa [pktgen] > [17250.998478] [<f80855ca>] spin_lock+0x8/0xa [pktgen] > [17250.998484] [<f80873b6>] pktgen_thread_worker+0x9b/0x631 [pktgen] > [17250.998491] [<c103f9f1>] ? autoremove_wake_function+0x0/0x2f > [17250.998497] [<c103f9f1>] ? autoremove_wake_function+0x0/0x2f > [17250.998503] [<f808731b>] ? pktgen_thread_worker+0x0/0x631 [pktgen] > [17250.998508] [<c103f6ce>] kthread+0x6a/0x6f > [17250.998514] [<c103f664>] ? kthread+0x0/0x6f > [17250.998520] [<c1002e42>] kernel_thread_helper+0x6/0x1a > [17250.998523] ---[ end trace a22d306b065d4a68 ]--- > [17251.011663] r8169 0000:02:00.0: eth0: link up > > [17419.011748] NOHZ: local_softirq_pending 08 > > But this stack trace is on pktgen side (the sender), and my patch was about the receiver ? I wonder if you dont hit another problem :) -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo(a)vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
From: Eric Dumazet on 16 Mar 2010 11:30 Le mardi 16 mars 2010 à 17:10 +0200, Sergey Senozhatsky a écrit : > [...] > >> NETDEV WATCHDOG: eth0 (r8169): transmit queue 0 timed out > Isn't it r8169 related? > This is tx side which seems blocked for more than 6 seconds. To really test the patch, you need following setup : machine A with r8169 NIC, patch applied, receiver of pktgen flood. machine B with any NIC, preferably a not buggy one, doing the pktgen flood to machine A If machine A survives, my patch is tested and ok. If machine B crashes, we have another problem to investigate -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo(a)vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
From: Sergey Senozhatsky on 16 Mar 2010 14:30 Hello, Got it right now. System completely froze. Even SysRq didn't work. /*spin_lock deadlock?*/ NOTE: I'm losing network constantly with pktgen tests [24208.010980] r8169 0000:02:00.0: eth0: link up [24220.010980] r8169 0000:02:00.0: eth0: link up [24232.011030] r8169 0000:02:00.0: eth0: link up [24340.010980] r8169 0000:02:00.0: eth0: link up [24352.010966] r8169 0000:02:00.0: eth0: link up [24364.010966] r8169 0000:02:00.0: eth0: link up [24376.010964] r8169 0000:02:00.0: eth0: link up [24388.010961] r8169 0000:02:00.0: eth0: link up [24400.010959] r8169 0000:02:00.0: eth0: link up [24412.010963] r8169 0000:02:00.0: eth0: link up Traces: [24600.625078] INFO: task events/0:9 blocked for more than 120 seconds. [24600.625083] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [24600.625087] events/0 D 00001636 0 9 2 0x00000000 [24600.625096] f7085ebc 00000046 a87e9490 00001636 c1617cc0 c1617cc0 c1617cc0 c1617cc0 [24600.625109] f707c250 c1617cc0 c1617cc0 00000000 00000000 00000000 00000000 f707bfc0 [24600.625122] c14745c8 c14745c8 f707bfc0 00000202 f7085efc c12c6449 00000000 00085edc [24600.625135] Call Trace: [24600.625148] [<c12c6449>] __mutex_lock_common+0x233/0x3af [24600.625155] [<c12c65ff>] mutex_lock_nested+0x12/0x15 [24600.625163] [<c1265e0f>] ? rtnl_lock+0xf/0x11 [24600.625168] [<c1265e0f>] rtnl_lock+0xf/0x11 [24600.625183] [<f9174acd>] rtl8169_reset_task+0x16/0xee [r8169] [24600.625191] [<c103c887>] worker_thread+0x161/0x233 [24600.625196] [<c103c845>] ? worker_thread+0x11f/0x233 [24600.625205] [<f9174ab7>] ? rtl8169_reset_task+0x0/0xee [r8169] [24600.625214] [<c103f9f1>] ? autoremove_wake_function+0x0/0x2f [24600.625220] [<c103c726>] ? worker_thread+0x0/0x233 [24600.625225] [<c103f6ce>] kthread+0x6a/0x6f [24600.625232] [<c103f664>] ? kthread+0x0/0x6f [24600.625238] [<c1002e42>] kernel_thread_helper+0x6/0x1a [24600.625242] INFO: lockdep is turned off. [24600.625259] INFO: task X:3176 blocked for more than 120 seconds. [24600.625262] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [24600.625266] X D 00000000 0 3176 3175 0x00400004 [24600.625273] f6435a10 00003046 00025709 00000000 c1617cc0 c1617cc0 c1617cc0 c1617cc0 [24600.625286] f60897d0 c1617c ... /*THE REST IS LOST*/ Sergey On (03/16/10 16:20), Eric Dumazet wrote: > > [...] > > >> NETDEV WATCHDOG: eth0 (r8169): transmit queue 0 timed out > > Isn't it r8169 related? > > > > This is tx side which seems blocked for more than 6 seconds. > > To really test the patch, you need following setup : > > machine A with r8169 NIC, patch applied, receiver of pktgen flood. > > machine B with any NIC, preferably a not buggy one, doing the pktgen > flood to machine A > > If machine A survives, my patch is tested and ok. > > If machine B crashes, we have another problem to investigate > >
From: Eric Dumazet on 16 Mar 2010 14:50 Le mardi 16 mars 2010 à 20:26 +0200, Sergey Senozhatsky a écrit : > Hello, > Got it right now. > > System completely froze. Even SysRq didn't work. > /*spin_lock deadlock?*/ > > NOTE: I'm losing network constantly with pktgen tests yes, every 12 seconds there is a reset because of fifo overflow > [24208.010980] r8169 0000:02:00.0: eth0: link up > [24220.010980] r8169 0000:02:00.0: eth0: link up > [24232.011030] r8169 0000:02:00.0: eth0: link up > [24340.010980] r8169 0000:02:00.0: eth0: link up > [24352.010966] r8169 0000:02:00.0: eth0: link up > [24364.010966] r8169 0000:02:00.0: eth0: link up > [24376.010964] r8169 0000:02:00.0: eth0: link up > [24388.010961] r8169 0000:02:00.0: eth0: link up > [24400.010959] r8169 0000:02:00.0: eth0: link up > [24412.010963] r8169 0000:02:00.0: eth0: link up > > > Traces: > [24600.625078] INFO: task events/0:9 blocked for more than 120 seconds. > [24600.625083] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > [24600.625087] events/0 D 00001636 0 9 2 0x00000000 > [24600.625096] f7085ebc 00000046 a87e9490 00001636 c1617cc0 c1617cc0 c1617cc0 c1617cc0 > [24600.625109] f707c250 c1617cc0 c1617cc0 00000000 00000000 00000000 00000000 f707bfc0 > [24600.625122] c14745c8 c14745c8 f707bfc0 00000202 f7085efc c12c6449 00000000 00085edc > [24600.625135] Call Trace: > [24600.625148] [<c12c6449>] __mutex_lock_common+0x233/0x3af > [24600.625155] [<c12c65ff>] mutex_lock_nested+0x12/0x15 > [24600.625163] [<c1265e0f>] ? rtnl_lock+0xf/0x11 > [24600.625168] [<c1265e0f>] rtnl_lock+0xf/0x11 > [24600.625183] [<f9174acd>] rtl8169_reset_task+0x16/0xee [r8169] > [24600.625191] [<c103c887>] worker_thread+0x161/0x233 > [24600.625196] [<c103c845>] ? worker_thread+0x11f/0x233 > [24600.625205] [<f9174ab7>] ? rtl8169_reset_task+0x0/0xee [r8169] > [24600.625214] [<c103f9f1>] ? autoremove_wake_function+0x0/0x2f > [24600.625220] [<c103c726>] ? worker_thread+0x0/0x233 > [24600.625225] [<c103f6ce>] kthread+0x6a/0x6f > [24600.625232] [<c103f664>] ? kthread+0x0/0x6f > [24600.625238] [<c1002e42>] kernel_thread_helper+0x6/0x1a > [24600.625242] INFO: lockdep is turned off. > [24600.625259] INFO: task X:3176 blocked for more than 120 seconds. > [24600.625262] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > [24600.625266] X D 00000000 0 3176 3175 0x00400004 > [24600.625273] f6435a10 00003046 00025709 00000000 c1617cc0 c1617cc0 c1617cc0 c1617cc0 > [24600.625286] f60897d0 c1617c ... > /*THE REST IS LOST*/ > > OK thanks for the report, this rtl8169_reset_task() seems pretty buggy, or multiple invocation... Did you tried removing the rtl8169_schedule_work() call from rtl8169_rx_interrupt() ? Maybe the reset is not necessary at all in case of fifo overflow.. Cumulative patch : diff --git a/drivers/net/r8169.c b/drivers/net/r8169.c index 9d3ebf3..d6ef4dd 100644 --- a/drivers/net/r8169.c +++ b/drivers/net/r8169.c @@ -1038,14 +1038,14 @@ static void rtl8169_vlan_rx_register(struct net_device *dev, } static int rtl8169_rx_vlan_skb(struct rtl8169_private *tp, struct RxDesc *desc, - struct sk_buff *skb) + struct sk_buff *skb, int polling) { u32 opts2 = le32_to_cpu(desc->opts2); struct vlan_group *vlgrp = tp->vlgrp; int ret; if (vlgrp && (opts2 & RxVlanTag)) { - vlan_hwaccel_receive_skb(skb, vlgrp, swab16(opts2 & 0xffff)); + __vlan_hwaccel_rx(skb, vlgrp, swab16(opts2 & 0xffff), polling); ret = 0; } else ret = -1; @@ -1062,7 +1062,7 @@ static inline u32 rtl8169_tx_vlan_tag(struct rtl8169_private *tp, } static int rtl8169_rx_vlan_skb(struct rtl8169_private *tp, struct RxDesc *desc, - struct sk_buff *skb) + struct sk_buff *skb, int polling) { return -1; } @@ -4429,12 +4429,20 @@ out: return done; } +/* + * Warning : rtl8169_rx_interrupt() might be called : + * 1) from NAPI (softirq) context + * (polling = 1 : we should call netif_receive_skb()) + * 2) from process context (rtl8169_reset_task()) + * (polling = 0 : we must call netif_rx() instead) + */ static int rtl8169_rx_interrupt(struct net_device *dev, struct rtl8169_private *tp, void __iomem *ioaddr, u32 budget) { unsigned int cur_rx, rx_left; unsigned int delta, count; + int polling = (budget != ~(u32)0) ? 1 : 0; cur_rx = tp->cur_rx; rx_left = NUM_RX_DESC + tp->dirty_rx - cur_rx; @@ -4459,7 +4467,6 @@ static int rtl8169_rx_interrupt(struct net_device *dev, if (status & RxCRC) dev->stats.rx_crc_errors++; if (status & RxFOVF) { - rtl8169_schedule_work(dev, rtl8169_reset_task); dev->stats.rx_fifo_errors++; } rtl8169_mark_to_asic(desc, tp->rx_buf_sz); @@ -4496,8 +4503,12 @@ static int rtl8169_rx_interrupt(struct net_device *dev, skb_put(skb, pkt_size); skb->protocol = eth_type_trans(skb, dev); - if (rtl8169_rx_vlan_skb(tp, desc, skb) < 0) - netif_receive_skb(skb); + if (rtl8169_rx_vlan_skb(tp, desc, skb, polling) < 0) { + if (likely(polling)) + netif_receive_skb(skb); + else + netif_rx(skb); + } dev->stats.rx_bytes += pkt_size; dev->stats.rx_packets++; -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo(a)vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
From: Sergey Senozhatsky on 16 Mar 2010 15:10
On (03/16/10 19:48), Eric Dumazet wrote: > > Traces: > > [24600.625078] INFO: task events/0:9 blocked for more than 120 seconds. > > [24600.625083] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > > [24600.625087] events/0 D 00001636 0 9 2 0x00000000 > > [24600.625096] f7085ebc 00000046 a87e9490 00001636 c1617cc0 c1617cc0 c1617cc0 c1617cc0 > > [24600.625109] f707c250 c1617cc0 c1617cc0 00000000 00000000 00000000 00000000 f707bfc0 > > [24600.625122] c14745c8 c14745c8 f707bfc0 00000202 f7085efc c12c6449 00000000 00085edc > > [24600.625135] Call Trace: > > [24600.625148] [<c12c6449>] __mutex_lock_common+0x233/0x3af > > [24600.625155] [<c12c65ff>] mutex_lock_nested+0x12/0x15 > > [24600.625163] [<c1265e0f>] ? rtnl_lock+0xf/0x11 > > [24600.625168] [<c1265e0f>] rtnl_lock+0xf/0x11 > > [24600.625183] [<f9174acd>] rtl8169_reset_task+0x16/0xee [r8169] > > [24600.625191] [<c103c887>] worker_thread+0x161/0x233 > > [24600.625196] [<c103c845>] ? worker_thread+0x11f/0x233 > > [24600.625205] [<f9174ab7>] ? rtl8169_reset_task+0x0/0xee [r8169] > > [24600.625214] [<c103f9f1>] ? autoremove_wake_function+0x0/0x2f > > [24600.625220] [<c103c726>] ? worker_thread+0x0/0x233 > > [24600.625225] [<c103f6ce>] kthread+0x6a/0x6f > > [24600.625232] [<c103f664>] ? kthread+0x0/0x6f > > [24600.625238] [<c1002e42>] kernel_thread_helper+0x6/0x1a > > [24600.625242] INFO: lockdep is turned off. > > [24600.625259] INFO: task X:3176 blocked for more than 120 seconds. > > [24600.625262] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > > [24600.625266] X D 00000000 0 3176 3175 0x00400004 > > [24600.625273] f6435a10 00003046 00025709 00000000 c1617cc0 c1617cc0 c1617cc0 c1617cc0 > > [24600.625286] f60897d0 c1617c ... > > /*THE REST IS LOST*/ > > > > > > OK thanks for the report, this rtl8169_reset_task() seems pretty buggy, > or multiple invocation... > > Did you tried removing the rtl8169_schedule_work() call from > rtl8169_rx_interrupt() ? > Not yet. I'm reading rtl8169_rx_interrupt now and rtl8169_schedule_work in case of RxFOVF grabbed my attention too. > Maybe the reset is not necessary at all in case of fifo overflow.. > > Cumulative patch : > Will try it. Sergey > diff --git a/drivers/net/r8169.c b/drivers/net/r8169.c > index 9d3ebf3..d6ef4dd 100644 > --- a/drivers/net/r8169.c > +++ b/drivers/net/r8169.c > @@ -1038,14 +1038,14 @@ static void rtl8169_vlan_rx_register(struct net_device *dev, > } > > static int rtl8169_rx_vlan_skb(struct rtl8169_private *tp, struct RxDesc *desc, > - struct sk_buff *skb) > + struct sk_buff *skb, int polling) > { > u32 opts2 = le32_to_cpu(desc->opts2); > struct vlan_group *vlgrp = tp->vlgrp; > int ret; > > if (vlgrp && (opts2 & RxVlanTag)) { > - vlan_hwaccel_receive_skb(skb, vlgrp, swab16(opts2 & 0xffff)); > + __vlan_hwaccel_rx(skb, vlgrp, swab16(opts2 & 0xffff), polling); > ret = 0; > } else > ret = -1; > @@ -1062,7 +1062,7 @@ static inline u32 rtl8169_tx_vlan_tag(struct rtl8169_private *tp, > } > > static int rtl8169_rx_vlan_skb(struct rtl8169_private *tp, struct RxDesc *desc, > - struct sk_buff *skb) > + struct sk_buff *skb, int polling) > { > return -1; > } > @@ -4429,12 +4429,20 @@ out: > return done; > } > > +/* > + * Warning : rtl8169_rx_interrupt() might be called : > + * 1) from NAPI (softirq) context > + * (polling = 1 : we should call netif_receive_skb()) > + * 2) from process context (rtl8169_reset_task()) > + * (polling = 0 : we must call netif_rx() instead) > + */ > static int rtl8169_rx_interrupt(struct net_device *dev, > struct rtl8169_private *tp, > void __iomem *ioaddr, u32 budget) > { > unsigned int cur_rx, rx_left; > unsigned int delta, count; > + int polling = (budget != ~(u32)0) ? 1 : 0; > > cur_rx = tp->cur_rx; > rx_left = NUM_RX_DESC + tp->dirty_rx - cur_rx; > @@ -4459,7 +4467,6 @@ static int rtl8169_rx_interrupt(struct net_device *dev, > if (status & RxCRC) > dev->stats.rx_crc_errors++; > if (status & RxFOVF) { > - rtl8169_schedule_work(dev, rtl8169_reset_task); > dev->stats.rx_fifo_errors++; > } > rtl8169_mark_to_asic(desc, tp->rx_buf_sz); > @@ -4496,8 +4503,12 @@ static int rtl8169_rx_interrupt(struct net_device *dev, > skb_put(skb, pkt_size); > skb->protocol = eth_type_trans(skb, dev); > > - if (rtl8169_rx_vlan_skb(tp, desc, skb) < 0) > - netif_receive_skb(skb); > + if (rtl8169_rx_vlan_skb(tp, desc, skb, polling) < 0) { > + if (likely(polling)) > + netif_receive_skb(skb); > + else > + netif_rx(skb); > + } > > dev->stats.rx_bytes += pkt_size; > dev->stats.rx_packets++; > > > |