Subject: OpenSSH 3.1 behaving bad + TCP window update bug?
To: None <tech-net@netbsd.org>
From: Tomas Svensson <tsn@gbdev.net>
List: tech-net
Date: 03/15/2002 02:30:29
OpenSSH 3.1 is still enabling TCP_NODELAY on all connections, which is
most likely a bad thing and is causing a packet flood when doing
things like ls -l over the Internet.

It is common that people think this stalling depends on a bad link,
but it doesn't happen with SSH Inc's sshd (because it sends big enough
frames). FreeBSD were probably going to disable TCP_NODELAY for
interactive ssh connections, but I haven't followed that closely.

At the end of the dump it seems like there is a bug in the TCP window
update code, it starts to ACK data it has not yet received?

tcpdump output below, all initial packets are 96 or 112 bytes small
and causes packet loss after a while.

00:54:41.903928 server.ssh > client.65507: P 14673:14769(96) ack 240 win 24820 <nop,nop,timestamp 8668303 199>
00:54:41.908723 server.ssh > client.65507: P 14769:14865(96) ack 240 win 24820 <nop,nop,timestamp 8668303 199>
00:54:41.908743 client.65507 > server.ssh: . ack 14865 win 17424 <nop,nop,timestamp 200 8668303> 
00:54:41.910279 server.ssh > client.65507: P 14865:14977(112) ack 240 win 24820 <nop,nop,timestamp 8668303 199> 
00:54:41.915000 server.ssh > client.65507: P 14977:15073(96) ack 240 win 24820 <nop,nop,timestamp 8668303 199>
00:54:41.915021 client.65507 > server.ssh: . ack 15073 win 17424 <nop,nop,timestamp 200 8668303> 
00:54:41.932423 server.ssh > client.65507: P 15073:15185(112) ack 240 win 24820 <nop,nop,timestamp 8668303 199> 
00:54:41.936694 server.ssh > client.65507: P 15185:15297(112) ack 240 win 24820 <nop,nop,timestamp 8668303 199> 
00:54:41.936715 client.65507 > server.ssh: . ack 15297 win 17408 <nop,nop,timestamp 200 8668303>

-- packet lost here thanks to the network congestion caused by the
   packet flood, causing the output from ls -l to stall.

00:54:41.945049 server.ssh > client.65507: P 15393:15489(96) ack 240 win 24820 <nop,nop,timestamp 8668303 199> 
00:54:41.945076 client.65507 > server.ssh: . ack 15297 win 17520 <nop,nop,timestamp 200 8668303>
00:54:41.954345 server.ssh > client.65507: P 15585:15681(96) ack 240 win 24820 <nop,nop,timestamp 8668303 199> 
00:54:41.954364 client.65507 > server.ssh: . ack 15297 win 17520 <nop,nop,timestamp 200 8668303>
00:54:41.957157 server.ssh > client.65507: P 15793:15889(96) ack 240 win 24820 <nop,nop,timestamp 8668303 199> 
00:54:41.957174 client.65507 > server.ssh: . ack 15297 win 17520 <nop,nop,timestamp 200 8668303>
00:54:41.964762 server.ssh > client.65507: P 16001:16097(96) ack 240 win 24820 <nop,nop,timestamp 8668303 199> 
00:54:41.964780 client.65507 > server.ssh: . ack 15297 win 17520 <nop,nop,timestamp 200 8668303>
00:54:41.967663 server.ssh > client.65507: P 16097:16209(112) ack 240 win 24820 <nop,nop,timestamp 8668303 199>
00:54:41.967681 client.65507 > server.ssh: . ack 15297 win 17520 <nop,nop,timestamp 200 8668303> 
00:54:41.976262 server.ssh > client.65507: P 16209:16321(112) ack 240 win 24820 <nop,nop,timestamp 8668303 199> 
00:54:41.976279 client.65507 > server.ssh: . ack 15297 win 17520 <nop,nop,timestamp 200 8668303>
00:54:41.978361 server.ssh > client.65507: P 16321:16417(96) ack 240 win 24820 <nop,nop,timestamp 8668303 199>
00:54:41.978378 client.65507 > server.ssh: . ack 15297 win 17520 <nop,nop,timestamp 200 8668303> 

--- A lot more of these tinygrams before a few packets at the end
    actually are 1448 bytes:

00:54:42.977248 server.ssh > client.65507: . 20745:22193(1448) ack 240 win 24820 <nop,nop,timestamp 8668306 199>
00:54:42.977278 client.65507 > server.ssh: . ack 22193 win 16072 <nop,nop,timestamp 202 8668306>
00:54:43.023580 server.ssh > client.65507: . 22193:23641(1448) ack 240 win 24820 <nop,nop,timestamp 8668306 199>
00:54:43.023610 client.65507 > server.ssh: . ack 30161 win 9552 <nop,nop,timestamp 202 8668306>
00:54:43.023675 client.65507 > server.ssh: . ack 30161 win 17520 <nop,nop,timestamp 202 8668306> 

-- Looks like a bug in the window update code or am I missing
   something?

00:54:43.041845 server.ssh > client.65507: . 23641:25089(1448) ack 240 win 24820 <nop,nop,timestamp 8668306 199>
00:54:43.041873 client.65507 > server.ssh: . ack 30161 win 17520 <nop,nop,timestamp 202 8668306>
00:54:43.059302 server.ssh > client.65507: . 25089:26537(1448) ack 240 win 24820 <nop,nop,timestamp 8668306 199>
00:54:43.059324 client.65507 > server.ssh: . ack 30161 win 17520 <nop,nop,timestamp 202 8668306>

-Tomas