[PROBLEM] TCP connection hangs when sending /dev/hda

Matjaz Omerzel (21442@gmx.net)
Mon, 11 Nov 2002 07:32:40 +0100


I am experiencing undeterministic network behaviour on a rather old 486.
Some TCP connections occasionally block within a few seconds from
connecting. There is no obvious rule: sometimes it works fine for a day,
then after a reboot (or even without one), most of the connections tend
to hang after a few seconds. Generally, if a connection doesn't block
for a minute, it works OK for the rest of the day.

Restarting network with /etc/init.d/network or rebooting sometimes helps
and brings the system from state in which nearly all of the
connection work to state in which most of the connections hang, or vice
versa - but not always. Very rarely, the connection which had been hung
for a few minutes would wake, transfer a few more bytes and hang again,
but 95% of the time it won't even wake.

To reconstruct:

Machine C(ontrol): Windows 95, IP 10.8.100.250, 3Com 3C905C, thoroughly
tested and working for years
Machine S(ubject): RedHat Linux 8, kernel 2.4.18-14, 100 MHz i486 with
32 Mb RAM, IP 10.8.32.1, Via Rhine DFE-530TX, working for years on win98

I wire the machines directly using a crossover cable. On machine C, I
just start two sink programs listening on ports 7999 and 8999, each
counting incoming bytes.

>From here on, everything written applies to machine S. First, I start:

dd if=/dev/zero bs=512 | nc 10.8.100.250 7999 &

and it runs as one would expect. Moreover, I have never seen this
connection to hang or fail in any way. But if I do

dd if=/dev/hda bs=512 | nc 10.8.100.250 8999 &

this would almost always stop just after transferring just a few
megabytes, leaving both sides waiting (process nc sleeping in I/O).

The funny thing is however, that even with the second connection
blocked, the first is still running smoothly.

Ping also works all the time and does not lose any packets. Therefore, I
assume that network drivers are functioning properly, but there might be
some subtle issues with the disk activity. But then again, wouldn't disk
activity affect both connections?

Blocking also occurs when sending a file instead of raw disk.

----- On S, netstat -to shows that the send queue is full (last line):

Active Internet connections (w/o servers)
Proto Recv-Q Send-Q Local Address Foreign Address
State Timer
tcp 0 0 10.8.32.1:ssh 10.8.100.250:1045
ESTABLISHED keepalive (6949.75/0/0)
tcp 0 0 10.8.32.1:ssh 10.8.100.250:2141
ESTABLISHED keepalive (7101.85/0/0)
tcp 0 0 10.8.32.1:ssh 10.8.100.250:2142
ESTABLISHED keepalive (7169.31/0/0)
tcp 0 12536 10.8.32.1:1029 10.8.100.250:8999
ESTABLISHED on (18.80/7/0)

----- And tcpdump looks as though as no acknowledgment from C had been
received. See last lines, this is the example in which blocking happened
almost immediately:

