Hi,
I think that I get the same probleme:
- making backup with dump to an ssh-pipe, the stderr output of the dump
command is broken... and may be the data stream (stdout) too...
- using rsync+ssh, the rsync program freeze randomly, while using
rsync+r(em)sh the same process succed.
That a really annoying bug...
freD.
Wout van Albada <[EMAIL PROTECTED]> wrote:
>
> 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
