Ubuntu
openssh package

openssh server should warn that .ssh/authorized_keys is not accessible (causing ssh pubkey authentication to fail silently)

Bug #505301 reported by LimCore
100
This bug affects 1 person
Affects Status Importance Assigned to Milestone
portable OpenSSH
Fix Released
Unknown
openssh (Ubuntu)
Fix Released
Wishlist
Unassigned

Bug Description

Client: Ubuntu 9.10
Server: Debian Lenny

This may be a bug in ubuntu client or in debian server.

SSH pubkey was working normally.
I today tried to passwd -l one of the users. After that time I noticed ssh pubkey login stoped working.

New account was crated on server (new user) with allowed pubkeys, but he is still not working as well (even though he was never passwd -l or nothing)

ssh pubkey works to root
ssh pubkey fails to any other user, including new user. Users is in AllowUsers

grep -i root /etc/ssh/sshd_config
AllowUsers root rafal svnwork userfoo
PermitRootLogin yes

Login to root (works)

Client:
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug1: Authentications that can continue: publickey,password
debug1: Next authentication method: publickey
debug1: Offering public key: rafal1-rafal@lcwood
debug1: Authentications that can continue: publickey,password
debug1: Offering public key: lcac_rafal_2_geovoucher_vm-rafal@aclc
debug1: Authentications that can continue: publickey,password
debug1: Offering public key: rafalsvn-rafal@lcwood
debug1: Authentications that can continue: publickey,password
debug1: Offering public key: rafaladmin-rafal@lcwood
debug1: Server accepts key: pkalg ssh-rsa blen 1045

Server:
Jan 9 23:32:33 vz1947 sshd[19677]: Failed publickey for root from 83.24.63.165 port 59835 ssh2
Jan 9 23:32:33 vz1947 sshd[19677]: debug3: mm_answer_keyallowed: key 0x82bc4f0 is not allowed
Jan 9 23:32:33 vz1947 sshd[19677]: debug3: mm_request_send entering: type 22
Jan 9 23:32:33 vz1947 sshd[19677]: debug3: mm_request_receive entering
Jan 9 23:32:33 vz1947 sshd[19677]: debug3: monitor_read: checking request 21
Jan 9 23:32:33 vz1947 sshd[19677]: debug3: mm_answer_keyallowed entering
Jan 9 23:32:33 vz1947 sshd[19677]: debug3: mm_answer_keyallowed: key_from_blob: 0x82bc4f0
Jan 9 23:32:33 vz1947 sshd[19677]: debug1: Checking blacklist file /usr/share/ssh/blacklist.RSA-8192
Jan 9 23:32:33 vz1947 sshd[19677]: debug1: Checking blacklist file /etc/ssh/blacklist.RSA-8192
Jan 9 23:32:33 vz1947 sshd[19677]: debug1: temporarily_use_uid: 0/0 (e=0/0)
Jan 9 23:32:33 vz1947 sshd[19677]: debug1: trying public key file /root/.ssh/authorized_keys
Jan 9 23:32:33 vz1947 sshd[19677]: debug1: fd 4 clearing O_NONBLOCK
Jan 9 23:32:33 vz1947 sshd[19677]: debug3: secure_filename: checking '/root/.ssh'
Jan 9 23:32:33 vz1947 sshd[19677]: debug3: secure_filename: checking '/root'
Jan 9 23:32:33 vz1947 sshd[19677]: debug3: secure_filename: terminating check at '/root'
Jan 9 23:32:33 vz1947 sshd[19677]: debug1: matching key found: file /root/.ssh/authorized_keys, line 1
Jan 9 23:32:33 vz1947 sshd[19677]: Found matching RSA key: 1b:7b:5b:a5:bf:40:7c:50:48:6f:5a:9b:f5:b3:43:1b

Login to userfoo (fails). Login is done from same client console (where I have same keys in ssh-add) just a moment after doing successfully ssh root@... that did worked via pubkey.
Pubkey does not work; Normal login via password works.

