ansible verbosity breaks testinfra/utils/ansible_runner.py in molecule 2.20.2

[Woytek-Polnik]

Issue Type

Verbosity for ansible in molecule.yml breaks verify tests.

provisioner:
  name: ansible
  config_options:
    defaults:
      verbosity: 1 // it can be 2 3 whatever

Molecule and Ansible details

Python 2.7, 3.7 Ansible 2.7., 2.8.* Molecule 2.20.2

All via pip

Actual Behaviour

molecule verify

Fails:

    ==================================== ERRORS ====================================
    ________________ ERROR collecting shared/tests/test_default.py _________________
    ../shared/tests/test_default.py:5: in <module>
        os.environ['MOLECULE_INVENTORY_FILE']).get_hosts('all')
    /usr/lib/python2.7/site-packages/testinfra/utils/ansible_runner.py:134: in get_hosts
        print(self.inventory)
    /usr/lib/python2.7/site-packages/testinfra/utils/__init__.py:44: in __get__
        value = obj.__dict__[self.func.__name__] = self.func(obj)
    /usr/lib/python2.7/site-packages/testinfra/utils/ansible_runner.py:154: in inventory
        return get_ansible_inventory(self.ansible_config, self.inventory_file)
    /usr/lib/python2.7/site-packages/testinfra/utils/ansible_runner.py:65: in get_ansible_inventory
        return json.loads(local.check_output(cmd, *args))
    /usr/lib64/python2.7/json/__init__.py:338: in loads
        return _default_decoder.decode(s)
    /usr/lib64/python2.7/json/decoder.py:366: in decode
        obj, end = self.raw_decode(s, idx=_w(s, 0).end())
    /usr/lib64/python2.7/json/decoder.py:384: in raw_decode
        raise ValueError("No JSON object could be decoded")
    E   ValueError: No JSON object could be decoded

Going deeper:

/usr/lib/python2.7/site-packages/testinfra/utils/ansible_runner.py:154: in inventory
        return get_ansible_inventory(self.ansible_config, self.inventory_file)
    /usr/lib/python2.7/site-packages/testinfra/utils/ansible_runner.py:65: in get_ansible_inventory
        return json.loads(local.check_output(cmd, *args))

*`local.check_output(cmd, args)` returns verbose text.**

verbosity: 1

Using /tmp/molecule/zerodowntime.boto/libvirt/ansible.cfg as config file
  {
        "_meta": {
.
.
}}

verbosity: 2

Ansible-inventory 2.8.2
      config file = /tmp/molecule/zerodowntime.boto/libvirt/ansible.cfg
      configured module search path = [u'/usr/lib/python2.7/site-packages/molecule/provisioner/ansible/plugins/libraries', u'/tmp/molecule/zerodowntime.boto/libvirt/library', u'/zerodowntime.boto/library']
      ansible python module location = /usr/lib/python2.7/site-packages/ansible
      executable location = /usr/bin/ansible-inventory
      python version = 2.7.5 (default, Jun 20 2019, 20:27:34) [GCC 4.8.5 20150623 (Red Hat 4.8.5-36)]
    Using /tmp/molecule/zerodowntime.boto/libvirt/ansible.cfg as config file
  {
        "_meta": {
.
.
}}

It cannot be dumped to json then

After cutting verbose lines to just pure

{
        "_meta": {
.
.
}}

it works.

Desired Behavior

It worked for molecule 2.20.0 ok with new it crashes.

[decentral1se]

Strange! Is this issue present in the latest release candidate?

[Woytek-Polnik]

with this

pip install   --index-url https://test.pypi.org/simple   --extra-index-url https://pypi.org/simple   molecule==2.22rc4.dev10

I have the same error

________________ ERROR collecting shared/tests/test_default.py _________________ ../shared/tests/test_default.py:6: in <module> os.environ['MOLECULE_INVENTORY_FILE']).get_hosts('all') /usr/lib/python2.7/site-packages/testinfra/utils/ansible_runner.py:127: in get_hosts inventory = self.inventory /usr/lib/python2.7/site-packages/testinfra/utils/__init__.py:44: in __get__ value = obj.__dict__[self.func.__name__] = self.func(obj) /usr/lib/python2.7/site-packages/testinfra/utils/ansible_runner.py:145: in inventory return get_ansible_inventory(self.ansible_config, self.inventory_file) /usr/lib/python2.7/site-packages/testinfra/utils/ansible_runner.py:58: in get_ansible_inventory return json.loads(local.check_output(cmd, *args)) /usr/lib64/python2.7/json/__init__.py:338: in loads return _default_decoder.decode(s) /usr/lib64/python2.7/json/decoder.py:366: in decode obj, end = self.raw_decode(s, idx=_w(s, 0).end()) /usr/lib64/python2.7/json/decoder.py:384: in raw_decode raise ValueError("No JSON object could be decoded") E ValueError: No JSON object could be decoded !!!!!!!!!!!!!!!!!!! Interrupted: 1 errors during collection !!!!!!!!!!!!!!!!!!!! =========================== 1 error in 0.71 seconds ============================

[decentral1se]

@ssbarnea this should also black releases :/

[ssbarnea]

I seen this error myself but I do not remember when and why. I do not use testinfra or ansible-runner myself so if we would have a very simple reproducer code it may be easier to get it fixed. Ideally a PR, one including a test, so we avoid regression.

[Woytek-Polnik]

https://github.com/WojciechPolnik/molecule_test_ansible_verbose created with molecule init role added requirements.txt from pip freeze python-3.7.4

default scenario causes fail ok scenario works

differences:

• instance_name
• ansible configuration

  config_options:
  defaults:
    verbosity: 2

[ssbarnea]

I managed to identify what caused this failure, the output of ansible inventory listing command contains one debug line which, obviously, makes the entire output an invalid JSON.

Using /root/.cache/molecule_parallel/test-init-.../default/ansible.cfg as config file

This seems like something caused by Ansible itself, a serious regression as all logging should go exclusively to stderr. I need to look from where it comes from...

[ssbarnea]

Mainly this is caused by https://github.com/ansible/ansible/issues/59973 which breaks testinfra. Is not Molecule bug but clearly affects it really badly.

[Woytek-Polnik]

You are correct but it was like this in ansible 2.7, 2.6, 2.5. So ansible did not change. Just it was change the way it is wrapped/output parsed

II the 1 debug line depends on the verbosity, with verbosity 2 you have more lines etc

III It works for Testinfa 1.* 2.*, fails for 3.*

[ssbarnea]

@WojciechPolnik Clearly Molecule has no fault in this and cannot even do anything about (other than avoiding nerwer versions of testinfra).

I will close this as we should look fixing https://github.com/philpep/testinfra/issues/470 and making a new release of testinfra.

[decentral1se]

@WojciechPolnik now that there is a fix in testinfra, would you be able to do some Q&A testing to support us? Please see the patch in https://github.com/philpep/testinfra/pull/471. Any logs/feedback is much appreciated.

[Woytek-Polnik]

@decentral1se I'll test it within 24h and give feedback

[decentral1se]

Thanks a lot :rocket:

[Woytek-Polnik]

Responded in philpep/testinfra#471