Hi,
I think I encountered a serious bug in ssh 1.2.27. There seems to be
a race condition where the ssh daemon (sshd) drops data when it has
to send it over a slow line. I sent this bug report to [EMAIL PROTECTED]
and [EMAIL PROTECTED] on 27/03 but have heard nothing from either so
far.
I'll try to clarify what happens:
There are two machines, server and client. Both machines run Solaris.
The client makes an ssh connection to the server to download a file:
server% ls -l /tmp/DATA
-rw-r--r-- 1 wout staff 200000 Mar 23 11:20 DATA
client% ssh server cat /tmp/DATA > /tmp/DATA
client% ls -l /tmp/DATA
-rw-r--r-- 1 wout staff 194560 Mar 24 17:10 /tmp/DATA
This would copy a file '/tmp/DATA' from server to /tmp/DATA on client.
In this particular case file DATA was 200000 bytes. The size has
to be larger then the buffers used inside sshd.
When the command is run, most data is sent over the line as it should
be. However, when the 'cat' process dies, sshd receives a SIGCHLD and
then fails to read the data left in the pipe to the 'cat' program.
To be more precise, sshd only reads the data left in the pipe to 'cat'
if it has space for it in the outgoing buffer (the buffer that is used
to store data going back to the client).
So the following happens (all in serverloop.c):
1. For a while sshd reads data from the 'cat' command. This data is
transmitted to the client, where it is put in /tmp/DATA.
2. cat writes the final data to the pipe to sshd and exits.
3. sshd receives a SIGCHLD and sets child_terminated and
child_just_terminated to 1.
4. sshd falls out of the select() (line 413) it was in
(it usually receives the signal during the select() call).
select() returns -1 because it was interrupted by the signal.
5. sshd empties readset and writeset (lines 415-422 serverloop.c).
6. The if statements on lines 426 and 446 fail.
7. sshd does its usual stuff and then calls
wait_until_can_do_something().
8. The call to packet_not_very_much_data_to_write() on line 353
returns false (because the outgoing buffer contains more than
16384 bytes). This causes fdout and fderr not to be set in the
readset file descriptor set (lines 355-358).
9. select() on line 413 returns 0 again (due to slow network
connection to client). This time the if statement on line
426 succeeds (child_just_terminated has been set to 0 earlier).
10. Descriptor fdout, fderr and fdin are closed (lines 432-442)
causing the data available to fdout never being read.
The change I made to fix this is in a patch (diff on original
serverloop.c and modified serverloop.c) you will find attached
to this mail. It changes lines 432-439. Instead of blindly closing
the fdout and fderr descriptors when select() returns 0, it only
closes them if the fdout_eof and fderr_eof flags have been set,
respectively. The bug was that the code in lines 426-443 assumed
that select() always provides information on fdout and fderr, which
is not the case as they had not been set in the readset.
For completeness, I also attach the 'sshd -d' output for a faulty
session (original sshd 1.2.27, data is lost) and output for a session
after having applied my patch.
Please let me know what you make of this.
Wout van Albada
Software Engineer
[EMAIL PROTECTED]
--- serverloop.c.ORIG Sun Mar 26 13:20:14 2000
+++ serverloop.c Sun Mar 26 13:25:15 2000
@@ -429,14 +429,14 @@
if (cleanup_context)
pty_cleanup_proc(cleanup_context);
- if (fdout != -1)
+ if (fdout != -1 && fdout_eof) {
close(fdout);
- fdout = -1;
- fdout_eof = 1;
- if (fderr != -1)
+ fdout = -1;
+ }
+ if (fderr != -1 && fderr_eof) {
close(fderr);
- fderr = -1;
- fderr_eof = 1;
+ fderr = -1;
+ }
if (fdin != -1)
close(fdin);
fdin = -1;
Original sshd 1.2.27 session (server):
13:39 [wout@dnp2] /usr/local/sbin 18#./sshd1.orig-2000.03.27 -p 5544 -d
debug: sshd version 1.2.27 [i386-unknown-solaris2.6]
debug: Initializing random number generator; seed file /etc/ssh_random_seed
log: Server listening on port 5544.
log: Generating 768 bit RSA key.
Generating p: ............++ (distance 180)
Generating q: ....++ (distance 62)
Computing the keys...
Testing the keys...
Key generation complete.
log: RSA key generation complete.
debug: Server will not fork when running in debugging mode.
log: Connection from 194.42.244.44 port 1022
debug: Client protocol version 1.5; client software version 1.2.27
debug: Sent 768 bit public key and 1024 bit host key.
debug: Encryption type: idea
debug: Received session key; encryption turned on.
debug: Installing crc compensation attack detector.
debug: Attempting authentication for wout.
debug: Trying rhosts with RSA host authentication for wout
debug: RhostsRSA authentication failed for 'wout', remote 'wout', host
'lisa.365.co.uk'.
log: RSA authentication for wout accepted.
debug: Received request for X11 forwarding with auth spoofing.
debug: bind port 6010: Address already in use
debug: Allocated channel 0 of type 1.
debug: Received authentication agent forwarding request.
debug: Allocated channel 1 of type 10.
debug: Executing command 'cat /tmp/DATA'
debug: Entering interactive session.
debug: Received SIGCHLD.
debug: End of interactive session; stdin 0, stdout (read 194560, sent 194560), stderr
567 bytes.
debug: Command exited with status 0.
debug: Received exit confirmation.
log: Closing connection to 194.42.244.44
Corresponding ssh output (client):
13:39 [wout@lisa] /tmp 32>ssh -v -p 5544 dnp2.football365.co.uk cat /tmp/DATA >
/tmp/DATA-orig-sshd
SSH Version 1.2.27 [sparc-sun-solaris2.7], protocol version 1.5.
Standard version. Does not use RSAREF.
lisa: Reading configuration data /etc/ssh_config
lisa: ssh_connect: getuid 1000 geteuid 0 anon 0
lisa: Connecting to dnp2.football365.co.uk [212.2.1.2] port 5544.
lisa: Allocated local port 1022.
lisa: Connection established.
lisa: Remote protocol version 1.5, remote software version 1.2.27
lisa: Waiting for server public key.
lisa: Received server public key (768 bits) and host key (1024 bits).
lisa: Host 'dnp2.football365.co.uk' is known and matches the host key.
lisa: Initializing random; seed file /home/wout/.ssh/random_seed
lisa: Encryption type: idea
lisa: Sent encrypted session key.
lisa: Installing crc compensation attack detector.
lisa: Received encrypted confirmation.
lisa: Trying rhosts or /etc/hosts.equiv with RSA host authentication.
lisa: Remote: Rhosts/hosts.equiv authentication refused: client user 'wout', server
user 'wout', client host 'lisa.365.co.uk'.
lisa: Server refused our rhosts authentication or host key.
lisa: Connection to authentication agent opened.
lisa: Trying RSA authentication via agent with '[EMAIL PROTECTED]'
lisa: Received RSA challenge from server.
lisa: Sending response to RSA challenge.
lisa: Remote: RSA authentication accepted.
lisa: RSA authentication accepted by server.
lisa: Failed to get local xauth data.
lisa: Requesting X11 forwarding with authentication spoofing.
lisa: Requesting authentication agent forwarding.
lisa: Sending command: cat /tmp/DATA
lisa: Entering interactive session.
log: executing remote command as user wout
Environment:
HOME=/homes/home/wout
USER=wout
LOGNAME=wout
PATH=/bin:/usr/bin:/usr/ucb:/usr/bin/X11:/usr/local/bin:/usr/local/bin
MAIL=/var/mail/wout
SHELL=/bin/tcsh
TZ=GB
SSH_CLIENT=194.42.244.44 1022 5544
DISPLAY=dnp2.football365.co.uk:11.0
SSH_AUTH_SOCK=/tmp/ssh-wout/ssh-17388-agent
Running /usr/openwin/bin/xauth add dnp2.football365.co.uk:11.0 MIT-MAGIC-COOKIE-1
213d7f173bd7c5698930191fa6ad6f21
Running /usr/openwin/bin/xauth add 212.2.1.2:11.0 MIT-MAGIC-COOKIE-1
213d7f173bd7c5698930191fa6ad6f21
lisa: Transferred: stdin 0, stdout 195127, stderr 0 bytes in 15.4 seconds
lisa: Bytes per second: stdin 0.0, stdout 12677.5, stderr 0.0
lisa: Exit status 0
13:40 [wout@lisa] /tmp 33>ls -l /tmp/DATA-orig-sshd
-rw-r--r-- 1 wout staff 194560 Mar 27 13:40 /tmp/DATA-orig-sshd
13:41 [wout@lisa] /tmp 34>sum /tmp/DATA-orig-sshd 11522
380 /tmp/DATA-orig-sshd
And on server:
13:43 [wout@dnp2] /usr/local/sbin 20#ls -l /tmp/DATA
-rw-r--r-- 1 root other 200000 Mar 23 11:20 /tmp/DATA
13:43 [wout@dnp2] /usr/local/sbin 21#sum /tmp/DATA
57919 391 /tmp/DATA
Patched sshd 1.2.27 session (server):
13:41 [wout@dnp2] /usr/local/sbin 19#./sshd -p 5544 -d
debug: sshd version 1.2.27 [i386-unknown-solaris2.6]
debug: Initializing random number generator; seed file /etc/ssh_random_seed
log: Server listening on port 5544.
log: Generating 768 bit RSA key.
Generating p: .............++ (distance 218)
Generating q: ...........++ (distance 196)
Computing the keys...
Testing the keys...
Key generation complete.
log: RSA key generation complete.
debug: Server will not fork when running in debugging mode.
log: Connection from 194.42.244.44 port 1021
debug: Client protocol version 1.5; client software version 1.2.27
debug: Sent 768 bit public key and 1024 bit host key.
debug: Encryption type: idea
debug: Received session key; encryption turned on.
debug: Installing crc compensation attack detector.
debug: Attempting authentication for wout.
debug: Trying rhosts with RSA host authentication for wout
debug: RhostsRSA authentication failed for 'wout', remote 'wout', host
'lisa.365.co.uk'.
log: RSA authentication for wout accepted.
debug: Received request for X11 forwarding with auth spoofing.
debug: bind port 6010: Address already in use
debug: Allocated channel 0 of type 1.
debug: Received authentication agent forwarding request.
debug: Allocated channel 1 of type 10.
debug: Executing command 'cat /tmp/DATA'
debug: Entering interactive session.
debug: Received SIGCHLD.
debug: End of interactive session; stdin 0, stdout (read 200000, sent 200000), stderr
567 bytes.
debug: Command exited with status 0.
debug: Received exit confirmation.
log: Closing connection to 194.42.244.44
Corresponding ssh output (client):
13:41 [wout@lisa] /tmp 35>ssh -v -p 5544 dnp2.football365.co.uk cat /tmp/DATA >
/tmp/DATA-patched-sshd
SSH Version 1.2.27 [sparc-sun-solaris2.7], protocol version 1.5.
Standard version. Does not use RSAREF.
lisa: Reading configuration data /etc/ssh_config
lisa: ssh_connect: getuid 1000 geteuid 0 anon 0
lisa: Connecting to dnp2.football365.co.uk [212.2.1.2] port 5544.
lisa: Allocated local port 1021.
lisa: Connection established.
lisa: Remote protocol version 1.5, remote software version 1.2.27
lisa: Waiting for server public key.
lisa: Received server public key (768 bits) and host key (1024 bits).
lisa: Host 'dnp2.football365.co.uk' is known and matches the host key.
lisa: Initializing random; seed file /home/wout/.ssh/random_seed
lisa: Encryption type: idea
lisa: Sent encrypted session key.
lisa: Installing crc compensation attack detector.
lisa: Received encrypted confirmation.
lisa: Trying rhosts or /etc/hosts.equiv with RSA host authentication.
lisa: Remote: Rhosts/hosts.equiv authentication refused: client user 'wout', server
user 'wout', client host 'lisa.365.co.uk'.
lisa: Server refused our rhosts authentication or host key.
lisa: Connection to authentication agent opened.
lisa: Trying RSA authentication via agent with '[EMAIL PROTECTED]'
lisa: Received RSA challenge from server.
lisa: Sending response to RSA challenge.
lisa: Remote: RSA authentication accepted.
lisa: RSA authentication accepted by server.
lisa: Failed to get local xauth data.
lisa: Requesting X11 forwarding with authentication spoofing.
lisa: Requesting authentication agent forwarding.
lisa: Sending command: cat /tmp/DATA
lisa: Entering interactive session.
log: executing remote command as user wout
Environment:
HOME=/homes/home/wout
USER=wout
LOGNAME=wout
PATH=/bin:/usr/bin:/usr/ucb:/usr/bin/X11:/usr/local/bin:/usr/local/bin
MAIL=/var/mail/wout
SHELL=/bin/tcsh
TZ=GB
SSH_CLIENT=194.42.244.44 1021 5544
DISPLAY=dnp2.football365.co.uk:11.0
SSH_AUTH_SOCK=/tmp/ssh-wout/ssh-17462-agent
Running /usr/openwin/bin/xauth add dnp2.football365.co.uk:11.0 MIT-MAGIC-COOKIE-1
89baa674c215da2f6c290a8e9442426d
Running /usr/openwin/bin/xauth add 212.2.1.2:11.0 MIT-MAGIC-COOKIE-1
89baa674c215da2f6c290a8e9442426d
lisa: Transferred: stdin 0, stdout 200567, stderr 0 bytes in 14.8 seconds
lisa: Bytes per second: stdin 0.0, stdout 13547.2, stderr 0.0
lisa: Exit status 0
13:42 [wout@lisa] /tmp 36>ls -l /tmp/DATA-patched-sshd
-rw-r--r-- 1 wout staff 200000 Mar 27 13:42 /tmp/DATA-patched-sshd
13:43 [wout@lisa] /tmp 37>sum /tmp/DATA-patched-sshd
57919 391 /tmp/DATA-patched-sshd
And on server:
13:43 [wout@dnp2] /usr/local/sbin 20#ls -l /tmp/DATA
-rw-r--r-- 1 root other 200000 Mar 23 11:20 /tmp/DATA
13:43 [wout@dnp2] /usr/local/sbin 21#sum /tmp/DATA
57919 391 /tmp/DATA