Client:
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug1: Authentications that can continue: publickey,password
debug1: Next authentication method: publickey
debug1: Offering public key: rafal1-rafal@lcwood
debug1: Authentications that can continue: publickey,password
debug1: Offering public key: lcac_rafal_2_geovoucher_vm-rafal@aclc
debug1: Authentications that can continue: publickey,password
debug1: Offering public key: rafalsvn-rafal@lcwood
debug1: Authentications that can continue: publickey,password
debug1: Offering public key: rafaladmin-rafal@lcwood
debug1: Authentications that can continue: publickey,password
debug1: Trying private key: /home/rafal/.ssh/identity
debug1: Trying private key: /home/rafal/.ssh/id_rsa
debug1: Trying private key: /home/rafal/.ssh/id_dsa
debug1: Next authentication method: password

Server:
Jan 10 00:54:16 vz1947 sshd[32763]: Connection from 83.24.63.165 port 56559
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: Client protocol version 2.0; client software version OpenSSH_5.1p1 Debian-6ubuntu2
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: match: OpenSSH_5.1p1 Debian-6ubuntu2 pat OpenSSH*
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: Enabling compatibility mode for protocol 2.0
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: Local version string SSH-2.0-OpenSSH_5.1p1 Debian-5
Jan 10 00:54:16 vz1947 sshd[32763]: debug2: fd 3 setting O_NONBLOCK
Jan 10 00:54:16 vz1947 sshd[32763]: debug2: Network child is on pid 32765
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: preauth child monitor started
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_request_receive entering
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: monitor_read: checking request 0
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_answer_moduli: got parameters: 1024 1024 8192
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_request_send entering: type 1
Jan 10 00:54:16 vz1947 sshd[32763]: debug2: monitor_read: 0 used once, disabling now
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_request_receive entering
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: monitor_read: checking request 5
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_answer_sign
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_answer_sign: signature 0x8a69030(271)
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_request_send entering: type 6
Jan 10 00:54:16 vz1947 sshd[32763]: debug2: monitor_read: 5 used once, disabling now
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_request_receive entering
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: monitor_read: checking request 7
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_answer_pwnamallow
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: Trying to reverse map address 83.24.63.165.
Jan 10 00:54:16 vz1947 sshd[32763]: debug2: parse_server_config: config reprocess config len 744
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_request_send entering: type 8
Jan 10 00:54:16 vz1947 sshd[32763]: debug2: monitor_read: 7 used once, disabling now
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_request_receive entering
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: monitor_read: checking request 48
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: PAM: initializing for "userfoo"
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: PAM: setting PAM_RHOST to "dmh165.neoplus.adsl.tpnet.pl"
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: PAM: setting PAM_TTY to "ssh"
Jan 10 00:54:16 vz1947 sshd[32763]: debug2: monitor_read: 48 used once, disabling now
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_request_receive entering
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: monitor_read: checking request 3
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_answer_authserv: service=ssh-connection, style=, role=
Jan 10 00:54:16 vz1947 sshd[32763]: debug2: monitor_read: 3 used once, disabling now
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_request_receive entering
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: monitor_read: checking request 11
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_answer_authpassword: sending result 0
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_request_send entering: type 12
Jan 10 00:54:16 vz1947 sshd[32763]: Failed none for userfoo from 83.24.63.165 port 56559 ssh2
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_request_receive entering
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: monitor_read: checking request 21
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_answer_keyallowed entering
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_answer_keyallowed: key_from_blob: 0x8a6c2e0
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: Checking blacklist file /usr/share/ssh/blacklist.RSA-8192
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: Checking blacklist file /etc/ssh/blacklist.RSA-8192
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: trying public key file /home/userfoo/.ssh/authorized_keys
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: restore_uid: 0/0
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: trying public key file /home/userfoo/.ssh/authorized_keys
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: restore_uid: 0/0
Jan 10 00:54:16 vz1947 sshd[32763]: Failed publickey for userfoo from 83.24.63.165 port 56559 ssh2
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_answer_keyallowed: key 0x8a6c2e0 is not allowed
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_request_send entering: type 22
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_request_receive entering
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: monitor_read: checking request 21
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_answer_keyallowed entering
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_answer_keyallowed: key_from_blob: 0x8a6c3c0
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: Checking blacklist file /usr/share/ssh/blacklist.RSA-8192
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: Checking blacklist file /etc/ssh/blacklist.RSA-8192
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: trying public key file /home/userfoo/.ssh/authorized_keys
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: restore_uid: 0/0
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: trying public key file /home/userfoo/.ssh/authorized_keys
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: restore_uid: 0/0
Jan 10 00:54:16 vz1947 sshd[32763]: Failed publickey for userfoo from 83.24.63.165 port 56559 ssh2
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_answer_keyallowed: key 0x8a6c3c0 is not allowed
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_request_send entering: type 22
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_request_receive entering
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: monitor_read: checking request 21
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_answer_keyallowed entering
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_answer_keyallowed: key_from_blob: 0x8a6c3c0
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: Checking blacklist file /usr/share/ssh/blacklist.RSA-8192
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: Checking blacklist file /etc/ssh/blacklist.RSA-8192
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: trying public key file /home/userfoo/.ssh/authorized_keys
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: restore_uid: 0/0
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: trying public key file /home/userfoo/.ssh/authorized_keys
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: restore_uid: 0/0
Jan 10 00:54:16 vz1947 sshd[32763]: Failed publickey for userfoo from 83.24.63.165 port 56559 ssh2
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_answer_keyallowed: key 0x8a6c3c0 is not allowed
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_request_send entering: type 22
Jan 10 00:54:16 vz1947 sshd[32763]: debug3: mm_request_receive entering
Jan 10 00:54:17 vz1947 sshd[32763]: debug3: monitor_read: checking request 21
Jan 10 00:54:17 vz1947 sshd[32763]: debug3: mm_answer_keyallowed entering
Jan 10 00:54:17 vz1947 sshd[32763]: debug3: mm_answer_keyallowed: key_from_blob: 0x8a6c3c0
Jan 10 00:54:17 vz1947 sshd[32763]: debug1: Checking blacklist file /usr/share/ssh/blacklist.RSA-8192
Jan 10 00:54:17 vz1947 sshd[32763]: debug1: Checking blacklist file /etc/ssh/blacklist.RSA-8192
Jan 10 00:54:17 vz1947 sshd[32763]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
Jan 10 00:54:17 vz1947 sshd[32763]: debug1: trying public key file /home/userfoo/.ssh/authorized_keys
Jan 10 00:54:17 vz1947 sshd[32763]: debug1: restore_uid: 0/0
Jan 10 00:54:17 vz1947 sshd[32763]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
Jan 10 00:54:17 vz1947 sshd[32763]: debug1: trying public key file /home/userfoo/.ssh/authorized_keys
Jan 10 00:54:17 vz1947 sshd[32763]: debug1: restore_uid: 0/0
Jan 10 00:54:17 vz1947 sshd[32763]: Failed publickey for userfoo from 83.24.63.165 port 56559 ssh2
Jan 10 00:54:17 vz1947 sshd[32763]: debug3: mm_answer_keyallowed: key 0x8a6c3c0 is not allowed

