[Fwd: [Fwd: openssh 2.9p2 hang problem]]
Mark Reardon
mark.reardon at irl.xerox.com
Wed Aug 22 20:37:23 EST 2001
Markus Friedl wrote:
>
> í'm not sure where the 'bug' is and whether this is 'really' a bug.
>
> try to talk to the openssh-unix-dev list, i'm too busy right now :(
>
> -m
>
> On Thu, Aug 16, 2001 at 03:51:19PM +0100, Mark Reardon wrote:
> > Hello Markus,
> >
> > I recently posted you with a mention of the 2.9p2 possible problem with
> > Solaris 2.6 - 8.
> >
> > Just forwarding on other feedback that users are sending me regarding my
> > original posting to the mailing list.
> >
> > If there is any way at all I can help [ including go away :) ] please do
> > not hesitate to mail me.
> >
> > Rgds,
> >
> > Mark
> >
> > "Hull, Deron" wrote:
> > >
> > > Mark,
> > >
> > > We have the exact same problem with ssh hanging if called from a cron job.
> > > We're also running solaris 2.6 at the server but I'm calling ssh from a cron
> > > job on a 2.8 box
> > > Both are openssh 2.9p2. The only thing I did in the configure script was to
> > > include --with-pam.
> > > We would have used 2.9p1 but X forwarding was broken on our 2.6 boxes by it.
> > > It was creating a directory under tmp (for mit cookie ) with permissions of
> > > 600 even though truss showed it attempting to do a mkdir of 0700. ??? umask
> > > problem?
> > >
> > > I'd be very interested to hear if there was any resolution to this problem.
> > > Haven't seen anything on the mailing list.
> > > I'm going to talk to one of our C programmers that has made custom changes
> > > to openssh for us in the past.
> > >
> > > Please let me know if you hear anything.
> > >
> > > Thanks
> > >
> > > Deron Hull
>
> Hello,
>
> I believe I may have discovered what appears to be a small anomoly in
> the way
> OpenSSH closes connections and thought if I gave you some feedback I
> might
> be able to make a very small contributution to the development of
> openssh.
> This might be a Solaris 2.6 anomoly or an openssh anomoly or a
> combination of both.
> I came across this apparent anomoly because we use openssh (via cron)
> here
> to check on our many Solaris boxes for archive logs filling up so we can
> kick
> off an archive log backup on the machine if needs be. It was noticed
> after a
> few days that cron began to behave strangely on the box that was ssh'ing
> out
> to all the servers. This was because cron had too many outstanding
> processes
> to kick off any more ( we would literally be doing hundreds of cron'd
> ssh tasks
> every hour ). It appears that openssh sometimes has trouble closing
> connections
> on Solaris. To try and get as much detail as possible I set up a simple
> job
> that continually ssh'd into a box and executed a command until it
> finally froze.
> It took literally hours for it to happen, but eventually it did. I also
> hacked
> around with the sshd code in a effort to be able to run sshd continually
> in debug
> mode to try and pick up any information there but this yielded no more
> clues to
> what the problem might be ( apart from pointing back to ssh closing
> connections
> on the Solaris client). Included below is the tail of the debug log on
> the client.
> last successful connection and then the freeze...
>
> If I can provide any more information I will be glad to help.
>
> Best Regards,
>
> Mark Reardon
>
> PS Many thanks for an excellent piece of software.
>
> + ssh -v -v -v xcalibur ps -ef | egrep '(arc0|arch)'_xitprd00 | grep -v
> grep | wc -l
> OpenSSH_2.9p2, SSH protocols 1.5/2.0, OpenSSL 0x0090601f
> debug1: Reading configuration data //.ssh/config
> debug1: Applying options for *
> debug1: Reading configuration data /usr/local/etc/ssh_config
> debug1: Applying options for *
> 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 xcalibur [13.219.48.22] 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: identity file //.ssh/identity type 0
> debug3: No RSA1 key file //.ssh/id_dsa.
> debug2: key_type_from_name: unknown key type '-----BEGIN'
> debug3: key_read: no key found
> debug3: key_read: no space
> debug3: key_read: no space
> debug3: key_read: no space
> debug3: key_read: no space
> debug3: key_read: no space
> debug3: key_read: no space
> debug3: key_read: no space
> debug3: key_read: no space
> debug3: key_read: no space
> debug3: key_read: no space
> debug2: key_type_from_name: unknown key type '-----END'
> debug3: key_read: no key found
> debug1: identity file //.ssh/id_dsa type 2
> debug1: identity file //.ssh/id_rsa1 type -1
> debug1: identity file //.ssh/id_rsa2 type -1
> debug1: Remote protocol version 1.99, 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
> debug2: kex_parse_kexinit:
> diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1
> debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
> debug2: kex_parse_kexinit:
> aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
> debug2: kex_parse_kexinit:
> aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
> debug2: kex_parse_kexinit:
> hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
> debug2: kex_parse_kexinit:
> hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
> debug2: kex_parse_kexinit: zlib
> debug2: kex_parse_kexinit: zlib
> debug2: kex_parse_kexinit:
> debug2: kex_parse_kexinit:
> debug2: kex_parse_kexinit: first_kex_follows 0
> debug2: kex_parse_kexinit: reserved 0
> debug2: kex_parse_kexinit:
> diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1
> debug2: kex_parse_kexinit: ssh-dss,ssh-rsa
> debug2: kex_parse_kexinit:
> aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
> debug2: kex_parse_kexinit:
> aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
> debug2: kex_parse_kexinit:
> hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
> debug2: kex_parse_kexinit:
> hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
> debug2: kex_parse_kexinit: none,zlib
> debug2: kex_parse_kexinit: none,zlib
> debug2: kex_parse_kexinit:
> debug2: kex_parse_kexinit:
> debug2: kex_parse_kexinit: first_kex_follows 0
> debug2: kex_parse_kexinit: reserved 0
> debug2: mac_init: found hmac-md5
> debug1: kex: server->client aes128-cbc hmac-md5 zlib
> debug2: mac_init: found hmac-md5
> debug1: kex: client->server aes128-cbc hmac-md5 zlib
> debug1: SSH2_MSG_KEX_DH_GEX_REQUEST sent
> debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
> debug1: dh_gen_key: priv key bits set: 127/256
> debug1: bits set: 1019/2049
> debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
> debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
> debug3: check_host_in_hostfile: filename //.ssh/known_hosts2
> debug3: check_host_in_hostfile: match line 195
> debug3: check_host_in_hostfile: filename //.ssh/known_hosts2
> debug3: key_read: type mismatch
> debug3: check_host_in_hostfile: match line 195
> debug1: Host 'xcalibur' is known and matches the RSA host key.
> debug1: Found key in //.ssh/known_hosts2:195
> debug1: bits set: 1017/2049
> debug1: ssh_rsa_verify: signature correct
> debug1: kex_derive_keys
> debug1: newkeys: mode 1
> debug1: Enabling compression at level 6.
> 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
> debug3: start over, passed a different list
> publickey,password,keyboard-interactive
> debug3: preferred publickey,password,keyboard-interactive
> debug3: authmethod_lookup publickey
> debug3: remaining preferred: password,keyboard-interactive
> debug3: authmethod_is_enabled publickey
> debug1: next auth method to try is publickey
> debug1: try pubkey: //.ssh/id_dsa
> debug3: send_pubkey_test
> debug2: we sent a publickey packet, wait for reply
> debug1: input_userauth_pk_ok: pkalg ssh-dss blen 434 lastkey 10ae98 hint
> 1
> debug2: input_userauth_pk_ok: fp
> b2:48:f6:61:cd:b8:d0:b5:58:85:95:be:7e:20:68:a8
> debug3: sign_and_send_pubkey
> debug1: read PEM private key done: type DSA
> debug1: sig size 20 20
> debug1: ssh-userauth2 successful: method publickey
> debug1: fd 6 setting O_NONBLOCK
> debug1: channel 0: new [client-session]
> debug1: channel_new: 0
> debug1: send channel open 0
> debug1: Entering interactive session.
> debug2: callback start
> debug1: client_init id 0 arg 0
> debug1: Sending command: ps -ef | egrep '(arc0|arch)'_xitprd00 | grep -v
> grep | wc -l
> debug2: callback done
> debug1: channel 0: open confirm rwindow 0 rmax 16384
> debug2: channel 0: rcvd adjust 32768
> 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: input open -> closed
> debug1: channel 0: close_read
> debug2: channel 0: no data after 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 0.3 seconds
> debug1: Bytes per second: stdin 0.0, stdout 0.0, stderr 0.0
> debug1: Exit status 0
> debug1: compress outgoing: raw data 1198, compressed 667, factor 0.56
> debug1: compress incoming: raw data 592, compressed 580, factor 0.98
> + ssh -v -v -v xcalibur ps -ef | egrep '(arc0|arch)'_xitprd00 | grep -v
> grep | wc -l
> OpenSSH_2.9p2, SSH protocols 1.5/2.0, OpenSSL 0x0090601f
> debug1: Reading configuration data //.ssh/config
> debug1: Applying options for *
> debug1: Reading configuration data /usr/local/etc/ssh_config
> debug1: Applying options for *
> 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 xcalibur [13.219.48.22] 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: identity file //.ssh/identity type 0
> debug3: No RSA1 key file //.ssh/id_dsa.
> debug2: key_type_from_name: unknown key type '-----BEGIN'
> debug3: key_read: no key found
> debug3: key_read: no space
> debug3: key_read: no space
> debug3: key_read: no space
> debug3: key_read: no space
> debug3: key_read: no space
> debug3: key_read: no space
> debug3: key_read: no space
> debug3: key_read: no space
> debug3: key_read: no space
> debug3: key_read: no space
> debug2: key_type_from_name: unknown key type '-----END'
> debug3: key_read: no key found
> debug1: identity file //.ssh/id_dsa type 2
> debug1: identity file //.ssh/id_rsa1 type -1
> debug1: identity file //.ssh/id_rsa2 type -1
> debug1: Remote protocol version 1.99, 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
> debug2: kex_parse_kexinit:
> diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1
> debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
> debug2: kex_parse_kexinit:
> aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
> debug2: kex_parse_kexinit:
> aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
> debug2: kex_parse_kexinit:
> hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
> debug2: kex_parse_kexinit:
> hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
> debug2: kex_parse_kexinit: zlib
> debug2: kex_parse_kexinit: zlib
> debug2: kex_parse_kexinit:
> debug2: kex_parse_kexinit:
> debug2: kex_parse_kexinit: first_kex_follows 0
> debug2: kex_parse_kexinit: reserved 0
> debug2: kex_parse_kexinit:
> diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1
> debug2: kex_parse_kexinit: ssh-dss,ssh-rsa
> debug2: kex_parse_kexinit:
> aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
> debug2: kex_parse_kexinit:
> aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
> debug2: kex_parse_kexinit:
> hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
> debug2: kex_parse_kexinit:
> hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
> debug2: kex_parse_kexinit: none,zlib
> debug2: kex_parse_kexinit: none,zlib
> debug2: kex_parse_kexinit:
> debug2: kex_parse_kexinit:
> debug2: kex_parse_kexinit: first_kex_follows 0
> debug2: kex_parse_kexinit: reserved 0
> debug2: mac_init: found hmac-md5
> debug1: kex: server->client aes128-cbc hmac-md5 zlib
> debug2: mac_init: found hmac-md5
> debug1: kex: client->server aes128-cbc hmac-md5 zlib
> debug1: SSH2_MSG_KEX_DH_GEX_REQUEST sent
> debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
> debug1: dh_gen_key: priv key bits set: 134/256
> debug1: bits set: 1009/2049
> debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
> debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
> debug3: check_host_in_hostfile: filename //.ssh/known_hosts2
> debug3: check_host_in_hostfile: match line 195
> debug3: check_host_in_hostfile: filename //.ssh/known_hosts2
> debug3: key_read: type mismatch
> debug3: check_host_in_hostfile: match line 195
> debug1: Host 'xcalibur' is known and matches the RSA host key.
> debug1: Found key in //.ssh/known_hosts2:195
> debug1: bits set: 1039/2049
> debug1: ssh_rsa_verify: signature correct
> debug1: kex_derive_keys
> debug1: newkeys: mode 1
> debug1: Enabling compression at level 6.
> 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
> debug3: start over, passed a different list
> publickey,password,keyboard-interactive
> debug3: preferred publickey,password,keyboard-interactive
> debug3: authmethod_lookup publickey
> debug3: remaining preferred: password,keyboard-interactive
> debug3: authmethod_is_enabled publickey
> debug1: next auth method to try is publickey
> debug1: try pubkey: //.ssh/id_dsa
> debug3: send_pubkey_test
> debug2: we sent a publickey packet, wait for reply
> debug1: input_userauth_pk_ok: pkalg ssh-dss blen 434 lastkey 10ae98 hint
> 1
> debug2: input_userauth_pk_ok: fp
> b2:48:f6:61:cd:b8:d0:b5:58:85:95:be:7e:20:68:a8
> debug3: sign_and_send_pubkey
> debug1: read PEM private key done: type DSA
> debug1: sig size 20 20
> debug1: ssh-userauth2 successful: method publickey
> debug1: fd 6 setting O_NONBLOCK
> debug1: channel 0: new [client-session]
> debug1: channel_new: 0
> debug1: send channel open 0
> debug1: Entering interactive session.
> debug2: callback start
> debug1: client_init id 0 arg 0
> debug1: Sending command: ps -ef | egrep '(arc0|arch)'_xitprd00 | grep -v
> grep | wc -l
> debug2: callback done
> debug1: channel 0: open confirm rwindow 0 rmax 16384
> debug2: channel 0: rcvd adjust 32768
> debug1: channel 0: rcvd eof
> debug1: channel 0: output open -> drain
> debug1: channel 0: obuf empty
> debug1: channel 0: output drain -> closed
> debug1: channel 0: close_write
>
> freeze happens here...( I have run this test lots of times and it always
> freezes at exactly the same spot
> - when it eventually does freeze )
>
> On the server we are ssh'ing from ( next morninng there are a few
> freezes overnight but not all are on host xcalibur )
>
> > # ps -ef | grep ssh | grep -v sshd
> > root 6202 6201 0 06:30:29 ? 0:00 ssh xcalibur df -k /oracle/u01/admin/xnnprd00/arch
> > root 21855 21854 0 01:00:20 ? 0:00 ssh xcalibur du -sk /oracle/u01/admin/xdnprd00/arch
> > root 21904 21903 0 16:45:41 ? 0:00 ssh xcalibur df -k /oracle/u01/admin/xvkprd00/arch
> > root 27654 27653 0 01:15:38 ? 0:00 ssh xcalibur df -k /oracle/u01/admin/xunprd00/arch
> > root 6857 6856 0 17:45:09 ? 0:00 ssh xcalibur df -k /oracle/u01/admin/xanprd00/arch
> > root 25886 25885 0 15:00:40 ? 0:00 ssh xcalibur du -sk /oracle/u01/admin/xvkprd00/arch
> > root 22924 22923 0 14:45:27 ? 0:00 ssh xcalibur du -sk /oracle/u01/admin/xitprd00/arch
> > root 6335 6334 0 09:19:33 ? 0:00 /usr/local/bin/ssh -x -oFallBackToRsh no -C -4 monet scp -p -f /etc/hosts.allow
> > root 25047 25026 0 08:20:56 pts/16 0:00 grep ssh
> > root 22533 22393 0 08:13:13 pts/6 0:00 ssh middleware
> > root 10348 10347 0 05:45:07 ? 0:00 ssh xesapbw df -k | grep saparch
> > root 17284 17283 0 14:27:59 ? 0:00 ssh xcalibur du -sk /oracle/u01/admin/xunprd00/arch
> > root 3007 3006 0 15:30:20 ? 0:00 ssh xcalibur df -k /oracle/u01/admin/xdnprd00/arch
> > root 9024 8592 0 18:00:46 ? 0:00 ssh xesapdb1 grep '^tmproot' /etc/shadow | grep -v '*LK*'
> > root 26020 2746 0 17:03:19 pts/17 0:00 ssh -v -v -v xcalibur ps -ef | egrep '(arc0|arch)'_xitprd00 | grep -v grep | wc
> > root 13526 13525 0 06:00:22 ? 0:00 ssh xcalibur df -k /oracle/u01/admin/xenprd00/arch
> > root 12757 12673 0 14:24:03 pts/2 0:01 ssh solar-2
> > root 28679 28678 0 17:15:40 ? 0:00 ssh xcalibur df -k /oracle/u01/admin/xvkprd00/arch
> > root 20119 40 0 07:55:18 pts/22 0:00 ssh devsrv1
> > root 13956 13955 0 02:00:03 ? 0:00 ssh -v -v -v devsrv1 df -k | grep saparch
More information about the openssh-unix-dev
mailing list