2.6.6 e1000 NETDEV WATCHDOG: eth0: transmit timed out

DISCUSSION David Greaves 5 participants 13 messages Jun 14, 2004 – Jun 21, 2004 2 messages not in the archive

Subsystems (2)

Networking Network drivers

lore

Share & tools

lore

David Greaves

author

2004-06-14 16:47 UTC #0 lore raw

I have 2 machines with Intel/Pro 1000MT cards.

One machine seems to work fine (AFAIK), the other has major problems. I've swapped the cards and the problem stays on the machine.

I'm using version 5.2.39-k2 from the stock 2.6.6 kernel on both machines.

Any sustained traffic causes repeated:

Jun 14 16:29:14 ash kernel: NETDEV WATCHDOG: eth0: transmit timed out
Jun 14 16:29:17 ash kernel: e1000: eth0 NIC Link is Up 1000 Mbps Full Duplex
Jun 14 16:29:17 ash kernel: nfs: server cu OK

I had a pair of Realtek r8169s that worked fine but only gave me 10Mb/s so I exchanged them for the Intel/Pro cards in the hope of something better - now, even with scp's rate limiter as low as 10kb/s this it still occurs.

I have played with all the module parameters and not found anything that affects it at 1Gbps

Even dropping to 100Mbps:

Jun 14 17:33:03 ash kernel: e1000: eth0 NIC Link is Up 100 Mbps Full Duplex
Jun 14 17:33:33 ash kernel: NETDEV WATCHDOG: eth0: transmit timed out

it can do 10Mbs:
scp reports a throughput of 1.0Mb/s (... less than thrilling) however scp now transfers a few Mb and says:
Disconnecting: Corrupted MAC on input.

I found this mail:
http://oss.sgi.com/projects/netdev/archive/2004-06/msg00256.html
from Stephen

which appears to reverse this mail:
http://marc.theaimsgroup.com/?l=linux-kernel&m=107516205706542&w=2
from Scott
which I gather was supposed to correct this problem :)

I have seen no suggestions about other subsystems (eg ACPI etc) that could also be tried.

David

David Greaves

author

2004-06-16 10:59 UTC #2 lore raw

In reply to a message not in the archive

Quoted 8 lines · Stephen Hemminger

How big is the transmit ring. Setting a bigger transmit ring fixed my problem
	modprobe e1000 TxDescriptors=1024
Also, there are lots of flavors of this chipset and board. One machine I was using had the IBM rebranded version and it would only do PCI33 not PCI66.

Thanks for replying Stephen - it's really frustrating :)

I did try TxDescriptors and various (most) other parameters (below are the actual parameter variations I tried - just cut from a 'history' for info).

After each one i downed the link and modprobe -r the driver.
I then ran a large file scp (quicker id+recovery than nfs hanging when the link died)

I invariably got an eth0 timed out after a few seconds - some variation but IIRC no more than 20% - ie 8-10Mb of a 1G file before it failed.

root@ash:~ # ethtool -g eth0
Ring parameters for eth0:
Pre-set maximums:

RX:             4096
RX Mini:        0
RX Jumbo:       0
TX:             4096
Current hardware settings:
RX:             256
RX Mini:        0
RX Jumbo:       0
TX:             1024

I've pulled all the cards and looked - they are all genuine Intel C39226-003 (Pro/1000 MT) This page http://support.intel.com/support/network/sb/cs-005980-prd38.htm
says: 82541 Gigabit Small Form 32/66
My system has PCI33 BTW.

I have also tried 2.6.7 this morning and have the same problem.

David

module parameters.
modprobe e1000 FlowControl=2
modprobe e1000 FlowControl=1
modprobe e1000 FlowControl=3
modprobe e1000 FlowControl=0
modprobe e1000 FlowControl=0 InterruptThrottleRate=100
modprobe e1000 FlowControl=0 InterruptThrottleRate=1 RxDescriptors=1024 ; ifup eth0
modprobe e1000 FlowControl=0 InterruptThrottleRate=1 RxDescriptors=4096 ; ifup eth0
modprobe e1000 FlowControl=0 InterruptThrottleRate=1 RxDescriptors=256 RxIntDelay=1 ; ifup eth0
modprobe e1000 FlowControl=0 InterruptThrottleRate=1 RxDescriptors=256 RxIntDelay=10 ; ifup eth0
modprobe e1000 FlowControl=0 InterruptThrottleRate=1 RxDescriptors=256 RxIntDelay=1000 ; ifup eth0
modprobe e1000 FlowControl=0 InterruptThrottleRate=1 RxDescriptors=256 RxIntDelay=0 RxAbsIntDelay=0 ; ifup eth0 modprobe e1000 FlowControl=0 InterruptThrottleRate=1 RxDescriptors=256 RxIntDelay=0 RxAbsIntDelay=0 TxIntDelay=0 ; ifup eth0 modprobe e1000 FlowControl=0 InterruptThrottleRate=1 RxDescriptors=256 RxIntDelay=0 RxAbsIntDelay=1024 TxIntDelay=53 ; ifup eth0 modprobe e1000 FlowControl=0 InterruptThrottleRate=1 RxDescriptors=256 RxIntDelay=0 RxAbsIntDelay=1024 TxIntDelay=64 ; ifup eth0 modprobe e1000 FlowControl=0 InterruptThrottleRate=1 RxDescriptors=256 RxIntDelay=0 RxAbsIntDelay=65535 TxIntDelay=64 ; ifup eth0 modprobe e1000 FlowControl=0 InterruptThrottleRate=1 RxDescriptors=256 RxIntDelay=0 RxAbsIntDelay=128 TxIntDelay=0 ; ifup eth0 modprobe e1000 FlowControl=0 InterruptThrottleRate=1 RxDescriptors=256 RxIntDelay=0 RxAbsIntDelay=128 TxIntDelay=32000 ; ifup eth0 modprobe e1000 FlowControl=0 InterruptThrottleRate=1 RxDescriptors=256 RxIntDelay=0 RxAbsIntDelay=128 TxIntDelay=32000 ; ifup eth0 modprobe e1000 FlowControl=0 InterruptThrottleRate=1 RxDescriptors=256 RxIntDelay=0 RxAbsIntDelay=128 TxIntDelay=64 XsumRX=1 ; ifup eth0 modprobe e1000 Speed=100
modprobe e1000 Speed=10

Jens Laas

2004-06-18 08:04 UTC #3 lore raw

(04.06.16 kl.11:59) David Greaves skrev följande till Stephen Hemminger:

We have seen the same symptoms. (2.6.x + e1000)

Our system is an SMP system. That might be whats triggering the problem. Is your system UP or SMP ?
(Next reboot we will test running on only one CPU).

We have tried with and without NAPI, both exhibit the same problem. We have tried different versions of e1000 without luck. We have tried with 100Mb and gigabit switches.

Make sure that flowcontrol is disabled on your switch (if it has it implemented).

Quoted 4 lines

Quoted 2 lines · Stephen Hemminger
How big is the transmit ring. Setting a bigger transmit ring fixed my problem
	modprobe e1000 TxDescriptors=1024

I wouldnt call that a fix, more like a workaround. It should work
regardless of ringsize.

Quoted 32 lines

