Ansible SSH problems delegate_to and closing control socket

[ashemedai]

ISSUE TYPE

Bug Report

COMPONENT NAME

ssh

ANSIBLE VERSION

ansible 2.4.0.0
  config file = None
  configured module search path = ['/home/jeroenr/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /usr/local/lib/python3.6/dist-packages/ansible
  executable location = /usr/local/bin/ansible
  python version = 3.6.2 (default, Aug  4 2017, 14:35:04) [GCC 6.4.0 20170724]

CONFIGURATION

% ansible-config dump --only-changed
CACHE_PLUGIN(ansible.cfg) = memory
COMMAND_WARNINGS(ansible.cfg) = True
DEFAULT_BECOME_ASK_PASS(ansible.cfg) = True
DEFAULT_BECOME_METHOD(ansible.cfg) = sudo
DEFAULT_GATHERING(ansible.cfg) = smart
DEFAULT_MANAGED_STR(ansible.cfg) = This file is managed by Ansible, don't make changes here - they will be overwritten.
DEFAULT_ROLES_PATH(ansible.cfg) = ['roles']
DEFAULT_UNDEFINED_VAR_BEHAVIOR(ansible.cfg) = True
DEFAULT_VAULT_PASSWORD_FILE(ansible.cfg) = bin/vault_passwords.sh
DEPRECATION_WARNINGS(ansible.cfg) = True
RETRY_FILES_ENABLED(ansible.cfg) = False
RETRY_FILES_SAVE_PATH(ansible.cfg) = /tmp
SYSTEM_WARNINGS(ansible.cfg) = True

OS / ENVIRONMENT

Debian GNU/Linux 8.9 (jessie)

SUMMARY

A playbook with a delegate_to another host seems to cause full or intermittent SSH socket closures.

STEPS TO REPRODUCE

We have a playbook and role for registering hosts on our Nagios monitoring system. This involves a delegate_to the Nagios monitoring server.

- name: Register in Nagios
  hosts: all
  gather_facts: yes
  become: yes
  vars_files:
  - ../roles/openssl/vars/main.yml
  - ../roles/haproxy/defaults/main.yml

  roles:
  - role: nagios-target
    delegate_to: "{{ nagios_target_delegation_host }}"

This is with no ssh_connection section or active .ssh/config.

EXPECTED RESULTS

As with 2.3.x.0 that all systems are registered on the Nagios server without problems.

ACTUAL RESULTS

% ansible-playbook -vvvv playbooks/nagios-target.yml -i inventory/servers 
ansible-playbook 2.4.0.0
  config file = /home/jeroen/deployment/ansible.cfg
  configured module search path = ['/home/jeroen/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /usr/local/lib/python3.6/dist-packages/ansible
  executable location = /usr/local/bin/ansible-playbook
  python version = 3.6.2 (default, Aug  4 2017, 14:35:04) [GCC 6.4.0 20170724]
Using /home/jeroen/deployment/ansible.cfg as config file
SUDO password: 
setting up inventory plugins
Parsed /home/jeroen/deployment/inventory/servers inventory source with ini plugin
Read vars_file '../roles/openssl/vars/main.yml'
Read vars_file '../roles/haproxy/defaults/main.yml'
Read vars_file '../roles/openssl/vars/main.yml'
Read vars_file '../roles/haproxy/defaults/main.yml'
Loading callback plugin default of type stdout, v2.0 from /usr/local/lib/python3.6/dist-packages/ansible/plugins/callback/__init__.py

PLAYBOOK: nagios-target.yml ***************************************************************************************************************************************************************************************
1 plays in playbooks/nagios-target.yml
Read vars_file '../roles/openssl/vars/main.yml'
Read vars_file '../roles/haproxy/defaults/main.yml'
Read vars_file '../roles/openssl/vars/main.yml'
Read vars_file '../roles/haproxy/defaults/main.yml'

PLAY [Register in Nagios] ***********************************************************************************************************************************************************************************************
Trying secret ScriptVaultSecret(filename='/home/jeroen/deployment/bin/vault_passwords.sh') for vault_id=default
Trying secret ScriptVaultSecret(filename='/home/jeroen/deployment/bin/vault_passwords.sh') for vault_id=default
Read vars_file '../roles/openssl/vars/main.yml'
Read vars_file '../roles/haproxy/defaults/main.yml'

TASK [Gathering Facts] ********************************************************************************************************************************************************************************************
Read vars_file '../roles/openssl/vars/main.yml'
Read vars_file '../roles/haproxy/defaults/main.yml'
Read vars_file '../roles/openssl/vars/main.yml'
Read vars_file '../roles/haproxy/defaults/main.yml'
Read vars_file '../roles/openssl/vars/main.yml'
Read vars_file '../roles/haproxy/defaults/main.yml'
Read vars_file '../roles/openssl/vars/main.yml'
Read vars_file '../roles/haproxy/defaults/main.yml'
Using module file /usr/local/lib/python3.6/dist-packages/ansible/modules/system/setup.py
Using module file /usr/local/lib/python3.6/dist-packages/ansible/modules/system/setup.py
Using module file /usr/local/lib/python3.6/dist-packages/ansible/modules/system/setup.py
Using module file /usr/local/lib/python3.6/dist-packages/ansible/modules/system/setup.py
Using module file /usr/local/lib/python3.6/dist-packages/ansible/modules/system/setup.py
<system01> ESTABLISH SSH CONNECTION FOR USER: None
<system-lb01> ESTABLISH SSH CONNECTION FOR USER: None
<system-lb02> ESTABLISH SSH CONNECTION FOR USER: None
<system-db01> ESTABLISH SSH CONNECTION FOR USER: None
<system02> ESTABLISH SSH CONNECTION FOR USER: None
<system-lb02> SSH: EXEC ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o ConnectTimeout=10 -o ControlPath=/home/jeroen/.ansible/cp/34a65294b7 system-lb02 '/bin/sh -c '"'"'echo ~ && sleep 0'"'"''
<system-lb01> SSH: EXEC ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o ConnectTimeout=10 -o ControlPath=/home/jeroen/.ansible/cp/4d7f5dbc63 system-lb01 '/bin/sh -c '"'"'echo ~ && sleep 0'"'"''
<system-db01> SSH: EXEC ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o ConnectTimeout=10 -o ControlPath=/home/jeroen/.ansible/cp/0b094931e6 system-db01 '/bin/sh -c '"'"'echo ~ && sleep 0'"'"''
<system01> SSH: EXEC ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o ConnectTimeout=10 -o ControlPath=/home/jeroen/.ansible/cp/e202920e0b system01 '/bin/sh -c '"'"'echo ~ && sleep 0'"'"''
<system02> SSH: EXEC ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o ConnectTimeout=10 -o ControlPath=/home/jeroen/.ansible/cp/484d4fc9eb system02 '/bin/sh -c '"'"'echo ~ && sleep 0'"'"''
<system01> (0, b'/home/jeroen\n', b'OpenSSH_7.5p1 Debian-10, OpenSSL 1.0.2l  25 May 2017\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 19: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_client_request_alive: done pid = 13013\r\ndebug3: mux_client_request_session: session request sent\r\ndebug1: mux_client_request_session: master session id: 2\r\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: Received exit status from master 0\r\n')
<system01> ESTABLISH SSH CONNECTION FOR USER: None
<system01> SSH: EXEC ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o ConnectTimeout=10 -o ControlPath=/home/jeroen/.ansible/cp/e202920e0b system01 '/bin/sh -c '"'"'( umask 77 && mkdir -p "` echo /home/jeroen/.ansible/tmp/ansible-tmp-1506091824.8956711-211943218474098 `" && echo ansible-tmp-1506091824.8956711-211943218474098="` echo /home/jeroen/.ansible/tmp/ansible-tmp-1506091824.8956711-211943218474098 `" ) && sleep 0'"'"''
<system-lb02> (0, b'/home/jeroen\n', b'OpenSSH_7.5p1 Debian-10, OpenSSL 1.0.2l  25 May 2017\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 19: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_client_request_alive: done pid = 13016\r\ndebug3: mux_client_request_session: session request sent\r\ndebug1: mux_client_request_session: master session id: 2\r\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: Received exit status from master 0\r\n')
<system-db01> (0, b'/home/jeroen\n', b'OpenSSH_7.5p1 Debian-10, OpenSSL 1.0.2l  25 May 2017\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 19: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_client_request_alive: done pid = 13019\r\ndebug3: mux_client_request_session: session request sent\r\ndebug1: mux_client_request_session: master session id: 2\r\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: Received exit status from master 0\r\n')
<system02> (0, b'/home/jeroen\n', b'OpenSSH_7.5p1 Debian-10, OpenSSL 1.0.2l  25 May 2017\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 19: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_client_request_alive: done pid = 13028\r\ndebug3: mux_client_request_session: session request sent\r\ndebug1: mux_client_request_session: master session id: 2\r\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: Received exit status from master 0\r\n')

And from this point on the hosts never really recover.
If I use a playbook without any delegate_to I don't have these issues. It could very well be another cause, but the delegate_to is the only clear lead I have so far.

[s-hertel]

Are you specifying the remote user somewhere? needs_info

[ashemedai]

@s-hertel Same user remotely as I use locally using SSH keys to log in and sudo for any jobs.

[denefoster]

I'm seeing very similar behaviour, not using delegate_to, but become_user. This is breaking the ssh pipelining, and thus requiring world readable tmpfiles in 2.4.

SSH debug output indicates the same problem, read_header failed and falls back to a non-pipelined connection

2.3 works perfectly.

[ashemedai]

@denefoster We also use become with these tasks, but not become_user at least. I need to do some more digging. But I have some other 2.4 problems to investigate as well.

[StephanZaat]

I'm also running into an issue here. It seems related. Pipelining seems to be broken for me in 2.4.
This results in errors from Ansible about the unpriviledged user when using modules that use become_user:

example:

  - name: Create {{ name }} database
    postgresql_db:
      name={{ name }}
      encoding='UTF-8'
    become_user: postgres

Result when running playbook using that task:

fatal: [<host>]: FAILED! => {"failed": true, "msg": "Failed to set permissions on the temporary files Ansible needs to create when becoming an unprivileged user (rc: 1, err: chown: changing ownership of '/tmp/ansible-tmp-1506598466.28-89299939212587/': Operation not permitted\nchown: changing ownership of '/tmp/ansible-tmp-1506598466.28-89299939212587/postgresql_db.py': Operation not permitted\n}). For information on working around this, see https://docs.ansible.com/ansible/become.html#becoming-an-unprivileged-user"}

I have enabled it in my ansible.cfg and it was running fine in 2.3.2 as shown below. In 2.4. the basic command requires the use of tmp files again.

$ ansible --version

ansible 2.3.2.0
  config file = /<homedir>/ansible.cfg
  configured module search path = Default w/o overrides
  python version = 2.7.13 (default, Jan 19 2017, 14:48:08) [GCC 6.3.0 20170118]

$ ansible -vvv -m shell -a 'echo ok'

Using /<stuff>/ansible.cfg as config file
META: ran handlers
Using module file /usr/local/lib/python2.7/dist-packages/ansible/modules/commands/command.py
<host> ESTABLISH SSH CONNECTION FOR USER: None
<host> SSH: EXEC ssh -C -o ControlMaster=auto -o ControlPersist=60s -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o ConnectTimeout=5 -o ControlPath=/<homedir>/cp/27a704658d <host> '/bin/sh -c '"'"'/usr/bin/python && sleep 0'"'"''
<host> (0, '\n{"changed": true, "end": "2017-09-28 13:23:25.469972", "stdout": "ok", "cmd": "echo ok", "rc": 0, "start": "2017-09-28 13:23:25.467350", "stderr": "", "delta": "0:00:00.002622", "invocation": {"module_args": {"warn": true, "executable": null, "_uses_shell": true, "_raw_params": "echo ok", "removes": null, "creates": null, "chdir": null}}, "warnings": []}\n', '')
<host> | SUCCESS | rc=0 >>
ok

META: ran handlers
META: ran handlers

$ ansible --version

ansible 2.4.0.0
  config file = /<homedir>/ansible.cfg
  configured module search path = [u'/<homedir>/.ansible/plugins/modules', u'/usr/share/ansible/plugins/modules']
  ansible python module location = /usr/local/lib/python2.7/dist-packages/ansible
  executable location = /usr/local/bin/ansible
  python version = 2.7.13 (default, Jan 19 2017, 14:48:08) [GCC 6.3.0 20170118]

$ ansible -i -vvv -m shell -a 'echo ok'

Using /<homedir>/ansible.cfg as config file
Parsed /<homedir>/central/inventory.ini inventory source with ini plugin
META: ran handlers
Using module file /usr/local/lib/python2.7/dist-packages/ansible/modules/commands/command.py
<<host>> ESTABLISH SSH CONNECTION FOR USER: None
<<host>> SSH: EXEC ssh -C -o ControlMaster=auto -o ControlPersist=60s -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o ConnectTimeout=5 -o ControlPath=/<homedir>/.ansible/cp/27a704658d <host> '/bin/sh -c '"'"'echo ~ && sleep 0'"'"''
<<host>> (0, '/<homedir>\n', '')
<<host>> ESTABLISH SSH CONNECTION FOR USER: None
<<host>> SSH: EXEC ssh -C -o ControlMaster=auto -o ControlPersist=60s -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o ConnectTimeout=5 -o ControlPath=/<homedir>/.ansible/cp/27a704658d <host> '/bin/sh -c '"'"'( umask 77 && mkdir -p "` echo /<homedir>/.ansible/tmp/ansible-tmp-1506597878.03-51745463315848 `" && echo ansible-tmp-1506597878.03-51745463315848="` echo /<homedir>/.ansible/tmp/ansible-tmp-1506597878.03-51745463315848 `" ) && sleep 0'"'"''
<<host>> (0, 'ansible-tmp-1506597878.03-51745463315848=/<homedir>/.ansible/tmp/ansible-tmp-1506597878.03-51745463315848\n', '')
<<host>> PUT /tmp/tmpvLp2WQ TO /<homedir>/.ansible/tmp/ansible-tmp-1506597878.03-51745463315848/command.py
<<host>> SSH: EXEC sftp -b - -C -o ControlMaster=auto -o ControlPersist=60s -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o ConnectTimeout=5 -o ControlPath=/<homedir>/.ansible/cp/27a704658d '[<host>]'
<<host>> (0, 'sftp> put /tmp/tmpvLp2WQ /<homedir>/.ansible/tmp/ansible-tmp-1506597878.03-51745463315848/command.py\n', '')
<<host>> ESTABLISH SSH CONNECTION FOR USER: None
<<host>> SSH: EXEC ssh -C -o ControlMaster=auto -o ControlPersist=60s -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o ConnectTimeout=5 -o ControlPath=/<homedir>/.ansible/cp/27a704658d <host> '/bin/sh -c '"'"'chmod u+x /<homedir>/.ansible/tmp/ansible-tmp-1506597878.03-51745463315848/ /<homedir>/.ansible/tmp/ansible-tmp-1506597878.03-51745463315848/command.py && sleep 0'"'"''
<<host>> (0, '', '')
<<host>> ESTABLISH SSH CONNECTION FOR USER: None
<<host>> SSH: EXEC ssh -C -o ControlMaster=auto -o ControlPersist=60s -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o ConnectTimeout=5 -o ControlPath=/<homedir>/.ansible/cp/27a704658d -tt <host> '/bin/sh -c '"'"'/usr/bin/python /<homedir>/.ansible/tmp/ansible-tmp-1506597878.03-51745463315848/command.py; rm -rf "/<homedir>/.ansible/tmp/ansible-tmp-1506597878.03-51745463315848/" > /dev/null 2>&1 && sleep 0'"'"''
<<host>> (0, '\r\n{"changed": true, "end": "2017-09-28 13:24:40.171699", "stdout": "ok", "cmd": "echo ok", "rc": 0, "start": "2017-09-28 13:24:40.168934", "stderr": "", "delta": "0:00:00.002765", "invocation": {"module_args": {"warn": true, "executable": null, "_uses_shell": true, "_raw_params": "echo ok", "removes": null, "creates": null, "chdir": null, "stdin": null}}}\r\n', 'Shared connection to <host> closed.\r\n')
<host> | SUCCESS | rc=0 >>
ok

META: ran handlers
META: ran handlers

[LucaLanziani]

+1 having the same problem of @StephanZaat myself

[samdoran]

Can you please test with a newer version of Ansible to see if this is still an issue?

needs_info

[ansibot]

@ashemedai This issue is waiting for your response. Please respond or the issue will be closed.

click here for bot help

[ashemedai]

I can no longer test this scenario. While I am still using Ansible, it is in a completely different set up.