VPS: root@vz1947(2010-01-09 23:55:02)~$ cat /root/.ssh/authorized_keys
ssh-rsa AAAAB3NzaC1yc2EAAAABIwAABAEArre0Hxv6tavCrtak9LbkbveZ4FxH7FXbcDk47h2KJIRcVGcZljEiUmlI3aobKM2XORZHeQggz5ReOqi2kzLKAfh1ILzQBKX3YzvOTnB7kX/Ed7DR1XDBwvvxfcXhwv5hkkzNhg3DyVK/8YLX3h00FyTxgv8nBLUhTR1adV9mrkpKcD/uSc6VzNWRPrmiWgiX70L3yx/uztoS8IHda9zNU4U5j86ll1yiZ35extGruPAzPa4rvdlLbuB4zMVZaGlZL/zwWFPcaVTPFDJXoAGn8aKk+mklH6BayT2WeVRpJlHFgVJuixrFvEFva7j1OXYWV810b5cUql4kk0JdiNebON25L2PCOeobjGVjl1ad5Xih3xewh+OH+zkhCnnNAe0DW54ZKZc2IauHqP7OphagYI3LDWysA1wECRd0FJZtr0y9LLqFMDYhSjG1B7LOLyihsSWXtCOjiQ9bt66UpV/5Lfn+uyCr3QCZe7L+bS4MlSnHQBYSR8UMSDHVExefWzAd6P7Uucgu6V5x5Z8dwt0dOODfdziBvIR2YlXV0kJtcPaojI5fdO6lfchtPXbEZqJgyHovUD+NhupTIFDWIaWHRYclC2HJLqcGPS9z1xGpQoPCbcrrGZLWE+EfiAneiIg13oKvFL0T7qOpkUURhwWjjE0arEqxfbYlTKZGitfMHfcrNIfSAMuKd/WiD3SpWCqfLcUwuCUtPFllRlaD75xhLF3ED0qfVvs3p9y2ejJ1e08GHCOcn8zJQxVw2ytepPDpglcerRvSrB8dIglHzxU8CXTD4KAmFc72BDce2H5CKaBZHpBhJ4yej+t8PImpMJxQ8ipwqz8XeiiHKDFW2m85RXMpHKak5vl6QyhSbTkvt5HrZh0vGrxz3Wybpq4v9IbjEQYFrNeKnFHJQgMD6f8btTymPoUB5koXNdgh1QXa+Zq/j6WsiB3nLxJZsqSNEc45/7hVcOU9mw/gHd2554f7D/5+DE9Gs/barrEuBxCMUat/uB10vPYF1cOSZ1k6L5VfcSaDcGXnGuFEVr5lZ4quMUg/yXNvK3GnpSQ/d2WEX6Wy2O9youKpvpd3hwReBT4zi4X5G2rGUWV+xs3atCfcWFeMISiXopwx2nJehaiHajPo4WyOD5tmlswFSDB68WzKiyKkxv0T6YHuvN4SNWgBEmXy7bClIEd2vGtDwyoZF/ZyDZO5U/W0qUqR04UTeFH7fvl/NRTwqR2o4t4xffAKsj+ZT8lbrrrb41bSut7v7AcbLfiO/q8aDoMu1tFlZkilU0ciMbT2FinIRqjyu7Ji7rTUvxteLwuiHDjIiXH/qLEB8Im2JzYlqUmTXm637OGznZhgQw78EU2IsPdF+USHxQ== rafaladmin-rafal@lcwood
VPS: root@vz1947(2010-01-09 23:55:09)~$ cat /home/userfoo/.ssh/authorized_keys
ssh-rsa AAAAB3NzaC1yc2EAAAABIwAABAEArre0Hxv6tavCrtak9LbkbveZ4FxH7FXbcDk47h2KJIRcVGcZljEiUmlI3aobKM2XORZHeQggz5ReOqi2kzLKAfh1ILzQBKX3YzvOTnB7kX/Ed7DR1XDBwvvxfcXhwv5hkkzNhg3DyVK/8YLX3h00FyTxgv8nBLUhTR1adV9mrkpKcD/uSc6VzNWRPrmiWgiX70L3yx/uztoS8IHda9zNU4U5j86ll1yiZ35extGruPAzPa4rvdlLbuB4zMVZaGlZL/zwWFPcaVTPFDJXoAGn8aKk+mklH6BayT2WeVRpJlHFgVJuixrFvEFva7j1OXYWV810b5cUql4kk0JdiNebON25L2PCOeobjGVjl1ad5Xih3xewh+OH+zkhCnnNAe0DW54ZKZc2IauHqP7OphagYI3LDWysA1wECRd0FJZtr0y9LLqFMDYhSjG1B7LOLyihsSWXtCOjiQ9bt66UpV/5Lfn+uyCr3QCZe7L+bS4MlSnHQBYSR8UMSDHVExefWzAd6P7Uucgu6V5x5Z8dwt0dOODfdziBvIR2YlXV0kJtcPaojI5fdO6lfchtPXbEZqJgyHovUD+NhupTIFDWIaWHRYclC2HJLqcGPS9z1xGpQoPCbcrrGZLWE+EfiAneiIg13oKvFL0T7qOpkUURhwWjjE0arEqxfbYlTKZGitfMHfcrNIfSAMuKd/WiD3SpWCqfLcUwuCUtPFllRlaD75xhLF3ED0qfVvs3p9y2ejJ1e08GHCOcn8zJQxVw2ytepPDpglcerRvSrB8dIglHzxU8CXTD4KAmFc72BDce2H5CKaBZHpBhJ4yej+t8PImpMJxQ8ipwqz8XeiiHKDFW2m85RXMpHKak5vl6QyhSbTkvt5HrZh0vGrxz3Wybpq4v9IbjEQYFrNeKnFHJQgMD6f8btTymPoUB5koXNdgh1QXa+Zq/j6WsiB3nLxJZsqSNEc45/7hVcOU9mw/gHd2554f7D/5+DE9Gs/barrEuBxCMUat/uB10vPYF1cOSZ1k6L5VfcSaDcGXnGuFEVr5lZ4quMUg/yXNvK3GnpSQ/d2WEX6Wy2O9youKpvpd3hwReBT4zi4X5G2rGUWV+xs3atCfcWFeMISiXopwx2nJehaiHajPo4WyOD5tmlswFSDB68WzKiyKkxv0T6YHuvN4SNWgBEmXy7bClIEd2vGtDwyoZF/ZyDZO5U/W0qUqR04UTeFH7fvl/NRTwqR2o4t4xffAKsj+ZT8lbrrrb41bSut7v7AcbLfiO/q8aDoMu1tFlZkilU0ciMbT2FinIRqjyu7Ji7rTUvxteLwuiHDjIiXH/qLEB8Im2JzYlqUmTXm637OGznZhgQw78EU2IsPdF+USHxQ== rafaladmin-rafal@lcwood
VPS: root@vz1947(2010-01-09 23:55:17)~$ sha1sum /home/userfoo/.ssh/authorized_keys
6617c1802b8884ab9d93a6dc6908c97bf5cc2dcc /home/userfoo/.ssh/authorized_keys
VPS: root@vz1947(2010-01-09 23:55:24)~$ sha1sum /root/.ssh/authorized_keys
6617c1802b8884ab9d93a6dc6908c97bf5cc2dcc /root/.ssh/authorized_keys
VPS: root@vz1947(2010-01-09 23:55:28)~$ stat /root/.ssh/authorized_keys /home/userfoo/.ssh/authorized_keys
  File: `/root/.ssh/authorized_keys'
  Size: 1429 Blocks: 8 IO Block: 4096 regular file
Device: 50h/80d Inode: 138149922 Links: 1
Access: (0644/-rw-r--r--) Uid: ( 0/ root) Gid: ( 0/ root)
Access: 2010-01-09 23:55:28.000000000 +0000
Modify: 2010-01-09 21:58:10.000000000 +0000
Change: 2010-01-09 21:58:10.000000000 +0000
  File: `/home/userfoo/.ssh/authorized_keys'
  Size: 1429 Blocks: 8 IO Block: 4096 regular file
