Re: Password auth turned off in OpenSSH

From: C. Linus Hicks (lhicks_at_nc.rr.com)
Date: 10/14/04

  • Next message: Darren Tucker: "Re: Password auth turned off in OpenSSH" 
    To: Darren Tucker <dtucker@zip.com.au>
Date: 14 Oct 2004 00:46:30 -0400

    On Tue, 2004-10-12 at 01:43, C. Linus Hicks wrote:
    > On Mon, 2004-10-11 at 20:48, Darren Tucker wrote:
    > > You can confirm this by turning up the debug level on sshd. You'll get
    > > a "Unrecognized authentication method name: password" from
    > > authmethod_lookup and you won't see the "try method" messages for these
    > > requests.
    >
    > Okay, thanks for the comprehensive explanation. I have set logging level
    > to debug3, restarted sshd, and re-opened the port in my firewall. I will
    > have to wait a while and see what turns up in my logs.

    Okay, so here's a typical protocol 2 connection attempt, and it does
    show the "Unrecognized authentication method name" message:

    Oct 12 07:34:16 lh2 sshd[20739]: debug1: Forked child 21690.
    Oct 12 07:34:16 lh2 sshd[21690]: Connection from 200.206.23.187 port 36463
    Oct 12 07:34:16 lh2 sshd[21690]: Did not receive identification string from 200.206.23.187
    Oct 12 07:34:16 lh2 sshd[21690]: debug1: Calling cleanup 0x8067da0(0x0)
    Oct 12 07:43:20 lh2 sshd[20739]: debug1: Forked child 21706.
    Oct 12 07:43:20 lh2 sshd[21706]: Connection from 200.206.23.187 port 52968
    Oct 12 07:43:20 lh2 sshd[21706]: debug1: Client protocol version 2.0; client software version libssh-0.1
    Oct 12 07:43:20 lh2 sshd[21706]: debug1: no match: libssh-0.1
    Oct 12 07:43:20 lh2 sshd[21706]: Enabling compatibility mode for protocol 2.0
    Oct 12 07:43:20 lh2 sshd[21706]: debug1: Local version string SSH-1.99-OpenSSH_3.1p1
    Oct 12 07:43:20 lh2 sshd[21706]: debug1: list_hostkey_types: ssh-rsa,ssh-dss
    Oct 12 07:43:20 lh2 sshd[21706]: debug1: SSH2_MSG_KEXINIT sent
    Oct 12 07:43:20 lh2 sshd[21706]: debug1: SSH2_MSG_KEXINIT received
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit: none,zlib
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit: none,zlib
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit:
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit:
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit: first_kex_follows 0
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit: reserved 0
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit: diffie-hellman-group1-sha1
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit: ssh-rsa
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit: aes128-cbc
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit: aes128-cbc
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit: hmac-sha1
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit: hmac-sha1
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit: none
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit: none
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit:
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit:
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit: first_kex_follows 0
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: kex_parse_kexinit: reserved 0
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: mac_init: found hmac-sha1
    Oct 12 07:43:20 lh2 sshd[21706]: debug1: kex: client->server aes128-cbc hmac-sha1 none
    Oct 12 07:43:20 lh2 sshd[21706]: debug2: mac_init: found hmac-sha1
    Oct 12 07:43:20 lh2 sshd[21706]: debug1: kex: server->client aes128-cbc hmac-sha1 none
    Oct 12 07:43:20 lh2 sshd[21706]: debug1: dh_gen_key: priv key bits set: 162/320
    Oct 12 07:43:20 lh2 sshd[21706]: debug1: bits set: 554/1024
    Oct 12 07:43:20 lh2 sshd[21706]: debug1: expecting SSH2_MSG_KEXDH_INIT
    Oct 12 07:43:20 lh2 sshd[21706]: debug1: bits set: 518/1024
    Oct 12 07:43:20 lh2 sshd[21706]: debug1: kex_derive_keys
    Oct 12 07:43:20 lh2 sshd[21706]: debug1: newkeys: mode 1
    Oct 12 07:43:20 lh2 sshd[21706]: debug1: SSH2_MSG_NEWKEYS sent
    Oct 12 07:43:20 lh2 sshd[21706]: debug1: waiting for SSH2_MSG_NEWKEYS
    Oct 12 07:43:20 lh2 sshd[21706]: debug1: newkeys: mode 0
    Oct 12 07:43:20 lh2 sshd[21706]: debug1: SSH2_MSG_NEWKEYS received
    Oct 12 07:43:20 lh2 sshd[21706]: debug1: KEX done
    Oct 12 07:43:21 lh2 sshd[21706]: debug1: userauth-request for user test service ssh-connection method password
    Oct 12 07:43:21 lh2 sshd[21706]: debug1: attempt 0 failures 0
    Oct 12 07:43:21 lh2 sshd[21706]: input_userauth_request: illegal user test
    Oct 12 07:43:21 lh2 sshd[21706]: debug1: Starting up PAM with username "NOUSER"
    Oct 12 07:43:21 lh2 sshd[21706]: debug3: Trying to reverse map address 200.206.23.187.
    Oct 12 07:43:21 lh2 sshd[21706]: debug1: PAM setting rhost to "200-206-23-187.interfile.com.br"
    Oct 12 07:43:21 lh2 sshd[21706]: debug2: Unrecognized authentication method name: password
    Oct 12 07:43:21 lh2 sshd[21706]: Failed password for illegal user test from 200.206.23.187 port 52968 ssh2
    Oct 12 07:43:21 lh2 sshd[21706]: Received disconnect from 200.206.23.187: 11: Bye Bye
    Oct 12 07:43:21 lh2 sshd[21706]: debug1: Calling cleanup 0x8052810(0x0)
    Oct 12 07:43:21 lh2 sshd[21706]: debug1: Calling cleanup 0x8067da0(0x0)

    Several other attempts where made in succession for other users
    including guest, admin (2 times), user, root (3 times), test (again),
    nobody, patrick (2 times), and 2 more times for root. Several hours
    later, someone tried to connect with putty. Notice that this one does
    show "Password authentication disabled" but not the "Unrecognized
    authentication method name":

    Oct 12 15:53:35 lh2 sshd[20739]: debug1: Forked child 22573.
    Oct 12 15:53:35 lh2 sshd[22573]: Connection from 207.248.47.254 port 19382
    Oct 12 15:53:35 lh2 sshd[22573]: debug1: Client protocol version 1.5; client software version PuTTY-Release-0.53b
    Oct 12 15:53:35 lh2 sshd[22573]: debug1: no match: PuTTY-Release-0.53b
    Oct 12 15:53:35 lh2 sshd[22573]: debug1: Local version string SSH-1.99-OpenSSH_3.1p1
    Oct 12 15:53:35 lh2 sshd[22573]: debug1: Sent 768 bit server key and 1024 bit host key.
    Oct 12 15:53:36 lh2 sshd[22573]: debug1: Encryption type: blowfish
    Oct 12 15:53:36 lh2 sshd[22573]: debug1: Received session key; encryption turned on.
    Oct 12 15:53:37 lh2 sshd[22573]: debug1: Installing crc compensation attack detector.
    Oct 12 15:53:37 lh2 sshd[22573]: debug1: Starting up PAM with username "oracle"
    Oct 12 15:53:37 lh2 sshd[22573]: debug3: Trying to reverse map address 207.248.47.254.
    Oct 12 15:53:37 lh2 sshd[22573]: debug1: PAM setting rhost to "cablelink47-254.intercable.net"
    Oct 12 15:53:37 lh2 sshd[22573]: debug1: Attempting authentication for oracle.
    Oct 12 15:53:38 lh2 sshd[22573]: Password authentication disabled.
    Oct 12 15:53:38 lh2 sshd[22573]: Failed password for oracle from 207.248.47.254 port 19382
    Oct 12 15:53:40 lh2 sshd[22573]: Password authentication disabled.
    Oct 12 15:53:40 lh2 sshd[22573]: Failed password for oracle from 207.248.47.254 port 19382
    Oct 12 15:53:44 lh2 sshd[22573]: Connection closed by 207.248.47.254
    Oct 12 15:53:44 lh2 sshd[22573]: debug1: Calling cleanup 0x8052810(0x0)
    Oct 12 15:53:44 lh2 sshd[22573]: debug1: Calling cleanup 0x8067da0(0x0)

    The information in my log files show that password authentication is not
    being allowed, however, I am noticing that PAM is getting started, yet
    it seems clear to me that there's no need to start it at all. Do I have
    any cause for concern over that? 

    -- 
