Gentoo Archives: gentoo-user

From: Michael Sullivan <michael@××××××××××××.com>
To: gentoo-user@l.g.o
Subject: Re: [gentoo-user] SSHd: Permission denied (publickey,keyboard-interactive).
Date: Fri, 12 Sep 2008 12:07:40
Message-Id: 1221221250.15782.63.camel@camille.espersunited.com
In Reply to: Re: [gentoo-user] SSHd: Permission denied (publickey,keyboard-interactive). by Eric Martin
1 On Fri, 2008-09-12 at 06:58 -0400, Eric Martin wrote:
2 > Michael Sullivan wrote:
3 > > On Fri, 2008-09-12 at 15:27 +0930, Iain Buchanan wrote:
4 > >> Michael Sullivan wrote:
5 > >>> I hooked up my old server box today so that I could update the software,
6 > >>> only to find that I could not ssh over to it:
7 > >>>
8 > >>> michael@camille ~ $ ssh bullet
9 > >>> Permission denied (publickey,keyboard-interactive).
10 > >>>
11 > >>> There were no 'official' logs, but a website I found on google suggested
12 > >>> running
13 > >>>
14 > >>> /usr/sbin/sshd -ddd -p 2202
15 > >>>
16 > >>> and then trying to shell over with
17 > >>>
18 > >>> ssh -p 2202<boxname>
19 > >>>
20 > >>> Here's the output. I piped it to a file:
21 > >> [snip]
22 > >>
23 > >>> I tried upgrading PAM and rebooting, but it didn't solve the problem.
24 > >>> I'm running pam-1.0.1, if that matters...
25 > >> what problem? you haven't actually said what is / isn't working! What's
26 > >> the output from the client when you try and ssh in with the command "ssh
27 > >> -p 2202 <boxname>"?
28 > >>
29 > >
30 > > I thought I was pretty clear on that, but here it is again:
31 > >
32 > > michael@camille ~ $ ssh -p 2202 bullet
33 > > Permission denied (publickey,keyboard-interactive).
34 > >
35 > > As you can see, I'm still locked out.
36 > >
37 > >
38 > try
39 >
40 > # ssh -p 2202 -vv bullet
41 >
42 > or
43 >
44 > #ssh -vv bullet
45 >
46 > as that will give you debug info from the client side of the connection.
47 > Is it safe to assume that you logged into it via the console to start
48 > SSHd on 2202? Also, does your user exist on the box? It sounds like
49 > 'no', especially when btmp is involved.
50 >
51
52 Yes I logged onto the console. I also logged on with michael on bullet
53 and it let me in, but I could not ssh to 127.0.0.1
54
55 Here's some more logging from unsuccessful attempts.
56 michael@camille ~ $ cat sshd.log
57 debug2: load_server_config: filename /etc/ssh/sshd_config
58 debug2: load_server_config: done config len = 237
59 debug2: parse_server_config: config /etc/ssh/sshd_config len 237
60 debug3: /etc/ssh/sshd_config:21 setting Protocol 2
61 debug3: /etc/ssh/sshd_config:60 setting PasswordAuthentication no
62 debug3: /etc/ssh/sshd_config:87 setting UsePAM yes
63 debug3: /etc/ssh/sshd_config:91 setting X11Forwarding yes
64 debug3: /etc/ssh/sshd_config:127 setting Subsystem
65 sftp /usr/lib/misc/sftp-server
66 debug1: sshd version OpenSSH_4.7p1
67 debug3: Not a RSA1 key file /etc/ssh/ssh_host_rsa_key.
68 debug1: read PEM private key done: type RSA
69 debug1: private host key: #0 type 1 RSA
70 debug3: Not a RSA1 key file /etc/ssh/ssh_host_dsa_key.
71 debug1: read PEM private key done: type DSA
72 debug1: private host key: #1 type 2 DSA
73 debug1: rexec_argv[0]='/usr/sbin/sshd'
74 debug1: rexec_argv[1]='-ddd'
75 debug1: rexec_argv[2]='-p'
76 debug1: rexec_argv[3]='2202'
77 debug2: fd 3 setting O_NONBLOCK
78 debug1: Bind to port 2202 on 0.0.0.0.
79 Server listening on 0.0.0.0 port 2202.
80 socket: Address family not supported by protocol
81 debug3: fd 4 is not O_NONBLOCK
82 debug1: Server will not fork when running in debugging mode.
83 debug3: send_rexec_state: entering fd = 7 config len 237
84 debug3: ssh_msg_send: type 0
85 debug3: send_rexec_state: done
86 debug1: rexec start in 4 out 4 newsock 4 pipe -1 sock 7
87 debug1: inetd sockets after dupping: 3, 3
88 Connection from 192.168.1.2 port 43258
89 debug1: Client protocol version 2.0; client software version OpenSSH_4.7
90 debug1: match: OpenSSH_4.7 pat OpenSSH*
91 debug1: Enabling compatibility mode for protocol 2.0
92 debug1: Local version string SSH-2.0-OpenSSH_4.7
93 debug2: fd 3 setting O_NONBLOCK
94 debug3: privsep user:group 22:22
95 debug1: permanently_set_uid: 22/22
96 debug1: list_hostkey_types: ssh-rsa,ssh-dss
97 debug1: SSH2_MSG_KEXINIT sent
98 debug1: SSH2_MSG_KEXINIT received
99 debug2: kex_parse_kexinit:
100 diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
101 debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
102 debug2: kex_parse_kexinit:
103 aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@×××××××××××.se,aes128-ctr,aes192-ctr,aes256-ctr
104 debug2: kex_parse_kexinit:
105 aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@×××××××××××.se,aes128-ctr,aes192-ctr,aes256-ctr
106 debug2: kex_parse_kexinit:
107 hmac-md5,hmac-sha1,umac-64@×××××××.com,hmac-ripemd160,hmac-ripemd160@×××××××.com,hmac-sha1-96,hmac-md5-96
108 debug2: kex_parse_kexinit:
109 hmac-md5,hmac-sha1,umac-64@×××××××.com,hmac-ripemd160,hmac-ripemd160@×××××××.com,hmac-sha1-96,hmac-md5-96
110 debug2: kex_parse_kexinit: none,zlib@×××××××.com
111 debug2: kex_parse_kexinit: none,zlib@×××××××.com
112 debug2: kex_parse_kexinit:
113 debug2: kex_parse_kexinit:
114 debug2: kex_parse_kexinit: first_kex_follows 0
115 debug2: kex_parse_kexinit: reserved 0
116 debug2: kex_parse_kexinit:
117 diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
118 debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
119 debug2: kex_parse_kexinit:
120 aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@×××××××××××.se,aes128-ctr,aes192-ctr,aes256-ctr
121 debug2: kex_parse_kexinit:
122 aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@×××××××××××.se,aes128-ctr,aes192-ctr,aes256-ctr
123 debug2: kex_parse_kexinit:
124 hmac-md5,hmac-sha1,umac-64@×××××××.com,hmac-ripemd160,hmac-ripemd160@×××××××.com,hmac-sha1-96,hmac-md5-96
125 debug2: kex_parse_kexinit:
126 hmac-md5,hmac-sha1,umac-64@×××××××.com,hmac-ripemd160,hmac-ripemd160@×××××××.com,hmac-sha1-96,hmac-md5-96
127 debug2: kex_parse_kexinit: zlib@×××××××.com,zlib,none
128 debug2: kex_parse_kexinit: zlib@×××××××.com,zlib,none
129 debug2: kex_parse_kexinit:
130 debug2: kex_parse_kexinit:
131 debug2: kex_parse_kexinit: first_kex_follows 0
132 debug2: kex_parse_kexinit: reserved 0
133 debug2: mac_setup: found hmac-md5
134 debug1: kex: client->server aes128-cbc hmac-md5 zlib@×××××××.com
135 debug2: mac_setup: found hmac-md5
136 debug1: kex: server->client aes128-cbc hmac-md5 zlib@×××××××.com
137 debug1: SSH2_MSG_KEX_DH_GEX_REQUEST received
138 debug3: mm_request_send entering: type 0
139 debug3: mm_choose_dh: waiting for MONITOR_ANS_MODULI
140 debug3: mm_request_receive_expect entering: type 1
141 debug3: mm_request_receive entering
142 debug2: Network child is on pid 17283
143 debug3: preauth child monitor started
144 debug3: mm_request_receive entering
145 debug3: monitor_read: checking request 0
146 debug3: mm_answer_moduli: got parameters: 1024 1024 8192
147 debug3: mm_request_send entering: type 1
148 debug3: mm_choose_dh: remaining 0
149 debug1: SSH2_MSG_KEX_DH_GEX_GROUP sent
150 debug2: dh_gen_key: priv key bits set: 127/256
151 debug2: bits set: 515/1024
152 debug1: expecting SSH2_MSG_KEX_DH_GEX_INIT
153 debug2: bits set: 513/1024
154 debug2: monitor_read: 0 used once, disabling now
155 debug3: mm_request_receive entering
156 debug3: mm_key_sign entering
157 debug3: mm_request_send entering: type 4
158 debug3: mm_key_sign: waiting for MONITOR_ANS_SIGN
159 debug3: mm_request_receive_expect entering: type 5
160 debug3: mm_request_receive entering
161 debug3: monitor_read: checking request 4
162 debug3: mm_answer_sign
163 debug3: mm_answer_sign: signature 0x80aa138(143)
164 debug3: mm_request_send entering: type 5
165 debug1: SSH2_MSG_KEX_DH_GEX_REPLY sent
166 debug2: kex_derive_keys
167 debug2: set_newkeys: mode 1
168 debug1: SSH2_MSG_NEWKEYS sent
169 debug1: expecting SSH2_MSG_NEWKEYS
170 debug2: monitor_read: 4 used once, disabling now
171 debug3: mm_request_receive entering
172 debug2: set_newkeys: mode 0
173 debug1: SSH2_MSG_NEWKEYS received
174 debug1: KEX done
175 debug1: userauth-request for user michael service ssh-connection method
176 none
177 debug1: attempt 0 failures 0
178 debug3: mm_getpwnamallow entering
179 debug3: mm_request_send entering: type 6
180 debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM
181 debug3: mm_request_receive_expect entering: type 7
182 debug3: mm_request_receive entering
183 debug3: monitor_read: checking request 6
184 debug3: mm_answer_pwnamallow
185 debug3: Trying to reverse map address 192.168.1.2.
186 debug2: parse_server_config: config reprocess config len 237
187 debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1
188 debug3: mm_request_send entering: type 7
189 debug2: input_userauth_request: setting up authctxt for michael
190 debug3: mm_start_pam entering
191 debug3: mm_request_send entering: type 47
192 debug3: mm_inform_authserv entering
193 debug3: mm_request_send entering: type 3
194 debug2: input_userauth_request: try method none
195 debug1: userauth-request for user michael service ssh-connection method
196 keyboard-interactive
197 debug1: attempt 1 failures 1
198 debug2: input_userauth_request: try method keyboard-interactive
199 debug1: keyboard-interactive devs
200 debug1: auth2_challenge: user=michael devs=
201 debug1: kbdint_alloc: devices 'pam'
202 debug2: auth2_challenge_start: devices pam
203 debug2: kbdint_next_device: devices <empty>
204 debug1: auth2_challenge_start: trying authentication method 'pam'
205 debug3: mm_sshpam_init_ctx
206 debug3: mm_request_send entering: type 50
207 debug3: mm_sshpam_init_ctx: waiting for MONITOR_ANS_PAM_INIT_CTX
208 debug3: mm_request_receive_expect entering: type 51
209 debug3: mm_request_receive entering
210 debug2: monitor_read: 6 used once, disabling now
211 debug3: mm_request_receive entering
212 debug3: monitor_read: checking request 47
213 debug1: PAM: initializing for "michael"
214 debug1: PAM: setting PAM_RHOST to "192.168.1.2"
215 debug1: PAM: setting PAM_TTY to "ssh"
216 debug2: monitor_read: 47 used once, disabling now
217 debug3: mm_request_receive entering
218 debug3: monitor_read: checking request 3
219 debug3: mm_answer_authserv: service=ssh-connection, style=
220 debug2: monitor_read: 3 used once, disabling now
221 debug3: mm_request_receive entering
222 debug3: monitor_read: checking request 50
223 debug3: mm_answer_pam_init_ctx
224 debug3: PAM: sshpam_init_ctx entering
225 debug3: ssh_msg_send: type 7
226 debug3: mm_request_send entering: type 51
227 debug3: mm_sshpam_query
228 debug3: mm_request_send entering: type 52
229 debug3: mm_sshpam_query: waiting for MONITOR_ANS_PAM_QUERY
230 debug3: mm_request_receive_expect entering: type 53
231 debug3: mm_request_receive entering
232 debug3: mm_request_receive entering
233 debug3: monitor_read: checking request 52
234 debug3: mm_answer_pam_query
235 debug3: PAM: sshpam_query entering
236 debug3: ssh_msg_recv entering
237 debug3: PAM: Authentication failure
238 PAM: Authentication failure for michael from 192.168.1.2
239 debug3: mm_request_send entering: type 53
240 debug3: mm_sshpam_query: pam_query returned -1
241 debug3: mm_sshpam_free_ctx
242 debug3: mm_request_send entering: type 56
243 debug3: mm_sshpam_free_ctx: waiting for MONITOR_ANS_PAM_FREE_CTX
244 debug3: mm_request_receive_expect entering: type 57
245 debug3: mm_request_receive entering
246 debug3: mm_request_receive entering
247 debug3: monitor_read: checking request 56
248 debug3: mm_answer_pam_free_ctx
249 debug3: PAM: sshpam_free_ctx entering
250 debug3: PAM: sshpam_thread_cleanup entering
251 debug3: mm_request_send entering: type 57
252 debug2: monitor_read: 56 used once, disabling now
253 Failed keyboard-interactive/pam for michael from 192.168.1.2 port 43258
254 ssh2
255 Connection closed by 192.168.1.2
256 debug1: do_cleanup
257 debug1: PAM: cleanup
258 debug3: PAM: sshpam_thread_cleanup entering
259 debug1: Unable to open the btmp file /var/log/btmp: No such file or
260 directory
261 debug3: mm_request_receive entering
262 debug1: do_cleanup
263 debug1: PAM: cleanup
264 debug3: PAM: sshpam_thread_cleanup entering
265
266 michael@camille ~ $ ssh -vv -p 2202 bullet
267 OpenSSH_4.7p1, OpenSSL 0.9.8g 19 Oct 2007
268 debug1: Reading configuration data /etc/ssh/ssh_config
269 debug2: ssh_connect: needpriv 0
270 debug1: Connecting to bullet [192.168.1.5] port 2202.
271 debug1: Connection established.
272 debug1: identity file /home/michael/.ssh/identity type -1
273 debug1: identity file /home/michael/.ssh/id_rsa type -1
274 debug1: identity file /home/michael/.ssh/id_dsa type -1
275 debug1: Remote protocol version 2.0, remote software version OpenSSH_4.7
276 debug1: match: OpenSSH_4.7 pat OpenSSH*
277 debug1: Enabling compatibility mode for protocol 2.0
278 debug1: Local version string SSH-2.0-OpenSSH_4.7
279 debug2: fd 3 setting O_NONBLOCK
280 debug1: SSH2_MSG_KEXINIT sent
281 debug1: SSH2_MSG_KEXINIT received
282 debug2: kex_parse_kexinit:
283 diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
284 debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
285 debug2: kex_parse_kexinit:
286 aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@×××××××××××.se,aes128-ctr,aes192-ctr,aes256-ctr
287 debug2: kex_parse_kexinit:
288 aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@×××××××××××.se,aes128-ctr,aes192-ctr,aes256-ctr
289 debug2: kex_parse_kexinit:
290 hmac-md5,hmac-sha1,umac-64@×××××××.com,hmac-ripemd160,hmac-ripemd160@×××××××.com,hmac-sha1-96,hmac-md5-96
291 debug2: kex_parse_kexinit:
292 hmac-md5,hmac-sha1,umac-64@×××××××.com,hmac-ripemd160,hmac-ripemd160@×××××××.com,hmac-sha1-96,hmac-md5-96
293 debug2: kex_parse_kexinit: zlib@×××××××.com,zlib,none
294 debug2: kex_parse_kexinit: zlib@×××××××.com,zlib,none
295 debug2: kex_parse_kexinit:
296 debug2: kex_parse_kexinit:
297 debug2: kex_parse_kexinit: first_kex_follows 0
298 debug2: kex_parse_kexinit: reserved 0
299 debug2: kex_parse_kexinit:
300 diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
301 debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
302 debug2: kex_parse_kexinit:
303 aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@×××××××××××.se,aes128-ctr,aes192-ctr,aes256-ctr
304 debug2: kex_parse_kexinit:
305 aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@×××××××××××.se,aes128-ctr,aes192-ctr,aes256-ctr
306 debug2: kex_parse_kexinit:
307 hmac-md5,hmac-sha1,umac-64@×××××××.com,hmac-ripemd160,hmac-ripemd160@×××××××.com,hmac-sha1-96,hmac-md5-96
308 debug2: kex_parse_kexinit:
309 hmac-md5,hmac-sha1,umac-64@×××××××.com,hmac-ripemd160,hmac-ripemd160@×××××××.com,hmac-sha1-96,hmac-md5-96
310 debug2: kex_parse_kexinit: none,zlib@×××××××.com
311 debug2: kex_parse_kexinit: none,zlib@×××××××.com
312 debug2: kex_parse_kexinit:
313 debug2: kex_parse_kexinit:
314 debug2: kex_parse_kexinit: first_kex_follows 0
315 debug2: kex_parse_kexinit: reserved 0
316 debug2: mac_setup: found hmac-md5
317 debug1: kex: server->client aes128-cbc hmac-md5 zlib@×××××××.com
318 debug2: mac_setup: found hmac-md5
319 debug1: kex: client->server aes128-cbc hmac-md5 zlib@×××××××.com
320 debug1: SSH2_MSG_KEX_DH_GEX_REQUEST(1024<1024<8192) sent
321 debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
322 debug2: dh_gen_key: priv key bits set: 119/256
323 debug2: bits set: 513/1024
324 debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
325 debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
326 debug1: checking without port identifier
327 debug1: Host 'bullet' is known and matches the RSA host key.
328 debug1: Found key in /home/michael/.ssh/known_hosts:2
329 debug1: found matching key w/out port
330 debug2: bits set: 515/1024
331 debug1: ssh_rsa_verify: signature correct
332 debug2: kex_derive_keys
333 debug2: set_newkeys: mode 1
334 debug1: SSH2_MSG_NEWKEYS sent
335 debug1: expecting SSH2_MSG_NEWKEYS
336 debug2: set_newkeys: mode 0
337 debug1: SSH2_MSG_NEWKEYS received
338 debug1: SSH2_MSG_SERVICE_REQUEST sent
339 debug2: service_accept: ssh-userauth
340 debug1: SSH2_MSG_SERVICE_ACCEPT received
341 debug2: key: /home/michael/.ssh/identity ((nil))
342 debug2: key: /home/michael/.ssh/id_rsa ((nil))
343 debug2: key: /home/michael/.ssh/id_dsa ((nil))
344 debug1: Authentications that can continue:
345 publickey,keyboard-interactive
346 debug1: Next authentication method: publickey
347 debug1: Trying private key: /home/michael/.ssh/identity
348 debug1: Trying private key: /home/michael/.ssh/id_rsa
349 debug1: Trying private key: /home/michael/.ssh/id_dsa
350 debug2: we did not send a packet, disable method
351 debug1: Next authentication method: keyboard-interactive
352 debug2: userauth_kbdint
353 debug2: we sent a keyboard-interactive packet, wait for reply
354 debug1: Authentications that can continue:
355 publickey,keyboard-interactive
356 debug2: we did not send a packet, disable method
357 debug1: No more authentication methods to try.
358 Permission denied (publickey,keyboard-interactive).
359
360 michael@camille ~ $ cat passwd.txt
361 michael:x:1000:100::/home/michael:/bin/bash