Device: 50h/80d Inode: 32736673 Links: 1
Access: (0600/-rw-------) Uid: ( 1000/ userfoo) Gid: ( 1000/ userfoo)
Access: 2010-01-09 23:55:24.000000000 +0000
Modify: 2010-01-09 23:51:45.000000000 +0000
Change: 2010-01-09 23:51:59.000000000 +0000
VPS: root@vz1947(2010-01-09 23:55:39)~$ stat /root/.ssh/ /home/userfoo/.ssh/
  File: `/root/.ssh/'
  Size: 4096 Blocks: 8 IO Block: 4096 directory
Device: 50h/80d Inode: 38633473 Links: 2
Access: (0700/drwx------) Uid: ( 0/ root) Gid: ( 0/ root)
Access: 2010-01-09 23:55:08.000000000 +0000
Modify: 2010-01-09 21:58:10.000000000 +0000
Change: 2010-01-09 21:58:10.000000000 +0000
  File: `/home/userfoo/.ssh/'
  Size: 4096 Blocks: 8 IO Block: 4096 directory
Device: 50h/80d Inode: 32736671 Links: 2
Access: (0600/drw-------) Uid: ( 1000/ userfoo) Gid: ( 1000/ userfoo)
Access: 2010-01-09 23:51:59.000000000 +0000
Modify: 2010-01-09 23:51:45.000000000 +0000
Change: 2010-01-09 23:51:59.000000000 +0000

