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>
