Re: 1e918876 breaks r8169 (linux-3.18+)

Re: 1e918876 breaks r8169 (linux-3.18+)

[Eric Dumazet]

On Sat, 2015-02-21 at 11:31 +0100, Florian Westphal wrote:
> Tomas Szepe <szepe@pinerecords.com> wrote:
> > > I tried to reproduce this without success so far on my RTL8168d/8111d device.
> > > I've been running 40 parallel netperf TCP_STREAM tests (1gbit) for the
> > > last 5 hours and so far I saw no watchdog tx timeouts.
> > > 
> > > I'll keep this running for a day or so to see if it just takes more time
> > > to trigger.
> > 
> > So, how's this coming along?  Don't you think the patch should be reverted
> > until the problem is diagnosed/understood/fixed?
> 
> Sorry.
> 
> David, please consider reverting
> 
> 1e918876853aa85435e0f17fd8b4a92dcfff53d6
> (r8169: add support for Byte Queue Limits)
> 
> 	and
> 
> 0bec3b700d106a8b0a34227b2976d1a582f1aab7
> (r8169: add support for xmit_more)
> 
> I cannot reproduce any hangs (tried for 2days with 40 parallel
> netperfs using both 100mbit and 1gbit receiver).
> 
> And I don't see anything wrong with the change either.
> Seems like some revisions of the HW are just dodgy?
> 
> I hate giving up, but I have no means to diagnose this any further.
> Even reporter says it doesn't affect all of his r8169 nics.
> 
> So I think the change is correct per se, but might be revealing some
> HW/firmware bug.

Hold on.

I believe there is one race in the way you access skb->xmit_more _after_

txd->opts1 = cpu_to_le32(status);

After this point, TX might have completed and TX completion already have
freed skb

Could Tomas try following fix ?