22:13:59.466888 10.8.32.1.1025 > 10.8.100.250.8999: S
1695174963:1695174963(0) win 5840 <mss 1460,sackOK,timestamp 42050
0,nop,wscale 0> (DF)
22:13:59.467142 10.8.100.250.8999 > 10.8.32.1.1025: S 9397777:9397777(0)
ack 1695174964 win 8760 <mss 1460,nop,wscale 0,nop,nop,timestamp 0
0,nop,nop,sackOK> (DF)
22:13:59.467629 10.8.32.1.1025 > 10.8.100.250.8999: . ack 1 win 5840
<nop,nop,timestamp 42050 0> (DF)
22:13:59.507591 10.8.32.1.1025 > 10.8.100.250.8999: . 1:1449(1448) ack 1
win 5840 <nop,nop,timestamp 42054 0> (DF)
22:13:59.508240 10.8.32.1.1025 > 10.8.100.250.8999: . 1449:2897(1448)
ack 1 win 5840 <nop,nop,timestamp 42055 0> (DF)
22:13:59.508644 10.8.100.250.8999 > 10.8.32.1.1025: . ack 2897 win 8760
<nop,nop,timestamp 87780 42054> (DF)
22:13:59.509079 10.8.32.1.1025 > 10.8.100.250.8999: P 2897:4097(1200)
ack 1 win 5840 <nop,nop,timestamp 42055 87780> (DF)
22:13:59.567121 10.8.32.1.1025 > 10.8.100.250.8999: . 4097:5545(1448)
ack 1 win 5840 <nop,nop,timestamp 42060 87780> (DF)
22:13:59.567673 10.8.32.1.1025 > 10.8.100.250.8999: . 5545:6993(1448)
ack 1 win 5840 <nop,nop,timestamp 42060 87780> (DF)
22:13:59.567597 10.8.100.250.8999 > 10.8.32.1.1025: . ack 5545 win 8760
<nop,nop,timestamp 87781 42055> (DF)
22:13:59.568833 10.8.32.1.1025 > 10.8.100.250.8999: . 6993:8441(1448)
ack 1 win 5840 <nop,nop,timestamp 42061 87781> (DF)
22:13:59.569104 10.8.32.1.1025 > 10.8.100.250.8999: P 8441:9889(1448)
ack 1 win 5840 <nop,nop,timestamp 42061 87781> (DF)
22:13:59.569509 10.8.32.1.1025 > 10.8.100.250.8999: . 9889:11337(1448)
ack 1 win 5840 <nop,nop,timestamp 42061 87781> (DF)
22:13:59.569243 10.8.100.250.8999 > 10.8.32.1.1025: . ack 5545 win 8760
<nop,nop,timestamp 87781 42055,nop,nop,sack sack 1 {6993:8441} > (DF)
22:13:59.570144 10.8.32.1.1025 > 10.8.100.250.8999: P 11337:12289(952)
ack 1 win 5840 <nop,nop,timestamp 42061 87781> (DF)
22:13:59.570443 10.8.100.250.8999 > 10.8.32.1.1025: . ack 5545 win 8760
<nop,nop,timestamp 87781 42055,nop,nop,sack sack 2
{11337:12289}{6993:8441} > (DF)
22:13:59.570911 10.8.32.1.1025 > 10.8.100.250.8999: . 5545:6993(1448)
ack 1 win 5840 <nop,nop,timestamp 42061 87781> (DF)
22:13:59.778121 10.8.32.1.1025 > 10.8.100.250.8999: . 5545:6993(1448)
ack 1 win 5840 <nop,nop,timestamp 42082 87781> (DF)
22:14:00.198058 10.8.32.1.1025 > 10.8.100.250.8999: . 5545:6993(1448)
ack 1 win 5840 <nop,nop,timestamp 42124 87781> (DF)
22:14:01.038056 10.8.32.1.1025 > 10.8.100.250.8999: . 5545:6993(1448)
ack 1 win 5840 <nop,nop,timestamp 42208 87781> (DF)
22:14:02.718115 10.8.32.1.1025 > 10.8.100.250.8999: . 5545:6993(1448)
ack 1 win 5840 <nop,nop,timestamp 42376 87781> (DF)
22:14:06.078083 10.8.32.1.1025 > 10.8.100.250.8999: . 5545:6993(1448)
ack 1 win 5840 <nop,nop,timestamp 42712 87781> (DF)
22:14:12.798119 10.8.32.1.1025 > 10.8.100.250.8999: . 5545:6993(1448)
ack 1 win 5840 <nop,nop,timestamp 43384 87781> (DF)
22:14:15.648644 10.8.100.250.8999 > 10.8.32.1.1025: R 9397778:9397778(0)
win 0 (DF)

If I close the connection end on C, S eventhough hung senses it
immediately and closes too.

I've tried the following, of which nothing had helped:
- upgrading kernel from 2.4.7-10 to 2.4.18-14
- changing PCI parameters (IRQ, latency timers)
- moving card to a different PCI slot
- removing other cards
- tweaking via-rhine.o parameters max_interrupt_work, rx_copybreak
- changing hdparam parameters
- enabling/disabling CONFIG_VIA_RHINE_MMIO in kernel
- experimenting with some sysctl parameters
- forcing the link to 10/100 and half/full duplex using mii-tool

The problem was the same when I used 3Com 3C905C NIC (Boomerang, 10/100
Mbit PCI NIC, driver 3c59x) instead of via-rhine. Obviously, the problem
cannot be related to either NIC hardware or the driver.