ProblemType: Bug
Architecture: amd64
Date: Sat Jan 9 23:59:02 2010
DistroRelease: Ubuntu 9.10
NonfreeKernelModules: nvidia
Package: ssh (not installed)
ProcEnviron:
 LANGUAGE=
 PATH=(custom, user)
 LANG=en_US.UTF-8
 SHELL=/bin/bash
ProcVersionSignature: Ubuntu 2.6.31-16.53-generic
SourcePackage: openssh
Uname: Linux 2.6.31-16-generic x86_64

Related branches

lp:debian/openssh
Revision history for this message
LimCore (limcore) wrote :
Revision history for this message
LimCore (limcore) wrote :

after chmod 700 /home/userfoo/.ssh/ ; /etc/init.d/ssh restart still identical problem

Revision history for this message
LimCore (limcore) wrote :

Solved, /home perms where wrong.

It would be nice to have openssh say a bit more about this problem in logs on DEBUG3, then just

Jan 10 00:54:16 vz1947 sshd[32763]: debug1: trying public key file /home/userfoo/.ssh/authorized_keys
Jan 10 00:54:16 vz1947 sshd[32763]: debug1: restore_uid: 0/0

Revision history for this message
LimCore (limcore) wrote :

Indeed this kind of error does not have a distinctive message for noone