Quoted 5 lines
Also, there are lots of flavors of this chipset and board. One machine I was using had the IBM rebranded version and it would only do PCI33 not PCI66.
Thanks for replying Stephen - it's really frustrating :)
I did try TxDescriptors and various (most) other parameters (below are the actual parameter variations I tried - just cut from a 'history' for info).
After each one i downed the link and modprobe -r the driver.
I then ran a large file scp (quicker id+recovery than nfs hanging when the link died)
I invariably got an eth0 timed out after a few seconds - some variation but IIRC no more than 20% - ie 8-10Mb of a 1G file before it failed.
root@ash:~ # ethtool -g eth0
Ring parameters for eth0:
Pre-set maximums:
RX:             4096
RX Mini:        0
RX Jumbo:       0
TX:             4096
Current hardware settings:
RX:             256
RX Mini:        0
RX Jumbo:       0
TX:             1024
I've pulled all the cards and looked - they are all genuine Intel C39226-003 (Pro/1000 MT) This page http://support.intel.com/support/network/sb/cs-005980-prd38.htm
says: 82541 Gigabit Small Form 32/66
My system has PCI33 BTW.

Quoted 6 lines

I have also tried 2.6.7 this morning and have the same problem.
David
module parameters.

I believe following is recommended by driver developers:
TxDescriptors=256 RxDescriptors=256 FlowControl=0 XsumRX=0

Cheers,
Jens Låås

-----------------------------------------------------------------------
'This mail automatically becomes portable when carried.'
-----------------------------------------------------------------------
Jens Låås Email: [email protected]
Department of Computer Services, SLU Phone: +46 18 67 35 15
Vindbrovägen 1
P.O. Box 7079
S-750 07 Uppsala
SWEDEN
-----------------------------------------------------------------------

David Greaves

author

2004-06-18 09:08 UTC #4 lore raw

Re: 2.6.6 e1000 NETDEV WATCHDOG: eth0: transmit timed out+ delay scheduler

Stephen, I applied your delay scheduler patch and some results appear below.

Quoted 6 lines · Jens Laas

(04.06.16 kl.11:59) David Greaves skrev följande till Stephen Hemminger:
We have seen the same symptoms. (2.6.x + e1000)
Our system is an SMP system. That might be whats triggering the problem. Is your system UP or SMP ?

Quoted 3 lines

(Next reboot we will test running on only one CPU).
We have tried with and without NAPI, both exhibit the same problem.

Me too

Quoted 1 line

We have tried different versions of e1000 without luck.

Me too, 3 cards.
(did I mention I have 2 machines with very similar specs (AMD/VIAKT600) and the other one works - actually, to be accurate, hasn't yet failed but hasn't yet run at full speed - and it has a higher CPU speed)

Quoted 1 line

We have tried with 100Mb and gigabit switches.

I'm now running two e1000's back to back over a piece of cat5...

Quoted 2 lines

Make sure that flowcontrol is disabled on your switch (if it has it implemented).

...so it's not that smart anymore ;)

Quoted 6 lines

Quoted 2 lines
module parameters.
I believe following is recommended by driver developers:
TxDescriptors=256 RxDescriptors=256 FlowControl=0 XsumRX=0

Yes, I'm running with module defaults unless otherwise stated but I've tried that combo (to no effect)

I'm speaking with Ganesh Venkatesan at intel about it. Ganesh you went off list - do you want to include Jens or maybe go back on-list?

A simple failure case for me is : 'ping -s 1500 ' This doesn't cause the timout but doesn't succeed either.

ping -f with standard packet size succeeds (slow rate though) and doesn't timeout.

Using 8139 100Mbs card:
272384 packets transmitted, 272383 packets received, 0% packet loss round-trip min/avg/max = 0.1/0.1/4.0 ms
real 0m32.179s

Using Pro/1000:
60992 packets transmitted, 60991 packets received, 0% packet loss round-trip min/avg/max = 0.0/0.5/8.4 ms
real 0m38.257s

any ping with -s >1500 results in 100% packet loss.

============
From hereon down it's 2.6.7 with Stephen's recent delay scheduler patch

This changed the behaviour.

Now ping -s 1500 works
but after that it gets lossy
root@ash:~ # ping -s3000 10.0.1.1
PING 10.0.1.1 (10.0.1.1): 3000 data bytes
3008 bytes from 10.0.1.1: icmp_seq=1 ttl=64 time=0.5 ms 3008 bytes from 10.0.1.1: icmp_seq=11 ttl=64 time=0.5 ms 3008 bytes from 10.0.1.1: icmp_seq=12 ttl=64 time=0.4 ms 3008 bytes from 10.0.1.1: icmp_seq=13 ttl=64 time=0.9 ms 3008 bytes from 10.0.1.1: icmp_seq=15 ttl=64 time=0.4 ms 3008 bytes from 10.0.1.1: icmp_seq=16 ttl=64 time=0.3 ms

and now I'm seeing ping generate:

Jun 18 09:41:57 ash kernel: NETDEV WATCHDOG: eth0: transmit timed out
Jun 18 09:41:59 ash kernel: e1000: eth0: e1000_watchdog: NIC Link is Up 1000 Mbps Full Duplex

ping -f now works for packet sizes up to -s 2952 (2 packets at mtu 1500)

ping -f -s 2953 results in:
PING 10.0.1.1 (10.0.1.1): 2953 data bytes ..............................ping: sendto: No buffer space available
ping: wrote 10.0.1.1 2961 chars, ret=-1
.ping: sendto: No buffer space available

nb. with the patch, between the same machines via an alternate pair of nics:
root@ash:~ # ping -f -s29550 haze
PING haze.dgreaves.com (10.0.0.88): 29550 data bytes
.
--- haze.dgreaves.com ping statistics ---
10592 packets transmitted, 10591 packets received, 0% packet loss round-trip min/avg/max = 5.4/5.5/83.5 ms

Increasing Transmit Descriptors to 4096 avoids the No buffer space available with packet sizes up to -s65468 (still 100% failure though)

I'm not sure that adds much now so I'll leave it until I get some more suggestions.

HTH

David

Jens Laas

2004-06-18 10:27 UTC #5 lore raw

Re: 2.6.6 e1000 NETDEV WATCHDOG: eth0: transmit timed out+ delay scheduler

(04.06.18 kl.10:08) David Greaves skrev följande till Jens Laas:

Quoted 4 lines

Stephen, I applied your delay scheduler patch and some results appear below.
Jens Laas wrote:

Quoted 8 lines

Quoted 6 lines
(04.06.16 kl.11:59) David Greaves skrev följande till Stephen Hemminger:
We have seen the same symptoms. (2.6.x + e1000)
Our system is an SMP system. That might be whats triggering the problem. Is your system UP or SMP ?
UP

Ok. This keeps getting stranger..

Quoted 9 lines

Quoted 4 lines
(Next reboot we will test running on only one CPU).
We have tried with and without NAPI, both exhibit the same problem.
Me too
Quoted 1 line
We have tried different versions of e1000 without luck.

...

Quoted 5 lines

Quoted 1 line
Make sure that flowcontrol is disabled on your switch (if it has it implemented).
...so it's not that smart anymore ;)
Quoted 1 line
Quoted 1 line

Quoted 7 lines

Quoted 5 lines
Quoted 1 line
module parameters.
I believe following is recommended by driver developers:
TxDescriptors=256 RxDescriptors=256 FlowControl=0 XsumRX=0
Yes, I'm running with module defaults unless otherwise stated but I've tried that combo (to no effect)

No effect here either. FlowControl and XsumRX are known troublemakers.

Quoted 2 lines

