Key exchange dead time (3 minutes or more) between client's request and server's reply - SSH

This is a discussion on Key exchange dead time (3 minutes or more) between client's request and server's reply - SSH ; I'm baffled by what is consistently a 3 minute or longer delay between my ssh client sending SSH2_MSG_KEXINIT and the ssh server responding to this request. Here's some debug output: OpenSSH_4.2p1, OpenSSL 0.9.8a 11 Oct 2005 debug1: Reading configuration data ...

+ Reply to Thread
Results 1 to 2 of 2

Thread: Key exchange dead time (3 minutes or more) between client's request and server's reply

  1. Key exchange dead time (3 minutes or more) between client's request and server's reply

    I'm baffled by what is consistently a 3 minute or longer delay between
    my ssh client sending SSH2_MSG_KEXINIT and the ssh server responding to
    this request. Here's some debug output:



    OpenSSH_4.2p1, OpenSSL 0.9.8a 11 Oct 2005
    debug1: Reading configuration data /usr/local/etc/ssh_config
    debug2: ssh_connect: needpriv 0
    debug1: Connecting to sqa-cm-bb [10.1.253.129] port 22.
    debug1: Connection established.
    debug1: identity file /export/home0/hagiwara/.ssh/identity type -1
    debug1: identity file /export/home0/hagiwara/.ssh/id_rsa type -1
    debug1: identity file /export/home0/hagiwara/.ssh/id_dsa type -1
    debug1: Remote protocol version 2.0, remote software version
    Sun_SSH_1.1
    debug1: no match: Sun_SSH_1.1
    debug1: Enabling compatibility mode for protocol 2.0
    debug1: Local version string SSH-2.0-OpenSSH_4.2
    debug2: fd 4 setting O_NONBLOCK
    debug1: SSH2_MSG_KEXINIT sent
    #### COMMENT: THREE MINUTE DELAY OCCURS HERE ########
    debug1: SSH2_MSG_KEXINIT received
    debug2: kex_parse_kexinit:
    diffie-hellman-group-exchange-sha1,diffie-hellman-gro

    up14-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,arcfour1

    28,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-c

    tr,aes192-ctr,aes256-ctr
    debug2: kex_parse_kexinit:
    aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour1

    28,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-c

    tr,aes192-ctr,aes256-ctr
    debug2: kex_parse_kexinit:
    hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@open

    ssh.com,hmac-sha1-96,hmac-md5-96
    debug2: kex_parse_kexinit:
    hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@open

    ssh.com,hmac-sha1-96,hmac-md5-96



    I believe I have ruled out any sort of DNS and/or reverse DNS problem,
    as I enabled all query logging on both the client and server's DNS
    resolver and I observe *no* DNS queries coming from either the ssh
    client or ssh server during, or immediately before and after, the 3
    minute delay.

    FWIW, the server resides on a solaris 10 non-global zone. But I've
    observed the same problem when ssh'ing to the other zones on this
    machine, including the global zone.

    Not sure what clue this might provide, but I also observe the same
    delay if I start from the ssh server and do "ssh localhost" or "ssh
    127.0.0.1" - so even coming from itself, the sshd is slow to respond to
    key exchange requests. Here is ssh debug output for this session:



    releng@sqa-cm-bb ~ $ ssh -vvv releng@localhost
    Sun_SSH_1.1, SSH protocols 1.5/2.0, OpenSSL 0x0090704f
    debug1: Reading configuration data /etc/ssh/ssh_config
    debug1: Rhosts Authentication disabled, originating port will not be
    trusted.
    debug1: ssh_connect: needpriv 0
    debug1: Connecting to localhost [127.0.0.1] port 22.
    debug1: Connection established.
    debug1: identity file /home/releng/.ssh/identity type -1
    debug1: identity file /home/releng/.ssh/id_rsa type -1
    debug1: identity file /home/releng/.ssh/id_dsa type -1
    debug1: Remote protocol version 2.0, remote software version
    Sun_SSH_1.1
    debug1: no match: Sun_SSH_1.1
    debug1: Enabling compatibility mode for protocol 2.0
    debug1: Local version string SSH-2.0-Sun_SSH_1.1
    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-ctr,aes128-cbc,arcfour,3des-cbc,blowfish-cbc
    debug2: kex_parse_kexinit:
    aes128-ctr,aes128-cbc,arcfour,3des-cbc,blowfish-cbc
    debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-sha1-96,hmac-md5-96
    debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-sha1-96,hmac-md5-96
    debug2: kex_parse_kexinit: none,zlib
    debug2: kex_parse_kexinit: none,zlib
    debug2: kex_parse_kexinit: i-default
    debug2: kex_parse_kexinit: i-default
    debug2: kex_parse_kexinit: first_kex_follows 0
    debug2: kex_parse_kexinit: reserved 0
    debug1: Failed to acquire GSS-API credentials for any mechanisms (No
    credentials were supplied, or the credentials were unavailable or
    inaccessible
    Unknown code 0
    )
    debug1: SSH2_MSG_KEXINIT sent
    debug3: kex_reset_dispatch -- should we dispatch_set(KEXINIT) here? 0
    && !0
    #### COMMENT: THREE MINUTE DELAY OCCURS HERE ########
    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-ctr,aes128-cbc,arcfour,3des-cbc,blowfish-cbc
    debug2: kex_parse_kexinit:
    aes128-ctr,aes128-cbc,arcfour,3des-cbc,blowfish-cbc
    debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-sha1-96,hmac-md5-96
    debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-sha1-96,hmac-md5-96
    debug2: kex_parse_kexinit: none,zlib
    debug2: kex_parse_kexinit: none,zlib
    debug2: kex_parse_kexinit: i-default
    debug2: kex_parse_kexinit: i-default
    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-rsa,ssh-dss
    debug2: kex_parse_kexinit:
    aes128-ctr,aes128-cbc,arcfour,3des-cbc,blowfish-cbc
    debug2: kex_parse_kexinit:
    aes128-ctr,aes128-cbc,arcfour,3des-cbc,blowfish-cbc
    debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-sha1-96,hmac-md5-96
    debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-sha1-96,hmac-md5-96
    debug2: kex_parse_kexinit: none,zlib
    debug2: kex_parse_kexinit: none,zlib



    -Bob
    Andover, MA


  2. Re: Key exchange dead time (3 minutes or more) between client's request and server's reply


    Found the culprit! A process on one of the other Solaris zones had
    created 1.5GB of log files in /tmp, reducing the amount of available
    swap space for all zones. As a result, all zones were thrashing the
    swap space and causing CPU demand to skyrocket.

    Stopped the offending process and removed the 1.5GB log files.
    Instantly ssh logins became several orders of magnitude more
    responsive.

    -Bob

    On Jan 4, 2:09 pm, tsr...@gmail.com wrote:
    > I'm baffled by what is consistently a 3 minute or longer delay between
    > my ssh client sending SSH2_MSG_KEXINIT and the ssh server responding to
    > this request. Here's some debug output:
    >
    > OpenSSH_4.2p1, OpenSSL 0.9.8a 11 Oct 2005
    > debug1: Reading configuration data /usr/local/etc/ssh_config
    > debug2: ssh_connect: needpriv 0
    > debug1: Connecting to sqa-cm-bb [10.1.253.129] port 22.
    > debug1: Connection established.
    > debug1: identity file /export/home0/hagiwara/.ssh/identity type -1
    > debug1: identity file /export/home0/hagiwara/.ssh/id_rsa type -1
    > debug1: identity file /export/home0/hagiwara/.ssh/id_dsa type -1
    > debug1: Remote protocol version 2.0, remote software version
    > Sun_SSH_1.1
    > debug1: no match: Sun_SSH_1.1
    > debug1: Enabling compatibility mode for protocol 2.0
    > debug1: Local version string SSH-2.0-OpenSSH_4.2
    > debug2: fd 4 setting O_NONBLOCK
    > debug1: SSH2_MSG_KEXINIT sent
    > #### COMMENT: THREE MINUTE DELAY OCCURS HERE ########
    > debug1: SSH2_MSG_KEXINIT received
    > debug2: kex_parse_kexinit:
    > diffie-hellman-group-exchange-sha1,diffie-hellman-gro
    >
    > up14-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,arcfour1
    >
    > 28,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-...@lysator.liu.se,aes128-c
    >
    > tr,aes192-ctr,aes256-ctr
    > debug2: kex_parse_kexinit:
    > aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour1
    >
    > 28,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-...@lysator.liu.se,aes128-c
    >
    > tr,aes192-ctr,aes256-ctr
    > debug2: kex_parse_kexinit:
    > hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@open
    >
    > ssh.com,hmac-sha1-96,hmac-md5-96
    > debug2: kex_parse_kexinit:
    > hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@open
    >
    > ssh.com,hmac-sha1-96,hmac-md5-96
    >
    > I believe I have ruled out any sort of DNS and/or reverse DNS problem,
    > as I enabled all query logging on both the client and server's DNS
    > resolver and I observe *no* DNS queries coming from either the ssh
    > client or ssh server during, or immediately before and after, the 3
    > minute delay.
    >
    > FWIW, the server resides on a solaris 10 non-global zone. But I've
    > observed the same problem when ssh'ing to the other zones on this
    > machine, including the global zone.
    >
    > Not sure what clue this might provide, but I also observe the same
    > delay if I start from the ssh server and do "ssh localhost" or "ssh
    > 127.0.0.1" - so even coming from itself, the sshd is slow to respond to
    > key exchange requests. Here is ssh debug output for this session:
    >
    > releng@sqa-cm-bb ~ $ ssh -vvv releng@localhost
    > Sun_SSH_1.1, SSH protocols 1.5/2.0, OpenSSL 0x0090704f
    > debug1: Reading configuration data /etc/ssh/ssh_config
    > debug1: Rhosts Authentication disabled, originating port will not be
    > trusted.
    > debug1: ssh_connect: needpriv 0
    > debug1: Connecting to localhost [127.0.0.1] port 22.
    > debug1: Connection established.
    > debug1: identity file /home/releng/.ssh/identity type -1
    > debug1: identity file /home/releng/.ssh/id_rsa type -1
    > debug1: identity file /home/releng/.ssh/id_dsa type -1
    > debug1: Remote protocol version 2.0, remote software version
    > Sun_SSH_1.1
    > debug1: no match: Sun_SSH_1.1
    > debug1: Enabling compatibility mode for protocol 2.0
    > debug1: Local version string SSH-2.0-Sun_SSH_1.1
    > 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-ctr,aes128-cbc,arcfour,3des-cbc,blowfish-cbc
    > debug2: kex_parse_kexinit:
    > aes128-ctr,aes128-cbc,arcfour,3des-cbc,blowfish-cbc
    > debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-sha1-96,hmac-md5-96
    > debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-sha1-96,hmac-md5-96
    > debug2: kex_parse_kexinit: none,zlib
    > debug2: kex_parse_kexinit: none,zlib
    > debug2: kex_parse_kexinit: i-default
    > debug2: kex_parse_kexinit: i-default
    > debug2: kex_parse_kexinit: first_kex_follows 0
    > debug2: kex_parse_kexinit: reserved 0
    > debug1: Failed to acquire GSS-API credentials for any mechanisms (No
    > credentials were supplied, or the credentials were unavailable or
    > inaccessible
    > Unknown code 0
    > )
    > debug1: SSH2_MSG_KEXINIT sent
    > debug3: kex_reset_dispatch -- should we dispatch_set(KEXINIT) here? 0
    > && !0
    > #### COMMENT: THREE MINUTE DELAY OCCURS HERE ########
    > 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-ctr,aes128-cbc,arcfour,3des-cbc,blowfish-cbc
    > debug2: kex_parse_kexinit:
    > aes128-ctr,aes128-cbc,arcfour,3des-cbc,blowfish-cbc
    > debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-sha1-96,hmac-md5-96
    > debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-sha1-96,hmac-md5-96
    > debug2: kex_parse_kexinit: none,zlib
    > debug2: kex_parse_kexinit: none,zlib
    > debug2: kex_parse_kexinit: i-default
    > debug2: kex_parse_kexinit: i-default
    > 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-rsa,ssh-dss
    > debug2: kex_parse_kexinit:
    > aes128-ctr,aes128-cbc,arcfour,3des-cbc,blowfish-cbc
    > debug2: kex_parse_kexinit:
    > aes128-ctr,aes128-cbc,arcfour,3des-cbc,blowfish-cbc
    > debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-sha1-96,hmac-md5-96
    > debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-sha1-96,hmac-md5-96
    > debug2: kex_parse_kexinit: none,zlib
    > debug2: kex_parse_kexinit: none,zlib
    >
    > -Bob
    > Andover, MA



+ Reply to Thread