summary: - pubkey login stoped working
+ openssh server should warn that .ssh/authorized_keys is not accessible
+ (causing ssh pubkey authentication to fail silently)
Changed in openssh (Ubuntu):
status: New → Confirmed
Revision history for this message
C de-Avillez (hggdh2) wrote :

please do nor confirm your own bugs.

Changed in openssh (Ubuntu):
status: Confirmed → New
Micah Gersten (micahg)
visibility: public → private
visibility: private → public
Revision history for this message
Micah Gersten (micahg) wrote :

On second thought, this isn't the correct upstream as the reported here is asking for /var/log/auth.log logging and according to upstream that should already be done. The upstream bug was for client notification of the issue which isn't really possible as described upstream.

Changed in openssh (Ubuntu):
importance: Undecided → Wishlist
Changed in openssh:
importance: Unknown → Undecided
status: Unknown → New
Jonathan Davies (jpds)
Changed in openssh:
importance: Undecided → Unknown
status: New → Unknown
Revision history for this message
LimCore (limcore) wrote :

The attached trivial patch applies the wish I described above,
it informs more why authorized_keys is not being used.

The patch is tested for all error conditions it should report, both with default LogLevel INFO, as well as with DEBUG3.

Below detaild explanation what it does - and results of test.

It needs debug1 level to show conditions that are typical (missing authorized_keys), and it logs usually conditions that look like errors (i.e. .ssh/authorized_keys exists, but is inaccessible)

Examples of what will be in log for various use cases conditions:

rm .ssh/authorized_keys
Jan 10 05:22:48 lcwood sshd[15934]: debug1: unable to open public key file /home/rafal/.ssh/authorized_keys

chmod 000 .ssh/authorized_keys
Jan 10 05:19:26 lcwood sshd[15763]: authorized_keys ERROR: permission denied for opening user rafal authorized keys /home/rafal/.ssh/authorized_keys!

chmod 000 .ssh/
Jan 10 05:21:08 lcwood sshd[15817]: authorized_keys ERROR: permission denied for opening user rafal authorized keys /home/rafal/.ssh/authorized_keys!

mv .ssh .ssh-2
ln -s .ssh .ssh
Jan 10 05:26:40 lcwood sshd[16088]: authorized_keys ERROR: Can not access user rafal authorized keys /home/rafal/.ssh/authorized_keys - Too many levels of symbolic links (errno=40)!

And with option (/etc/ssh/sshd_config)
  LogLevel INFO
only the error conditions thes ones with ERROR are loged, since they are undexpted.

Revision history for this message
Micah Gersten (micahg) wrote :

Updating upstream bug

