You may have some other problem. I've been using rsync-ssh with
1.2.27 since it was released, and 1.2.26 before that, etc.....
to do remote backups of the identical data sets to three different
servers automatically on a daily basis. The data includes a large
number of both large and small files and has proceeded without any
difficulty for several years now.
> 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
>