I'm speaking with Ganesh Venkatesan at intel about it. Ganesh you went off list - do you want to include Jens or maybe go back on-list?

If others run into this problem I'm sure they'll appreciate if its on list.
Since we have no idea what causes this (AFAIK) it may be a more general problem than the device driver.

Quoted 5 lines

A simple failure case for me is : 'ping -s 1500 ' This doesn't cause the timout but doesn't succeed either.
ping -f with standard packet size succeeds (slow rate though) and doesn't timeout.

I dont see the ping problems at all. Unless you try to ping when the interface has "hanged" ?

Quoted 11 lines

Using 8139 100Mbs card:
272384 packets transmitted, 272383 packets received, 0% packet loss round-trip min/avg/max = 0.1/0.1/4.0 ms
real 0m32.179s
Using Pro/1000:
60992 packets transmitted, 60991 packets received, 0% packet loss round-trip min/avg/max = 0.0/0.5/8.4 ms
real 0m38.257s

Quoted 6 lines

any ping with -s >1500 results in 100% packet loss.
============
From hereon down it's 2.6.7 with Stephen's recent delay scheduler patch
This changed the behaviour.

This is strange unless you are actually using the delay scheduler ?
Default is sch_generic (that is pfifo) that does not exhibit the problems correct by the patch.

Quoted 4 lines

10592 packets transmitted, 10591 packets received, 0% packet loss round-trip min/avg/max = 5.4/5.5/83.5 ms
Increasing Transmit Descriptors to 4096 avoids the No buffer space available with packet sizes up to -s65468 (still 100% failure though)

Increasing nr of buffers is not a way to fix the problem.

I had hoped to hear something about this from Scott..

Cheers,
Jens

Quoted 7 lines

I'm not sure that adds much now so I'll leave it until I get some more suggestions.
HTH
David

David Greaves

author

2004-06-18 12:51 UTC #6 lore raw

Re: 2.6.6 e1000 NETDEV WATCHDOG: eth0: transmit timed out+ delay scheduler

New info:
I booted into XP and the card works there - so it doesn't look like a simple hardware incompatibility.
[I've got no real way to test the performance but cygwin's wget against apache1.3 on the linux box returns about 25M/s initially and then 15M/s sustained for 500Mb]

Quoted 6 lines · Jens Laas

Quoted 2 lines
I'm speaking with Ganesh Venkatesan at intel about it. Ganesh you went off list - do you want to include Jens or maybe go back on-list?
If others run into this problem I'm sure they'll appreciate if its on list.
Since we have no idea what causes this (AFAIK) it may be a more general problem than the device driver.

I tend to agree - but I wasn't sure if this was the place and I'll do as I'm told ;)

Quoted 8 lines

Quoted 4 lines
A simple failure case for me is : 'ping -s 1500 ' This doesn't cause the timout but doesn't succeed either.
ping -f with standard packet size succeeds (slow rate though) and doesn't timeout.
I dont see the ping problems at all. Unless you try to ping when the interface has "hanged" ?

<sigh> thought that might be helpful.
Ping with -s and -f seems to allow me to trigger errors and it seems a lot more debug-able than scp or nfs :) No all tests are when it's reset and 'clean'

Quoted 9 lines

Quoted 4 lines
============
From hereon down it's 2.6.7 with Stephen's recent delay scheduler patch
This changed the behaviour.
This is strange unless you are actually using the delay scheduler ?
Default is sch_generic (that is pfifo) that does not exhibit the problems correct by the patch.

I'll go back and double check in case I cocked up...
(I noticed the e1000 module rebuild but you're right that's incidental)

I've rebuilt the kernel and modules with and w/o patch and rebooted a few times and I can't reproduce that effect - sorry for the red herring. So after I reverted Stephens patch the results I reported are still reproducable w/o the patch.

Quoted 7 lines

Quoted 4 lines
10592 packets transmitted, 10591 packets received, 0% packet loss round-trip min/avg/max = 5.4/5.5/83.5 ms
Increasing Transmit Descriptors to 4096 avoids the No buffer space available with packet sizes up to -s65468 (still 100% failure though)
Increasing nr of buffers is not a way to fix the problem.

agreed - however in my ignorance of the deep behaviour I'm reporting things that affect behaviour in ways I don't expect. I expected it to take longer to run out of buffers - that didn't happen :)

(Anyway, on retesting I find that this was wrong - I suspect the interface was down and I didn't notice)

Quoted 2 lines

I had hoped to hear something about this from Scott..

I'm happy to hear from anyone - I don't have *that* long until my RMA option expires and I don't fancy keeping them as ornaments!

David

Stephen Hemminger

2004-06-18 18:11 UTC #11 lore raw

In reply to Jens Laas

To get to the root of these problems, could you:

* Give full lspci -v output for the boards in question.

* Are you using any special queuing or shaping (output of "tc qdisc ls")

* You could try the following, which dumps out the state of the transmit ring in case of error. and tries to see if it is one of the other watchdog hooks in this driver.

------

drivers/net/e1000/e1000_main.c +22 -1

diff -Nru a/drivers/net/e1000/e1000_main.c b/drivers/net/e1000/e1000_main.c
@@ -1426,6 +1426,7 @@
 			 * but we've got queued Tx work that's never going
 			 * to get done, so reset controller to flush Tx.
 			 * (Do the reset outside of interrupt context). */
+			printk("%s: link lost but ring is full\n", netdev->name);
 			schedule_work(&adapter->tx_timeout_task);
 		}
 	}

@@ -1450,8 +1451,12 @@
 	i = txdr->next_to_clean;
 	if(txdr->buffer_info[i].dma &&
 	   time_after(jiffies, txdr->buffer_info[i].time_stamp + HZ) &&
-	   !(E1000_READ_REG(&adapter->hw, STATUS) & E1000_STATUS_TXOFF))
+	   !(E1000_READ_REG(&adapter->hw, STATUS) & E1000_STATUS_TXOFF)) {
+		printk("%s: may be hung last tx was %ld ticks\n",
+		       netdev->name, 
+		       (long)(jiffies - txdr->buffer_info[i].time_stamp));
 		netif_stop_queue(netdev);
+	}
 
 	/* Reset the timer */
 	mod_timer(&adapter->watchdog_timer, jiffies + 2 * HZ);

@@ -1826,6 +1831,7 @@
 {
 	struct e1000_adapter *adapter = netdev->priv;
 
+	printk("%s: transmit timeout from queuing\n", netdev->name);
 	/* Do the reset outside of interrupt context */
 	schedule_work(&adapter->tx_timeout_task);
 }

