Subject: strange ethernet performance (long)
To: NetBSD PPC port <port-macppc@netbsd.org>
From: Sean Sweda <sweda@advantageit.com>
List: port-macppc
Date: 03/22/2000 01:18:54
Hardware:
7500, upgraded to 120 MHz 604
NetBSD 1.4.1 and 1.4.2
3com 3c905 10/100 ethernet
HP ProCurve switch (true wire speed)

relevant dmesg output:
ep0 at pci0 dev 13 function 0: 3Com 3c905-TX 10/100 Ethernet
ep0: interrupting at irq 23
ep0: address 00:60:08:cd:1e:6c, 8KB word-wide FIFO, 3:5 Rx:Tx split
nsphy0 at ep0 phy 24: DP83840 10/100 media interface, rev. 1
nsphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
Lite-On Communications 82C168/82C169 (PNIC) 10/100 Ethernet (ethernet network, r
evision 0x20) at pci0 dev 14 function 0 not configured


I recently installed a 3c905 and afterward I wanted to test its performance
so I tried to ftp a couple of large files from a Sun that also has a
fast ethernet connection.  I was only able to get about 60-80 KB/s when
downloading files, which was *very* disappointing.  However, when uploading
files to the Sun I was getting 400-500 KB/s.  I originally thought this
might just be the disk performance.

Anyways, I noticed that 1.4.2 was released, so I downloaded the tarballs
from one of the ftp mirrors which happens to be very close.  I was shocked
to realize that when I was downloading the files from the mirror site I
was getting over 300 KB/s!  Obviously the problem wasn't the disk, it
was the ethernet driver.

It struck me that perhaps things were happening too fast for the
ethernet driver on the local network.  I made sure that I wasn't
experiencing some kind of local network issues by using ftp to
transfer files from a couple of other machines on the local network. 
I was only able to see a performance problem when sending files to the
netbsd box.  It does not matter which machine initiates the ftp
connection, netbsd has trouble when receiving data on the local
network.

Does anyone have an idea what is going on here?  How much testing has
gone into fast ethernet on netbsd/ppc?  Upgrading to 1.4.2 did not
change anything.  

I also have an Asante 10/100 card which the kernel does not recognize,
which I would love to test against the 3Com card.  I read that there
is a new Tulip driver which may work, but it is only in -current.  Would
it be possible to integrate the new driver into a 1.4.2 kernel?  Any
tips or hints here would be greatly appreciated.


Here is some additional output which may be of interest:

first is "netstat -s"
second is "tcpdump" for the ftp to the netbsd mirror site (320.50 KB/s)
third is the "tcpdump" for the local ftp attempt (61.63 KB/s)
(apologies for not wrapping the text)


root@marauders 12:54am [/tmp]% netstat -s
ip:
        60509 total packets received
        0 bad header checksums
        0 with size smaller than minimum
        0 with data size < data length
        0 with length > max ip packet size
        0 with header length < data size
        0 with data length < header length
        0 with bad options
        0 with incorrect version number
        10 fragments received   0 fragments dropped (dup or out of space)
        0 malformed fragments dropped
        0 fragments dropped after timeout
        5 packets reassembled ok
        58888 packets for this host
        137 packets for unknown/unsupported protocol
        0 packets forwarded (0 packets fast forwarded)
        1479 packets not forwardable
        0 redirects sent
        58327 packets sent from this host
        0 packets sent with fabricated ip header
        0 output packets dropped due to no bufs, etc.
        0 output packets discarded due to no route
        0 output datagrams fragmented
        0 fragments created
        0 datagrams that can't be fragmented
icmp:
        24 calls to icmp_error
        0 errors not generated because old message was icmp
        Output histogram:
                echo reply: 3
                destination unreachable: 24
        9 messages with bad code fields
        0 messages < minimum length
        0 bad checksums
        0 messages with bad length
        Input histogram:
                destination unreachable: 30
                echo: 3
        3 message responses generated
igmp:
        107 messages received
        0 messages received with too few bytes
        0 messages received with bad checksum
        107 membership queries received
        0 membership queries received with invalid field(s)
        0 membership reports received
        0 membership reports received with invalid field(s)
        0 membership reports received for groups to which we belong
        0 membership reports sent