diff --git a/drivers/net/ethernet/realtek/r8169.c b/drivers/net/ethernet/realtek/r8169.c
index ad0020af2193..f2764366a36c 100644
--- a/drivers/net/ethernet/realtek/r8169.c
+++ b/drivers/net/ethernet/realtek/r8169.c
@@ -7050,6 +7050,7 @@ static netdev_tx_t rtl8169_start_xmit(struct sk_buff *skb,
 	u32 opts[2];
 	int frags;
 	bool stop_queue;
+	bool xmit_more;
 
 	if (unlikely(!TX_FRAGS_READY_FOR(tp, skb_shinfo(skb)->nr_frags))) {
 		netif_err(tp, drv, dev, "BUG! Tx Ring full when queue awake!\n");
@@ -7091,7 +7092,7 @@ static netdev_tx_t rtl8169_start_xmit(struct sk_buff *skb,
 	txd->opts2 = cpu_to_le32(opts[1]);
 
 	netdev_sent_queue(dev, skb->len);
-
+	xmit_more = skb->xmit_more;
 	skb_tx_timestamp(skb);
 
 	/* Force memory writes to complete before releasing descriptor */
@@ -7108,7 +7109,7 @@ static netdev_tx_t rtl8169_start_xmit(struct sk_buff *skb,
 
 	stop_queue = !TX_FRAGS_READY_FOR(tp, MAX_SKB_FRAGS);
 
-	if (!skb->xmit_more || stop_queue ||
+	if (!xmit_more || stop_queue ||
 	    netif_xmit_stopped(netdev_get_tx_queue(dev, 0))) {
 		RTL_W8(TxPoll, NPQ);
 

Re: 1e918876 breaks r8169 (linux-3.18+)

[Florian Westphal]

Eric Dumazet <eric.dumazet@gmail.com> wrote:
> Hold on.
> 
> I believe there is one race in the way you access skb->xmit_more _after_
> 
> txd->opts1 = cpu_to_le32(status);
> 
> After this point, TX might have completed and TX completion already have
> freed skb

Hmm, I _thought_ HW would not start xmit of this descriptor/skb until after

RTL_W8(TxPoll, NPQ);

call a bit later... your patch surely looks safer though, thanks for
looking into this.

> Could Tomas try following fix ?

In addition -- Tomas, on your affected board -- did you try
turning off gso/tso?

Holger Hoffstätte mentioned on lkml that his affected r8169 nic is
stable with xmit_more+bql after disabling gso/tso on the nic

(ethtool -k $dev to display settings, "-K $dev tso off gso off" to
 disable offloads).

Re: 1e918876 breaks r8169 (linux-3.18+)

[Eric Dumazet]

On Sat, 2015-02-21 at 18:46 +0100, Florian Westphal wrote:
> Eric Dumazet <eric.dumazet@gmail.com> wrote:
> > Hold on.
> > 
> > I believe there is one race in the way you access skb->xmit_more _after_
> > 
> > txd->opts1 = cpu_to_le32(status);
> > 
> > After this point, TX might have completed and TX completion already have
> > freed skb
> 
> Hmm, I _thought_ HW would not start xmit of this descriptor/skb until after
> 
> RTL_W8(TxPoll, NPQ);

Note this 'kick' does not provide tail ptr.

NIC basically looks at TX descriptors to find ones with the DescOwn bit
set. It stops when if find one TX descriptor _without_ DescOwn.

So what can happen here is the NIC was kicked earlier (prior transmit),
but found your TX descriptor, before you got a chance to read
skb->xmit_more

This is why we have these wmb() everywhere. We want to do

txd->opts1 = XXX

Only when we are really ready.

Re: 1e918876 breaks r8169 (linux-3.18+)

[Florian Westphal]

Eric Dumazet <eric.dumazet@gmail.com> wrote:
> On Sat, 2015-02-21 at 18:46 +0100, Florian Westphal wrote:
> > Eric Dumazet <eric.dumazet@gmail.com> wrote:
> > > Hold on.
> > > 
> > > I believe there is one race in the way you access skb->xmit_more _after_
> > > 
> > > txd->opts1 = cpu_to_le32(status);
> > > 
> > > After this point, TX might have completed and TX completion already have
> > > freed skb
> > 
> > Hmm, I _thought_ HW would not start xmit of this descriptor/skb until after
> > 
> > RTL_W8(TxPoll, NPQ);
> 
> Note this 'kick' does not provide tail ptr.
> 
> NIC basically looks at TX descriptors to find ones with the DescOwn bit
> set. It stops when if find one TX descriptor _without_ DescOwn.

Makes sense, thanks for explaining this.

Re: 1e918876 breaks r8169 (linux-3.18+)

[Tomas Szepe]

> > Could Tomas try following fix ?
> 
> In addition -- Tomas, on your affected board -- did you try
> turning off gso/tso?
> 
> Holger Hoffstätte mentioned on lkml that his affected r8169 nic is
> stable with xmit_more+bql after disabling gso/tso on the nic
> 
> (ethtool -k $dev to display settings, "-K $dev tso off gso off" to
>  disable offloads).

They're always off on this NIC (cannot be turned on).

# ethtool -k eth1| grep segmentation-offload
tcp-segmentation-offload: off
generic-segmentation-offload: off [requested on]
# ethtool -K eth1 gso on tso on
Could not change any device features
# ethtool -k eth1| grep segmentation-offload
tcp-segmentation-offload: off
generic-segmentation-offload: off [requested on]

-- 
Tomas Szepe <szepe@pinerecords.com>

Re: 1e918876 breaks r8169 (linux-3.18+)

[Tomas Szepe]

> > David, please consider reverting
> > 
> > 1e918876853aa85435e0f17fd8b4a92dcfff53d6
> > (r8169: add support for Byte Queue Limits)
> > 
> > 	and
> > 
> > 0bec3b700d106a8b0a34227b2976d1a582f1aab7
> > (r8169: add support for xmit_more)
> > 
> > I cannot reproduce any hangs (tried for 2days with 40 parallel
> > netperfs using both 100mbit and 1gbit receiver).
> > 
> > And I don't see anything wrong with the change either.
> > Seems like some revisions of the HW are just dodgy?
> > 
> > I hate giving up, but I have no means to diagnose this any further.
> > Even reporter says it doesn't affect all of his r8169 nics.
> > 
> > So I think the change is correct per se, but might be revealing some
> > HW/firmware bug.
> 
> Hold on.
> 
> I believe there is one race in the way you access skb->xmit_more _after_
> 
> txd->opts1 = cpu_to_le32(status);
> 
> After this point, TX might have completed and TX completion already have
> freed skb
> 
> Could Tomas try following fix ?
> 
> diff --git a/drivers/net/ethernet/realtek/r8169.c b/drivers/net/ethernet/realtek/r8169.c
> index ad0020af2193..f2764366a36c 100644
> ...

Sure, just did.  Unfortunately, 3.19.0 + 0bec3b70 + this patch results
in a driver that retains the problem.

Sorry,
-- 
Tomas Szepe <szepe@pinerecords.com>

Re: 1e918876 breaks r8169 (linux-3.18+)

[Eric Dumazet]

On Sat, 2015-02-21 at 20:05 +0100, Tomas Szepe wrote:

> Sure, just did.  Unfortunately, 3.19.0 + 0bec3b70 + this patch results
> in a driver that retains the problem.

OK, could you test following patch instead ?

diff --git a/drivers/net/ethernet/realtek/r8169.c b/drivers/net/ethernet/realtek/r8169.c
index ad0020af2193..18d0decb5093 100644
--- a/drivers/net/ethernet/realtek/r8169.c
+++ b/drivers/net/ethernet/realtek/r8169.c
@@ -7050,6 +7050,7 @@ static netdev_tx_t rtl8169_start_xmit(struct sk_buff *skb,
 	u32 opts[2];
 	int frags;
 	bool stop_queue;
+	bool xmit_more;
 
 	if (unlikely(!TX_FRAGS_READY_FOR(tp, skb_shinfo(skb)->nr_frags))) {
 		netif_err(tp, drv, dev, "BUG! Tx Ring full when queue awake!\n");
@@ -7091,7 +7092,7 @@ static netdev_tx_t rtl8169_start_xmit(struct sk_buff *skb,
 	txd->opts2 = cpu_to_le32(opts[1]);
 
 	netdev_sent_queue(dev, skb->len);
-
+	xmit_more = skb->xmit_more;
 	skb_tx_timestamp(skb);
 
 	/* Force memory writes to complete before releasing descriptor */
@@ -7108,7 +7109,14 @@ static netdev_tx_t rtl8169_start_xmit(struct sk_buff *skb,
 
 	stop_queue = !TX_FRAGS_READY_FOR(tp, MAX_SKB_FRAGS);
 
-	if (!skb->xmit_more || stop_queue ||
+	if (stop_queue) {
+		/* Avoid wrongly optimistic queue wake-up: rtl_tx thread must
+		 * not miss a ring update when it notices a stopped queue.
+		 */
+		smp_wmb();
+		netif_stop_queue(dev);
+	}
+	if (!xmit_more ||
 	    netif_xmit_stopped(netdev_get_tx_queue(dev, 0))) {
 		RTL_W8(TxPoll, NPQ);
 
@@ -7116,11 +7124,6 @@ static netdev_tx_t rtl8169_start_xmit(struct sk_buff *skb,
 	}
 
 	if (stop_queue) {
-		/* Avoid wrongly optimistic queue wake-up: rtl_tx thread must
-		 * not miss a ring update when it notices a stopped queue.
-		 */
-		smp_wmb();
-		netif_stop_queue(dev);
 		/* Sync with rtl_tx:
 		 * - publish queue status and cur_tx ring index (write barrier)
 		 * - refresh dirty_tx ring index (read barrier).

Re: 1e918876 breaks r8169 (linux-3.18+)

[Tomas Szepe]

> > Sure, just did.  Unfortunately, 3.19.0 + 0bec3b70 + this patch results
> > in a driver that retains the problem.
> 
> OK, could you test following patch instead ?

Yup, but tough luck: 3.19.0 + 0bec3b70 + this patch -> problem present.

-- 
Tomas Szepe <szepe@pinerecords.com>

Re: 1e918876 breaks r8169 (linux-3.18+)

[David Miller]

From: Tomas Szepe <szepe@pinerecords.com>
Date: Sun, 22 Feb 2015 01:41:51 +0100

>> > Sure, just did.  Unfortunately, 3.19.0 + 0bec3b70 + this patch results
>> > in a driver that retains the problem.
>> 
>> OK, could you test following patch instead ?
> 
> Yup, but tough luck: 3.19.0 + 0bec3b70 + this patch -> problem present.

I'm reverting the two commits for now, as below.

We can put them back in if we can resolve the problems.

====================
[PATCH] r8169: Revert BQL and xmit_more support.

There are certain regressions which are pointing to
these two commits which we are having a hard time
resolving.  So revert them for now.

Specifically this reverts:

	commit 0bec3b700d106a8b0a34227b2976d1a582f1aab7
	Author: Florian Westphal <fw@strlen.de>
	Date:   Wed Jan 7 10:49:49 2015 +0100

	    r8169: add support for xmit_more

and

	commit 1e918876853aa85435e0f17fd8b4a92dcfff53d6
	Author: Florian Westphal <fw@strlen.de>
	Date:   Wed Oct 1 13:38:03 2014 +0200

	    r8169: add support for Byte Queue Limits

There were some attempts by Eric Dumazet to address some obvious
problems in the TX flow, to see if they would fix the problems,
but none of them seem to help for the regression reporters.

Signed-off-by: David S. Miller <davem@davemloft.net>
---
 drivers/net/ethernet/realtek/r8169.c | 30 +++++++-----------------------
 1 file changed, 7 insertions(+), 23 deletions(-)

diff --git a/drivers/net/ethernet/realtek/r8169.c b/drivers/net/ethernet/realtek/r8169.c
index ad0020a..b156092 100644
--- a/drivers/net/ethernet/realtek/r8169.c
+++ b/drivers/net/ethernet/realtek/r8169.c
@@ -5067,8 +5067,6 @@ static void rtl_hw_reset(struct rtl8169_private *tp)
 	RTL_W8(ChipCmd, CmdReset);
 
 	rtl_udelay_loop_wait_low(tp, &rtl_chipcmd_cond, 100, 100);
-
-	netdev_reset_queue(tp->dev);
 }
 
 static void rtl_request_uncached_firmware(struct rtl8169_private *tp)
@@ -7049,7 +7047,6 @@ static netdev_tx_t rtl8169_start_xmit(struct sk_buff *skb,
 	u32 status, len;
 	u32 opts[2];
 	int frags;
-	bool stop_queue;
 
 	if (unlikely(!TX_FRAGS_READY_FOR(tp, skb_shinfo(skb)->nr_frags))) {
 		netif_err(tp, drv, dev, "BUG! Tx Ring full when queue awake!\n");
@@ -7090,8 +7087,6 @@ static netdev_tx_t rtl8169_start_xmit(struct sk_buff *skb,
 
 	txd->opts2 = cpu_to_le32(opts[1]);
 
-	netdev_sent_queue(dev, skb->len);
-
 	skb_tx_timestamp(skb);
 
 	/* Force memory writes to complete before releasing descriptor */
@@ -7106,16 +7101,11 @@ static netdev_tx_t rtl8169_start_xmit(struct sk_buff *skb,
 
 	tp->cur_tx += frags + 1;
 
-	stop_queue = !TX_FRAGS_READY_FOR(tp, MAX_SKB_FRAGS);
+	RTL_W8(TxPoll, NPQ);
 
-	if (!skb->xmit_more || stop_queue ||
-	    netif_xmit_stopped(netdev_get_tx_queue(dev, 0))) {
-		RTL_W8(TxPoll, NPQ);
-
-		mmiowb();
-	}
+	mmiowb();
 
-	if (stop_queue) {
+	if (!TX_FRAGS_READY_FOR(tp, MAX_SKB_FRAGS)) {
 		/* Avoid wrongly optimistic queue wake-up: rtl_tx thread must
 		 * not miss a ring update when it notices a stopped queue.
 		 */
@@ -7198,7 +7188,6 @@ static void rtl8169_pcierr_interrupt(struct net_device *dev)
 static void rtl_tx(struct net_device *dev, struct rtl8169_private *tp)
 {
 	unsigned int dirty_tx, tx_left;
-	unsigned int bytes_compl = 0, pkts_compl = 0;
 
 	dirty_tx = tp->dirty_tx;
 	smp_rmb();
@@ -7222,8 +7211,10 @@ static void rtl_tx(struct net_device *dev, struct rtl8169_private *tp)
 		rtl8169_unmap_tx_skb(&tp->pci_dev->dev, tx_skb,
 				     tp->TxDescArray + entry);
 		if (status & LastFrag) {
-			pkts_compl++;
-			bytes_compl += tx_skb->skb->len;
+			u64_stats_update_begin(&tp->tx_stats.syncp);
+			tp->tx_stats.packets++;
+			tp->tx_stats.bytes += tx_skb->skb->len;
+			u64_stats_update_end(&tp->tx_stats.syncp);
 			dev_kfree_skb_any(tx_skb->skb);
 			tx_skb->skb = NULL;
 		}
@@ -7232,13 +7223,6 @@ static void rtl_tx(struct net_device *dev, struct rtl8169_private *tp)
 	}
 
 	if (tp->dirty_tx != dirty_tx) {
-		netdev_completed_queue(tp->dev, pkts_compl, bytes_compl);
-
-		u64_stats_update_begin(&tp->tx_stats.syncp);
-		tp->tx_stats.packets += pkts_compl;
-		tp->tx_stats.bytes += bytes_compl;
-		u64_stats_update_end(&tp->tx_stats.syncp);
-
 		tp->dirty_tx = dirty_tx;
 		/* Sync with rtl8169_start_xmit:
 		 * - publish dirty_tx ring index (write barrier)
-- 
2.1.0