Revision history for this message
Micah Gersten (micahg) wrote :

Marking this Triaged as we have an upstream bug. Thank you Limcore for upstreaming this.

Changed in openssh (Ubuntu):
status: New → Triaged
Revision history for this message
LimCore (limcore) wrote :

Created new upstream bug because bugzilla 1554 was for something a bit different

Revision history for this message
LimCore (limcore) wrote :

Upstream applied such patch (less verbose version of it, but still providing needed information in the log).

So what's next, lets get in applied to 10.04?

Revision history for this message
Micah Gersten (micahg) wrote :

Here's a link to the version that was accepted:
https://bugzilla.mindrot.org/attachment.cgi?id=1772

Revision history for this message
In , Rafal-maj-it (rafal-maj-it) wrote :

If authorized_keys exists, but has chmod 000, or .ssh has chmod 000 or 600, or for other reason it can not be read by server, then there is little clue, in the logs, what is going on.

Just:
debug1: trying public key file /home/userfoo/.ssh/authorized_keys
debug1: restore_uid: 0/0

Admin should be informed that there was some problem accessing authorized_keys (other then not-existing file).

Revision history for this message
In , Rafal-maj-it (rafal-maj-it) wrote :

Also in Ubuntu https://bugs.launchpad.net/ubuntu/+source/openssh/+bug/505301

Revision history for this message
In , Rafal-maj-it (rafal-maj-it) wrote :

Created an attachment (id=1771)
More log/debug about why authorized_keys could not be used

This will provide more information.

On DebugLevel INFO it will only inform when there was I/O error when accessing existing .ssh/authorized_keys file (like, 000 permitions etc)

On DEBUG3 it will also inform if the file simply was not existing to make full log clear about this.

Revision history for this message
In , Darren Tucker (dtucker) wrote :

The keyfile not existing is not unusual (it's the default state) and is probably not worth mentioning. Adding a debug message for the rest seems reasonable as long as we don't editorialize too much.

Revision history for this message
In , Darren Tucker (dtucker) wrote :

Created an attachment (id=1772)
ssh-pubkey-debug.patch

Output a debug if we can't open an existing keyfile.

Revision history for this message
In , Darren Tucker (dtucker) wrote :

Patch #1772 has been applied and will be in the 5.4 release. Thanks for the report.

Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package openssh - 1:5.2p1-2ubuntu1

---------------
openssh (1:5.2p1-2ubuntu1) lucid; urgency=low

  * Resynchronise with Debian. Remaining changes:
    - Add support for registering ConsoleKit sessions on login.
    - Drop openssh-blacklist and openssh-blacklist-extra to Suggests; they
      take up a lot of CD space, and I suspect that rolling them out in
      security updates has covered most affected systems now.
    - Convert to Upstart. The init script is still here for the benefit of
      people running sshd in chroots.

openssh (1:5.2p1-2) unstable; urgency=low

  [ Colin Watson ]
  * Backport from upstream:
    - After sshd receives a SIGHUP, ignore subsequent HUPs while sshd
      re-execs itself. Prevents two HUPs in quick succession from resulting
      in sshd dying (LP: #497781).
    - Output a debug if we can't open an existing keyfile (LP: #505301).
  * Use host compiler for ssh-askpass-gnome when cross-compiling.
  * Don't run tests when cross-compiling.
  * Drop change from 1:3.6.1p2-5 to disable cmsg_type check for file
    descriptor passing when running on Linux 2.0. The previous stable
    release of Debian dropped support for Linux 2.4, let alone 2.0, so this
    very likely has no remaining users depending on it.

  [ Kees Cook ]
  * Implement DebianBanner server configuration flag that can be set to "no"
    to allow sshd to run without the Debian-specific extra version in the
    initial protocol handshake (closes: #562048).
 -- Colin Watson <email address hidden> Sat, 16 Jan 2010 03:58:17 +0000

Changed in openssh (Ubuntu):
status: Triaged → Fix Released
Revision history for this message
In , Darren Tucker (dtucker) wrote :

With the release of 5.4p1, this bug is now considered closed.

Bug Watch Updater (bug-watch-updater)
Changed in openssh:
status: Unknown → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.