tcp:
        50083 packets sent
                11537 data packets (4303223 bytes)
                61 data packets (15125 bytes) retransmitted
                7099 ack-only packets (36701 delayed)
                0 URG only packets
                0 window probe packets
                30080 window update packets
                1306 control packets
        49307 packets received
                8971 acks (for 4245424 bytes)
                654 duplicate acks
                0 acks for unsent data
                39090 packets (47560643 bytes) received in-sequence
                138 completely duplicate packets (37222 bytes)
                0 old duplicate packets
                13 packets with some dup. data (6448 bytes duped)
                2704 out-of-order packets (3218585 bytes)
                0 packets (0 bytes) of data after window
                0 window probes
                58 window update packets
                2 packets received after close
                0 discarded for bad checksums
                0 discarded for bad header offset fields
                0 discarded because packet too short
        537 connection requests
        258 connection accepts
        732 connections established (including accepts)
        787 connections closed (including 25 drops)
        57 embryonic connections dropped
        8728 segments updated rtt (of 8462 attempts)
        141 retransmit timeouts
                0 connections dropped by rexmit timeout
        0 persist timeouts (resulting in 0 dropped connections)
        17 keepalive timeouts
                0 keepalive probes sent
                17 connections dropped by keepalive
        2944 correct ACK header predictions
        36304 correct data packet header predictions
        665 PCB hash misses
        28 dropped due to no socket
        0 connections drained due to memory shortage
        4 bad connection attempts
        258 SYN cache entries added
                0 hash collisions
                258 completed
                0 aborted (no space to build PCB)
                0 timed out
                0 dropped due to overflow
                0 dropped due to bucket overflow
                0 dropped due to RST
                0 dropped due to ICMP unreachable
        2 SYN,ACKs retransmitted
        0 duplicate SYNs received for entries already in the cache
        0 SYNs dropped (no route or no space)
udp:
        9580 datagrams received
        0 with incomplete header
        0 with bad data length field
        0 with bad checksum
        24 dropped due to no socket
        1422 broadcast/multicast datagrams dropped due to no socket
        0 dropped due to full socket buffers
        8134 delivered
        5795 PCB hash misses
        8194 datagrams output