Using 3Com 3C509B NIC (which is a 10 Mbit ISA card) however, I was
unable to reproduce this bizarre behaviour, and all connections were
working all of the time, no matter how hard I tried. (Interesting
enough, I also observed that the transfer ratio was much smoother with
3C509B, whereas with via-rhine everything was happening in short
"bursts", suggesting that there might be interrupts in question.)

Does anyone have a clue on what might be happening? Are the problems
hardware-related, driver-related, CPU-speed related,
queue-overflow-related or a combination of PCI-IDE and drivers? Or
perhaps something else?

Any ideas would be greatly appreciated.

Attached below are some details about my system S. Sorry for the long
post.

Matjaz Omerzel

----------------------------------------------------------
# netstat -s

Ip:
40060 total packets received
0 forwarded
0 incoming packets discarded
40045 incoming packets delivered
79869 requests sent out
Icmp:
114 ICMP messages received
0 input ICMP message failed.
ICMP input histogram:
destination unreachable: 10
echo requests: 104
114 ICMP messages sent
0 ICMP messages failed
ICMP output histogram:
destination unreachable: 10
echo replies: 104
Tcp:
2 active connections openings
1 passive connection openings
0 failed connection attempts
0 connection resets received
3 connections established
39935 segments received
79745 segments send out
24 segments retransmited
0 bad segments received.
0 resets sent
Udp:
0 packets received
10 packets to unknown port received.
0 packet receive errors
10 packets sent
TcpExt:
ArpFilter: 0
77 delayed acks sent
1 packets directly queued to recvmsg prequeue.
1 packets directly received from prequeue
10 packets header predicted
TCPPureAcks: 48
TCPHPAcks: 39674
TCPRenoRecovery: 0
TCPSackRecovery: 4
TCPSACKReneging: 0
TCPFACKReorder: 0
TCPSACKReorder: 0
TCPRenoReorder: 0
TCPTSReorder: 0
TCPFullUndo: 0
TCPPartialUndo: 0
TCPDSACKUndo: 0
TCPLossUndo: 0
TCPLoss: 2
TCPLostRetransmit: 0
TCPRenoFailures: 0
TCPSackFailures: 0
TCPLossFailures: 0
TCPFastRetrans: 5
TCPForwardRetrans: 0
TCPSlowStartRetrans: 0
TCPTimeouts: 0
TCPRenoRecoveryFail: 0
TCPSackRecoveryFail: 4
TCPSchedulerFailed: 0
TCPRcvCollapsed: 0
TCPDSACKOldSent: 0
TCPDSACKOfoSent: 0
TCPDSACKRecv: 0
TCPDSACKOfoRecv: 0
TCPAbortOnSyn: 0
TCPAbortOnData: 0
TCPAbortOnClose: 0
TCPAbortOnMemory: 0
TCPAbortOnTimeout: 0
TCPAbortOnLinger: 0
TCPAbortFailed: 0
TCPMemoryPressures: 0

# mii-diag -sv

mii-diag.c:v2.06 8/7/2002 Donald Becker (becker@scyld.com)
http://www.scyld.com/diag/index.html
Using the default interface 'eth0'.
Using the new SIOCGMIIPHY value on PHY 24 (BMCR 0x3000).
The autonegotiated capability is 01e0.
The autonegotiated media type is 100baseTx-FD.
Basic mode control register 0x3000: Auto-negotiation enabled.
You have link beat, and everything is working OK.
This transceiver is capable of 100baseTx-FD 100baseTx 10baseT-FD
10baseT.
Able to perform Auto-negotiation, negotiation complete.
Your link partner advertised 45e1: Flow-control 100baseTx-FD 100baseTx
10baseT-FD 10baseT, w/ 802.3X flow control.
End of basic transceiver information.

MII PHY #24 transceiver registers:
3000 782d 0040 6176 05e1 45e1 0003 0000
0000 0000 0000 0000 0000 0000 0000 0000
1000 0300 0000 0000 0000 01ce 0200 0000
003f 8d3e 0f00 ff40 002f 0000 80a0 000b.
Basic mode control register 0x3000: Auto-negotiation enabled.
Basic mode status register 0x782d ... 782d.
Link status: established.
Capable of 100baseTx-FD 100baseTx 10baseT-FD 10baseT.
Able to perform Auto-negotiation, negotiation complete.
Vendor ID is 00:10:18:--:--:--, model 23 rev. 6.
No specific information is known about this transceiver type.
I'm advertising 05e1: Flow-control 100baseTx-FD 100baseTx 10baseT-FD
10baseT
Advertising no additional info pages.
IEEE 802.3 CSMA/CD protocol.
Link partner capability is 45e1: Flow-control 100baseTx-FD 100baseTx
10baseT-FD 10baseT.
Negotiation completed.