@@ -1834,6 +1840,21 @@
 e1000_tx_timeout_task(struct net_device *netdev)
 {
 	struct e1000_adapter *adapter = netdev->priv;
+	unsigned long now = jiffies;
+	int i;
+
+	printk("%s: state=0x%lx transmit ring size=%u count=%u to_use=%u to_clean=%u\n",
+	       netdev->name, netdev->state,
+	       adapter->tx_ring.size, adapter->tx_ring.count,
+	       adapter->tx_ring.next_to_use, adapter->tx_ring.next_to_clean);
+	
+	for (i = 0; i < adapter->tx_ring.count; ++i) {
+		struct e1000_buffer *b = &adapter->tx_ring.buffer_info[i];
+		printk(" %d: skb=%p dma=%llu length=%lu time=+%ld watch=%u\n",
+		       i, b->skb, b->dma, b->length, 
+		       (long) (now - b->time_stamp), b->next_to_watch);
+	}
+	
 
 	netif_device_detach(netdev);
 	e1000_down(adapter);

David Greaves

author

2004-06-18 18:44 UTC #12 lore raw

Quoted 5 lines · Stephen Hemminger

To get to the root of these problems, could you:
* Give full lspci -v output for the boards in question.

ash:
00:07.0 Ethernet controller: Intel Corp.: Unknown device 1076
Subsystem: Intel Corp.: Unknown device 1176
Flags: bus master, 66Mhz, medium devsel, latency 32, IRQ 11 Memory at e3020000 (32-bit, non-prefetchable) [size=128K] Memory at e3000000 (32-bit, non-prefetchable) [size=128K] I/O ports at b400 [size=64]
Expansion ROM at <unassigned> [disabled] [size=128K]
Capabilities: [dc] Power Management version 2
Capabilities: [e4] PCI-X non-bridge device.
Capabilities: [f0] Message Signalled Interrupts: 64bit+
Queue=0/0 Enable-

Quoted 3 lines

* Are you using any special queuing or shaping (output of "tc qdisc ls")

no
root@ash:~ # tc qdisc ls
RTNETLINK answers: Invalid argument
Dump terminated

Quoted 5 lines

* You could try the following, which dumps out the state of the transmit ring in case of error. and tries to see if it is one of the other watchdog hooks in this driver.

patched :)

Test

root@ash:/usr/src/linux # ifdown eth0 ; modprobe -r e1000;modprobe e1000; ifup eth0ifdown: interface eth0 not configured root@ash:/usr/src/linux # ping 10.0.1.1
PING 10.0.1.1 (10.0.1.1): 56 data bytes
64 bytes from 10.0.1.1: icmp_seq=0 ttl=64 time=0.3 ms
64 bytes from 10.0.1.1: icmp_seq=1 ttl=64 time=0.1 ms
64 bytes from 10.0.1.1: icmp_seq=2 ttl=64 time=0.1 ms
64 bytes from 10.0.1.1: icmp_seq=3 ttl=64 time=0.2 ms

--- 10.0.1.1 ping statistics ---
4 packets transmitted, 4 packets received, 0% packet loss round-trip min/avg/max = 0.1/0.1/0.3 ms root@ash:/usr/src/linux # ping -s 1500 10.0.1.1 PING 10.0.1.1 (10.0.1.1): 1500 data bytes
1508 bytes from 10.0.1.1: icmp_seq=0 ttl=64 time=0.3 ms 1508 bytes from 10.0.1.1: icmp_seq=1 ttl=64 time=0.4 ms 1508 bytes from 10.0.1.1: icmp_seq=2 ttl=64 time=0.3 ms

--- 10.0.1.1 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 0.3/0.3/0.4 ms root@ash:/usr/src/linux # ping -s 3000 10.0.1.1 PING 10.0.1.1 (10.0.1.1): 3000 data bytes
3008 bytes from 10.0.1.1: icmp_seq=0 ttl=64 time=0.4 ms 3008 bytes from 10.0.1.1: icmp_seq=3 ttl=64 time=0.3 ms

--- 10.0.1.1 ping statistics ---
7 packets transmitted, 2 packets received, 71% packet loss round-trip min/avg/max = 0.3/0.3/0.4 ms

messages: (the 'after 5000 jiffies' is mine)

Jun 18 19:37:43 ash kernel: Copyright (c) 1999-2004 Intel Corporation.
Jun 18 19:37:44 ash kernel: e1000: eth0: e1000_probe: Intel(R) PRO/1000 Network Co
nnection
Jun 18 19:37:46 ash kernel: e1000: eth0: e1000_watchdog: NIC Link is Up 1000 Mbps

Full Duplex

Jun 18 19:38:18 ash kernel: eth0: may be hung last tx was 2457 ticks

