Re: inconsistent lock state

Re: inconsistent lock state

[Oleg Nesterov]

Sergey Senozhatsky wrote:
>
> Hello,
>
> Hardly reproducible.
> /*
> * 2.6.33. x86. ASUS f3jc
> */
>
> [329645.010697] =================================
> [329645.010699] [ INFO: inconsistent lock state ]
> [329645.010703] 2.6.33-33-0-dbg #31
> [329645.010705] ---------------------------------
> [329645.010708] inconsistent {IN-SOFTIRQ-W} -> {SOFTIRQ-ON-W} usage.
>
> ...
>
> [329645.011083]  [<c128858d>] netif_receive_skb+0x340/0x360
> [329645.011093]  [<fd1ab6f4>] rtl8169_rx_interrupt+0x2bf/0x37e [r8169]
> [329645.011100]  [<fd1aba02>] rtl8169_reset_task+0x38/0xcd [r8169]
> [329645.011105]  [<c1044f71>] worker_thread+0x1ac/0x27c

I don't understand this code, but at first glance drivers/net/r8169.c
is obviously buggy.

The work->func, rtl8169_reset_task(), calls rtl8169_rx_interrupt() ->
netif_receive_skb(), and the last one may only be called from softirq.

Oleg.

Re: inconsistent lock state

[Eric Dumazet]

Le lundi 08 mars 2010 à 13:51 +0100, Oleg Nesterov a écrit :
> Sergey Senozhatsky wrote:
> >
> > Hello,
> >
> > Hardly reproducible.
> > /*
> > * 2.6.33. x86. ASUS f3jc
> > */
> >
> > [329645.010697] =================================
> > [329645.010699] [ INFO: inconsistent lock state ]
> > [329645.010703] 2.6.33-33-0-dbg #31
> > [329645.010705] ---------------------------------
> > [329645.010708] inconsistent {IN-SOFTIRQ-W} -> {SOFTIRQ-ON-W} usage.
> >
> > ...
> >
> > [329645.011083]  [<c128858d>] netif_receive_skb+0x340/0x360
> > [329645.011093]  [<fd1ab6f4>] rtl8169_rx_interrupt+0x2bf/0x37e [r8169]
> > [329645.011100]  [<fd1aba02>] rtl8169_reset_task+0x38/0xcd [r8169]
> > [329645.011105]  [<c1044f71>] worker_thread+0x1ac/0x27c
> 
> I don't understand this code, but at first glance drivers/net/r8169.c
> is obviously buggy.
> 
> The work->func, rtl8169_reset_task(), calls rtl8169_rx_interrupt() ->
> netif_receive_skb(), and the last one may only be called from softirq.
> 

Yes, this is wrong. In this context (process context, not softirq), we
should use netif_rx() or just drop frames if we are in reset phase.

Also, this driver schedules a reset in case a fifo error is reported in
rtl8169_rx_interrupt()

                if (status & RxFOVF) {
                        rtl8169_schedule_work(dev, rtl8169_reset_task);
                        dev->stats.rx_fifo_errors++;
                }


This seems very strange too : In case of a RX spike, we reset card ?

Re: inconsistent lock state

[David Miller]

From: Eric Dumazet <eric.dumazet@gmail.com>
Date: Mon, 15 Mar 2010 22:01:05 +0100

> Also, this driver schedules a reset in case a fifo error is reported in
> rtl8169_rx_interrupt()
> 
>                 if (status & RxFOVF) {
>                         rtl8169_schedule_work(dev, rtl8169_reset_task);
>                         dev->stats.rx_fifo_errors++;
>                 }
> 
> 
> This seems very strange too : In case of a RX spike, we reset card ?

It's possible that this has been found to hang the card.

If so, it should be documented because otherwise yes we
should not be doing this.

[PATCH] r8169: Fix rtl8169_rx_interrupt()

[Eric Dumazet]

Le lundi 15 mars 2010 à 22:01 +0100, Eric Dumazet a écrit :

> Yes, this is wrong. In this context (process context, not softirq), we
> should use netif_rx() or just drop frames if we are in reset phase.
> 

Sergey,

Here is a compiled but untested patch (I dont have the hardware), could
you please test it ?

Thanks

[PATCH] r8169: Fix rtl8169_rx_interrupt()

In case a reset is performed, rtl8169_rx_interrupt() is called from
process context instead of softirq context. Special care must be taken
to call appropriate network core services (netif_rx() instead of
netif_receive_skb()). VLAN handling also corrected.

Reported-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
Diagnosed-by: Oleg Nesterov <oleg@redhat.com>
Signed-off-by: Eric Dumazet <eric.dumazet@gmail.com>
---
diff --git a/drivers/net/r8169.c b/drivers/net/r8169.c
index 9d3ebf3..d873639 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;
@@ -4496,8 +4504,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++;

Re: [PATCH] r8169: Fix rtl8169_rx_interrupt()

[Sergey Senozhatsky]

