Mitogen fails on `pip` module

[strangeman]

• Ansible and Python versions:

ansible --version
ansible 2.7.9
  configured module search path = [u'/home/strangeman/.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.16 (default, Apr  6 2019, 01:42:57) [GCC 8.3.0]

• Ansible config:

ANSIBLE_PIPELINING(/mnt/src/sources/playbooks/ansible.cfg) = True
ANSIBLE_SSH_ARGS(/mnt/src/sources/playbooks/ansible.cfg) = -o StrictHostKeyChecking=no -o PreferredAuthentications=publickey -o ControlMaster=auto -o ControlPersist=60s
CACHE_PLUGIN(/mnt/src/sources/playbooks/ansible.cfg) = yaml
CACHE_PLUGIN_CONNECTION(/mnt/src/sources/playbooks/ansible.cfg) = ./ansible-cache
CACHE_PLUGIN_TIMEOUT(/mnt/src/sources/playbooks/ansible.cfg) = 86400
DEFAULT_CALLBACK_WHITELIST(/mnt/src/sources/playbooks/ansible.cfg) = [u'print_changed']
DEFAULT_GATHERING(/mnt/src/sources/playbooks/ansible.cfg) = smart
DEFAULT_LOOKUP_PLUGIN_PATH(/mnt/src/sources/playbooks/ansible.cfg) = [u'/mnt/src/sources/playbooks/lookup_plugins']
DEFAULT_MANAGED_STR(/mnt/src/sources/playbooks/ansible.cfg) = Ansible managed, do not edit directly
DEFAULT_ROLES_PATH(/mnt/src/sources/playbooks/ansible.cfg) = [u'/mnt/src/sources/playbooks/roles']
DEFAULT_STRATEGY(/mnt/src/sources/playbooks/ansible.cfg) = mitogen_linear
DEFAULT_STRATEGY_PLUGIN_PATH(/mnt/src/sources/playbooks/ansible.cfg) = [u'/usr/local/lib/python2.7/dist-packages/ansible_mitogen/plugins/strategy']
DEFAULT_TIMEOUT(/mnt/src/sources/playbooks/ansible.cfg) = 60
RETRY_FILES_ENABLED(/mnt/src/sources/playbooks/ansible.cfg) = False
RETRY_FILES_SAVE_PATH(/mnt/src/sources/playbooks/ansible.cfg) = /mnt/src/sources/playbooks/.ansible-retry

• On target hosts we use Centos 7 with Python 2.7.5
• Mitogen version: 0.2.7 (also tried with master version).
• Sample playbook:

- name: Install gunicorn and wheel
  pip: name={{ item }} executable=/opt/nginxauth/env/bin/pip
  become: true
  become_user: "nginxauth"
  with_items:
    - gunicorn
    - wheel

• Fail log:

The full traceback is:
Traceback (most recent call last):
  File "master:/usr/local/lib/python2.7/dist-packages/ansible_mitogen/runner.py", line 883, in _run
    self._run_code(code, mod)
  File "master:/usr/local/lib/python2.7/dist-packages/ansible_mitogen/runner.py", line 862, in _run_code
    exec('exec code in vars(mod)')
  File "<string>", line 1, in <module>
  File "master:/usr/local/lib/python2.7/dist-packages/ansible/modules/packaging/language/pip.py", line 240, in <module>
  File "/usr/lib/python2.7/site-packages/pkg_resources.py", line 2998, in <module>
    _declare_state('object', working_set = WorkingSet())
  File "/usr/lib/python2.7/site-packages/pkg_resources.py", line 476, in __init__
    self.add_entry(entry)
  File "/usr/lib/python2.7/site-packages/pkg_resources.py", line 491, in add_entry
    for dist in find_distributions(entry, True):
  File "/usr/lib/python2.7/site-packages/pkg_resources.py", line 1982, in find_on_path
    path_item = _normalize_cached(path_item)
  File "/usr/lib/python2.7/site-packages/pkg_resources.py", line 2142, in _normalize_cached
    _cache[filename] = result = normalize_path(filename)
  File "/usr/lib/python2.7/site-packages/pkg_resources.py", line 2136, in normalize_path
    return os.path.normcase(os.path.realpath(filename))
  File "/usr/lib64/python2.7/posixpath.py", line 368, in realpath
    return abspath(path)
  File "/usr/lib64/python2.7/posixpath.py", line 356, in abspath
    cwd = os.getcwd()
OSError: [Errno 2] No such file or directory


failed: [testhost.com] (item=[u'gunicorn', u'wheel']) => {
    "changed": false, 
    "item": [
        "gunicorn", 
        "wheel"
    ], 
    "module_stderr": "Traceback (most recent call last):\n  File \"master:/usr/local/lib/python2.7/dist-packages/ansible_mitogen/runner.py\", line 883, in _run\n    self._run_code(code, mod)\n  File \"master:/usr/local/lib/python2.7/dist-packages/ansible_mitogen/runner.py\", line 862, in _run_code\n    exec('exec code in vars(mod)')\n  File \"<string>\", line 1, in <module>\n  File \"master:/usr/local/lib/python2.7/dist-packages/ansible/modules/packaging/language/pip.py\", line 240, in <module>\n  File \"/usr/lib/python2.7/site-packages/pkg_resources.py\", line 2998, in <module>\n    _declare_state('object', working_set = WorkingSet())\n  File \"/usr/lib/python2.7/site-packages/pkg_resources.py\", line 476, in __init__\n    self.add_entry(entry)\n  File \"/usr/lib/python2.7/site-packages/pkg_resources.py\", line 491, in add_entry\n    for dist in find_distributions(entry, True):\n  File \"/usr/lib/python2.7/site-packages/pkg_resources.py\", line 1982, in find_on_path\n    path_item = _normalize_cached(path_item)\n  File \"/usr/lib/python2.7/site-packages/pkg_resources.py\", line 2142, in _normalize_cached\n    _cache[filename] = result = normalize_path(filename)\n  File \"/usr/lib/python2.7/site-packages/pkg_resources.py\", line 2136, in normalize_path\n    return os.path.normcase(os.path.realpath(filename))\n  File \"/usr/lib64/python2.7/posixpath.py\", line 368, in realpath\n    return abspath(path)\n  File \"/usr/lib64/python2.7/posixpath.py\", line 356, in abspath\n    cwd = os.getcwd()\nOSError: [Errno 2] No such file or directory\n", 
    "module_stdout": "", 
    "msg": "MODULE FAILURE\nSee stdout/stderr for the exact error", 
    "rc": 1
}

[dw]

Thanks for reporting this, it looks new. Can you please check what version of pip is installed on those machines (pip --version should suffice)

[strangeman]

pip 9.0.1. Upgrade to latest (19.1.1) doesn't help, same error.

[dw]

This may be a new issue as of Ansible 2.7:

The pip module has added a dependency on setuptools to support version requirements, this requirement is for the Python interpreter that executes the module and not the Python interpreter that the module is managing.

pkg_resources is a component of setuptools. Looks like it's trying to parse the "master:" filenames and failing, should be a relatively easy fix

[nigelm]

I think I have just run into the same issue, although it was being disguised for me by me installing python36 from EPEL and using pip with a venv based on python36. However I am also using a target of Centos 7.6.1810 and ansible 2.7.10 (running on a Mac).

In any case, you can work around for this task by setting mitogen_task_isolation: fork - so my previously failing task looks like this:-

- name: build app requirements
  pip:
    requirements: ~healthchecks/webapp/healthchecks/requirements.txt
    virtualenv:   ~healthchecks/webapp/venv
    virtualenv_command: /usr/bin/python3.6 -m venv
  become_user: healthchecks
  vars:
    mitogen_task_isolation: fork

[strangeman]

@nigelm thanks for the workaround, it helped!

[dw]

@nigelm that's a curious discovery! Thanks for mentioning the workaround, it means this must be some kind of new state sharing issue

[dw]

Related-ish: ansible/ansible#47361

In this instance, pkg_resources may be a red herring. realpath() does not fail when fed "master:"-prefixed paths, or indeed when fed complete junk. The key is:

  File "/usr/lib64/python2.7/posixpath.py", line 356, in abspath
    cwd = os.getcwd()
OSError: [Errno 2] No such file or directory

Where:

ERRORS
       ENOENT The current working directory has been unlinked.

That likely means a prior module invocation has changed the process CWD to somewhere within a temporary directory belonging to a prior task, and during task cleanup that directory was removed. I'm very surprised this hasn't been an issue previously :) It also explains why "mitogen_task_isolation: fork" solves the problem (the fork parent has a constant CWD inherited from whatever SSH set up, probably the user homedir)

