more TCP weirdness

samkaski@cs.helsinki.fi (pmonta@halibut.imedia.com)
Fri, 12 Feb 1999 04:28:37 -0800


I tried some ttcp tests with 2.2.2pre2 with puzzling results.

Sometimes everything is fine:

gig1:~# /flash/local/ttcp -r -s -n 16384 -b 65000
ttcp-r: buflen=8192, nbuf=16384, align=16384/0, port=5001, sockbufsize=65000 tcp
ttcp-r: socket
ttcp-r: rcvbuf
ttcp-r: accept from 192.168.2.1
ttcp-r: 134217728 bytes in 3.19 real seconds = 41027.75 KB/sec +++
ttcp-r: 16409 I/O calls, msec/call = 0.20, calls/sec = 5136.29
ttcp-r: 0.0user 2.7sys 0:03real 87% 0i+0d 0maxrss 0+2pf 0+0csw

but, randomly, sometimes the transfer does not go well:

gig1:~# /flash/local/ttcp -r -s -n 16384 -b 65000
ttcp-r: buflen=8192, nbuf=16384, align=16384/0, port=5001, sockbufsize=65000 tcp
ttcp-r: socket
ttcp-r: rcvbuf
ttcp-r: accept from 192.168.2.1
ttcp-r: 134217728 bytes in 40.60 real seconds = 3228.57 KB/sec +++
ttcp-r: 16477 I/O calls, msec/call = 2.52, calls/sec = 405.86
ttcp-r: 0.0user 2.7sys 0:40real 6% 0i+0d 0maxrss 0+2pf 0+0csw

The 65000-byte socket buffer is an effort to get slightly higher
rates (these tests are with the G-NIC II gigabit card; yes, the driver
is alpha, but see my earlier 100baseT message). If the default socket
buffer is used, things are slightly more solid: I did a dozen or so
of the small transfers, "-n 16384", without incident, but "-n 163840"
consistently gets wedged.

Here is a tcpdump fragment (the formatting is botched due to cut and paste):

11:31:39.237508 192.168.2.2.5001 > 192.168.2.1.1051: . ack 241921170 win 63712 <nop,nop,timestamp 90977 64915> (DF)
11:31:39.237556 192.168.2.1.1051 > 192.168.2.2.5001: P 1:1449(1448) ack 0 win 32120 <nop,nop,timestamp 64964 90977> (DF)
11:31:39.237565 192.168.2.1.1051 > 192.168.2.2.5001: . 1449:2897(1448) ack 0 win 32120 <nop,nop,timestamp 64964 90977> ( DF)
11:31:39.237788 192.168.2.2.5001 > 192.168.2.1.1051: . ack 2897 win 62264 <nop,nop,timestamp 90977 64964> (DF)
11:31:39.237823 192.168.2.1.1051 > 192.168.2.2.5001: . 2897:4345(1448) ack 0 win 32120 <nop,nop,timestamp 64964 90977> ( DF)
11:31:39.727530 192.168.2.2.5001 > 192.168.2.1.1051: . ack 4345 win 63712 <nop,nop,timestamp 91026 64964> (DF)
11:31:39.727562 192.168.2.1.1051 > 192.168.2.2.5001: . 4345:5793(1448) ack 0 win 32120 <nop,nop,timestamp 65013 91026> ( DF)
11:31:39.727569 192.168.2.1.1051 > 192.168.2.2.5001: . 5793:7241(1448) ack 0 win 32120 <nop,nop,timestamp 65013 91026> ( DF)
11:31:39.727575 192.168.2.1.1051 > 192.168.2.2.5001: P 7241:8689(1448) ack 0 win 32120 <nop,nop,timestamp 65013 91026> ( DF)
11:31:39.727806 192.168.2.2.5001 > 192.168.2.1.1051: . ack 7241 win 62264 <nop,nop,timestamp 91026 65013> (DF)
11:31:39.727842 192.168.2.1.1051 > 192.168.2.2.5001: . 8689:10137(1448) ack 0 win 32120 <nop,nop,timestamp 65013 91026> (DF)
11:31:39.727849 192.168.2.1.1051 > 192.168.2.2.5001: . 10137:11585(1448) ack 0 win 32120 <nop,nop,timestamp 65013 91026> (DF)
11:31:39.728089 192.168.2.2.5001 > 192.168.2.1.1051: . ack 10137 win 62264 <nop,nop,timestamp 91026 65013> (DF)
11:31:39.728122 192.168.2.1.1051 > 192.168.2.2.5001: . 11585:13033(1448) ack 0 win 32120 <nop,nop,timestamp 65014 91026> (DF)
11:31:39.728129 192.168.2.1.1051 > 192.168.2.2.5001: . 13033:14481(1448) ack 0 win 32120 <nop,nop,timestamp 65014 91026> (DF)
11:31:39.728368 192.168.2.2.5001 > 192.168.2.1.1051: . ack 13033 win 63712 <nop,nop,timestamp 91026 65014> (DF)
11:31:39.728401 192.168.2.1.1051 > 192.168.2.2.5001: . 14481:15929(1448) ack 0 win 32120 <nop,nop,timestamp 65014 91026> (DF)
11:31:39.728408 192.168.2.1.1051 > 192.168.2.2.5001: P 15929:17377(1448) ack 0 win 32120 <nop,nop,timestamp 65014 91026> (DF)
11:31:39.728414 192.168.2.1.1051 > 192.168.2.2.5001: . 17377:18825(1448) ack 0 win 32120 <nop,nop,timestamp 65014 91026> (DF)
11:31:39.728646 192.168.2.2.5001 > 192.168.2.1.1051: . ack 14481 win 63712 <nop,nop,timestamp 91026 65014> (DF)
11:31:39.728683 192.168.2.1.1051 > 192.168.2.2.5001: . 18825:20273(1448) ack 0 win 32120 <nop,nop,timestamp 65014 91026> (DF)
11:31:39.728649 192.168.2.2.5001 > 192.168.2.1.1051: . ack 14481 win 63712 <nop,nop,timestamp 91026 65014> (DF)
11:31:40.768078 192.168.2.1.1051 > 192.168.2.2.5001: . 14481:15929(1448) ack 0 win 32120 <nop,nop,timestamp 65118 91026> (DF)

Just now things seemed to go rather badly haywire with many kmem_free
messages during a transfer; eventually the telnet link to the machine
failed entirely, no pings, etc.

Would it make sense to try with echo 0 >/proc/sys/net/ipv4/tcp_timestamps
once I can reboot? I suppose binary search since 2.2.0pre6 might be fruitful
too (at least 2.2.2pre2 seems faster in wedged mode :-) ). Any other hints
welcome.

Cheers,
Peter Monta pmonta@imedia.com
Imedia Corp.

-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.rutgers.edu
Please read the FAQ at http://www.tux.org/lkml/