tcpdump: listening on ep0
00:17:34.512315 marauders.65418 > bigfoot.eecs.umich.edu.ftp: P 1907157335:1907157350(15) ack 3867086446 win 17520 <nop,nop,timestamp 8456 65979822> [tos 0x10]
00:17:34.556666 bigfoot.eecs.umich.edu.ftp > marauders.65418: P 1:15(14) ack 15 win 32120 <nop,nop,timestamp 65985167 8456> (DF) [tos 0x10]
00:17:34.557270 marauders.65418 > bigfoot.eecs.umich.edu.ftp: P 15:21(6) ack 15 win 17520 <nop,nop,timestamp 8456 65985167> [tos 0x10]
00:17:34.602177 bigfoot.eecs.umich.edu.ftp > marauders.65418: P 15:63(48) ack 21 win 32120 <nop,nop,timestamp 65985172 8456> (DF) [tos 0x10]
00:17:34.603175 marauders.65285 > bigfoot.eecs.umich.edu.3869: S 2575295544:2575295544(0) win 16384 <mss 1460,nop,wscale 0,nop,nop,timestamp[|tcp]>
00:17:34.649686 bigfoot.eecs.umich.edu.3869 > marauders.65285: S 447994181:447994181(0) ack 2575295545 win 32120 <mss 1460,nop,nop,timestamp 65985176[|tcp]> (DF)
00:17:34.649915 marauders.65285 > bigfoot.eecs.umich.edu.3869: . ack 1 win 17520 <nop,nop,timestamp 8457 65985176>
00:17:34.650284 marauders.65418 > bigfoot.eecs.umich.edu.ftp: P 21:36(15) ack 63 win 17520 <nop,nop,timestamp 8457 65985172> [tos 0x10]
00:17:34.702618 bigfoot.eecs.umich.edu.ftp > marauders.65418: P 63:135(72) ack 36 win 32120 <nop,nop,timestamp 65985181 8457> (DF) [tos 0x10]
00:17:34.729410 bigfoot.eecs.umich.edu.3869 > marauders.65285: P 1:1449(1448) ack 1 win 32120 <nop,nop,timestamp 65985184 8457> (DF) [tos 0x10]
00:17:34.729708 marauders.65285 > bigfoot.eecs.umich.edu.3869: . ack 1449 win 17520 <nop,nop,timestamp 8457 65985184> [tos 0x8]
00:17:34.730716 bigfoot.eecs.umich.edu.3869 > marauders.65285: P 1449:2897(1448) ack 1 win 32120 <nop,nop,timestamp 65985184 8457> (DF) [tos 0x10]
00:17:34.730990 marauders.65285 > bigfoot.eecs.umich.edu.3869: . ack 2897 win 17520 <nop,nop,timestamp 8457 65985184> [tos 0x8]
00:17:34.778531 bigfoot.eecs.umich.edu.3869 > marauders.65285: P 2897:4345(1448) ack 1 win 32120 <nop,nop,timestamp 65985189 8457> (DF) [tos 0x10]
00:17:34.778795 marauders.65285 > bigfoot.eecs.umich.edu.3869: . ack 4345 win 17520 <nop,nop,timestamp 8457 65985189> [tos 0x8]
00:17:34.779503 bigfoot.eecs.umich.edu.3869 > marauders.65285: P 4345:5793(1448) ack 1 win 32120 <nop,nop,timestamp 65985189 8457> (DF) [tos 0x10]
00:17:34.779820 marauders.65285 > bigfoot.eecs.umich.edu.3869: . ack 5793 win 17520 <nop,nop,timestamp 8457 65985189> [tos 0x8]
00:17:34.780969 bigfoot.eecs.umich.edu.3869 > marauders.65285: P 5793:7241(1448) ack 1 win 32120 <nop,nop,timestamp 65985189 8457> (DF) [tos 0x10]
00:17:34.781239 marauders.65285 > bigfoot.eecs.umich.edu.3869: . ack 7241 win 17520 <nop,nop,timestamp 8457 65985189> [tos 0x8]
00:17:34.781528 bigfoot.eecs.umich.edu.3869 > marauders.65285: P 7241:8689(1448) ack 1 win 32120 <nop,nop,timestamp 65985189 8457> (DF) [tos 0x10]
00:17:34.782062 marauders.65285 > bigfoot.eecs.umich.edu.3869: . ack 8689 win 17520 <nop,nop,timestamp 8457 65985189> [tos 0x8]
00:17:34.826233 bigfoot.eecs.umich.edu.3869 > marauders.65285: P 8689:10137(1448) ack 1 win 32120 <nop,nop,timestamp 65985194 8457> (DF) [tos 0x10]
00:17:34.826518 marauders.65285 > bigfoot.eecs.umich.edu.3869: . ack 10137 win 17520 <nop,nop,timestamp 8457 65985194> [tos 0x8]
00:17:34.827173 bigfoot.eecs.umich.edu.3869 > marauders.65285: P 10137:11585(1448) ack 1 win 32120 <nop,nop,timestamp 65985194 8457> (DF) [tos 0x10]
00:17:34.827437 marauders.65285 > bigfoot.eecs.umich.edu.3869: . ack 11585 win 17520 <nop,nop,timestamp 8457 65985194> [tos 0x8]
00:17:34.829476 bigfoot.eecs.umich.edu.3869 > marauders.65285: P 11585:13033(1448) ack 1 win 32120 <nop,nop,timestamp 65985194 8457> (DF) [tos 0x10]
00:17:34.829758 marauders.65285 > bigfoot.eecs.umich.edu.3869: . ack 13033 win 17520 <nop,nop,timestamp 8457 65985194> [tos 0x8]
00:17:34.831151 bigfoot.eecs.umich.edu.3869 > marauders.65285: P 13033:14481(1448) ack 1 win 32120 <nop,nop,timestamp 65985194 8457> (DF) [tos 0x10]
00:17:34.831478 marauders.65285 > bigfoot.eecs.umich.edu.3869: . ack 14481 win 17520 <nop,nop,timestamp 8457 65985194> [tos 0x8]
00:17:34.831965 bigfoot.eecs.umich.edu.3869 > marauders.65285: P 14481:15929(1448) ack 1 win 32120 <nop,nop,timestamp 65985194 8457> (DF) [tos 0x10]
00:17:34.832279 marauders.65285 > bigfoot.eecs.umich.edu.3869: . ack 15929 win 17520 <nop,nop,timestamp 8457 65985194> [tos 0x8]
00:17:34.833075 bigfoot.eecs.umich.edu.3869 > marauders.65285: P 15929:17377(1448) ack 1 win 32120 <nop,nop,timestamp 65985194 8457> (DF) [tos 0x10]
00:17:34.833355 marauders.65285 > bigfoot.eecs.umich.edu.3869: . ack 17377 win 17520 <nop,nop,timestamp 8457 65985194> [tos 0x8]
00:17:34.834388 bigfoot.eecs.umich.edu.3869 > marauders.65285: P 17377:18825(1448) ack 1 win 32120 <nop,nop,timestamp 65985194 8457> (DF) [tos 0x10]
00:17:34.834669 marauders.65285 > bigfoot.eecs.umich.edu.3869: . ack 18825 win 17520 <nop,nop,timestamp 8457 65985194> [tos 0x8]
00:17:34.835239 bigfoot.eecs.umich.edu.3869 > marauders.65285: P 18825:20273(1448) ack 1 win 32120 <nop,nop,timestamp 65985194 8457> (DF) [tos 0x10]
00:17:34.835512 marauders.65285 > bigfoot.eecs.umich.edu.3869: . ack 20273 win 17520 <nop,nop,timestamp 8457 65985194> [tos 0x8]


