Sep 032014
 

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.

Website Pin Facebook Twitter Myspace Friendfeed Technorati del.icio.us Digg Google StumbleUpon Premium Responsive

  5 Responses to “When ssh and ansible play poorly together”

  1. For the record, I’m still seeing these messages. Rather annoying.

  2. Just happened to randomly stumble upon this. I’m the author of pam_ssh_agent_auth. I too consider that message spurious and annoying; it should be suppressed unless and until the second phase also fails. I’ll open a bug for it; I had my head in the code over this past weekend working on getting the new key formats and certificate-based-auth working. I’ll see about fixing this too.

    Thanks!

  3. Someone wrote in: I’ve added -K to the ansible-playbook call and it worked for me.