Hanging ssh sessions with openssh-5.1p1 and Solaris 8 & 10 - openssh

This is a discussion on Hanging ssh sessions with openssh-5.1p1 and Solaris 8 & 10 - openssh ; Did you figure anything out on this? I have the exact same issue since moving to openssh 5.1p1 on Solaris 10. At first I thought it was this old ssh.com v3.2 client (before they changed to tectia) that we've been ...

+ Reply to Thread
Results 1 to 3 of 3

Thread: Hanging ssh sessions with openssh-5.1p1 and Solaris 8 & 10

  1. Hanging ssh sessions with openssh-5.1p1 and Solaris 8 & 10

    Did you figure anything out on this? I have the exact same issue
    since moving to openssh 5.1p1 on Solaris 10. At first I thought it
    was this old ssh.com v3.2 client (before they changed to tectia) that
    we've been using, but the trial SecureCRT 6.1 client doesn't exhibit
    this issue on a large paste.


  2. Re: Hanging ssh sessions with openssh-5.1p1 and Solaris 8 & 10

    I was trying to reply to the original thread
    http://groups.google.com/group/maili...815469c90068e2

    The issue is that on large copy & paste into the ssh client will cause
    the connection to hang showing no output. The original thread above
    claims this occurs with pasting >= 1024 characters but I haven't
    actually counted them. Debug mode for the sshd process does not
    output any additional info. On clients in which I could run a debug,
    the problem does not occur, such as a openssh 5.1p1 command line
    client. I can reproduce this issue using puTTy consistently. The
    trial version of SecureCRT 6.1 can paste in large amounts of data
    without causing the hang.

  3. Re: Hanging ssh sessions with openssh-5.1p1 and Solaris 8 & 10

    Installed snapshot for the test
    # ssh -v
    OpenSSH_5.1p1-snap20081105, OpenSSL 0.9.8i 15 Sep 2008

    Here is the sshd log with my "Notes" added:
    Nov 5 13:56:01 someserv sshd[960]: [ID 800047 local7.debug] debug1:
    fd 6 clearing O_NONBLOCK
    Nov 5 13:56:01 someserv sshd[960]: [ID 800047 local7.debug] debug1:
    Forked child 1094.
    Nov 5 13:56:01 someserv sshd[960]: [ID 800047 local7.debug] debug3:
    send_rexec_state: entering fd = 11 config len 214
    Nov 5 13:56:01 someserv sshd[960]: [ID 800047 local7.debug] debug3:
    ssh_msg_send: type 0
    Nov 5 13:56:01 someserv sshd[960]: [ID 800047 local7.debug] debug3:
    send_rexec_state: done
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug1:
    rexec start in 6 out 6 newsock 6 pipe 8 sock 11
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug1:
    inetd sockets after dupping: 5, 5
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.info]
    Connection from 10.10.18.23 port 2266
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug1:
    Client protocol version 1.99; client software version 3.2.9 SSH Secure
    Shell for
    Windows
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug1:
    no match: 3.2.9 SSH Secure Shell for Windows
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug1:
    Enabling compatibility mode for protocol 2.0
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug1:
    Local version string SSH-2.0-OpenSSH_5.1
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug2:
    fd 5 setting O_NONBLOCK
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug2:
    Network child is on pid 1095
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    preauth child monitor started
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_request_receive entering
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    monitor_read: checking request 4
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_answer_sign
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_answer_sign: signature 7f718(55)
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_request_send entering: type 5
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug2:
    monitor_read: 4 used once, disabling now
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_request_receive entering
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    monitor_read: checking request 6
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_answer_pwnamallow
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    Trying to reverse map address 10.10.18.23.
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug2:
    parse_server_config: config reprocess config len 214
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    auth_shadow_acctexpired: today 14188 sp_expire -1 days left -14189
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    account expiration disabled
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_request_send entering: type 7
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug2:
    monitor_read: 6 used once, disabling now
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_request_receive entering
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    monitor_read: checking request 3
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_answer_authserv: service=ssh-connection, style=
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug2:
    monitor_read: 3 used once, disabling now
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_request_receive entering
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    monitor_read: checking request 10
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_answer_authpassword: sending result 0
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_request_send entering: type 11
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.info] Failed
    none for sshuser from 10.10.18.23 port 2266 ssh2
    Nov 5 13:56:01 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_request_receive entering
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    monitor_read: checking request 10
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    auth_shadow_pwexpired: today 14188 sp_lstchg 13934 sp_max -1
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    password expiration disabled
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_answer_authpassword: sending result 1
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_request_send entering: type 11
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.info] Accepted
    password for sshuser from 10.10.18.23 port 2266 ssh2
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug1:
    monitor_child_preauth: sshuser has been authenticated by privileged
    process
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_get_keystate: Waiting for new keys
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_request_receive_expect entering: type 24
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_request_receive entering
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_newkeys_from_blob: 89648(118)
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug2:
    mac_setup: found hmac-md5
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_get_keystate: Waiting for second key
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_newkeys_from_blob: 89648(118)
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug2:
    mac_setup: found hmac-md5
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_get_keystate: Getting compression state
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_get_keystate: Getting Network I/O buffers
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_share_sync: Share sync
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_share_sync: Share sync end
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.info] User
    child is on pid 1096
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_request_receive entering
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug1:
    permanently_set_uid: 100/1
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug2:
    set_newkeys: mode 0
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug2:
    set_newkeys: mode 1
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug1:
    Entering interactive session for SSH2.
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug2:
    fd 4 setting O_NONBLOCK
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug2:
    fd 6 setting O_NONBLOCK
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug1:
    server_init_dispatch_20
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug3:
    Received SSH2_MSG_IGNORE
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug1:
    server_input_channel_open: ctype session rchan 0 win 10000 max 512
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug1:
    input_session_request
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug1:
    channel 0: new [server-session]
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug2:
    session_new: allocate (allocated 0 max 10)
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug3:
    session_unused: session id 0 unused
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug1:
    session_new: session 0
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug1:
    session_open: channel 0
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug1:
    session_open: session 0: link with channel 0
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug1:
    server_input_channel_open: confirm session
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug3:
    Received SSH2_MSG_IGNORE
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug1:
    server_input_channel_req: channel 0 request pty-req reply 0
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug1:
    session_by_channel: session 0 channel 0
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug1:
    session_input_channel_req: session 0 req pty-req
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug1:
    Allocating pty.
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug3:
    mm_request_send entering: type 25
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug3:
    mm_pty_allocate: waiting for MONITOR_ANS_PTY
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    monitor_read: checking request 25
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug3:
    mm_request_receive_expect entering: type 26
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_answer_pty entering
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug3:
    mm_request_receive entering
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug2:
    session_new: allocate (allocated 0 max 10)
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    session_unused: session id 0 unused
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug1:
    session_new: session 0
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_request_send entering: type 26
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_answer_pty: tty /dev/pts/2 ptyfd 4
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug1:
    session_pty_req: session 0 alloc /dev/pts/2
    Nov 5 13:56:02 someserv sshd[1094]: [ID 800047 local7.debug] debug3:
    mm_request_receive entering
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug3:
    Received SSH2_MSG_IGNORE
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug1:
    server_input_channel_req: channel 0 request shell reply 1
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug1:
    session_by_channel: session 0 channel 0
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug1:
    session_input_channel_req: session 0 req shell
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug2:
    fd 5 setting TCP_NODELAY
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug2:
    channel 0: rfd 10 isatty
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug2:
    fd 10 setting O_NONBLOCK
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug3:
    fd 8 is O_NONBLOCK
    Nov 5 13:56:02 someserv sshd[1098]: [ID 800047 local7.debug] debug1:
    Setting controlling tty using TIOCSCTTY.
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug3:
    Received SSH2_MSG_IGNORE
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug1:
    server_input_channel_req: channel 0 request window-change reply 0
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug1:
    session_by_channel: session 0 channel 0
    Nov 5 13:56:02 someserv sshd[1096]: [ID 800047 local7.debug] debug1:
    session_input_channel_req: session 0 req window-change
    Nov 5 13:56:02 someserv sshd[1098]: [ID 800047 local7.debug] debug3:
    channel 0: close_fds r -1 w -1 e -1 c -1
    Note: ogin complete at this point
    Note: then I paste a large buffer
    Nov 5 13:56:27 someserv sshd[1096]: [ID 800047 local7.debug] debug3:
    Received SSH2_MSG_IGNORE
    Note: client is hung, no new output shown on client side, only one log
    msg appeared, shown above

+ Reply to Thread