tcpdump: listening on ep0
00:33:10.709188 marauders.65246 > pembleton.ftp: P 4045265577:4045265599(22) ack 368106949 win 17520 <nop,nop,timestamp 10329 434569175> [tos 0x10]
00:33:10.709591 pembleton.ftp > marauders.65246: P 1:54(53) ack 22 win 10136 <nop,nop,timestamp 434570388 10329> (DF)
00:33:10.710232 marauders.65246 > pembleton.ftp: P 22:28(6) ack 54 win 17520 <nop,nop,timestamp 10329 434570388> [tos 0x10]
00:33:10.710942 pembleton.ftp > marauders.65246: P 54:105(51) ack 28 win 10136 <nop,nop,timestamp 434570388 10329> (DF)
00:33:10.711938 marauders.65244 > pembleton.62414: S 531044971:531044971(0) win 16384 <mss 1460,nop,wscale 0,nop,nop,timestamp[|tcp]>
00:33:10.712179 pembleton.62414 > marauders.65244: S 370951216:370951216(0) ack 531044972 win 10136 <nop,nop,timestamp 434570388 10329,nop,[|tcp]> (DF)
00:33:10.712385 marauders.65244 > pembleton.62414: . ack 1 win 17520 <nop,nop,timestamp 10329 434570388>
00:33:10.712731 marauders.65246 > pembleton.ftp: P 28:50(22) ack 105 win 17520 <nop,nop,timestamp 10329 434570388> [tos 0x10]
00:33:10.713558 pembleton.ftp > marauders.65246: P 105:192(87) ack 50 win 10136 <nop,nop,timestamp 434570388 10329> (DF)
00:33:10.714401 pembleton.62414 > marauders.65244: P 1:1449(1448) ack 1 win 10136 <nop,nop,timestamp 434570388 10329> (DF)
00:33:10.896414 marauders.65244 > pembleton.62414: . ack 1449 win 17520 <nop,nop,timestamp 10329 434570388> [tos 0x8]
00:33:10.896480 marauders.65246 > pembleton.ftp: . ack 192 win 17520 <nop,nop,timestamp 10329 434570388> [tos 0x10]
00:33:10.897157 pembleton.62414 > marauders.65244: . 1449:2897(1448) ack 1 win 10136 <nop,nop,timestamp 434570406 10329> (DF)
00:33:10.897385 pembleton.62414 > marauders.65244: P 2897:4345(1448) ack 1 win 10136 <nop,nop,timestamp 434570406 10329> (DF)
00:33:10.897580 marauders.65244 > pembleton.62414: . ack 4345 win 14624 <nop,nop,timestamp 10329 434570406> [tos 0x8]
00:33:10.897779 marauders.65244 > pembleton.62414: . ack 4345 win 17520 <nop,nop,timestamp 10329 434570406> [tos 0x8]
00:33:10.898194 pembleton.62414 > marauders.65244: . 4345:5793(1448) ack 1 win 10136 <nop,nop,timestamp 434570406 10329> (DF)
00:33:10.898440 pembleton.62414 > marauders.65244: . 5793:7241(1448) ack 1 win 10136 <nop,nop,timestamp 434570406 10329> (DF)
00:33:10.898596 pembleton.62414 > marauders.65244: P 7241:8193(952) ack 1 win 10136 <nop,nop,timestamp 434570406 10329> (DF)
00:33:10.898800 marauders.65244 > pembleton.62414: . ack 7241 win 14624 <nop,nop,timestamp 10329 434570406> [tos 0x8]
00:33:10.899420 pembleton.62414 > marauders.65244: . 8193:9641(1448) ack 1 win 10136 <nop,nop,timestamp 434570406 10329> (DF)
00:33:10.899661 pembleton.62414 > marauders.65244: P 9641:11089(1448) ack 1 win 10136 <nop,nop,timestamp 434570406 10329> (DF)
00:33:10.899883 pembleton.62414 > marauders.65244: . 11089:12537(1448) ack 1 win 10136 <nop,nop,timestamp 434570407 10329> (DF)
00:33:10.900061 marauders.65244 > pembleton.62414: . ack 9641 win 12224 <nop,nop,timestamp 10329 434570406> [tos 0x8]
00:33:10.900210 marauders.65244 > pembleton.62414: . ack 12537 win 9328 <nop,nop,timestamp 10329 434570406> [tos 0x8]
00:33:10.900691 pembleton.62414 > marauders.65244: . 12537:13985(1448) ack 1 win 10136 <nop,nop,timestamp 434570407 10329> (DF)
00:33:10.900927 pembleton.62414 > marauders.65244: . 13985:15433(1448) ack 1 win 10136 <nop,nop,timestamp 434570407 10329> (DF)
00:33:10.901079 pembleton.62414 > marauders.65244: P 15433:16385(952) ack 1 win 10136 <nop,nop,timestamp 434570407 10329> (DF)
00:33:10.901300 marauders.65244 > pembleton.62414: . ack 15433 win 7880 <nop,nop,timestamp 10329 434570407> [tos 0x8]
00:33:10.901946 pembleton.62414 > marauders.65244: . 20729:22177(1448) ack 1 win 10136 <nop,nop,timestamp 434570407 10329> (DF)
00:33:10.902162 marauders.65244 > pembleton.62414: . ack 16385 win 9328 <nop,nop,timestamp 10329 434570407> [tos 0x8]
00:33:10.902778 pembleton.62414 > marauders.65244: . 22177:23625(1448) ack 1 win 10136 <nop,nop,timestamp 434570407 10329> (DF)
00:33:10.902956 pembleton.62414 > marauders.65244: . 23625:24577(952) ack 1 win 10136 <nop,nop,timestamp 434570407 10329> (DF)
00:33:10.903156 marauders.65244 > pembleton.62414: . ack 16385 win 13672 <nop,nop,timestamp 10329 434570407> [tos 0x8]
00:33:10.903294 marauders.65244 > pembleton.62414: . ack 16385 win 13672 <nop,nop,timestamp 10329 434570407> [tos 0x8]
00:33:10.903536 marauders.65244 > pembleton.62414: . ack 16385 win 17520 <nop,nop,timestamp 10329 434570407> [tos 0x8]
00:33:10.903785 pembleton.62414 > marauders.65244: . 24577:26025(1448) ack 1 win 10136 <nop,nop,timestamp 434570407 10329> (DF)
00:33:10.904019 pembleton.62414 > marauders.65244: . 26025:27473(1448) ack 1 win 10136 <nop,nop,timestamp 434570407 10329> (DF)
00:33:10.904192 marauders.65244 > pembleton.62414: . ack 16385 win 17520 <nop,nop,timestamp 10329 434570407> [tos 0x8]
00:33:10.904329 marauders.65244 > pembleton.62414: . ack 16385 win 17520 <nop,nop,timestamp 10329 434570407> [tos 0x8]

---
Sean Sweda
sweda@ibl.org                     http://www.ibl.org/~sweda
sweda@advantageit.com             http://www.advantageit.com