Jun 18 19:38:20 ash kernel: eth0: may be hung last tx was 4457 ticks
Jun 18 19:38:22 ash kernel: eth0: may be hung last tx was 6457 ticks
Jun 18 19:38:24 ash kernel: eth0: may be hung last tx was 8457 ticks
Jun 18 19:38:26 ash kernel: NETDEV WATCHDOG: eth0: transmit timed out after 5000 j
iffies
Jun 18 19:38:26 ash kernel: eth0: transmit timeout from queuing
Jun 18 19:38:26 ash kernel: eth0: may be hung last tx was 10457 ticks
Jun 18 19:38:26 ash kernel: eth0: state=0x7 transmit ring size=4096 count=256 to_u
se=66 to_clean=59
Jun 18 19:38:26 ash kernel:  0: skb=00000000 dma=0 length=42 time=+29527 watch=0
Jun 18 19:38:26 ash kernel:  1: skb=00000000 dma=0 length=98 time=+29527 watch=1
Jun 18 19:38:26 ash kernel:  2: skb=00000000 dma=0 length=98 time=+28526 watch=2
Jun 18 19:38:26 ash kernel:  3: skb=00000000 dma=0 length=98 time=+27525 watch=3
Jun 18 19:38:26 ash kernel:  4: skb=00000000 dma=0 length=98 time=+26524 watch=4
Jun 18 19:38:26 ash kernel:  5: skb=00000000 dma=0 length=42 time=+24528 watch=5
Jun 18 19:38:26 ash kernel:  6: skb=00000000 dma=0 length=0 time=+20324251 watch=7
Jun 18 19:38:26 ash kernel:  7: skb=00000000 dma=0 length=110 time=+24510 watch=0
Jun 18 19:38:26 ash kernel:  8: skb=00000000 dma=0 length=0 time=+20324251 watch=9
Jun 18 19:38:26 ash kernel:  9: skb=00000000 dma=0 length=110 time=+24510 watch=0
Jun 18 19:38:26 ash kernel:  10: skb=00000000 dma=0 length=0 time=+20324251 watch=
11
Jun 18 19:38:26 ash kernel:  11: skb=00000000 dma=0 length=110 time=+24510 watch=0
Jun 18 19:38:26 ash kernel:  12: skb=00000000 dma=0 length=0 time=+20324251 watch=
13
Jun 18 19:38:26 ash kernel:  13: skb=00000000 dma=0 length=110 time=+24510 watch=0
Jun 18 19:38:26 ash kernel:  14: skb=00000000 dma=0 length=0 time=+20324251 watch=
15
Jun 18 19:38:26 ash kernel:  15: skb=00000000 dma=0 length=110 time=+24510 watch=0
Jun 18 19:38:26 ash kernel:  16: skb=00000000 dma=0 length=0 time=+20324251 watch=
17
Jun 18 19:38:26 ash kernel:  17: skb=00000000 dma=0 length=257 time=+24510 watch=0
Jun 18 19:38:26 ash kernel:  18: skb=00000000 dma=0 length=0 time=+20324251 watch=
19
Jun 18 19:38:26 ash kernel:  19: skb=00000000 dma=0 length=110 time=+22510 watch=0
Jun 18 19:38:26 ash kernel:  20: skb=00000000 dma=0 length=0 time=+20324251 watch=
21
Jun 18 19:38:26 ash kernel:  21: skb=00000000 dma=0 length=110 time=+22510 watch=0
Jun 18 19:38:26 ash kernel:  22: skb=00000000 dma=0 length=0 time=+20324251 watch=
23
Jun 18 19:38:26 ash kernel:  23: skb=00000000 dma=0 length=110 time=+22510 watch=0
Jun 18 19:38:26 ash kernel:  24: skb=00000000 dma=0 length=0 time=+20324251 watch=
25
Jun 18 19:38:26 ash kernel:  25: skb=00000000 dma=0 length=110 time=+22510 watch=0
Jun 18 19:38:26 ash kernel:  26: skb=00000000 dma=0 length=0 time=+20324251 watch=
27
Jun 18 19:38:26 ash kernel:  27: skb=00000000 dma=0 length=110 time=+22510 watch=0
Jun 18 19:38:26 ash kernel:  28: skb=00000000 dma=0 length=0 time=+20324251 watch=
29
Jun 18 19:38:26 ash kernel:  29: skb=00000000 dma=0 length=110 time=+22510 watch=0
Jun 18 19:38:26 ash kernel:  30: skb=00000000 dma=0 length=0 time=+20324251 watch=
31
Jun 18 19:38:26 ash kernel:  31: skb=00000000 dma=0 length=110 time=+22510 watch=0
Jun 18 19:38:26 ash kernel:  32: skb=00000000 dma=0 length=0 time=+20324251 watch=
33
Jun 18 19:38:26 ash kernel:  33: skb=00000000 dma=0 length=110 time=+22510 watch=0
Jun 18 19:38:26 ash kernel:  34: skb=00000000 dma=0 length=0 time=+20324251 watch=
35
Jun 18 19:38:26 ash kernel:  35: skb=00000000 dma=0 length=110 time=+22510 watch=0
Jun 18 19:38:26 ash kernel:  36: skb=00000000 dma=0 length=0 time=+20324251 watch=
37
Jun 18 19:38:26 ash kernel:  37: skb=00000000 dma=0 length=110 time=+22510 watch=0
Jun 18 19:38:26 ash kernel:  38: skb=00000000 dma=0 length=1514 time=+21082 watch=
38
Jun 18 19:38:26 ash kernel:  39: skb=00000000 dma=0 length=62 time=+21082 watch=39
Jun 18 19:38:26 ash kernel:  40: skb=00000000 dma=0 length=0 time=+20324251 watch=
41
Jun 18 19:38:26 ash kernel:  41: skb=00000000 dma=0 length=110 time=+20510 watch=0
Jun 18 19:38:26 ash kernel:  42: skb=00000000 dma=0 length=0 time=+20324251 watch=
43
Jun 18 19:38:26 ash kernel:  43: skb=00000000 dma=0 length=110 time=+20510 watch=0
Jun 18 19:38:26 ash kernel:  44: skb=00000000 dma=0 length=0 time=+20324251 watch=
45
Jun 18 19:38:26 ash kernel:  45: skb=00000000 dma=0 length=110 time=+20510 watch=0
Jun 18 19:38:26 ash kernel:  46: skb=00000000 dma=0 length=0 time=+20324251 watch=
47
Jun 18 19:38:26 ash kernel:  47: skb=00000000 dma=0 length=110 time=+20510 watch=0
Jun 18 19:38:26 ash kernel:  48: skb=00000000 dma=0 length=0 time=+20324251 watch=
49
Jun 18 19:38:26 ash kernel:  49: skb=00000000 dma=0 length=110 time=+20510 watch=0
Jun 18 19:38:26 ash kernel:  50: skb=00000000 dma=0 length=1514 time=+20081 watch=
50
Jun 18 19:38:26 ash kernel:  51: skb=00000000 dma=0 length=62 time=+20081 watch=51
Jun 18 19:38:26 ash kernel:  52: skb=00000000 dma=0 length=1514 time=+19080 watch=
52
Jun 18 19:38:26 ash kernel:  53: skb=00000000 dma=0 length=62 time=+19080 watch=53
Jun 18 19:38:26 ash kernel:  54: skb=00000000 dma=0 length=1514 time=+11459 watch=
54
Jun 18 19:38:26 ash kernel:  55: skb=00000000 dma=0 length=1514 time=+11458 watch=
55
Jun 18 19:38:26 ash kernel:  56: skb=00000000 dma=0 length=82 time=+11458 watch=56
Jun 18 19:38:26 ash kernel:  57: skb=00000000 dma=0 length=1514 time=+10457 watch=
57
Jun 18 19:38:26 ash kernel:  58: skb=00000000 dma=0 length=1514 time=+10457 watch=
58
Jun 18 19:38:26 ash kernel:  59: skb=f0740420 dma=934467074 length=82 time=+10457
watch=59
Jun 18 19:38:26 ash kernel:  60: skb=d6e91420 dma=397015042 length=1514 time=+9456
watch=60
Jun 18 19:38:26 ash kernel:  61: skb=f07406a0 dma=935571458 length=1514 time=+9456
watch=61
Jun 18 19:38:26 ash kernel:  62: skb=f3fcde20 dma=26358274 length=82 time=+9456 wa
tch=62
Jun 18 19:38:26 ash kernel:  63: skb=f0740ba0 dma=397012994 length=1514 time=+8455
watch=63
Jun 18 19:38:26 ash kernel:  64: skb=d6e914c0 dma=935573506 length=1514 time=+8455
watch=64
Jun 18 19:38:26 ash kernel:  65: skb=f0740600 dma=937204738 length=82 time=+8455 w
atch=65
Jun 18 19:38:26 ash kernel:  66: skb=00000000 dma=0 length=0 time=+20324251 watch=
0
<snip many duplicate lines>
Jun 18 19:38:26 ash kernel: eth0: link lost but ring is full
Jun 18 19:38:26 ash kernel: eth0: state=0x16 transmit ring size=4096 count=256 to_
use=9 to_clean=2
Jun 18 19:38:26 ash kernel:  0: skb=00000000 dma=0 length=1514 time=+1 watch=0
Jun 18 19:38:26 ash kernel:  1: skb=00000000 dma=0 length=1514 time=+1 watch=1
Jun 18 19:38:26 ash kernel:  2: skb=f0740060 dma=26400258 length=82 time=+1 watch=
2
Jun 18 19:38:26 ash kernel:  3: skb=f0740ec0 dma=594843650 length=1514 time=+1 wat
ch=3
Jun 18 19:38:26 ash kernel:  4: skb=d6e91a60 dma=594841602 length=1514 time=+1 wat
ch=4
Jun 18 19:38:26 ash kernel:  5: skb=f0740560 dma=937203714 length=82 time=+1 watch
=5
Jun 18 19:38:26 ash kernel:  6: skb=d6e919c0 dma=426745858 length=1514 time=+1 wat
ch=6
Jun 18 19:38:26 ash kernel:  7: skb=d6e91880 dma=426747906 length=1514 time=+1 wat
ch=7
Jun 18 19:38:26 ash kernel:  8: skb=f65ca920 dma=934469122 length=82 time=+1 watch
=8
Jun 18 19:38:26 ash kernel:  9: skb=00000000 dma=0 length=0 time=+20324352 watch=0
Jun 18 19:38:26 ash kernel:  10: skb=00000000 dma=0 length=0 time=+20324352 watch=
0
<snip many many lines>
=0
Jun 18 19:38:26 ash kernel:  255: skb=00000000 dma=0 length=0 time=+20324352 watch

David

David Greaves

author

2004-06-18 21:28 UTC #14 lore raw

In reply to a message not in the archive

OK
Thanks for the pointers and time Stephen, much appreciated :)

