OpenSSH solaris: bad return code after exec of remote command

[David Batterham]

Hi OpenSSH developers,

I am using openSSH (now 2.9.9p2, but prob occurs in 2.9p2 also) to execute
commands on a remote machine which outputs data to stdout then pipes it to
another invocation of ssh which connects back to the first machine in the same
way, where it starts a program to read and store the output from the command on
the second machine. I am using the "command" option in the keys file to force
execution of a particular command when that key is used for authentication. 

My problem is this. The remote ssh returns an error code of 255 (using echo $?),
or (-1 in the debug), despite the command executing successfully. about 5-10% of
the time it returns 0. In all cases it "appears" the command completed
successully, and is simply an issue of ssh failing to close the channel cleanly.
My guess is that one side is closing before the other acknowledges and therefore
thinks the channel has been prematurely terminated. 

My questions are: How sure can I be that I am indeed getting all data from the
pipe? How can I accurately determine the exit status of the command (ufsdump)
which is piping data into ssh, regardless of ssh's exit status ? Has anyone else
seen this problem and/or resolved it ?

If more debug would be helpful, please let me know...

Below is the debug from the remote side when it fails:

<snip>
debug1: Remote: Forced command: /les/galaxy/sysadmin/backup/sbin/receiver
debug1: input_userauth_pk_ok: pkalg ssh-dss blen 435 lastkey 12bac0 hint 0
debug1: read PEM private key done: type DSA
debug1: sig size 20 20
debug1: Remote: Forced command: /les/galaxy/sysadmin/backup/sbin/receiver
debug1: ssh-userauth2 successful: method publickey
debug1: fd 5 setting O_NONBLOCK
debug1: fd 7 setting O_NONBLOCK
debug1: fd 8 setting O_NONBLOCK
debug1: channel 0: new [client-session]
debug1: channel_new: 0
debug1: send channel open 0
debug1: Entering interactive session.
debug1: client_init id 0 arg 0
debug1: channel request 0: shell
debug1: channel 0: open confirm rwindow 0 rmax 16384
debug1: channel 0: read<=0 rfd 5 len 0
debug1: channel 0: read failed
debug1: channel 0: input open -> drain
debug1: channel 0: close_read
debug1: channel 0: input: no drain shortcut
debug1: channel 0: ibuf empty
debug1: channel 0: input drain -> closed
debug1: channel 0: send eof
debug1: channel 0: rcvd eof
debug1: channel 0: output open -> drain
debug1: channel 0: rcvd close
debug1: channel 0: obuf empty
debug1: channel 0: output drain -> closed
debug1: channel 0: close_write
debug1: channel 0: send close
debug1: channel 0: is dead
debug1: channel_free: channel 0: status: The following connections are open:
  #0 client-session (t4 r0 i8/0 o128/0 fd -1/-1)
debug1: channel_free: channel 0: dettaching channel user
debug1: Transferred: stdin 0, stdout 0, stderr 0 bytes in 15.3 seconds
debug1: Bytes per second: stdin 0.0, stdout 0.0, stderr 0.0
debug1: Exit status -1


This is the debug when it works:

OpenSSH_2.9p2, SSH protocols 1.5/2.0, OpenSSL 0x0090602f
debug1: Reading configuration data /opt/OBSDssh/etc/ssh_config
debug1: Seeding random number generator
debug1: Rhosts Authentication disabled, originating port will not be trusted.
debug1: restore_uid
debug1: ssh_connect: getuid 0 geteuid 0 anon 1
debug1: Connecting to galaxy [my_ip_was_here] port 22.
debug1: temporarily_use_uid: 0/1 (e=0)
debug1: restore_uid
debug1: temporarily_use_uid: 0/1 (e=0)
debug1: restore_uid
debug1: Connection established.
debug1: read PEM private key done: type DSA
debug1: read PEM private key done: type RSA
debug1: identity file /.ssh/backup-sender type 2
debug1: Remote protocol version 2.0, remote software version OpenSSH_2.9p2
debug1: match: OpenSSH_2.9p2 pat ^OpenSSH
Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_2.9p2
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug1: kex: server->client aes128-cbc hmac-md5 none
debug1: kex: client->server aes128-cbc hmac-md5 none
debug1: SSH2_MSG_KEX_DH_GEX_REQUEST sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
debug1: dh_gen_key: priv key bits set: 135/256
debug1: bits set: 1017/2049
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug1: Host 'galaxy' is known and matches the RSA host key.
debug1: Found key in //.ssh/known_hosts2:1
debug1: bits set: 1027/2049
debug1: ssh_rsa_verify: signature correct
debug1: kex_derive_keys
debug1: newkeys: mode 1
debug1: SSH2_MSG_NEWKEYS sent
debug1: waiting for SSH2_MSG_NEWKEYS
debug1: newkeys: mode 0
debug1: SSH2_MSG_NEWKEYS received
debug1: done: ssh_kex2.
debug1: send SSH2_MSG_SERVICE_REQUEST
debug1: service_accept: ssh-userauth
debug1: got SSH2_MSG_SERVICE_ACCEPT
debug1: authentications that can continue:
publickey,password,keyboard-interactive
debug1: next auth method to try is publickey
debug1: try pubkey: /.ssh/backup-sender
debug1: Remote: Forced command: /les/galaxy/sysadmin/backup/sbin/receiver
debug1: input_userauth_pk_ok: pkalg ssh-dss blen 435 lastkey 12bac0 hint 0
debug1: read PEM private key done: type DSA
debug1: sig size 20 20
debug1: Remote: Forced command: /les/galaxy/sysadmin/backup/sbin/receiver
debug1: ssh-userauth2 successful: method publickey
debug1: fd 5 setting O_NONBLOCK
debug1: fd 7 setting O_NONBLOCK
debug1: fd 8 setting O_NONBLOCK
debug1: channel 0: new [client-session]
debug1: channel_new: 0
debug1: send channel open 0
debug1: Entering interactive session.
debug1: client_init id 0 arg 0
debug1: channel request 0: shell
debug1: channel 0: open confirm rwindow 0 rmax 16384
debug1: channel 0: read<=0 rfd 5 len 0
debug1: channel 0: read failed
debug1: channel 0: input open -> drain
debug1: channel 0: close_read
debug1: channel 0: input: no drain shortcut
debug1: channel 0: ibuf empty
debug1: channel 0: input drain -> closed
debug1: channel 0: send eof
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
debug1: channel 0: rcvd eof
debug1: channel 0: output open -> drain
debug1: channel 0: rcvd close
debug1: channel 0: obuf empty
debug1: channel 0: output drain -> closed
debug1: channel 0: close_write
debug1: channel 0: send close
debug1: channel 0: is dead
debug1: channel_free: channel 0: status: The following connections are open:
  #0 client-session (t4 r0 i8/0 o128/0 fd -1/-1)
debug1: channel_free: channel 0: dettaching channel user
debug1: Transferred: stdin 0, stdout 0, stderr 0 bytes in 16.3 seconds
debug1: Bytes per second: stdin 0.0, stdout 0.0, stderr 0.0
debug1: Exit status 0

Thanks,
Dave


-- 
---------------------------------------------------------------
David Batterham                     PHONE: +61 3 95001017
System Administrator                FAX:   +61 3 95001191
Lochard Pty Ltd                     EMAIL: david at lochard.com.au