When ansible_python_interpreter is set to search for Python in the env, mitogen fails.

[ayaz]

Ansible: 2.5.5

If ansible_python_interpreter parameter is defined in the following manner in the playbook, the below listed error comes up:

ansible_python_interpreter: "/usr/bin/env python"

TASK [kubernetes/preinstall : Pre-upgrade | check if old credential dir exists] ************************************************************
task path: /Users/ayaz/Work/Cloudways/Cluster/kubespray/roles/kubernetes/preinstall/tasks/pre_upgrade.yml:2
Friday 29 June 2018  12:30:21 +0500 (0:00:00.099)       0:00:17.488 ***********
[pid 21418] 12:30:21.535102 D mitogen: unix.connect(path='/var/folders/_0/9b9z3xf527xg1pslfj_64q900000gn/T/mitogen_unix_jAzUOK')
[pid 21418] 12:30:21.536470 D mitogen: unix.connect(): local ID is 2019, remote is 0
[pid 21281] 12:30:21.538047 D mitogen: mitogen.parent.Stream('default').connect()
[pid 21418] 12:30:21.554305 D mitogen: mitogen.core.Stream('unix_listener.21281').on_disconnect()
[pid 21418] 12:30:21.554981 D mitogen: Waker(Broker(0x111175990) rfd=68, wfd=69).on_disconnect()
[pid 21281] 12:30:21.554914 D mitogen: mitogen.core.Stream('unix_client.21418').on_disconnect()
fatal: [av2-k8s-worker]: UNREACHABLE! => {
    "changed": false,
    "msg": "Child start failed: [Errno 2] No such file or directory. Command was: \"/usr/bin/env python\" \"-c\" \"import codecs,os,sys;_=codecs.decode;exec(_(_(\\\"eNptkNFLwzAQxp+3v6Jvl7CwJXVTKRSUPogPIhSxDzokbTMNdklJ29Xtr/faDtaKLyG/++6+77iYJaGtlqUuFaFzx9oR6Z2HsLPum9BgPsN/3pQ+4UxwTi8cszE5VMXAWWErReIxuDEkY2gRMLA6Ynwha0zde2HoQS5dqw140uS9qH5U1tQyLVQvr5rKrVJtVuWx/rIGcM/Zn7ZF2A8elKu0NW/B1baPVeagHTLcxw+vHLbhdGzoQSzIVGBTXADZ69p+KhPIozzddc+ysJksAl/4t4ICnaNT63StiGDw9PjyzDl/N1iPwg/SXTi3pTJ4V3Ap0KVTMidCXN9sKIOTLgeDc1PCoAU8+NkwGmvtVIP1euP7GLSI/ltBdCv8An8xnww=\\\".encode(),\\\"base64\\\"),\\\"zip\\\"))\"",
    "unreachable": true
}

Setting ansible_python_interpreter to a direct Python path resolves this issue.

[dw]

Thanks for filing these! I should have a solution for you shortly after cutting the first stable release today. I need to figure out precisely what Ansible is doing -- that variable isn't a simple shell fragment, it also forms the '#!hashbang' line of scripts on the target, and so its syntax is quite limited.

[dw]

This bug is a little more subtle than it may seem. Parsing of the hashbang varies across BSD and Linux, where Linux only parses up to one argument out of it, which may contain spaces. BSD on the other hand continues tokenization, making it possible to specify many more arguments.

While it does not impact your use case, a general fix requires an approach to the above.

My first thought was to throw an error noting the portability problems of including more than one argument, however that means Mitogen deviates from vanilla Ansible behaviour.

Just passing everything through introduces a few new issues -- an inexplicable infinite loop in bash when using the simplest 3-argument "/usr/bin/env" "ansible_bash_interpreter" setting.

Basically this needs more research to figure out the ideal behaviour. I can't check in code I know can trigger infinite loops :)

[dw]

So this bug is actually pretty amazing. Ansible's documentation for its own variable is totally incorrect, the actual usage of "ansible_*_interpreter" means it is always a shell fragment.

Adding to the previous comment, none of the hashbang processing differences across operating systems actually matters, because even though Ansible updates the hashbang, in this case with a value that doesn't even work on Linux (it can trigger an infinite exec loop in some cases), it always invokes the module as "$ansible_foo_interpreter /path/to/module" using a shell fragment, even by explicitly stripping off the hashbang it created upfront (called via ActionBase._execute_module()).

That means you can stuff arbitrary shell into ansible_*_interpreter, and so that must be supported.

[danquack]

@dw after upgrading to 2.2 the Ansible interpreter is giving me this error.

fatal: [host.domain.com]: UNREACHABLE! => {"changed": false, "msg": "EOF on stream; last 300 bytes received: u\"Warning: Permanently added 'host.domain.com' (ECDSA) to the list of known hosts.\\r\\nzsh:1: no such file or directory: /usr/bin/env python\\n\"", "unreachable": true}
When I actually go to the host that environment resolves.

Heres the vvv output