Ganesh and Jens - you said you'd like to keep this on-list so Stephen let's ensure your reply is archived...

David

Quoted 68 lines · Stephen Hemminger

It will be up to Intel (Genesh et al) to look at this.
Quoted 29 lines · On Fri, 18 Jun 2004 19:44:10 +0100 David Greaves <[email protected]> wrote:
Quoted 7 lines · Stephen Hemminger
To get to the root of these problems, could you:
* Give full lspci -v output for the boards in question.
ash:
00:07.0 Ethernet controller: Intel Corp.: Unknown device 1076
Subsystem: Intel Corp.: Unknown device 1176
Flags: bus master, 66Mhz, medium devsel, latency 32, IRQ 11 Memory at e3020000 (32-bit, non-prefetchable) [size=128K] Memory at e3000000 (32-bit, non-prefetchable) [size=128K] I/O ports at b400 [size=64]
Expansion ROM at <unassigned> [disabled] [size=128K]
Capabilities: [dc] Power Management version 2
Capabilities: [e4] PCI-X non-bridge device.
Capabilities: [f0] Message Signalled Interrupts: 64bit+
Queue=0/0 Enable-
Quoted 4 lines
Jun 18 19:38:18 ash kernel: eth0: may be hung last tx was 2457 ticks
This means the code that in the e1000 watchdog is seeing the stuck board. The driver then calls netif_stop_queue which seems odd.
Quoted 11 lines
Jun 18 19:38:20 ash kernel: eth0: may be hung last tx was 4457 ticks
Jun 18 19:38:22 ash kernel: eth0: may be hung last tx was 6457 ticks
Jun 18 19:38:24 ash kernel: eth0: may be hung last tx was 8457 ticks
Jun 18 19:38:26 ash kernel: NETDEV WATCHDOG: eth0: transmit timed out after 5000 j
iffies
Jun 18 19:38:26 ash kernel: eth0: transmit timeout from queuing
Jun 18 19:38:26 ash kernel: eth0: may be hung last tx was 10457 ticks
Jun 18 19:38:26 ash kernel: eth0: state=0x7 transmit ring size=4096 count=256 to_u
se=66 to_clean=59
The state bits show:
XOFF - stopped (but that was done in e1000_watchdog) START - board is running
PRESENT - board is present.
That looks okay, but what was the state in the e1000 watchdog??

Thayne Harbaugh

2004-06-21 16:42 UTC #7 lore raw

Re: 2.6.6 e1000 NETDEV WATCHDOG: eth0: transmit timed out+ delay scheduler

In reply to David Greaves

Quoted 7 lines · David Greaves

Quoted 1 line · Jens Laas
We have tried different versions of e1000 without luck.
Me too, 3 cards.
(did I mention I have 2 machines with very similar specs (AMD/VIAKT600) and the other one works - actually, to be accurate, hasn't yet failed but hasn't yet run at full speed - and it has a higher CPU speed)

What do you mean by, ". . . hasn't yet run at full speed - and it has a higher CPU speed . . ." ? Does this mean that you can't get the card to have a reasonable throughput (~900Mbps)?

Signature · 2 lines

Thayne Harbaugh
Linux Networx

David Greaves

author

2004-06-21 17:29 UTC #8 lore raw

Re: 2.6.6 e1000 NETDEV WATCHDOG: eth0: transmit timed out+ delay scheduler

Quoted 10 lines · Thayne Harbaugh

Quoted 6 lines · David Greaves
Quoted 3 lines · Jens Laas
We have tried different versions of e1000 without luck.

Quoted 11 lines

Quoted 4 lines
Me too, 3 cards.
(did I mention I have 2 machines with very similar specs (AMD/VIAKT600) and the other one works - actually, to be accurate, hasn't yet failed but hasn't yet run at full speed - and it has a higher CPU speed)
What do you mean by, ". . . hasn't yet run at full speed - and it has a higher CPU speed . . ." ? Does this mean that you can't get the card to have a reasonable throughput (~900Mbps)?

It sounded reasonable when I wrote it :)

I have 2 machines I can easily test with (wired back to back)
Machine 1 has an AMD3000+ CPU, machine 2 has an AMD3200+ cpu (maybe not relevant - maybe important if it's timing related?)

Machine one stalls within a few kb.
Machine two has shown no signs of failure yet.

However the other machine has not been stressed at all so it has 'not yet run at full speed' - not surprising since it has no friends with working gigabit cards :)

David
PS
I tried some experiments this weekend with a third machine but I got nasty kernel oopses on the second (supposedly good) whenever I did ifconfig eth1 mtu 9000 and I've not had time to get any proper results or a minimal failure yet.

simply issuing
ifconfig eth1 mtu 9000
on the second machine gave me this:

Jun 18 16:33:08 haze kernel: printk: 1 messages suppressed.
Jun 18 16:33:08 haze kernel: ifconfig: page allocation failure. order:3, mode:0x20
Jun 18 16:33:08 haze kernel:  [__alloc_pages+728/848] __alloc_pages+0x2d8/0x350
Jun 18 16:33:08 haze kernel:  [__get_free_pages+37/64] __get_free_pages+0x25/0x40
Jun 18 16:33:08 haze kernel:  [kmem_getpages+32/176] kmem_getpages+0x20/0xb0
Jun 18 16:33:08 haze kernel:  [cache_grow+166/512] cache_grow+0xa6/0x200
Jun 18 16:33:08 haze kernel:  [cache_alloc_refill+342/544] cache_alloc_refill+0x156/0x220
Jun 18 16:33:08 haze kernel:  [__kmalloc+116/128] __kmalloc+0x74/0x80

...

I'll report more fully when I can produce something consistent.

[email protected]

2004-06-21 17:43 UTC #9 lore raw

Re: 2.6.6 e1000 NETDEV WATCHDOG: eth0: transmit timed out+ delay scheduler

David:

Could you try the following patch to workaround the meemory allocation issue you are reporting?

---------------------

e1000_main.c-patched renamed from e1000_main.c +6 -6