C. Linus Hicks <lhicks@nc.rr.com>
  • Next message: Darren Tucker: "Re: Password auth turned off in OpenSSH"

    Relevant Pages

    • Re: openssh and opie challenge
      ... > varied on whether the problem is with sshd or pam). ... > Is there a way to get sshd to display the opie challenge before ... I guess you're using the "password" authentication method, ... (The second line shouldn't actually disable password authentication, ...
      (comp.security.ssh)
    • sshd keybased only, still wants shadow
      ... using key-based auth only (no passwd based auth at all). ... At debug level 3 I see that sshd still tries to read /etc/shadow, ...
      (comp.security.ssh)
    • Re: gssapi-with-mic
      ... I have even downloaded the seam-1.0.2 package. ... telnet etc but unfortunately no sshd. ... Victor Sudakov, VAS4-RIPE, VAS47-RIPN ...
      (comp.unix.solaris)
    • ssh debug
      ... I need to increase debug level of my sshd. ... Can I do this without stopping the daemon? ... can I stop and start the sshd without reboot the system? ... sshd -ddd but the the command hangs before full starting the daemon ...
      (comp.unix.sco.misc)
    • Re: ssh debug
      ... | I need to increase debug level of my sshd. ... | Can I do this without stopping the daemon? ... can I stop and start the sshd without reboot the system? ... | sshd -ddd but the the command hangs before full starting the daemon ...
      (comp.unix.sco.misc)