[-- Attachment #1: Type: text/plain, Size: 3237 bytes --]

Hello,

Sure. Give me a couple of days. By the way, should I test against .34
or .33?

	Sergey


On (03/16/10 01:33), Eric Dumazet wrote:
> Le lundi 15 mars 2010 à 22:01 +0100, Eric Dumazet a écrit :
> 
> > Yes, this is wrong. In this context (process context, not softirq), we
> > should use netif_rx() or just drop frames if we are in reset phase.
> > 
> 
> Sergey,
> 
> Here is a compiled but untested patch (I dont have the hardware), could
> you please test it ?
> 
> Thanks
> 
> [PATCH] r8169: Fix rtl8169_rx_interrupt()
> 
> In case a reset is performed, rtl8169_rx_interrupt() is called from
> process context instead of softirq context. Special care must be taken
> to call appropriate network core services (netif_rx() instead of
> netif_receive_skb()). VLAN handling also corrected.
> 
> Reported-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
> Diagnosed-by: Oleg Nesterov <oleg@redhat.com>
> Signed-off-by: Eric Dumazet <eric.dumazet@gmail.com>
> ---
> diff --git a/drivers/net/r8169.c b/drivers/net/r8169.c
> index 9d3ebf3..d873639 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;
> @@ -4496,8 +4504,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++;
> 
> 

[-- Attachment #2: Type: application/pgp-signature, Size: 316 bytes --]

Re: [PATCH] r8169: Fix rtl8169_rx_interrupt()

[Eric Dumazet]

Le mardi 16 mars 2010 à 08:50 +0200, Sergey Senozhatsky a écrit :
> Hello,
> 
> Sure. Give me a couple of days. By the way, should I test against .34
> or .33?
> 

It's an old bug anyway, so you can pick up whats is the best for you.
My personal pref would be current kernel.

To trigger the original condition (fifo overflow), you might flood your
machine from another one with small packets, for example using pktgen.

Thanks

Re: [PATCH] r8169: Fix rtl8169_rx_interrupt()

[Sergey Senozhatsky]

[-- Attachment #1: Type: text/plain, Size: 4209 bytes --]

Hello,

Eric, I did pktgen testing (3 times).

sudo cat /proc/net/pktgen/eth0 
Params: count 1000000000  min_pkt_size: 42  max_pkt_size: 42
     frags: 0  delay: 0  clone_skb: 4000000  ifname: eth0
     flows: 0 flowlen: 0
     queue_map_min: 0  queue_map_max: 0
     dst_min: 10.6.22.59  dst_max: 
        src_min:   src_max: 
     src_mac: 00:1a:92:c9:a0:68 dst_mac: 00:1a:92:c9:a0:68
     udp_src_min: 9  udp_src_max: 9  udp_dst_min: 9  udp_dst_max: 9
     src_mac_count: 0  dst_mac_count: 0
     Flags: 
Current:
     pkts-sofar: 1000000000  errors: 0
     started: 9957912410us  stopped: 16682620361us idle: 1231us
     seq_num: 1000000001  cur_dst_mac_offset: 0  cur_src_mac_offset: 0
     cur_saddr: 0x3b16060a  cur_daddr: 0x3b16060a
     cur_udp_dst: 9  cur_udp_src: 9
     cur_queue_map: 0
     flows: 0
Result: OK: 6724707951(c6724706719+d1231) nsec, 1000000000 (42byte,0frags)
  148705pps 49Mb/sec (49964880bps) errors: 0


Without any errors from the r8169 side. Can we consider testing successful?
If so, fell free to add Tested-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>


	Sergey



On (03/16/10 01:33), Eric Dumazet wrote:
> > Yes, this is wrong. In this context (process context, not softirq), we
> > should use netif_rx() or just drop frames if we are in reset phase.
> > 
> 
> Sergey,
> 
> Here is a compiled but untested patch (I dont have the hardware), could
> you please test it ?
> 
> Thanks
> 
> [PATCH] r8169: Fix rtl8169_rx_interrupt()
> 
> In case a reset is performed, rtl8169_rx_interrupt() is called from
> process context instead of softirq context. Special care must be taken
> to call appropriate network core services (netif_rx() instead of
> netif_receive_skb()). VLAN handling also corrected.
> 
> Reported-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
> Diagnosed-by: Oleg Nesterov <oleg@redhat.com>
> Signed-off-by: Eric Dumazet <eric.dumazet@gmail.com>
> ---
> diff --git a/drivers/net/r8169.c b/drivers/net/r8169.c
> index 9d3ebf3..d873639 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;
> @@ -4496,8 +4504,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++;
> 
> 

[-- Attachment #2: Type: application/pgp-signature, Size: 316 bytes --]

Re: [PATCH] r8169: Fix rtl8169_rx_interrupt()

[Sergey Senozhatsky]

[-- Attachment #1: Type: text/plain, Size: 5442 bytes --]

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



	Sergey


On (03/16/10 01:33), Eric Dumazet wrote:
> > Yes, this is wrong. In this context (process context, not softirq), we
> > should use netif_rx() or just drop frames if we are in reset phase.
> > 
> 
> Sergey,
> 
> Here is a compiled but untested patch (I dont have the hardware), could
> you please test it ?
> 
> Thanks
> 
> [PATCH] r8169: Fix rtl8169_rx_interrupt()
> 
> In case a reset is performed, rtl8169_rx_interrupt() is called from
> process context instead of softirq context. Special care must be taken
> to call appropriate network core services (netif_rx() instead of
> netif_receive_skb()). VLAN handling also corrected.
> 
> Reported-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
> Diagnosed-by: Oleg Nesterov <oleg@redhat.com>
> Signed-off-by: Eric Dumazet <eric.dumazet@gmail.com>
> ---
> diff --git a/drivers/net/r8169.c b/drivers/net/r8169.c
> index 9d3ebf3..d873639 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;
> @@ -4496,8 +4504,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++;
> 
> 

[-- Attachment #2: Type: application/pgp-signature, Size: 316 bytes --]

Re: [PATCH] r8169: Fix rtl8169_rx_interrupt()

[Eric Dumazet]

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 :)

Re: [PATCH] r8169: Fix rtl8169_rx_interrupt()

[Sergey Senozhatsky]

[-- Attachment #1: Type: text/plain, Size: 2843 bytes --]

On (03/16/10 16:05), Eric Dumazet wrote:
> > 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 ?
> 

[...]
>> NETDEV WATCHDOG: eth0 (r8169): transmit queue 0 timed out
Isn't it r8169 related?


> I wonder if you dont hit another problem :)
:)


	Sergey

[-- Attachment #2: Type: application/pgp-signature, Size: 316 bytes --]

Re: [PATCH] r8169: Fix rtl8169_rx_interrupt()

[Eric Dumazet]

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

Re: [PATCH] r8169: Fix rtl8169_rx_interrupt()

[Sergey Senozhatsky]

[-- Attachment #1: Type: text/plain, Size: 2982 bytes --]

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
> 
> 

[-- Attachment #2: Type: application/pgp-signature, Size: 316 bytes --]

Re: [PATCH] r8169: Fix rtl8169_rx_interrupt()

[Eric Dumazet]

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++;

Re: [PATCH] r8169: Fix rtl8169_rx_interrupt()

[Sergey Senozhatsky]

[-- Attachment #1: Type: text/plain, Size: 4906 bytes --]

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++;
> 
> 
> 

[-- Attachment #2: Type: application/pgp-signature, Size: 316 bytes --]

Re: [PATCH] r8169: Fix rtl8169_rx_interrupt()

[Sergey Senozhatsky]

[-- Attachment #1: Type: text/plain, Size: 7388 bytes --]

Hello,

cumulative patch:

[  155.337373] ------------[ cut here ]------------
[  155.337386] WARNING: at net/sched/sch_generic.c:255 dev_watchdog+0xc1/0x125()
[  155.337390] Hardware name: F3JC                
[  155.337394] NETDEV WATCHDOG: eth0 (r8169): transmit queue 0 timed out
[  155.337397] 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 snd_hda_intel snd_hda_codec
asus_laptop sparse_keymap mmc_core led_class snd_pcm snd_timer snd_page_alloc psmouse rng_core snd soundcore sg i2c_i801 evdev serio_raw r8169 mii usbhid hid uhci_hcd ehci_hcd
sr_mod cdrom sd_mod usbcore ata_piix
[  155.337468] Pid: 7, comm: ksoftirqd/1 Tainted: G        W  2.6.34-rc1-dbg-git6-r8169 #47
[  155.337472] Call Trace:
[  155.337481]  [<c102e293>] warn_slowpath_common+0x65/0x7c
[  155.337506]  [<c126ac34>] ? dev_watchdog+0xc1/0x125
[  155.337512]  [<c102e2de>] warn_slowpath_fmt+0x24/0x27
[  155.337517]  [<c126ac34>] dev_watchdog+0xc1/0x125
[  155.337525]  [<c1036afb>] ? run_timer_softirq+0x120/0x1eb
[  155.337530]  [<c1036b51>] run_timer_softirq+0x176/0x1eb
[  155.337536]  [<c1036afb>] ? run_timer_softirq+0x120/0x1eb
[  155.337566]  [<c126ab73>] ? dev_watchdog+0x0/0x125
[  155.337576]  [<c1032d39>] __do_softirq+0x8d/0x117
[  155.337667]  [<c1032dee>] do_softirq+0x2b/0x43
[  155.337729]  [<c1032fc1>] run_ksoftirqd+0x71/0x140
[  155.337745]  [<c1032f50>] ? run_ksoftirqd+0x0/0x140
[  155.337810]  [<c103f60e>] kthread+0x6a/0x6f
[  155.337832]  [<c103f5a4>] ? kthread+0x0/0x6f
[  155.337903]  [<c1002e42>] kernel_thread_helper+0x6/0x1a
[  155.337907] ---[ end trace a22d306b065d4a68 ]---
[  155.350902] r8169 0000:02:00.0: eth0: link up
[  167.350892] r8169 0000:02:00.0: eth0: link up



	Sergey



On (03/16/10 19:48), Eric Dumazet wrote:
> > 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++;
> 
> 
> 

[-- Attachment #2: Type: application/pgp-signature, Size: 316 bytes --]