# lspci -vvv

00:10.0 Host bridge: United Microelectronics [UMC] UM8881F (rev 01)
Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr-
Stepping- SERR- FastB2B-
Status: Cap- 66Mhz- UDF- FastB2B- ParErr- DEVSEL=medium >TAbort-
<TAbort- <MAbort+ >SERR- <PERR-
Latency: 0

00:12.0 ISA bridge: United Microelectronics [UMC] UM8886F (rev 01)
Control: I/O+ Mem+ BusMaster+ SpecCycle+ MemWINV- VGASnoop- ParErr-
Stepping- SERR- FastB2B-
Status: Cap- 66Mhz- UDF- FastB2B- ParErr- DEVSEL=medium >TAbort-
<TAbort- <MAbort- >SERR- <PERR-
Latency: 0

00:16.0 Ethernet controller: VIA Technologies, Inc. VT86C100A [Rhine]
(rev 06)
Subsystem: D-Link System Inc DFE-530TX rev A
Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV+ VGASnoop- ParErr-
Stepping- SERR+ FastB2B-
Status: Cap- 66Mhz- UDF- FastB2B- ParErr- DEVSEL=medium >TAbort-
<TAbort- <MAbort- >SERR- <PERR-
Latency: 200 (29500ns min, 38000ns max), cache line size 04
Interrupt: pin A routed to IRQ 11
Region 0: I/O ports at 4000 [size=128]
Region 1: Memory at 90000000 (32-bit, non-prefetchable) [size=128]
Expansion ROM at fe000000 [disabled] [size=64K]

00:17.0 USB Controller: OPTi Inc. 82C861 (rev 10) (prog-if 10 [OHCI])
Subsystem: OPTi Inc. 82C861
Control: I/O- Mem+ BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr-
Stepping- SERR- FastB2B-
Status: Cap- 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort-
<TAbort- <MAbort- >SERR- <PERR+
Interrupt: pin A routed to IRQ 0
Region 0: Memory at 10000000 (32-bit, non-prefetchable) [size=4K]

00:18.0 VGA compatible controller: S3 Inc. 86c868 [Vision 868 VRAM] vers
0 (prog-if 00 [VGA])
Control: I/O+ Mem+ BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr-
Stepping+ SERR- FastB2B-
Status: Cap- 66Mhz- UDF- FastB2B- ParErr- DEVSEL=medium >TAbort-
<TAbort- <MAbort- >SERR- <PERR-
Interrupt: pin A routed to IRQ 0
Region 0: Memory at 14000000 (32-bit, non-prefetchable) [size=64M]
Expansion ROM at <unassigned> [disabled] [size=64K]

00:19.0 IDE interface: Quantum Designs (H.K.) Ltd QD-8580 (rev 01)
(prog-if 00 [])
Control: I/O+ Mem+ BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr-
Stepping- SERR- FastB2B-
Status: Cap- 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort-
<TAbort- <MAbort- >SERR- <PERR+
Interrupt: pin A routed to IRQ 14
Region 0: I/O ports at 01f0 [size=8]
Region 1: I/O ports at 03f4
Region 2: I/O ports at 0170 [size=8]
Region 3: I/O ports at 0374
Expansion ROM at 000c8000 [disabled] [size=16K]

# cat /proc/interrupts

CPU0
0: 12049 XT-PIC timer
1: 3 XT-PIC keyboard
2: 0 XT-PIC cascade
8: 1 XT-PIC rtc
11: 434 XT-PIC eth0
13: 0 XT-PIC fpu
14: 2884 XT-PIC ide0
NMI: 0
ERR: 0

# via-diag

