When ssh and ansible play poorly together

Last night, this worked fine. This morning, it fails:

# ansible-playbook jail-mailjail.yml 

PLAY [mailjails] ************************************************************** 

GATHERING FACTS *************************************************************** 
failed: [mailjail.example.org] => {"failed": true, "parsed": false}
invalid output was: Sorry, try again.
Sorry, try again.
Sorry, try again.
sudo: 3 incorrect password attempts


TASK: [pkg | install pkg] ***************************************************** 
FATAL: no hosts matched or all hosts have already failed -- aborting


PLAY RECAP ******************************************************************** 
           to retry, use: --limit @/root/jail-mailjail.retry

mailjail.example.org      : ok=0    changed=0    unreachable=0    failed=1   

Keep in mind that this host uses the sudo auth via ssh-agent method I stole from Michael Lucas (and wrote about recently). I am convinced (now) that this auto mechanism has been broken by something I’ve done.

I tried various things:

• ssh in as the ansible user: OK
• clear out the ssh keys from ssh-agent and run ssh-add again: OK

Interesting: the result when trying without any keys in ssh-agent is exactly the same.

Eventually…. I got around to checking the logs on the maillog host:

Sep  3 13:45:52 mailjail sshd[6433]: channel 3: open failed: administratively prohibited: open failed
Sep  3 13:45:52 mailjail sudo[52998]: pam_ssh_agent_auth: error: Error reading response length from authentication socket.
Sep  3 13:45:52 mailjail sudo[52998]: pam_ssh_agent_auth: Failed Authentication: `ansible' as `ansible' using /usr/home/ansible/.ssh/authorized_keys

Oh…

Searching is finding nothing. I tried removing some bits from /usr/home/ansible/.ssh/authorized_keys but that didn’t help:

- from="10.55.0.113",no-port-forwarding,no-X11-forwarding ssh-rsa..
+ ssh-rsa

I confirmed this is not an ssh by connecting to the node in question and issuing some local commands:

# ansible mailjail.example.org -m shell -a 'ls -a'
mailjail.example.org | success | rc=0 >>
.
..
.ansible
.bash_history
.cshrc
.joe_state
.login
.login_conf
.mail_aliases
.mailrc
.profile
.rhosts
.shrc
.ssh

I now believe this is just a sudo issue:

# ansible mailjail.example.org -m shell -a 'sudo ls'
mailjail.example.org | FAILED | rc=1 >>
Sorry, try again.
Sorry, try again.
Sorry, try again.
sudo: 3 incorrect password attempts

Let’s start with the basics:

# ssh ansible@10.80.0.68
$ sudo ls
Sorry, try again.
Sorry, try again.
Sorry, try again.
sudo: 3 incorrect password attempts
$ bash
[ansible@mailjail ~]$ sudo ls
Sorry, try again.
Sorry, try again.
Sorry, try again.
sudo: 3 incorrect password attempts
[ansible@mailjail ~]$ 

After rereading Mr Lucas’ blog post, I tried the test above again, this time with agent forwarding enabled:

# ssh -A ansible@10.80.0.68
$ sudo ls
.ansible	.bash_history	.cshrc		.joe_state	.login		.login_conf	.mail_aliases	.mailrc		.profile	.rhosts		.shrc		.ssh

Ahhh, so ansible is not doing enabling forwarding…

The conversation on Twitter eventually prompted me to restart the node (which was running in a jail). This this allowed sudo to work. However, I started seeing this in the logs:

Sep  3 15:16:54 mailjail sshd[75124]: subsystem request for sftp by user ansible
Sep  3 15:16:55 mailjail sudo[75196]: pam_ssh_agent_auth: Authentication refused: bad ownership or modes for file /usr/home/ansible/.ssh/authorized_keys
Sep  3 15:16:55 mailjail sudo[75196]: pam_ssh_agent_auth: matching key found: file /usr/home/ansible/.ssh/authorized_keys, line 1
Sep  3 15:16:55 mailjail sudo[75196]: pam_ssh_agent_auth: Found matching RSA key: 42:f1:d1:bd:2a:20:e4:7b:98:4c:3f:6b:54:f2:ec:00
Sep  3 15:16:55 mailjail sudo[75196]: pam_ssh_agent_auth: Authenticated: `ansible' as `ansible' using /usr/home/ansible/.ssh/authorized_keys

