[Click] Long Latency for large packets...

[Nicholas Weaver]

	I've got a very simple bridge:

src_em0 :: FromDevice(em0, PROMISC true);
src_em1 :: FromDevice(em1, PROMISC true);
dest_em0 :: ToDevice(em0);
dest_em1 :: ToDevice(em1);

queue0 :: Queue;
queue1 :: Queue;

src_em0 -> queue0 -> dest_em1;
src_em1 -> queue1 -> dest_em0;

	Running in userlevel on FreeBSD.  

On one side of the bridge is my workstation (tomato), on the other is
the rest of the network, and I've experienced some performance, emm,
anomoalies.


	When packets are not fragmented, performance is very good. 

A ping across the bridge to my workstation:

> sudo ping -c 5 -s 1470 -t 2000 tomato.icsi.berkeley.edu
PING tomato.icsi.berkeley.edu (192.150.186.58): 1470 data bytes
1478 bytes from 192.150.186.58: icmp_seq=0 ttl=63 time=1.591 ms
1478 bytes from 192.150.186.58: icmp_seq=1 ttl=63 time=1.446 ms
1478 bytes from 192.150.186.58: icmp_seq=2 ttl=63 time=1.508 ms
1478 bytes from 192.150.186.58: icmp_seq=3 ttl=63 time=1.570 ms
1478 bytes from 192.150.186.58: icmp_seq=4 ttl=63 time=1.488 ms


	When packets are just large enough to be fragmented,
performance really suffers:

>sudo ping -c 5 -s 1480 -t 2000 tomato.icsi.berkeley.edu
PING tomato.icsi.berkeley.edu (192.150.186.58): 1480 data bytes
1488 bytes from 192.150.186.58: icmp_seq=0 ttl=63 time=1257.351 ms
1488 bytes from 192.150.186.58: icmp_seq=1 ttl=63 time=1257.169 ms
1488 bytes from 192.150.186.58: icmp_seq=2 ttl=63 time=1024.715 ms
1488 bytes from 192.150.186.58: icmp_seq=3 ttl=63 time=1014.689 ms
1488 bytes from 192.150.186.58: icmp_seq=4 ttl=63 time=1253.562 ms


Looking at the TCP Dumps (annotated) from the two interfaces

A single ping of 1470 bytes

Outside> 08:52:12.068299 192.150.187.6 > 192.150.186.58: icmp: echo request
Inside > 08:52:12.068372 192.150.187.6 > 192.150.186.58: icmp: echo request

Inside > 08:52:12.069048 192.150.186.58 > 192.150.187.6: icmp: echo reply
Outside> 08:52:12.069084 192.150.186.58 > 192.150.187.6: icmp: echo reply


Ping of 1480 bytes:



Outside> 08:54:18.590240 .6 > .58: icmp: echo request (frag 38709:1480 at 0+)
Outside> 08:54:18.590254 .6 > .58: icmp (frag 38709:8 at 1480)
Inside > 08:54:18.590379 .6 > .58: icmp: echo request (frag 38709:1480 at 0+)
Inside > 08:54:18.975908 .6 > .58: icmp (frag 38709:8 at 1480)


Inside > 08:54:18.976333 .58 > .6: icmp: echo reply (frag 56996:1480 at 0+)
Inside > 08:54:18.976346 .58 > .6: icmp (frag 56996:8 at 1480)
Outside> 08:54:18.976378 .58 > .6: icmp: echo reply (frag 56996:1480 at 0+)
Outside> 08:54:19.866448 .58 > .6: icmp (frag 56996:8 at 1480)


As can be seen by the TCP dumps, the initial fragment passes quickly,
but the very small (8 byte) fragment is taking a long time to traverse
the click bridge: almost .5 seconds!  This is really impacting my
overall performance, as NSF and everything else goes through the
bridge now.

Suggestions as for the source?  Fixing?

Thanks.

-- 
Nicholas C. Weaver                               nweaver at icsi.berkeley.edu
     This message has been ROT-13 encrypted twice for higher security.