mitogen-hq / mitogen

Distributed self-replicating programs in Python
https://mitogen.networkgenomics.com/
BSD 3-Clause "New" or "Revised" License
2.34k stars 199 forks source link

docker_image_info fails with "Error: Module unable to decode valid JSON on stdin." #819

Closed anxstj closed 2 years ago

anxstj commented 3 years ago

The docker_image_info module fails to work with mitogon 0.3.0.

# ansible --version
ansible 2.10.6
  config file = /etc/ansible/ansible.cfg
  configured module search path = ['/root/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /usr/local/lib/python3.7/dist-packages/ansible
  executable location = /usr/local/bin/ansible
  python version = 3.7.3 (default, Jul 25 2020, 13:03:44) [GCC 8.3.0]
# ansible-config dump --only-changed
<empty>

Example playbook which demonstrates the error:

# cat create.yml 
---
- name: Create
  hosts: localhost
  connection: local
  gather_facts: false
  strategy: mitogen_linear

  tasks:
    - set_fact:
        molecule_yml:
          platforms:
            - name: debian
    - name: Discover local Docker images
      docker_image_info:
        name: "molecule_local/{{ item.name }}"
        docker_host: 'unix://var/run/docker.sock'
      with_items: "{{ molecule_yml.platforms }}"

The call which reproduces the error:

# ansible-playbook -vvv create.yml
...
TASK [Discover local Docker images] **************************************************************************************************
task path: /tests/unit_test/create.yml:13
redirecting (type: modules) ansible.builtin.docker_image_info to community.general.docker_image_info
[task 2031] 15:55:51.071750 D ansible_mitogen.affinity: CPU mask for WorkerProcess: 0x000008
[task 2031] 15:55:51.097813 D ansible_mitogen.process: will use multiplexer 0 (/tmp/mitogen_unix_4i3mvo2u.sock) to connect to "localhost"                                                                                                                                   
[task 2031] 15:55:51.098147 D mitogen.unix: client: connecting to /tmp/mitogen_unix_4i3mvo2u.sock
[task 2031] 15:55:51.098516 D mitogen.unix: client: local ID is 1, remote is 0
[mux  1995] 15:55:51.098611 D mitogen.unix: listener: accepted connection from PID 2031: unix_client.2031
[mux  1995] 15:55:51.099630 D mitogen.parent: creating connection to context 2 using mitogen.parent
[mux  1995] 15:55:51.217154 D mitogen.parent: command line for Connection(None): /usr/bin/python3 -c "import codecs,os,sys;_=codecs.decode;exec(_(_(\"eNqFkt2K2zAQha/tpxD0QhIxkZ00LDY1tKS0FLqkOGVT2A1FsSddEUcSkrKu+/SdOPuTbC96Y/RpxkfnDFMlq9L4sVUWGI9d0p2R2hKErXE7xos4wnNzsBOWJlma8heuknNyWM1OXLfGA6vOwZ3D6hw6hDck3CtPGgNe00CktW1PpO73xgEJhlzLmiyWP0iWjrPZiLCP0nVKkywf8YRo6IjSAZx1gF/SGrPzpFU7GFSLo7xY9j7AXnxVGyddLz45uYcOA3rxrQ/3Ro+3TzfiBpxXRnsxGV+JCrw5uBqe+9CbmBt8Tgcv0Ndi+ViJIxyb73GIrQw4uz0pS0KbwSnFMM1QhN9QH4LctDCUxcE7sVFa2EHj1HcXR1GEidiT0thBCxJnxW+LyZqTd5gcY0WvBEfl8MTDyf9tMV0PYwb9oBwy/VB9vknpurz87dSD2LLLQnKJI8r2KphfoAtnTHifTWQO07f5TEJdZHk+45THKNU5FYBlCb3+8n2RpumdpmihNg3a5/G8/MmOu9UYCxo3iroN5ZhPNiy7Sqc5T+gfZVFpa8uXvlVCuw09rtvWPj4wH86nFXrV3f2v+1+X2aXL5+Wc8L/3rgIK\".encode(),\"base64\"),\"zip\"))"            
[mux  1995] 15:55:51.223568 D mitogen.parent: child for Connection(None) started: pid:2034 stdin:77 stdout:77 stderr:None
[mux  1995] 15:55:51.241924 D mitogen.parent: BootstrapProtocol(local.2034): first stage started succcessfully
[mux  1995] 15:55:51.243855 D mitogen.parent: BootstrapProtocol(local.2034): first stage received mitogen.core source
[mux  1995] 15:55:51.290546 D mitogen.parent: BootstrapProtocol(local.2034): new child booted successfully
[mux  1995] 15:55:51.290957 D mitogen.[local.2034]: Python version is 3.7.3 (default, Jul 25 2020, 13:03:44) 
[GCC 8.3.0]
[mux  1995] 15:55:51.291061 D mitogen.[local.2034]: Parent is context 0 (master); my ID is 2
[mux  1995] 15:55:51.291138 D mitogen.[local.2034]: pid:2034 ppid:1995 uid:0/0, gid:0/0 host:'12a9e3495aec'
[mux  1995] 15:55:51.291219 D mitogen.[local.2034]: Recovered sys.executable: '/usr/bin/python3'
[mux  1995] 15:55:51.291734 D mitogen.parent: starting function call to local.2034: ansible_mitogen.target.init_child(log_level=10, candidate_temp_dirs=['~/.ansible/tmp', '/var/tmp', '/tmp'])                                                                             
[mux  1995] 15:55:51.292369 D mitogen.responder: ansible is a package at /usr/local/lib/python3.7/dist-packages/ansible/__init__.py with submodules ['_vendor', 'cli', 'collections', 'compat', 'config', 'constants', 'context', 'errors', 'executor', 'galaxy', 'inventory', 'module_utils', 'modules', 'parsing', 'playbook', 'plugins', 'release', 'template', 'utils', 'vars']                               
[mux  1995] 15:55:51.292643 D mitogen.responder: sending ansible (0.52 KiB) to local.2034
[mux  1995] 15:55:51.293107 D mitogen.responder: ansible.module_utils is a package at /usr/local/lib/python3.7/dist-packages/ansible/module_utils/__init__.py with submodules ['_text', 'ansible_release', 'api', 'basic', 'common', 'compat', 'connection', 'csharp', 'distro', 'facts', 'json_utils', 'parsing', 'powershell', 'pycompat24', 'service', 'six', 'splitter', 'urls', 'yumdnf']                    
[mux  1995] 15:55:51.293322 D mitogen.responder: sending ansible.module_utils (0.47 KiB) to local.2034
[mux  1995] 15:55:51.341697 D mitogen: PkgutilMethod(): loading 'ansible.module_utils.distro' using <_frozen_importlib_external.SourceFileLoader object at 0x7f939c2ef0b8> failed: loader for distro cannot handle ansible.module_utils.distro                              
[mux  1995] 15:55:51.341831 D mitogen: _get_module_via_sys_modules('ansible.module_utils.distro') -> <module 'distro' from '/usr/local/lib/python3.7/dist-packages/distro.py'>                                                                                              
[mux  1995] 15:55:51.341912 D mitogen: sys.modules['ansible.module_utils.distro'].__name__ is incorrect, assuming this is a hacky module alias and ignoring it. Got 'distro', module object: <module 'distro' from '/usr/local/lib/python3.7/dist-packages/distro.py'>      
[mux  1995] 15:55:51.342046 D mitogen: ParentEnumerationMethod(): 'ansible.module_utils.distro' is PKG_DIRECTORY: '/usr/local/lib/python3.7/dist-packages/ansible/module_utils/distro/__init__.py'                                                                          
[mux  1995] 15:55:51.379146 D mitogen: _get_module_via_sys_modules('markupsafe._speedups') -> <module 'markupsafe._speedups' from '/usr/local/lib/python3.7/dist-packages/markupsafe/_speedups.cpython-37m-x86_64-linux-gnu.so'>                                            
[mux  1995] 15:55:51.379423 D mitogen: get_module_source('markupsafe._speedups'): cannot find source
[mux  1995] 15:55:51.422386 D mitogen: _get_module_via_sys_modules('yaml._yaml') -> <module 'yaml._yaml' from '/usr/local/lib/python3.7/dist-packages/yaml/_yaml.cpython-37m-x86_64-linux-gnu.so'>                                                                          
[mux  1995] 15:55:51.422661 D mitogen: get_module_source('yaml._yaml'): cannot find source
[mux  1995] 15:55:51.423052 D mitogen.responder: ansible.config is a package at /usr/local/lib/python3.7/dist-packages/ansible/config/__init__.py with submodules ['data', 'manager']                                                                                       
[mux  1995] 15:55:51.423205 D mitogen.responder: sending ansible.config (0.22 KiB) to local.2034
[mux  1995] 15:55:51.423459 D mitogen.responder: sending ansible.config.data (0.90 KiB) to local.2034
[mux  1995] 15:55:51.426152 D mitogen.responder: sending ansible.config.manager (10.46 KiB) to local.2034
[mux  1995] 15:55:51.427107 D mitogen.responder: sending ansible.constants (5.65 KiB) to local.2034
[mux  1995] 15:55:51.427469 D mitogen.responder: sending ansible.context (2.00 KiB) to local.2034
[mux  1995] 15:55:51.428143 D mitogen.responder: ansible.errors is a package at /usr/local/lib/python3.7/dist-packages/ansible/errors/__init__.py with submodules ['yaml_strings']                                                                                          
[mux  1995] 15:55:51.428852 D mitogen.responder: sending ansible.errors (6.49 KiB) to local.2034
[mux  1995] 15:55:51.429246 D mitogen.responder: sending ansible.errors.yaml_strings (2.91 KiB) to local.2034
[mux  1995] 15:55:51.429449 D mitogen.responder: sending ansible.module_utils._text (0.92 KiB) to local.2034
[mux  1995] 15:55:51.429803 D mitogen.responder: ansible.module_utils.common is a package at /usr/local/lib/python3.7/dist-packages/ansible/module_utils/common/__init__.py with submodules ['_collections_compat', '_json_compat', '_utils', 'collections', 'dict_transformations', 'file', 'json', 'network', 'parameters', 'process', 'removed', 'sys_info', 'text', 'validation', 'warnings']                 
[mux  1995] 15:55:51.429935 D mitogen.responder: sending ansible.module_utils.common (0.49 KiB) to local.2034
[mux  1995] 15:55:51.430144 D mitogen.responder: sending ansible.module_utils.common._collections_compat (1.03 KiB) to local.2034
[mux  1995] 15:55:51.430323 D mitogen.responder: sending ansible.module_utils.common._json_compat (0.81 KiB) to local.2034
[mux  1995] 15:55:51.430587 D mitogen.responder: sending ansible.module_utils.common._utils (1.32 KiB) to local.2034
[mux  1995] 15:55:51.430946 D mitogen.responder: sending ansible.module_utils.common.collections (2.44 KiB) to local.2034
[mux  1995] 15:55:51.431457 D mitogen.responder: sending ansible.module_utils.common.file (3.87 KiB) to local.2034
[mux  1995] 15:55:51.432137 D mitogen.responder: sending ansible.module_utils.common.parameters (4.43 KiB) to local.2034
[mux  1995] 15:55:51.432420 D mitogen.responder: sending ansible.module_utils.common.process (1.62 KiB) to local.2034
[mux  1995] 15:55:51.432904 D mitogen.responder: sending ansible.module_utils.common.sys_info (3.05 KiB) to local.2034
[mux  1995] 15:55:51.433186 D mitogen.responder: ansible.module_utils.common.text is a package at /usr/local/lib/python3.7/dist-packages/ansible/module_utils/common/text/__init__.py with submodules ['converters', 'formatters']                                          
[mux  1995] 15:55:51.433333 D mitogen.responder: sending ansible.module_utils.common.text (0.33 KiB) to local.2034
[mux  1995] 15:55:51.434280 D mitogen.responder: sending ansible.module_utils.common.text.converters (5.15 KiB) to local.2034
[mux  1995] 15:55:51.434694 D mitogen.responder: sending ansible.module_utils.common.text.formatters (2.61 KiB) to local.2034
[mux  1995] 15:55:51.436098 D mitogen.responder: sending ansible.module_utils.common.validation (6.61 KiB) to local.2034
[mux  1995] 15:55:51.436355 D mitogen.responder: sending ansible.module_utils.common.warnings (1.19 KiB) to local.2034
[mux  1995] 15:55:51.436647 D mitogen.responder: ansible.module_utils.compat is a package at /usr/local/lib/python3.7/dist-packages/ansible/module_utils/compat/__init__.py with submodules ['_selectors2', 'importlib', 'paramiko', 'selectors']                           
[mux  1995] 15:55:51.436771 D mitogen.responder: sending ansible.module_utils.compat (0.31 KiB) to local.2034
[mux  1995] 15:55:51.437021 D mitogen.responder: ansible.module_utils.distro is a package at /usr/local/lib/python3.7/dist-packages/ansible/module_utils/distro/__init__.py with submodules ['_distro']                                                                     
[mux  1995] 15:55:51.437218 D mitogen.responder: sending ansible.module_utils.distro (1.55 KiB) to local.2034
[mux  1995] 15:55:51.437420 D mitogen.responder: ansible.module_utils.parsing is a package at /usr/local/lib/python3.7/dist-packages/ansible/module_utils/parsing/__init__.py with submodules ['convert_bool']                                                              
[mux  1995] 15:55:51.437539 D mitogen.responder: sending ansible.module_utils.parsing (0.27 KiB) to local.2034
[mux  1995] 15:55:51.437791 D mitogen.responder: sending ansible.module_utils.parsing.convert_bool (1.32 KiB) to local.2034
[mux  1995] 15:55:51.438162 D mitogen.responder: sending ansible.module_utils.pycompat24 (2.97 KiB) to local.2034
[mux  1995] 15:55:51.439086 D mitogen.responder: ansible.module_utils.six is a package at /usr/local/lib/python3.7/dist-packages/ansible/module_utils/six/__init__.py with submodules []                                                                                    
[mux  1995] 15:55:51.440939 D mitogen.responder: sending ansible.module_utils.six (12.14 KiB) to local.2034
[mux  1995] 15:55:51.441371 D mitogen.responder: ansible.parsing is a package at /usr/local/lib/python3.7/dist-packages/ansible/parsing/__init__.py with submodules ['ajson', 'dataloader', 'mod_args', 'plugin_docs', 'quoting', 'splitter', 'utils', 'vault', 'yaml']     
[mux  1995] 15:55:51.441576 D mitogen.responder: sending ansible.parsing (1.06 KiB) to local.2034
[mux  1995] 15:55:51.441859 D mitogen.responder: sending ansible.parsing.quoting (1.17 KiB) to local.2034
[mux  1995] 15:55:51.442144 D mitogen.responder: ansible.parsing.yaml is a package at /usr/local/lib/python3.7/dist-packages/ansible/parsing/yaml/__init__.py with submodules ['constructor', 'dumper', 'loader', 'objects']                                                
[mux  1995] 15:55:51.442305 D mitogen.responder: sending ansible.parsing.yaml (1.02 KiB) to local.2034
[mux  1995] 15:55:51.443130 D mitogen.responder: sending ansible.parsing.yaml.objects (4.84 KiB) to local.2034
[mux  1995] 15:55:51.443574 D mitogen.responder: ansible.utils is a package at /usr/local/lib/python3.7/dist-packages/ansible/utils/__init__.py with submodules ['cmd_functions', 'collection_loader', 'color', 'context_objects', 'display', 'encrypt', 'fqcn', 'galaxy', 'hashing', 'helpers', 'jsonrpc', 'listify', 'multiprocessing', 'path', 'plugin_docs', 'py3compat', 'sentinel', 'shlex', 'singleton', 'ssh_functions', 'unicode', 'unsafe_proxy', 'vars', 'version']                                                                          
[mux  1995] 15:55:51.443743 D mitogen.responder: sending ansible.utils (1.29 KiB) to local.2034
[mux  1995] 15:55:51.444456 D mitogen.responder: sending ansible.utils.color (3.82 KiB) to local.2034
[mux  1995] 15:55:51.444850 D mitogen.responder: sending ansible.utils.context_objects (2.21 KiB) to local.2034
[mux  1995] 15:55:51.446426 D mitogen.responder: sending ansible.utils.display (8.37 KiB) to local.2034
[mux  1995] 15:55:51.446711 D mitogen.responder: sending ansible.utils.fqcn (1.19 KiB) to local.2034
[mux  1995] 15:55:51.447251 D mitogen.responder: sending ansible.utils.path (3.81 KiB) to local.2034
[mux  1995] 15:55:51.447590 D mitogen.responder: sending ansible.utils.py3compat (1.87 KiB) to local.2034
[mux  1995] 15:55:51.447840 D mitogen.responder: sending ansible.utils.singleton (0.91 KiB) to local.2034
[mux  1995] 15:55:51.448298 D mitogen.responder: sending ansible.utils.unsafe_proxy (3.80 KiB) to local.2034
[mux  1995] 15:55:51.448583 D mitogen.responder: sending ansible.module_utils.basic (42.68 KiB) to local.2034
[mux  1995] 15:55:51.449402 D mitogen.responder: sending ansible.module_utils.json_utils (2.61 KiB) to local.2034
[mux  1995] 15:55:51.449828 D mitogen.responder: sending ansible.release (1.00 KiB) to local.2034
[mux  1995] 15:55:51.450263 D mitogen.responder: ansible_mitogen is a package at /usr/local/share/mitogen/ansible_mitogen/__init__.py with submodules ['affinity', 'compat', 'connection', 'loaders', 'logging', 'mixins', 'module_finder', 'parsing', 'planner', 'plugins', 'process', 'runner', 'services', 'strategy', 'target', 'transport_config']                                                           
[mux  1995] 15:55:51.450414 D mitogen.responder: sending ansible_mitogen (0.41 KiB) to local.2034
[mux  1995] 15:55:51.533437 D mitogen.responder: sending ansible_mitogen.target (7.91 KiB) to local.2034
[mux  1995] 15:55:51.540179 D mitogen.responder: sending mitogen.fork (2.61 KiB) to local.2034
[mux  1995] 15:55:51.620572 D mitogen.responder: sending mitogen.parent (18.83 KiB) to local.2034
[mux  1995] 15:55:51.626504 D mitogen.responder: sending mitogen.select (1.60 KiB) to local.2034
[mux  1995] 15:55:51.661976 D mitogen.responder: sending mitogen.service (8.88 KiB) to local.2034
[mux  1995] 15:55:51.662195 D mitogen.responder: sending ansible_mitogen.runner (8.71 KiB) to local.2034
[mux  1995] 15:55:51.662457 D mitogen.importer.[local.2034]: received ansible
[mux  1995] 15:55:51.662555 D mitogen.importer.[local.2034]: received ansible.module_utils
[mux  1995] 15:55:51.662655 D mitogen.importer.[local.2034]: received ansible.config
[mux  1995] 15:55:51.662746 D mitogen.importer.[local.2034]: received ansible.config.data
[mux  1995] 15:55:51.662831 D mitogen.importer.[local.2034]: received ansible.config.manager
[mux  1995] 15:55:51.662918 D mitogen.importer.[local.2034]: received ansible.constants
[mux  1995] 15:55:51.663004 D mitogen.importer.[local.2034]: received ansible.context
[mux  1995] 15:55:51.663090 D mitogen.importer.[local.2034]: received ansible.errors
[mux  1995] 15:55:51.663174 D mitogen.importer.[local.2034]: received ansible.errors.yaml_strings
[mux  1995] 15:55:51.663257 D mitogen.importer.[local.2034]: received ansible.module_utils._text
[mux  1995] 15:55:51.663337 D mitogen.importer.[local.2034]: received ansible.module_utils.common
[mux  1995] 15:55:51.663416 D mitogen.importer.[local.2034]: received ansible.module_utils.common._collections_compat
[mux  1995] 15:55:51.663493 D mitogen.importer.[local.2034]: received ansible.module_utils.common._json_compat
[mux  1995] 15:55:51.663573 D mitogen.importer.[local.2034]: received ansible.module_utils.common._utils
[mux  1995] 15:55:51.663663 D mitogen.importer.[local.2034]: received ansible.module_utils.common.collections
[mux  1995] 15:55:51.663743 D mitogen.importer.[local.2034]: received ansible.module_utils.common.file
[mux  1995] 15:55:51.663820 D mitogen.importer.[local.2034]: received ansible.module_utils.common.parameters
[mux  1995] 15:55:51.663898 D mitogen.importer.[local.2034]: received ansible.module_utils.common.process
[mux  1995] 15:55:51.663978 D mitogen.importer.[local.2034]: received ansible.module_utils.common.sys_info
[mux  1995] 15:55:51.664056 D mitogen.importer.[local.2034]: received ansible.module_utils.common.text
[mux  1995] 15:55:51.664133 D mitogen.importer.[local.2034]: received ansible.module_utils.common.text.converters
[mux  1995] 15:55:51.664212 D mitogen.importer.[local.2034]: received ansible.module_utils.common.text.formatters
[mux  1995] 15:55:51.664289 D mitogen.importer.[local.2034]: received ansible.module_utils.common.validation
[mux  1995] 15:55:51.664370 D mitogen.importer.[local.2034]: received ansible.module_utils.common.warnings
[mux  1995] 15:55:51.664457 D mitogen.importer.[local.2034]: received ansible.module_utils.compat
[mux  1995] 15:55:51.664544 D mitogen.importer.[local.2034]: received ansible.module_utils.distro
[mux  1995] 15:55:51.664633 D mitogen.importer.[local.2034]: received ansible.module_utils.parsing
[mux  1995] 15:55:51.664714 D mitogen.importer.[local.2034]: received ansible.module_utils.parsing.convert_bool
[mux  1995] 15:55:51.664793 D mitogen.importer.[local.2034]: received ansible.module_utils.pycompat24
[mux  1995] 15:55:51.664872 D mitogen.importer.[local.2034]: received ansible.module_utils.six
[mux  1995] 15:55:51.664949 D mitogen.importer.[local.2034]: received ansible.parsing
[mux  1995] 15:55:51.665029 D mitogen.importer.[local.2034]: received ansible.parsing.quoting
[mux  1995] 15:55:51.665107 D mitogen.importer.[local.2034]: received ansible.parsing.yaml
[mux  1995] 15:55:51.665184 D mitogen.importer.[local.2034]: received ansible.parsing.yaml.objects
[mux  1995] 15:55:51.665261 D mitogen.importer.[local.2034]: received ansible.utils
[mux  1995] 15:55:51.665338 D mitogen.importer.[local.2034]: received ansible.utils.color
[mux  1995] 15:55:51.665416 D mitogen.importer.[local.2034]: received ansible.utils.context_objects
[mux  1995] 15:55:51.665496 D mitogen.importer.[local.2034]: received ansible.utils.display
[mux  1995] 15:55:51.665573 D mitogen.importer.[local.2034]: received ansible.utils.fqcn
[mux  1995] 15:55:51.665657 D mitogen.importer.[local.2034]: received ansible.utils.path
[mux  1995] 15:55:51.665733 D mitogen.importer.[local.2034]: received ansible.utils.py3compat
[mux  1995] 15:55:51.665810 D mitogen.importer.[local.2034]: received ansible.utils.singleton
[mux  1995] 15:55:51.665888 D mitogen.importer.[local.2034]: received ansible.utils.unsafe_proxy
[mux  1995] 15:55:51.665965 D mitogen.importer.[local.2034]: received ansible.module_utils.basic
[mux  1995] 15:55:51.666042 D mitogen.importer.[local.2034]: received ansible.module_utils.json_utils
[mux  1995] 15:55:51.666119 D mitogen.importer.[local.2034]: received ansible.release
[mux  1995] 15:55:51.666196 D mitogen.importer.[local.2034]: received ansible_mitogen
[mux  1995] 15:55:51.666273 D mitogen.importer.[local.2034]: received ansible_mitogen.target
[mux  1995] 15:55:51.666353 D mitogen.importer.[local.2034]: received mitogen.fork
[mux  1995] 15:55:51.666432 D mitogen.importer.[local.2034]: received mitogen.parent
[mux  1995] 15:55:51.666510 D mitogen.importer.[local.2034]: received mitogen.select
[mux  1995] 15:55:51.666586 D mitogen.importer.[local.2034]: received mitogen.service
[mux  1995] 15:55:51.666721 D mitogen.importer.[local.2034]: received ansible_mitogen.runner
[mux  1995] 15:55:51.666806 D mitogen.[local.2034]: Dispatcher: dispatching (None, 'ansible_mitogen.target', None, 'init_child', (), Kwargs({'log_level': 10, 'candidate_temp_dirs': ['~/.ansible/tmp', '/var/tmp', '/tmp']}))                                              
[mux  1995] 15:55:51.666882 D mitogen.importer.[local.2034]: requesting ansible_mitogen
[mux  1995] 15:55:51.666955 D mitogen.importer.[local.2034]: requesting ansible_mitogen.target
[mux  1995] 15:55:51.675032 D mitogen.importer.[local.2034]: requesting mitogen.fork
[mux  1995] 15:55:51.676105 D mitogen.importer.[local.2034]: requesting mitogen.parent
[mux  1995] 15:55:51.693135 D mitogen.importer.[local.2034]: requesting thread
[mux  1995] 15:55:51.693961 D mitogen.importer.[local.2034]: requesting mitogen.service
[mux  1995] 15:55:51.698541 D mitogen.importer.[local.2034]: requesting mitogen.select
[mux  1995] 15:55:51.700072 D mitogen.importer.[local.2034]: json.decoder is submodule of a locally loaded package
[mux  1995] 15:55:51.700486 D mitogen.importer.[local.2034]: json.scanner is submodule of a locally loaded package
[mux  1995] 15:55:51.701522 D mitogen.importer.[local.2034]: json.encoder is submodule of a locally loaded package
[mux  1995] 15:55:51.703138 D mitogen.importer.[local.2034]: requesting ansible
[mux  1995] 15:55:51.703436 D mitogen.importer.[local.2034]: requesting ansible.module_utils
[mux  1995] 15:55:51.703569 D mitogen.importer.[local.2034]: requesting ansible.module_utils.json_utils
[mux  1995] 15:55:51.704097 D mitogen.importer.[local.2034]: requesting ansible_mitogen.runner
[mux  1995] 15:55:51.709091 D mitogen.importer.[local.2034]: ctypes._endian is submodule of a locally loaded package
[mux  1995] 15:55:51.710011 D mitogen.importer.[local.2034]: requesting StringIO
[mux  1995] 15:55:51.710128 D mitogen.importer.[local.2034]: requesting ansible.module_utils.basic
[mux  1995] 15:55:51.725546 D mitogen.importer.[local.2034]: requesting systemd
[mux  1995] 15:55:51.731298 D mitogen.importer.[local.2034]: requesting ansible.module_utils.compat
[mux  1995] 15:55:51.731440 D mitogen.importer.[local.2034]: requesting ansible.module_utils.compat.selectors
[mux  1995] 15:55:51.731520 D mitogen.importer.[local.2034]: sending new ansible.module_utils.compat.selectors request to parent
[mux  1995] 15:55:51.731628 D mitogen.responder: local.2034 requested module ansible.module_utils.compat.selectors
[mux  1995] 15:55:51.731727 D mitogen: PkgutilMethod(): loading 'ansible.module_utils.compat.selectors' using <_frozen_importlib_external.SourceFileLoader object at 0x7f939da5d668> failed: loader for selectors cannot handle ansible.module_utils.compat.selectors       
[mux  1995] 15:55:51.731818 D mitogen: _get_module_via_sys_modules('ansible.module_utils.compat.selectors') -> <module 'selectors' from '/usr/lib/python3.7/selectors.py'>                                                                                                  
[mux  1995] 15:55:51.731901 D mitogen: sys.modules['ansible.module_utils.compat.selectors'].__name__ is incorrect, assuming this is a hacky module alias and ignoring it. Got 'selectors', module object: <module 'selectors' from '/usr/lib/python3.7/selectors.py'>       
[mux  1995] 15:55:51.732649 D mitogen.responder: sending ansible.module_utils.compat.selectors (1.99 KiB) to local.2034
[mux  1995] 15:55:51.733088 D mitogen.importer.[local.2034]: received ansible.module_utils.compat.selectors
[mux  1995] 15:55:51.733530 D mitogen.importer.[local.2034]: requesting ansible.module_utils._text
[mux  1995] 15:55:51.733795 D mitogen.importer.[local.2034]: requesting ansible.module_utils.six
[mux  1995] 15:55:51.738976 D mitogen.importer.[local.2034]: requesting ansible.module_utils.common
[mux  1995] 15:55:51.739112 D mitogen.importer.[local.2034]: requesting ansible.module_utils.common.text
[mux  1995] 15:55:51.739189 D mitogen.importer.[local.2034]: requesting ansible.module_utils.common.text.converters
[mux  1995] 15:55:51.740163 D mitogen.importer.[local.2034]: requesting ansible.module_utils.common._collections_compat
[mux  1995] 15:55:51.740289 D mitogen.importer.[local.2034]: requesting ansible.module_utils.common.text.formatters
[mux  1995] 15:55:51.740881 D mitogen.importer.[local.2034]: requesting ansible.module_utils.common._json_compat
[mux  1995] 15:55:51.741388 D mitogen.importer.[local.2034]: requesting ansible.module_utils.common.process
[mux  1995] 15:55:51.741486 D mitogen.importer.[local.2034]: requesting ansible.module_utils.common.file
[mux  1995] 15:55:51.742573 D mitogen.importer.[local.2034]: requesting ansible.module_utils.common.sys_info
[mux  1995] 15:55:51.743116 D mitogen.importer.[local.2034]: requesting ansible.module_utils.distro
[mux  1995] 15:55:51.743353 D mitogen.importer.[local.2034]: requesting ansible.module_utils.common._utils
[mux  1995] 15:55:51.743719 D mitogen.importer.[local.2034]: requesting ansible.module_utils.pycompat24
[mux  1995] 15:55:51.744843 D mitogen.importer.[local.2034]: requesting ansible.module_utils.common.parameters
[mux  1995] 15:55:51.745844 D mitogen.importer.[local.2034]: requesting ansible.module_utils.common.collections
[mux  1995] 15:55:51.746384 D mitogen.importer.[local.2034]: requesting ansible.module_utils.common.validation
[mux  1995] 15:55:51.748136 D mitogen.importer.[local.2034]: requesting ansible.module_utils.parsing
[mux  1995] 15:55:51.748566 D mitogen.importer.[local.2034]: requesting ansible.module_utils.parsing.convert_bool
[mux  1995] 15:55:51.749457 D mitogen.importer.[local.2034]: ansible.module_utils.six has no submodule moves
[mux  1995] 15:55:51.749580 D mitogen.importer.[local.2034]: requesting ansible.module_utils.common.warnings
[mux  1995] 15:55:51.749716 D ansible_mitogen.runner.[local.2034]: EnvironmentFileWatcher('/root/.pam_environment') installed; existing keys: []                                                                                                                            
[mux  1995] 15:55:51.750773 D ansible_mitogen.runner.[local.2034]: EnvironmentFileWatcher('/etc/environment') installed; existing keys: []                                                                                                                                  
[mux  1995] 15:55:51.751089 D mitogen.parent.[local.2034]: upgraded Poller with EpollPoller (new: 4 readers, 0 writers; old: 4 readers, 0 writers)                                                                                                                          
[mux  1995] 15:55:51.751184 D mitogen.parent.[local.2034]: upgrading Router(Broker(d240)) with capabilities to start new children
[mux  1995] 15:55:51.751268 D mitogen.[local.2034]: sending message to Context(0, 'master'): Message(0, 2, 2, 105, 1000, ''..0)
[mux  1995] 15:55:51.751380 D mitogen: IdAllocator(Router(Broker(4940))): allocating [3..1003)
[mux  1995] 15:55:51.751475 D mitogen: IdAllocator(Router(Broker(4940))): allocating [3..1003) to Context(2, 'local.2034')
[mux  1995] 15:55:51.752224 D mitogen.parent.[local.2034]: creating connection to context 3 using mitogen.fork
[mux  1995] 15:55:51.753424 D mitogen.parent.[local.2034]: child for Connection(None) started: pid:2039 stdin:15 stdout:15 stderr:None
[mux  1995] 15:55:51.754014 D mitogen.parent.[local.2034]: BootstrapProtocol(fork.2039): new child booted successfully
[mux  1995] 15:55:51.754163 D mitogen.[local.2034]: Router(Broker(d240)): registering Context(3, 'fork.2039') to stream <Stream fork.2039 #18d0>                                                                                                                            
[mux  1995] 15:55:51.754328 D mitogen.route_monitor: Adding route to 3 via <Stream local.2034 #c208>
[mux  1995] 15:55:51.754417 D mitogen.parent: Router(Broker(4940)): adding route to context 3 via <Stream local.2034 #c208>
[mux  1995] 15:55:51.755285 D ansible_mitogen.target.[local.2034]: Selected temp directory: '/root/.ansible/tmp' (from ['/root/.ansible/tmp', '/var/tmp', '/tmp', '/tmp', '/var/tmp', '/usr/tmp', '/tests/unit_test'])                                                      
[mux  1995] 15:55:51.755412 D mitogen.[local.2034]: Dispatcher: Message(2, 0, 0, 101, 1000, b'\x80\x02(NX\x16\x00\x00\x00ansible_mitogen.targetq\x00NX\n\x00\x00\x00init_childq'..186) -> {'fork_context': Context(3, 'fork.2039'), 'home_dir': '/root', 'good_temp_dir': '/root/.ansible/tmp'}                                                                                                                   
[mux  1995] 15:55:51.755763 D mitogen.[fork.2039]: Router(Broker(cf28)): registering Context(2, 'parent') to stream <Stream parent #1be0>                                                                                                                                   
[mux  1995] 15:55:51.755844 D mitogen.[fork.2039]: Python version is 3.7.3 (default, Jul 25 2020, 13:03:44) 
[GCC 8.3.0]
[mux  1995] 15:55:51.755913 D mitogen.[fork.2039]: Parent is context 2 (parent); my ID is 3
[mux  1995] 15:55:51.755981 D mitogen.[fork.2039]: pid:2039 ppid:2034 uid:0/0, gid:0/0 host:'12a9e3495aec'
[mux  1995] 15:55:51.756045 D mitogen.[fork.2039]: Recovered sys.executable: '/usr/bin/python3'
redirecting (type: modules) ansible.builtin.docker_image_info to community.general.docker_image_info
[task 2031] 15:55:51.760789 D ansible_mitogen.planner: <class 'ansible_mitogen.planner.BinaryPlanner'> rejected 'docker_image_info'
[task 2031] 15:55:51.760947 D ansible_mitogen.planner: <class 'ansible_mitogen.planner.NewStylePlanner'> rejected 'docker_image_info'
[task 2031] 15:55:51.761050 D ansible_mitogen.planner: <class 'ansible_mitogen.planner.JsonArgsPlanner'> rejected 'docker_image_info'
[task 2031] 15:55:51.761132 D ansible_mitogen.planner: <class 'ansible_mitogen.planner.WantJsonPlanner'> rejected 'docker_image_info'
[task 2031] 15:55:51.761203 D ansible_mitogen.planner: <class 'ansible_mitogen.planner.OldStylePlanner'> accepted 'docker_image_info' (filename '/usr/local/lib/python3.7/dist-packages/ansible_collections/community/general/plugins/modules/docker_image_info.py')        
[mux  1995] 15:55:51.761752 D mitogen.service: caching small file /usr/local/lib/python3.7/dist-packages/ansible_collections/community/general/plugins/modules/docker_image_info.py                                                                                         
[mux  1995] 15:55:51.761935 D mitogen.service: requesting Context(2, 'local.2034') cache and forward small file to Context(2, 'local.2034'): /usr/local/lib/python3.7/dist-packages/ansible_collections/community/general/plugins/modules/docker_image_info.py              
[task 2031] 15:55:51.762607 D mitogen.parent: starting function call to local.2034: ansible_mitogen.target.run_module(kwargs={'runner_name': 'OldStyleRunner', 'module': 'docker_image_info', 'path': '/usr/local/lib/python3.7/dist-packages/ansible_collections/community/general/plugins/modules/docker_image_info.py', 'json_args': '{"name": "molecule_local/debian", "docker_host": "unix://var/run/docker.sock", "_ansible_check_mode": false, "_ansible_no_log": false, "_ansible_debug": false, "_ansible_diff": false, "_ansible_verbosity": 3, "_ansible_version": "2.10.6", "_ansible_module_name": "docker_image_info", "_ansible_syslog_facility": "LOG_USER", "_ansible_selinux_special_fs": ["fuse", "nfs", "vboxsf", "ramfs", "9p", "vfat"], "_ansible_string_conversion_action": "warn", "_ansible_socket": null, "_ansible_shell_executable": "/bin/sh", "_ansible_keep_remote_files": false, "_ansible_tmpdir": null, "_ansible_remote_tmp": "~/.ansible/tmp"}', 'env': {}, 'interpreter_fragment': '/usr/bin/python3', 'is_python': False, 'good_temp_dir': '/root/.ansible/tmp', 'cwd': '/tests/unit_test', 'extra_env': {}, 'emulate_tty': True, 'service_context': Context(0, None)})                                         
[mux  1995] 15:55:51.763069 D mitogen.service.[local.2034]: PushFileService().store_and_forward('/usr/local/lib/python3.7/dist-packages/ansible_collections/community/general/plugins/modules/docker_image_info.py', [blob: 8673 bytes], Context(2, 'local.2034')) 'mitogen.Pool.dcf8.0'                                                                                                                          
[mux  1995] 15:55:51.763616 D mitogen.service.[local.2034]: Pool(dcf8, size=2, th='MainThread'): initialized
[mux  1995] 15:55:51.763907 D mitogen.[local.2034]: Dispatcher: dispatching ('12a9e3495aec-2031-7f939eb9e740-108c727cd5', 'ansible_mitogen.target', None, 'run_module', (), Kwargs({'kwargs': {'runner_name': 'OldStyleRunner', 'module': 'docker_image_info', 'path': '/usr/local/lib/python3.7/dist-packages/ansible_collections/community/general/plugins/modules/docker_image_info.py', 'json_args': '{"name": "molecule_local/debian", "docker_host": "unix://var/run/docker.sock", "_ansible_check_mode": false, "_ansible_no_log": false, "_ansible_debug": false, "_ansible_diff": false, "_ansible_verbosity": 3, "_ansible_version": "2.10.6", "_ansible_module_name": "docker_image_info", "_ansible_syslog_facility": "LOG_USER", "_ansible_selinux_special_fs": ["fuse", "nfs", "vboxsf", "ramfs", "9p", "vfat"], "_ansible_string_conversion_action": "warn", "_ansible_socket": null, "_ansible_shell_executable": "/bin/sh", "_ansible_keep_remote_files": false, "_ansible_tmpdir": null, "_ansible_remote_tmp": "~/.ansible/tmp"}', 'env': {}, 'interpreter_fragment': '/usr/bin/python3', 'is_python': False, 'good_temp_dir': '/root/.ansible/tmp', 'cwd': '/tests/unit_test', 'extra_env': {}, 'emulate_tty': True, 'service_context': Context(0, 'master')}}))                                                                                                        
[mux  1995] 15:55:51.764527 D ansible_mitogen.target.[local.2034]: exec_args(['/bin/sh', '-c', '/usr/bin/python3 /root/.ansible/tmp/ansible_mitogen_runner_68q5dpvs/docker_image_info.py /root/.ansible/tmp/ansible_mitogen_runner_68q5dpvs/ansible_mitogen22ngb1zb-args'], ..., chdir=None)                                                                                                                      
[mux  1995] 15:55:51.956554 D mitogen.[local.2034]: Dispatcher: Message(2, 1, 0, 101, 1002, b'\x80\x02(X)\x00\x00\x0012a9e3495aec-2031-7f939eb9e740-108c727cd5q'..1262) -> {'rc': 1, 'stdout': '\r\n{"msg": "Error: Module unable to decode valid JSON on stdin.  Unable to figure out what parameters were passed", "failed": true}\r\n', 'stderr': ''}                                                          
[task 2031] 15:55:51.958676 D ansible_mitogen.connection: Call took 196 ms: ansible_mitogen.target.run_module(kwargs={'runner_name': 'OldStyleRunner', 'module': 'docker_image_info', 'path': '/usr/local/lib/python3.7/dist-packages/ansible_collections/community/general/plugins/modules/docker_image_info.py', 'json_args': '{"name": "molecule_local/debian", "docker_host": "unix://var/run/docker.sock", "_ansible_check_mode": false, "_ansible_no_log": false, "_ansible_debug": false, "_ansible_diff": false, "_ansible_verbosity": 3, "_ansible_version": "2.10.6", "_ansible_module_name": "docker_image_info", "_ansible_syslog_facility": "LOG_USER", "_ansible_selinux_special_fs": ["fuse", "nfs", "vboxsf", "ramfs", "9p", "vfat"], "_ansible_string_conversion_action": "warn", "_ansible_socket": null, "_ansible_shell_executable": "/bin/sh", "_ansible_keep_remote_files": false, "_ansible_tmpdir": null, "_ansible_remote_tmp": "~/.ansible/tmp"}', 'env': {}, 'interpreter_fragment': '/usr/bin/python3', 'is_python': False, 'good_temp_dir': '/root/.ansible/tmp', 'cwd': '/tests/unit_test', 'extra_env': {}, 'emulate_tty': True, 'service_context': Context(0, None)})                                                 
[task 2031] 15:55:51.959043 D ansible_mitogen.mixins: _remove_tmp_path(None)
[task 2031] 15:55:51.959170 D ansible_mitogen.mixins: _remove_tmp_path(None)
[task 2031] 15:55:51.962607 D mitogen.parent: starting no-reply function call to 'local.2034': mitogen.core.Dispatcher.forget_chain('12a9e3495aec-2031-7f939eb9e740-108c727cd5')                                                                                            
[mux  1995] 15:55:51.963248 D ansible_mitogen.services: decrementing reference count for Context(2, 'local.2034')
[mux  1995] 15:55:51.963600 D mitogen.[local.2034]: Dispatcher: dispatching (None, 'mitogen.core', 'Dispatcher', 'forget_chain', ('12a9e3495aec-2031-7f939eb9e740-108c727cd5',), Kwargs({}))                                                                                
[mux  1995] 15:55:51.963723 D mitogen.[local.2034]: Dispatcher: Message(2, 1, 0, 101, 0, b'\x80\x02(NX\x0c\x00\x00\x00mitogen.coreq\x00X\n\x00\x00\x00Dispatcherq\x01X\x0c\x00\x00\x00forge'..146) -> None                                                                  
[task 2031] 15:55:51.964117 D mitogen: MitogenProtocol(unix_listener.1995): disconnecting
failed: [localhost] (item={'name': 'debian'}) => {
    "ansible_loop_var": "item",
    "changed": false,
    "item": {
        "name": "debian"
    },
    "msg": "Error: Module unable to decode valid JSON on stdin.  Unable to figure out what parameters were passed"
}
[mux  1995] 15:55:51.964449 D mitogen: <Side of unix_client.2031 fd 76>: empty read, disconnecting
[task 2031] 15:55:51.964404 D mitogen: Waker(fd=12/13): disconnecting
[mux  1995] 15:55:51.964717 D mitogen: MitogenProtocol(unix_client.2031): disconnecting
[task 2031] 15:55:51.964827 D mitogen: Router(Broker(d550)): stats: 0 module requests in 0 ms, 0 sent (0 ms minify time), 0 negative responses. Sent 0.0 kb total, 0.0 kb avg.                                                                                              

PLAY RECAP ***************************************************************************************************************************
localhost                  : ok=1    changed=0    unreachable=0    failed=1    skipped=0    rescued=0    ignored=0 
s1113950 commented 3 years ago

Does this work without Mitogen? It looks like a specific issue with the input json possibly 🤔 , https://stackoverflow.com/questions/48314367/ansible-local-test-new-module-with-errormodule-unable-to-decode-valid-json-on is related

anxstj commented 3 years ago

Yes, it works without mitogen (uncomment strategy: mitogen_linear).

Actually, the task comes from molecule-docker which fails for the same reason.

quulah commented 3 years ago

Encountered the same thing with the route53 module. Works without strategy: mitogen_linear as well.

edganiukov commented 3 years ago

I faced the same issue with https://docs.ansible.com/ansible/latest/collections/google/cloud/gcp_iam_service_account_module.html But it works with strategy: free

dnmvisser commented 3 years ago

Seeing this with the iam_cert module too

anxstj commented 3 years ago

I just stumbled over this again, and recognized that the error happens only if the docker image is not present on the controller node.

For the record: It happens also with ansible-core 2.11:

ansible [core 2.11.2] 
  config file =~/.ansible.cfg
  configured module search path = ['~/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /usr/local/venv/lib/python3.9/site-packages/ansible
  ansible collection location = ~/.ansible/collections:/usr/share/ansible/collections
  executable location = /usr/local/venv/bin/ansible
  python version = 3.9.6 (default, Jul 16 2021, 00:00:00) [GCC 11.1.1 20210531 (Red Hat 11.1.1-3)]
  jinja version = 3.0.1
  libyaml = True
anxstj commented 2 years ago

I can not reproduce the error with 0.3.2 or 0.3.3. I will close the issue.