$ ls -ld /usr/home/ansible/.ssh /usr/home/ansible/.ssh/authorized_keys
drwx------  2 ansible  ansible    4 Sep  3 14:24 /usr/home/ansible/.ssh
-rw-------  1 ansible  ansible  794 Apr  6 21:33 /usr/home/ansible/.ssh/authorized_keys

That seems just fine. What is is complaining about?

I found the above messages confusing and tried to solve the problem, but it turns out it’s not a problem at all, or so I think. After finding this post, I tried adding debug allow_user_owned_authorized_keys_file to /usr/local/etc/pam.d/sudo. Now my attempts yielded these messages:

Sep  3 15:14:00 mailjail sshd[74208]: subsystem request for sftp by user ansible
Sep  3 15:14:01 mailjail sudo[74289]: pam_ssh_agent_auth: Beginning pam_ssh_agent_auth for user ansible
Sep  3 15:14:01 mailjail sudo[74289]: pam_ssh_agent_auth: Attempting authentication: `ansible' as `ansible' using /usr/home/ansible/.ssh/authorized_keys
Sep  3 15:14:01 mailjail sudo[74289]: pam_ssh_agent_auth: Contacted ssh-agent of user ansible (1001)
Sep  3 15:14:01 mailjail sudo[74289]: pam_ssh_agent_auth: trying public key file /usr/home/ansible/.ssh/authorized_keys
Sep  3 15:14:01 mailjail sudo[74289]: pam_ssh_agent_auth: secure_filename: checking for uid: 1001
Sep  3 15:14:01 mailjail sudo[74289]: pam_ssh_agent_auth: secure_filename: checking '/usr/home/ansible/.ssh'
Sep  3 15:14:01 mailjail sudo[74289]: pam_ssh_agent_auth: secure_filename: checking '/usr/home/ansible'
Sep  3 15:14:01 mailjail sudo[74289]: pam_ssh_agent_auth: secure_filename: terminating check at '/usr/home/ansible'
Sep  3 15:14:01 mailjail sudo[74289]: pam_ssh_agent_auth: key not found
Sep  3 15:14:01 mailjail sudo[74289]: pam_ssh_agent_auth: trying public key file /usr/home/ansible/.ssh/authorized_keys
Sep  3 15:14:01 mailjail sudo[74289]: pam_ssh_agent_auth: secure_filename: checking for uid: 0
Sep  3 15:14:01 mailjail sudo[74289]: pam_ssh_agent_auth: Authentication refused: bad ownership or modes for file /usr/home/ansible/.ssh/authorized_keys
Sep  3 15:14:01 mailjail sudo[74289]: pam_ssh_agent_auth: trying public key file /usr/home/ansible/.ssh/authorized_keys
Sep  3 15:14:01 mailjail sudo[74289]: pam_ssh_agent_auth: secure_filename: checking for uid: 1009
Sep  3 15:14:01 mailjail sudo[74289]: pam_ssh_agent_auth: secure_filename: checking '/usr/home/ansible/.ssh'
Sep  3 15:14:01 mailjail sudo[74289]: pam_ssh_agent_auth: secure_filename: checking '/usr/home/ansible'
Sep  3 15:14:01 mailjail sudo[74289]: pam_ssh_agent_auth: secure_filename: terminating check at '/usr/home/ansible'
Sep  3 15:14:01 mailjail sudo[74289]: pam_ssh_agent_auth: matching key found: file /usr/home/ansible/.ssh/authorized_keys, line 1
Sep  3 15:14:01 mailjail sudo[74289]: pam_ssh_agent_auth: Found matching RSA key: bd:42:f1:d1:2a:00:20:e4:7b:98:4c:3f:6b:54:f2:ec
Sep  3 15:14:01 mailjail sudo[74289]: pam_ssh_agent_auth: ssh_rsa_verify: signature correct
Sep  3 15:14:01 mailjail sudo[74289]: pam_ssh_agent_auth: Authenticated: `ansible' as `ansible' using /usr/home/ansible/.ssh/authorized_keys

As shown above, pam_ssh_agent_auth tried uid=0 first, and failed. Then it tried uid=1009, which matches the ansible user, and succeeded.

In my opinion, the bad ownership or modes message which appears without debug mode is spurious.

The end

I have no idea why the original problem occurred. Sadly, I suspect it will return again. At least then I know what I’m dealing with and can dig deeper.