@@ -796,7 +796,7 @@ e1000_setup_tx_resources(struct e1000_ad
 	int size;
 
 	size = sizeof(struct e1000_buffer) * txdr->count;
-	txdr->buffer_info = kmalloc(size, GFP_KERNEL);
+	txdr->buffer_info = vmalloc(size);
 	if(!txdr->buffer_info) {
 		return -ENOMEM;
 	}

@@ -809,7 +809,7 @@ e1000_setup_tx_resources(struct e1000_ad
 
 	txdr->desc = pci_alloc_consistent(pdev, txdr->size, &txdr->dma);
 	if(!txdr->desc) {
-		kfree(txdr->buffer_info);
+		vfree(txdr->buffer_info);
 		return -ENOMEM;
 	}
 	memset(txdr->desc, 0, txdr->size);

@@ -913,7 +913,7 @@ e1000_setup_rx_resources(struct e1000_ad
 	int size;
 
 	size = sizeof(struct e1000_buffer) * rxdr->count;
-	rxdr->buffer_info = kmalloc(size, GFP_KERNEL);
+	rxdr->buffer_info = vmalloc(size);
 	if(!rxdr->buffer_info) {
 		return -ENOMEM;
 	}

@@ -927,7 +927,7 @@ e1000_setup_rx_resources(struct e1000_ad
 	rxdr->desc = pci_alloc_consistent(pdev, rxdr->size, &rxdr->dma);
 
 	if(!rxdr->desc) {
-		kfree(rxdr->buffer_info);
+		vfree(rxdr->buffer_info);
 		return -ENOMEM;
 	}
 	memset(rxdr->desc, 0, rxdr->size);

@@ -1051,7 +1051,7 @@ e1000_free_tx_resources(struct e1000_ada
 
 	e1000_clean_tx_ring(adapter);
 
-	kfree(adapter->tx_ring.buffer_info);
+	vfree(adapter->tx_ring.buffer_info);
 	adapter->tx_ring.buffer_info = NULL;
 
 	pci_free_consistent(pdev, adapter->tx_ring.size,

@@ -1120,7 +1120,7 @@ e1000_free_rx_resources(struct e1000_ada
 
 	e1000_clean_rx_ring(adapter);
 
-	kfree(rx_ring->buffer_info);
+	vfree(rx_ring->buffer_info);
 	rx_ring->buffer_info = NULL;
 
 	pci_free_consistent(pdev, rx_ring->size, rx_ring->desc, rx_ring->dma);

e1000.h-patched renamed from e1000.h +3 -2

@@ -49,6 +49,7 @@
 #include <linux/delay.h>
 #include <linux/timer.h>
 #include <linux/slab.h>
+#include <linux/vmalloc.h>
 #include <linux/interrupt.h>
 #include <linux/string.h>
 #include <linux/pagemap.h>

@@ -159,9 +160,9 @@ struct e1000_adapter;
 struct e1000_buffer {
 	struct sk_buff *skb;
 	uint64_t dma;
-	unsigned long length;
 	unsigned long time_stamp;
-	unsigned int next_to_watch;
+	uint16_t next_to_watch;
+	uint16_t length;
 };
 
 struct e1000_desc_ring {

----------------------
ganesh.

Quoted 69 lines · David Greaves

Quoted 17 lines · Thayne Harbaugh
On Fri, 2004-06-18 at 03:08, David Greaves wrote:
Quoted 12 lines
Jens Laas wrote:
Quoted 3 lines
We have tried different versions of e1000 without luck.
Me too, 3 cards.
(did I mention I have 2 machines with very similar specs (AMD/VIAKT600) and the other one works - actually, to be accurate, hasn't yet failed but hasn't yet run at full speed - and it has a higher CPU speed)
Quoted 6 lines
What do you mean by, ". . . hasn't yet run at full speed - and it has a higher CPU speed . . ." ? Does this mean that you can't get the card to have a reasonable throughput (~900Mbps)?
It sounded reasonable when I wrote it :)
I have 2 machines I can easily test with (wired back to back) Machine 1 has an AMD3000+ CPU, machine 2 has an AMD3200+ cpu (maybe not relevant - maybe important if it's timing related?)
Machine one stalls within a few kb.
Machine two has shown no signs of failure yet.
However the other machine has not been stressed at all so it has 'not yet run at full speed' - not surprising since it has no friends with working gigabit cards :)
David
PS
I tried some experiments this weekend with a third machine but I got nasty kernel oopses on the second (supposedly good) whenever I did ifconfig eth1 mtu 9000 and I've not had time to get any proper results or a minimal failure yet.
simply issuing
ifconfig eth1 mtu 9000
on the second machine gave me this:
Jun 18 16:33:08 haze kernel: printk: 1 messages suppressed.
Jun 18 16:33:08 haze kernel: ifconfig: page allocation failure. order:3,
mode:0x20
Jun 18 16:33:08 haze kernel:  [__alloc_pages+728/848]
__alloc_pages+0x2d8/0x350
Jun 18 16:33:08 haze kernel:  [__get_free_pages+37/64]
__get_free_pages+0x25/0x40
Jun 18 16:33:08 haze kernel:  [kmem_getpages+32/176] kmem_getpages+0x20/0xb0
Jun 18 16:33:08 haze kernel:  [cache_grow+166/512] cache_grow+0xa6/0x200
Jun 18 16:33:08 haze kernel:  [cache_alloc_refill+342/544]
cache_alloc_refill+0x156/0x220
Jun 18 16:33:08 haze kernel:  [__kmalloc+116/128] __kmalloc+0x74/0x80
...
I'll report more fully when I can produce something consistent.

David Greaves

author

2004-06-21 18:34 UTC #10 lore raw

Re: 2.6.6 e1000 NETDEV WATCHDOG: eth0: transmit timed out+ delay scheduler

OK
applied patch

ifdown eth1; modprobe -r e1000;modprobe e1000;ifup eth1; ifconfig eth1 mtu 9000 (so no reboot)

dmesg:
e1000: Ignoring new-style parameters in presence of obsolete ones Intel(R) PRO/1000 Network Driver - version 5.2.52-k4 Copyright (c) 1999-2004 Intel Corporation.
e1000: eth1: e1000_probe: Intel(R) PRO/1000 Network Connection
e1000: eth1: e1000_watchdog: NIC Link is Up 1000 Mbps Full Duplex
ifconfig: page allocation failure. order:3, mode:0x20

[<c01310a8>] __alloc_pages+0x2d8/0x350
[<c0131145>] __get_free_pages+0x25/0x40
[<c0134620>] kmem_getpages+0x20/0xb0
[<c0135186>] cache_grow+0xa6/0x200
[<c0135436>] cache_alloc_refill+0x156/0x220
[<c01359f4>] __kmalloc+0x74/0x80
[<c02a3427>] alloc_skb+0x47/0xe0
[<f89e45a2>] e1000_alloc_rx_buffers+0x62/0x100 [e1000]
[<f89e1045>] e1000_up+0x45/0xb0 [e1000]
[<f89e363c>] e1000_change_mtu+0x7c/0x110 [e1000]
[<c02a8ea9>] dev_set_mtu+0x79/0x90
[<c02a94a5>] dev_ioctl+0x1f5/0x280
[<c02e271e>] inet_ioctl+0x8e/0xa0
[<c02a0039>] sock_ioctl+0xe9/0x290
[<c015c50f>] sys_ioctl+0xef/0x260
[<c0110570>] do_page_fault+0x0/0x4da
[<c0103fb7>] syscall_call+0x7/0xb

ifconfig: page allocation failure. order:3, mode:0x20

[<c01310a8>] __alloc_pages+0x2d8/0x350
[<c0131145>] __get_free_pages+0x25/0x40
[<c0134620>] kmem_getpages+0x20/0xb0
[<c0135186>] cache_grow+0xa6/0x200
[<c0135436>] cache_alloc_refill+0x156/0x220
[<c0111a1a>] wake_up_state+0x1a/0x20
[<c01359f4>] __kmalloc+0x74/0x80
[<c02a3427>] alloc_skb+0x47/0xe0
[<f89e45a2>] e1000_alloc_rx_buffers+0x62/0x100 [e1000]
[<f89e41e7>] e1000_clean_rx_irq+0xf7/0x450 [e1000]
[<c011175f>] recalc_task_prio+0x8f/0x190
[<f89e3e73>] e1000_clean+0x43/0xc0 [e1000]
[<c02a861a>] net_rx_action+0x6a/0xf0
[<c01190bd>] __do_softirq+0x7d/0x80
[<c01190e6>] do_softirq+0x26/0x30
[<c0105ded>] do_IRQ+0xfd/0x130
[<c0104124>] common_interrupt+0x18/0x20
[<f89e3d37>] e1000_irq_enable+0x27/0x30 [e1000]
[<f89e109d>] e1000_up+0x9d/0xb0 [e1000]
[<f89e363c>] e1000_change_mtu+0x7c/0x110 [e1000]
[<c02a8ea9>] dev_set_mtu+0x79/0x90
[<c02a94a5>] dev_ioctl+0x1f5/0x280
[<c02e271e>] inet_ioctl+0x8e/0xa0
[<c02a0039>] sock_ioctl+0xe9/0x290
[<c015c50f>] sys_ioctl+0xef/0x260
[<c0110570>] do_page_fault+0x0/0x4da
[<c0103fb7>] syscall_call+0x7/0xb

kdeinit: page allocation failure. order:3, mode:0x20

[<c01310a8>] __alloc_pages+0x2d8/0x350
[<c0131145>] __get_free_pages+0x25/0x40
[<c0134620>] kmem_getpages+0x20/0xb0
[<c0135186>] cache_grow+0xa6/0x200
[<c0135436>] cache_alloc_refill+0x156/0x220
[<c01359f4>] __kmalloc+0x74/0x80
[<c02a3427>] alloc_skb+0x47/0xe0
[<f89e45a2>] e1000_alloc_rx_buffers+0x62/0x100 [e1000]
[<f89e41e7>] e1000_clean_rx_irq+0xf7/0x450 [e1000]
[<f89e3e73>] e1000_clean+0x43/0xc0 [e1000]
[<c02a861a>] net_rx_action+0x6a/0xf0
[<c01190bd>] __do_softirq+0x7d/0x80
[<c01190e6>] do_softirq+0x26/0x30
[<c0105ded>] do_IRQ+0xfd/0x130
[<c0104124>] common_interrupt+0x18/0x20

...

David

Quoted 174 lines · [email protected] wrote:

David:
Could you try the following patch to workaround the meemory allocation issue you are reporting?
---------------------
e1000_main.c-patched renamed from e1000_main.c +6 -6
@@ -796,7 +796,7 @@ e1000_setup_tx_resources(struct e1000_ad
 	int size;
 
 	size = sizeof(struct e1000_buffer) * txdr->count;
-	txdr->buffer_info = kmalloc(size, GFP_KERNEL);
+	txdr->buffer_info = vmalloc(size);
 	if(!txdr->buffer_info) {
 		return -ENOMEM;
 	}
@@ -809,7 +809,7 @@ e1000_setup_tx_resources(struct e1000_ad
 
 	txdr->desc = pci_alloc_consistent(pdev, txdr->size, &txdr->dma);
 	if(!txdr->desc) {
-		kfree(txdr->buffer_info);
+		vfree(txdr->buffer_info);
 		return -ENOMEM;
 	}
 	memset(txdr->desc, 0, txdr->size);
@@ -913,7 +913,7 @@ e1000_setup_rx_resources(struct e1000_ad
 	int size;
 
 	size = sizeof(struct e1000_buffer) * rxdr->count;
-	rxdr->buffer_info = kmalloc(size, GFP_KERNEL);
+	rxdr->buffer_info = vmalloc(size);
 	if(!rxdr->buffer_info) {
 		return -ENOMEM;
 	}
@@ -927,7 +927,7 @@ e1000_setup_rx_resources(struct e1000_ad
 	rxdr->desc = pci_alloc_consistent(pdev, rxdr->size, &rxdr->dma);
 
 	if(!rxdr->desc) {
-		kfree(rxdr->buffer_info);
+		vfree(rxdr->buffer_info);
 		return -ENOMEM;
 	}
 	memset(rxdr->desc, 0, rxdr->size);
@@ -1051,7 +1051,7 @@ e1000_free_tx_resources(struct e1000_ada
 
 	e1000_clean_tx_ring(adapter);
 
-	kfree(adapter->tx_ring.buffer_info);
+	vfree(adapter->tx_ring.buffer_info);
 	adapter->tx_ring.buffer_info = NULL;
 
 	pci_free_consistent(pdev, adapter->tx_ring.size,
@@ -1120,7 +1120,7 @@ e1000_free_rx_resources(struct e1000_ada
 
 	e1000_clean_rx_ring(adapter);
 
-	kfree(rx_ring->buffer_info);
+	vfree(rx_ring->buffer_info);
 	rx_ring->buffer_info = NULL;
 
 	pci_free_consistent(pdev, rx_ring->size, rx_ring->desc, rx_ring->dma);
e1000.h-patched renamed from e1000.h +3 -3
@@ -49,6 +49,7 @@
 #include <linux/delay.h>
 #include <linux/timer.h>
 #include <linux/slab.h>
+#include <linux/vmalloc.h>
 #include <linux/interrupt.h>
 #include <linux/string.h>
 #include <linux/pagemap.h>
@@ -159,9 +160,9 @@ struct e1000_adapter;
 struct e1000_buffer {
 	struct sk_buff *skb;
 	uint64_t dma;
-	unsigned long length;
 	unsigned long time_stamp;
-	unsigned int next_to_watch;
+	uint16_t next_to_watch;
+	uint16_t length;
 };
 
 struct e1000_desc_ring {
----------------------
ganesh.
Quoted 80 lines · David Greaves
Quoted 24 lines · Thayne Harbaugh
Quoted 10 lines · David Greaves
Quoted 5 lines · Jens Laas
We have tried different versions of e1000 without luck.
Quoted 8 lines
Me too, 3 cards.
(did I mention I have 2 machines with very similar specs (AMD/VIAKT600) and the other one works - actually, to be accurate, hasn't yet failed but hasn't yet run at full speed - and it has a higher CPU speed)
Quoted 8 lines
What do you mean by, ". . . hasn't yet run at full speed - and it has a higher CPU speed . . ." ? Does this mean that you can't get the card to have a reasonable throughput (~900Mbps)?
It sounded reasonable when I wrote it :)
I have 2 machines I can easily test with (wired back to back) Machine 1 has an AMD3000+ CPU, machine 2 has an AMD3200+ cpu (maybe not relevant - maybe important if it's timing related?)
Machine one stalls within a few kb.
Machine two has shown no signs of failure yet.
However the other machine has not been stressed at all so it has 'not yet run at full speed' - not surprising since it has no friends with working gigabit cards :)
David
PS
I tried some experiments this weekend with a third machine but I got nasty kernel oopses on the second (supposedly good) whenever I did ifconfig eth1 mtu 9000 and I've not had time to get any proper results or a minimal failure yet.
simply issuing
ifconfig eth1 mtu 9000
on the second machine gave me this:
Jun 18 16:33:08 haze kernel: printk: 1 messages suppressed.
Jun 18 16:33:08 haze kernel: ifconfig: page allocation failure. order:3,
mode:0x20
Jun 18 16:33:08 haze kernel:  [__alloc_pages+728/848]
__alloc_pages+0x2d8/0x350
Jun 18 16:33:08 haze kernel:  [__get_free_pages+37/64]
__get_free_pages+0x25/0x40
Jun 18 16:33:08 haze kernel:  [kmem_getpages+32/176] kmem_getpages+0x20/0xb0
Jun 18 16:33:08 haze kernel:  [cache_grow+166/512] cache_grow+0xa6/0x200
Jun 18 16:33:08 haze kernel:  [cache_alloc_refill+342/544]
cache_alloc_refill+0x156/0x220
Jun 18 16:33:08 haze kernel:  [__kmalloc+116/128] __kmalloc+0x74/0x80
...
I'll report more fully when I can produce something consistent.