If there are only a few previous tasks, would you mind listing the module names being used? I'd like to add a test for this, so it'd be nice to know how it happens.

In any case I believe the fix is straightforward - we should be saving and restoring the CWD across tasks. Will hold off on doing this until we have a reproduction, in case this diagnosis is way of.

[dw]

Some possible candidates:

] ag '\bchdir\(' modules
modules/commands/command.py:259:        os.chdir(chdir)
modules/commands/expect.py:167:        os.chdir(chdir)
modules/network/f5/bigip_command.py:375:    def chdir(self):
modules/system/service.py:246:            os.chdir("/")

The support code also has quite elaborate code for ensuring CWD is sane before executing any module (basic.py "_set_cwd"), but it discards any errors that occur. The last remaining instance relates to "chdir("/")", which seems unlikely to be capable of generating ENOENT

edit: looks like it could be caused by anything calling AnsibleModule.run_command(..., cwd=...), which means pretty much any module :)

[dw]

Trivial repro (uses custom module from integration tests lib/modules/)

- hosts: cos7
  become: true
  tasks:
  - custom_python_run_script:
      script: |
        import os
        os.chdir(module.tmpdir)
        result['tmpdir'] = module.tmpdir
  - pip:
      name: pip
      virtualenv: /opt/nginxauth/env

Definitely a CWD issue.

[dw]

This is now on the master branch and will make it into the next release. To be updated when a new release is made, subscribe to https://networkgenomics.com/mail/mitogen-announce/

Thanks for reporting this!