Bug 1264

Hi,

This is regarding the issue found on SSHD (OpenSSH 4.3) on HP-UX. Our application works well with OPENSSH4.2 and below version for HP-UX. Further it works fine for all versions of OpenSSH for all other OS like Linux, Solaris, AIX, Tru64 etc.

Our application is using SSH protocol [Version 2] to connect to the SSHD server and it runs few commands on the server. It uses Perl SSH2 libraries, which gives us the wrapper functionality for ssh2 protocol. For each command to execute on the server it uses a function called cmd() which internally opens a new channel and closes it after executing the command. But in this case, the channel is not closed by the SSH server which is supposed to do and it continues to open uptill 10 channels.  When it tries to open the 11th channel it says "no more sessions". So only the first 10 commands gets executed and we receive the output and rest of the commands are not executed.

We found that this problem is only on HPUX where OpenSSH 4.3 is installed. It works fine with other OS where OpenSSH 4.3 is installed.

Please provide some help on this

The server log [sshd log in debug mode] 

debug2: load_server_config: filename /opt/ssh/etc/sshd_config debug2: load_server_config: done config len = 350 debug2: parse_server_config: config /opt/ssh/etc/sshd_config len 350 debug1: TOKEN IS protocol debug1: TOKEN IS loglevel debug1: TOKEN IS kerberosauthentication debug1: TOKEN IS usepam debug1: TOKEN IS x11forwarding debug1: TOKEN IS x11displayoffset debug1: TOKEN IS x11uselocalhost debug1: TOKEN IS clientaliveinterval debug1: TOKEN IS maxstartups debug1: TOKEN IS subsystem debug3: RNG is ready, skipping seeding debug1: sshd version OpenSSH_4.3p2-hpn [ HP-UX Secure Shell-A.04.30.015 ] debug3: Not a RSA1 key file /opt/ssh/etc/ssh_host_rsa_key. debug1: read PEM private key done: type RSA debug1: private host key: #0 type 1 RSA debug3: Not a RSA1 key file /opt/ssh/etc/ssh_host_dsa_key. debug1: read PEM private key done: type DSA debug1: private host key: #1 type 2 DSA debug1: rexec_argv[0]='/opt/ssh/sbin/sshd' debug1: rexec_argv[1]='-ddd' debug2: fd 4 setting O_NONBLOCK debug1: Bind to port 22 on ::. Server listening on :: port 22. debug2: fd 5 setting O_NONBLOCK debug1: Bind to port 22 on 0.0.0.0. Server listening on 0.0.0.0 port 22. debug3: fd 6 is not O_NONBLOCK debug1: Server will not fork when running in debugging mode. debug3: send_rexec_state: entering fd = 9 config len 350 debug3: ssh_msg_send: type 0 debug3: send_rexec_state: done debug1: rexec start in 6 out 6 newsock 6 pipe -1 sock 9 debug1: inetd sockets after dupping: 4, 4 debug1: audit connection from 15.1.196.211 port 1023 euid 0 Connection from 15.1.196.211 port 1023 debug1: Client protocol version 2.0; client software version 1.29 debug1: no match: 1.29 debug1: Enabling compatibility mode for protocol 2.0 debug1: Local version string SSH-2.0-OpenSSH_4.3p2-hpn debug2: fd 4 setting O_NONBLOCK debug2: Network child is on pid 19937 debug3: preauth child monitor started debug3: mm_request_receive entering debug3: privsep user:group 102:102 debug1: permanently_set_uid: 102/102 debug1: list_hostkey_types: ssh-rsa,ssh-dss debug1: SSH2_MSG_KEXINIT sent debug1: SSH2_MSG_KEXINIT received debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha1,diffie-hellman-group14-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,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96 debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96 debug2: kex_parse_kexinit: none,zlib@openssh.com debug2: kex_parse_kexinit: none,zlib@openssh.com 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-group1-sha1 debug2: kex_parse_kexinit: ssh-dss,ssh-rsa debug2: kex_parse_kexinit: 3des-cbc,blowfish-cbc,arcfour debug2: kex_parse_kexinit: 3des-cbc,blowfish-cbc,arcfour debug2: kex_parse_kexinit: hmac-sha1,hmac-md5 debug2: kex_parse_kexinit: hmac-sha1,hmac-md5 debug2: kex_parse_kexinit: none debug2: kex_parse_kexinit: none 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-sha1 debug1: kex: client->server 3des-cbc hmac-sha1 none debug2: mac_init: found hmac-sha1 debug1: kex: server->client 3des-cbc hmac-sha1 none debug2: dh_gen_key: priv key bits set: 202/384 debug2: bits set: 495/1024 debug1: expecting SSH2_MSG_KEXDH_INIT debug2: bits set: 512/1024 debug3: mm_key_sign entering debug3: mm_request_send entering: type 4 debug3: monitor_read: checking request 4 debug3: mm_answer_sign debug3: mm_answer_sign: signature 4004f000(55) debug3: mm_request_send entering: type 5 debug2: monitor_read: 4 used once, disabling now debug3: mm_request_receive entering debug3: mm_key_sign: waiting for MONITOR_ANS_SIGN debug3: mm_request_receive_expect entering: type 5 debug3: mm_request_receive entering debug2: kex_derive_keys debug2: set_newkeys: mode 1 debug1: SSH2_MSG_NEWKEYS sent debug1: expecting SSH2_MSG_NEWKEYS debug2: set_newkeys: mode 0 debug1: SSH2_MSG_NEWKEYS received debug1: KEX done debug1: userauth-request for user root service ssh-connection method none debug1: attempt 0 failures 0 debug3: mm_getpwnamallow entering debug3: mm_request_send entering: type 6 debug3: monitor_read: checking request 6 debug3: mm_answer_pwnamallow debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1 debug3: mm_request_send entering: type 7 debug2: monitor_read: 6 used once, disabling now debug3: mm_request_receive entering debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM debug3: mm_request_receive_expect entering: type 7 debug3: mm_request_receive entering debug2: input_userauth_request: setting up authctxt for root debug3: mm_start_pam entering debug3: mm_request_send entering: type 45 debug3: monitor_read: checking request 45 debug1: PAM: initializing for "root" debug3: Trying to reverse map address 15.1.196.211. debug3: mm_inform_authserv entering debug3: mm_request_send entering: type 3 debug3: auth_allowed: method=none user=root debug3: Trying to reverse map address 15.1.196.211. debug2: input_userauth_request: try method none debug3: mm_auth_password entering debug3: mm_request_send entering: type 10 debug3: mm_auth_password: waiting for MONITOR_ANS_AUTHPASSWORD debug3: mm_request_receive_expect entering: type 11 debug3: mm_request_receive entering debug1: PAM: setting PAM_RHOST to "rssstpa.esr.hp.com" debug2: monitor_read: 45 used once, disabling now debug3: mm_request_receive entering debug3: monitor_read: checking request 3 debug3: mm_answer_authserv: service=ssh-connection, style= debug2: monitor_read: 3 used once, disabling now debug3: mm_request_receive entering debug3: monitor_read: checking request 10 debug3: mm_answer_authpassword: sending result 0 debug3: mm_request_send entering: type 11 debug3: mm_auth_password: user not authenticated Failed none for root from 15.1.196.211 port 1023 ssh2 debug3: audit failed auth attempt, method none euid 102 debug3: auth_allowed: method=publickey user=root debug3: auth_allowed: method=password user=root debug3: auth_allowed: method=keyboard-interactive user=root Failed none for root from 15.1.196.211 port 1023 ssh2 debug3: audit failed auth attempt, method none euid 0 debug1: audit event euid 0 user root event 3 (AUTH_FAIL_NONE) debug3: mm_request_receive entering debug1: userauth-request for user root service ssh-connection method password debug1: attempt 1 failures 1 debug3: auth_allowed: method=password user=root debug2: input_userauth_request: try method password debug3: mm_auth_password entering debug3: mm_request_send entering: type 10 debug3: monitor_read: checking request 10 debug3: auth_allowed: method=kerberos user=root debug1: temporarily_use_uid: 0/3 (e=0/3) debug1: restore_uid: 0/3 debug1: Kerberos password authentication failed: -1765328249 debug1: krb5_cleanup_proc called debug3: auth_allowed: method=kerberos_or_local user=root debug3: PAM: sshpam_passwd_conv called with 1 messages debug1: PAM: password authentication accepted for root debug3: mm_answer_authpassword: sending result 1 debug3: mm_request_send entering: type 11 debug3: mm_request_receive_expect entering: type 46 debug3: mm_request_receive entering debug3: mm_auth_password: waiting for MONITOR_ANS_AUTHPASSWORD debug3: mm_request_receive_expect entering: type 11 debug3: mm_request_receive entering debug3: mm_auth_password: user authenticated debug3: mm_do_pam_account entering debug3: mm_request_send entering: type 46 debug1: do_pam_account: called debug3: PAM: do_pam_account pam_acct_mgmt = 0 (Success) debug3: mm_request_send entering: type 47 Accepted password for root from 15.1.196.211 port 1023 ssh2 debug1: monitor_child_preauth: root has been authenticated by privileged process debug3: mm_get_keystate: Waiting for new keys debug3: mm_request_receive_expect entering: type 24 debug3: mm_request_receive entering debug3: mm_request_receive_expect entering: type 47 debug3: mm_request_receive entering debug3: mm_do_pam_account returning 1 Accepted password for root from 15.1.196.211 port 1023 ssh2 debug3: mm_send_keystate: Sending new keys: 40028b10 40028bd0 debug3: mm_newkeys_to_blob: converting 40028b10 debug3: mm_newkeys_to_blob: converting 40028bd0 debug3: mm_send_keystate: New keys have been sent debug3: mm_send_keystate: Sending compression state debug3: mm_request_send entering: type 24 debug3: mm_newkeys_from_blob: 40083790(121) debug2: mac_init: found hmac-sha1 debug3: mm_get_keystate: Waiting for second key debug3: mm_newkeys_from_blob: 40083790(121) debug2: mac_init: found hmac-sha1 debug3: mm_get_keystate: Getting compression state debug3: mm_get_keystate: Getting Network I/O buffers debug3: mm_share_sync: Share sync debug3: mm_share_sync: Share sync end debug3: mm_send_keystate: Finished sending state debug1: audit event euid 0 user root event 2 (AUTH_SUCCESS) debug2: set_newkeys: mode 0 debug2: set_newkeys: mode 1 debug1: Entering interactive session for SSH2. debug2: fd 6 setting O_NONBLOCK debug2: fd 10 setting O_NONBLOCK debug1: server_init_dispatch_20 debug1: server_input_channel_open: ctype session rchan 0 win 32768 max 16384 debug1: input_session_request debug1: channel 0: new [server-session] debug1: session_new: init debug1: session_new: session 0 debug1: session_open: channel 0 debug1: session_open: session 0: link with channel 0 debug1: server_input_channel_open: confirm session debug1: server_input_channel_req: channel 0 request shell reply 0 debug1: session_by_channel: session 0 channel 0 debug1: session_input_channel_req: session 0 req shell debug1: audit run command euid 0 user root command '/sbin/sh' debug1: PAM: establishing credentials debug2: fd 13 setting O_NONBLOCK debug2: fd 12 setting O_NONBLOCK debug2: fd 15 setting O_NONBLOCK debug2: tcpwinsz: 32768 for connection: 4 debug2: channel 0: read 461 from efd 15 debug2: channel 0: rwin 32768 elen 461 euse 1 debug2: channel 0: sent ext data 461 debug2: channel 0: read 44 from efd 15 debug2: channel 0: rwin 32307 elen 44 euse 1 debug2: channel 0: sent ext data 44 debug2: channel 0: read 25 from efd 15 debug2: channel 0: rwin 32263 elen 25 euse 1 debug2: channel 0: sent ext data 25 debug2: channel 0: read 15 from efd 15 debug2: channel 0: rwin 31071 elen 15 euse 1 debug2: channel 0: sent ext data 15 debug2: channel 0: read 25 from efd 15 debug2: channel 0: rwin 31056 elen 25 euse 1 debug2: channel 0: sent ext data 25 debug2: channel 0: read 25 from efd 15 debug2: channel 0: rwin 31031 elen 25 euse 1 debug2: channel 0: sent ext data 25 debug1: server_input_channel_open: ctype session rchan 1 win 32768 max 16384 debug1: input_session_request debug1: channel 1: new [server-session] debug1: session_new: session 1 debug1: session_open: channel 1 debug1: session_open: session 1: link with channel 1 debug1: server_input_channel_open: confirm session debug1: server_input_channel_req: channel 1 request exec reply 0 debug1: session_by_channel: session 1 channel 1 debug1: session_input_channel_req: session 1 req exec debug1: audit run command euid 0 user root command 'which cat' debug1: PAM: establishing credentials debug2: fd 16 setting O_NONBLOCK debug2: fd 14 setting O_NONBLOCK debug2: fd 18 setting O_NONBLOCK debug2: tcpwinsz: 32768 for connection: 4 debug2: channel 1: read 511 from efd 18 debug2: channel 1: rwin 32768 elen 511 euse 1 debug2: channel 1: sent ext data 511 debug1: Received SIGCHLD. debug1: session_by_pid: pid 19952 debug1: session_exit_message: session 1 channel 1 pid 19952 debug2: channel 1: request exit-status confirm 0 debug1: session_exit_message: release channel 1 debug2: channel 1: write failed debug2: channel 1: close_write debug2: channel 1: output open -> closed debug2: notify_done: reading debug2: channel 1: read<=0 rfd 16 len 0 debug2: channel 1: read failed debug2: channel 1: close_read debug2: channel 1: input open -> drain debug2: channel 1: read 0 from efd 18 debug2: channel 1: closing read-efd 18 debug2: channel 1: ibuf empty debug2: channel 1: send eof debug2: channel 1: input drain -> closed debug2: channel 1: send close debug3: channel 1: will not send data after close debug2: channel 1: rcvd close debug3: channel 1: will not send data after close debug2: channel 1: is dead debug2: channel 1: gc: notify user debug1: session_by_channel: session 1 channel 1 debug1: session_close_by_channel: channel 1 child 19952 debug1: session_close_by_channel: channel 1: has child debug2: channel 1: is dead debug2: channel 1: gc: notify user debug1: session_by_channel: session 1 channel 1 debug1: session_close_by_channel: channel 1 child 19952 debug1: session_close_by_channel: channel 1: has child debug1: server_input_channel_open: ctype session rchan 2 win 32768 max 16384 debug1: input_session_request