task path: /tmp/ping.yml:8
[pid 19822] 09:46:16.814934 D mitogen: unix.connect(path='/tmp/mitogen_unix_aCZPr0')
[pid 19822] 09:46:16.820545 D mitogen: unix.connect(): local ID is 1, remote is 0
[pid 19803] 09:46:16.826078 D mitogen: mitogen.ssh.Stream(u'default').connect()
[pid 19803] 09:46:16.959634 D mitogen: hybrid_tty_create_child() pid=19826 stdio=62, tty=16, cmd: "ssh" "-o" "Compression yes" "-o" "ServerAliveInterval 15" "-o" "ServerAliveCountMax 3" "-o" "StrictHostKeyChecking no" "-o" "UserKnownHostsFile /dev/null" "-o" "GlobalKnownHostsFile /dev/null" "-C" "-o" "ControlMaster=auto" "-o" "ControlPersist=60s" "host.domain.com" "'/usr/bin/env python'" "-c" "'import codecs,os,sys;_=codecs.decode;exec(_(_(\"eNqFkTFPwzAQhefmV2Q7W7Vap+0AkSyBOiAGhBQhOkCFktgBq6ltnKRp+fVc00pNysDk+/Te3TudE7YStpo47RShgWdtj3QRIhTWbwiNgxHWsnEzwlnEOb1wwvrkUY1OnJe2UiTpg+/Dqg8tAgZWB4wv0xpTt6EQIcjUt9pAmBrZiWqv8qZOs1J18rSp/DTTZuoO9Zc1gHuOrmxj0TXulK+0NW/xfN3FKrPTHhnuk4dXDmsxbDt5EEsyFNgQx0C2urafysTyu0nzjTJ357du9nF0e8PnFGiA01qva0UiBk+PL8+c83cDuEVuJR6bBkvxQY7nltYpg0cGnwGdeJVKEs3miwVl8KMdTiqcuPhWDNoMjj9QuHPAsqtPV71yt/+5/24ZDbb8BQ51sCk=\".encode(),\"base64\"),\"zip\"))'"
[pid 19803] 09:46:16.961421 D mitogen: mitogen.ssh.Stream(u'local.19826').connect(): child process stdin/stdout=62
[pid 19803] 09:46:17.008152 D mitogen: mitogen.ssh.Stream(u'local.19826'): received "Warning: Permanently added 'host.domain.com' (ECDSA) to the list of known hosts.\r\n"
[pid 19803] 09:46:17.631863 D mitogen: mitogen.ssh.Stream(u'local.19826'): received 'zsh:1: no such file or directory: /usr/bin/env python\n'
[pid 19803] 09:46:17.633008 D mitogen: mitogen.ssh.Stream(u'local.19826'): child process exit status was 32512
[pid 19822] 09:46:17.634223 D mitogen: mitogen.core.Stream(u'unix_listener.19803').on_disconnect()
[pid 19822] 09:46:17.634513 D mitogen: Waker(Broker(0x7fd553b5c850) rfd=13, wfd=14).on_disconnect()
[pid 19803] 09:46:17.634543 D mitogen: mitogen.core.Stream(u'unix_client.19822').on_disconnect()
fatal: [host.domain.com]: UNREACHABLE! => {
    "changed": false, 
    "msg": "EOF on stream; last 300 bytes received: u\"Warning: Permanently added 'host.domain.com' (ECDSA) to the list of known hosts.\\r\\nzsh:1: no such file or directory: /usr/bin/env python\\n\"", 
    "unreachable": true
}

[dw]

Oh man, you gotta be kidding me. This is the bug that keeps on giving :( Clearly the tests I added don't actually cover your case! Will look at this promptly, and hopefully another release for Mondayish

[dw]

Hi @danquack

Can you please share the relevant config when/where you're setting ansible_python_interpreter.

[danquack]

Running RHEL7->RHEL7, below is the playbook. Do you need any other info?

- hosts: all
  become_user: root
  gather_facts: no
  vars:
    ansible_python_interpreter: "/usr/bin/env python"
  tasks:
  - ping:

[dw]

I'm still in minor shock this slipped through. :)

Running this locally, it seems to work fine! I hate to ask, but is there no chance your ansible.cfg is pointing at an older ansible_mitogen version? I tried under Python 2.6/2.7/3.4

Don't waste too much time looking -- it might be a thinko on my end! But from first glance it seems the only two places I extract that variable, it is passed through the parser correctly.

edit: ooh, I had one thought. If you ever 'pip install'd an older ansible_mitogen, it may end up in sys.modules search list ahead of whatever is in ansible.cfg. That can be worked around with code, so if that's the case, I still consider this a bug!

[danquack]

ansible.cfg

[defaults]
library         = /usr/share/ansible:/opt/ansible/library
forks          = 200
gathering = implicit
gather_subset = all,!ohai,!hardware,!virtual,!network
gather_timeout = 20
roles_path     = /etc/ansible/roles:/opt/ansible/roles
host_key_checking = False
callback_whitelist = foreman
timeout = 30
remote_user = linux_admin
log_path = /var/log/ansible.log
private_key_file = /home/linux_admin/.ssh/id_rsa.ansible
strategy_plugins    = /opt/mitogen/ansible_mitogen/plugins/strategy
strategy                  = mitogen_free
bin_ansible_callbacks = True
retry_files_enabled = False
[privilege_escalation]
become=True
become_method=sudo
become_user=root
[paramiko_connection]
[ssh_connection]
pipelining = True
[accelerate]
[selinux]
[colors]

ansible --version:
ansible 2.5.5
  config file = /etc/ansible/ansible.cfg
  configured module search path = [u'/usr/share/ansible', u'/opt/ansible/library']
  ansible python module location = /usr/lib/python2.7/site-packages/ansible
  executable location = /usr/bin/ansible
  python version = 2.7.5 (default, Feb 20 2018, 09:19:12) [GCC 4.8.5 20150623 (Red Hat 4.8.5-28)]

[dw]

Hi Dan :) Can you please try http://github.com/dw/mitogen/archive/dmw.tar.gz and let me know if the problem persists? I was able to reproduce your issue when a pip-installed old version of the package exists, and the commit above works around that.

[danquack]

@dw good to close