via-diag.c:v2.06 5/22/2001 Donald Becker (becker@scyld.com)
http://www.scyld.com/diag/index.html
Index #1: Found a VIA VT3043 Rhine adapter at 0x4000.
Station address 00:50:ba:e0:29:ea.
Tx enabled, Rx enabled, full-duplex (0x0c1a).
Receive mode is 0x6c: Normal unicast and hashed multicast.
Transmit mode is 0x20: Normal transmit, 256 byte threshold.
VIA VT3043 Rhine chip registers at 0x4000
0x000: e0ba5000 206cea29 00000c1a 4eff0000 80000000 00000000 011340a0
01134170
0x020: 80000400 00000600 01c31010 011340b0 80000000 00000600 01719810
011340c0
0x040: 00000000 00e0803c 01edaa00 01134180 00000000 00e0803c 01edaa00
01134180
0x060: 01719080 01eda43c 00000000 00061008 782d0100 00000080 00070020
00000000
No interrupt sources are pending (0000).

# cat /proc/ioports

00000000-0009ffff : System RAM
000a0000-000bffff : Video RAM area
000c0000-000c7fff : Video ROM
000f0000-000fffff : System ROM
00100000-01ffffff : System RAM
00100000-001e4d33 : Kernel code
001e4d34-0021a73f : Kernel data
10000000-10000fff : OPTi Inc. 82C861
14000000-17ffffff : S3 Inc. 86c868 [Vision 868 VRAM] vers 0
90000000-9000007f : VIA Technologies, Inc. VT3043 [Rhine]
90000000-9000007f : via-rhine
ffff78c6-ffffffff : reserved

# Excerpt from /var/log/messages with "options via-rhine debug=7" in
/etc/modules.conf

Nov 4 21:40:37 gate kernel: via-rhine.c:v1.10-LK1.1.14 May-3-2002
Written by Donald Becker
Nov 4 21:40:37 gate kernel:
http://www.scyld.com/network/via-rhine.html
Nov 4 21:40:37 gate kernel: via-rhine: reset finished after 5
microseconds.
Nov 4 21:40:37 gate kernel: eth0: VIA VT86C100A Rhine at 0x90000000,
00:50:ba:e0:29:ea, IRQ 11.
Nov 4 21:40:37 gate kernel: eth0: MII PHY found at address 8, status
0x782d advertising 05e1 Link 45e1.
Nov 4 21:40:37 gate kernel: eth0: reset finished after 5 microseconds.
Nov 4 21:40:37 gate kernel: eth0: Setting full-duplex based on MII #8
link partner capability of 45e1.
Nov 4 21:40:41 gate login(pam_unix)[392]: session opened for user root
by LOGIN(uid=0)
Nov 4 21:40:41 gate -- root[392]: ROOT LOGIN ON tty1
Nov 4 21:41:04 gate kernel: status 0001.
Nov 4 21:41:04 gate kernel: <upt, status 0001.
Nov 4 21:41:06 gate kernel: ne_rx() status is 00468f00.
Nov 4 21:41:06 gate kernel: <7status 00468f00.
Nov 4 21:41:07 gate kernel: ne_rx() status is 00468f00.
Nov 4 21:41:08 gate kernel: g interrupt, status=0x0000.
Nov 4 21:41:09 gate kernel: ne_rx() status is 00468f00.
Nov 4 21:41:12 gate kernel: rx() status is 00468f00.
Nov 4 21:41:13 gate kernel: g interrupt, status=0x0000.
Nov 4 21:41:23 gate kernel:
Nov 4 21:41:25 gate kernel: ng interrupt, status=0x0000.
Nov 4 21:41:31 gate kernel:
Nov 4 21:41:33 gate kernel:
Nov 4 21:41:52 gate kernel: >eth0: Interrupt, status 0002.
Nov 4 21:42:20 gate kernel: <7
Nov 4 21:42:30 gate dhcpd: receive_packet failed on eth0: Network is
down
Nov 4 21:42:31 gate network: Shutting down interface eth0: succeeded
Nov 4 21:42:33 gate network: Shutting down loopback interface:
succeeded
Nov 4 21:42:34 gate sysctl: net.ipv4.ip_forward = 0
Nov 4 21:42:35 gate sysctl: net.ipv4.conf.default.rp_filter = 1
Nov 4 21:42:35 gate sysctl: kernel.core_uses_pid = 1
Nov 4 21:42:35 gate network: Setting network parameters: succeeded
Nov 4 21:42:38 gate network: Bringing up loopback interface: succeeded
Nov 4 21:42:40 gate kernel: eth0: reset finished after 5 microseconds.
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/