debug1: input_session_request debug1: channel 10: new [server-session] debug1: session_open: channel 10 no more sessions debug1: session open failed, free channel 10 debug1: channel 10: free: server-session, nchannels 11 debug3: channel 10: status: The following connections are open:   #0 server-session (t4 r0 i0/0 o0/0 fd 13/12 cfd -1)   #1 server-session (t4 r1 i3/0 o3/0 fd -1/-1 cfd -1)   #2 server-session (t4 r2 i3/0 o3/0 fd -1/-1 cfd -1)   #3 server-session (t4 r3 i3/0 o3/0 fd -1/-1 cfd -1)   #4 server-session (t4 r4 i3/0 o3/0 fd -1/-1 cfd -1)   #5 server-session (t4 r5 i3/0 o3/0 fd -1/-1 cfd -1)   #6 server-session (t4 r6 i3/0 o3/0 fd -1/-1 cfd -1)   #7 server-session (t4 r7 i3/0 o3/0 fd -1/-1 cfd -1)   #8 server-session (t4 r8 i3/0 o3/0 fd -1/-1 cfd -1)   #9 server-session (t4 r9 i3/0 o3/0 fd -1/-1 cfd -1)   #10 server-session (t10 r-1 i0/0 o0/0 fd -1/-1 cfd -1)  debug3: channel 10: close_fds r -1 w -1 e -1 c -1 debug1: server_input_channel_open: failure session


Regards,
Ajay