Molecule: Report failure reason when molecule idempotence runs

[james-portman]

Issue Type

• Feature request

Molecule and Ansible details

Latest from pip

Desired Behaviour

When molecule idempotence fails (running molecule converge), the failures should be printed.

Actual Behaviour (Bug report only)

molecule idempotence just reports that some error was encountered during converge.
In order to find out, you then have to run molecule converge again yourself.
This is hiding errors during automated testing, as well as causing molecule converge to be run manually again when used during dev.

[saez0pub]

Hello,

I agree, I have to edit manualy command/converge.py and comment these lines :

ansible.remove_cli_arg('_out')
ansible.remove_cli_arg('_err')

and

ansible.add_env_arg('ANSIBLE_NOCOLOR', 'true')
ansible.add_env_arg('ANSIBLE_FORCE_COLOR', 'false')

This lack of vebrosty is a problem, I cann't know why the idempotence has failed, the message "Skipping due to errors during converge" is not enougth.

[rgreinho]

This feature is already implemented.

A way to see it is to run the following steps:

mkdir -p  /tmp/molecule-issue835
cd /tmp/molecule-issue835
molecule init --role issue835
cd issue835
cat > tasks/main.yml << EOF
---
- name: Non idempotent task
  command: echo 'I told you I was not idempotent.'
EOF
molecule test

And the output will show the non idempotent role and task:

--> Idempotence test in progress (can take a few minutes)...
--> Starting Ansible Run...
ERROR: Idempotence test failed because of the following tasks:
ERROR: * [issue835] => issue835 : Non idempotent task

If you see Skipping due to errors during converge, it means the converge failed, therefore you cannot test for idempotence.

[james-portman]

I will double check but this issue is with regards to running molecule idempotence, not molecule test.
Sometimes errors occur during running molecule idempotence even after a successful run of molecule converge earlier.

In this case the error is not shown.

[rgreinho]

No problem. I obtain the same result using molecule idempotence:

$ molecule idempotence
--> Idempotence test in progress (can take a few minutes)...
--> Starting Ansible Run...
ERROR: Idempotence test failed because of the following tasks:
ERROR: * [issue835] => issue835 : Non idempotent task

[james-portman]

Just to confirm,
I used your initial setup then ran molecule converge which worked fine.
I then changed the command to /bin/false to force an error during future runs (which does happen in some situations)
then I ran molecule idempotence which gave the output:

[james@localhost issue835]$ molecule idempotence
--> Idempotence test in progress (can take a few minutes)...
--> Starting Ansible Run...
--> Skipping due to errors during converge.

This is the situation in which I would like more output or errors

[rgreinho]

That makes complete sense. If you set the command in the task to /bin/false, the task will always fail, therefore converge will never complete, therefore idempotence will never pass.

[james-portman]

My concern is the lack of output or reason for the failure. Sometimes this happens with legitimate code. I was just using /bin/false to force the example

[rgreinho]

I hear you. But in that case the message is clear: if your converge fails, you cannot expect idempotence to work, therefore go back to fix to the converge, and once it works, re-run idempotence.

There would be something to fix only if converge would work, and idempotence would fail without giving any reason.

If you can provide us with a reproducible example of such a use case, I'll work on it, otherwise I'll close this issue.

[retr0h]

You will also notice molecule fails with first error. Molecule's test sequence is destroy, dependency, syntax, create, converge, idempotence, and verify.

If there is an error at any one of those steps, Molecule will stop.

The molecule converge subcommand is a simple converge, with all stdout/err being displayed.

The molecule idempotence subcommand, simply runs a converge, but silences all stdout/err so we can analyze it later. However, it doesn't do anything special. It's simply a converge.

Therefore, when running molecule test, the converge should fail, if indeed there was a non exit-0, with the reason on your screen. The only time it would be hidden is by idempotence. However, I don't recommend running idempotence while developing roles, it hides important details.

As you see test failed in the converge stage as expected.

[jodewey:~/git/molecule/molecule-issue835/issue835] [molecule-env-2.7.13] base-box* ± molecule test
--> Destroying instances...
==> issue835: Forcing shutdown of VM...
==> issue835: Destroying VM and associated drives...
--> Checking playbook's syntax...
playbook: playbook.yml
--> Creating instances...
Bringing machine 'issue835' up with 'virtualbox' provider...
==> issue835: Cloning VM...
..
..
--> Starting Ansible Run...

PLAY [all] *********************************************************************

TASK [Gathering Facts] *********************************************************
ok: [issue835]

TASK [issue835 : Non idempotent task] ******************************************
fatal: [issue835]: FAILED! => {"changed": true, "cmd": ["/bin/false"], "delta": "0:00:00.009622", "end": "2017-05-31 16:57:36.874591", "failed": true, "rc": 1, "start": "2017-05-31 16:57:36.864969", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}

PLAY RECAP *********************************************************************
issue835                   : ok=1    changed=0    unreachable=0    failed=1

[saez0pub]

Hello,

Failure of an ansible run depends of the context on the server.
So It's not because you have run once a playbook that he won't fail cause the context has changed.

At least the task and the error would be helpful.

I'm trying to get back the context I had to fix in order to pass the converge, it was linked to docker and I was trying to remove a kernel module. the task Has not changed on the first run, but had failled on the converge without a change.

[saez0pub]

Here is an example :

$ mkdir -p issue835/tasks/
$ cat > issue835/tasks/main.yml << EOF
- name: create /tmp/test1
  file: name=/tmp/test1 state=directory
- name: replace /tmp/test1 by /tmp/test2
  shell: ls -ld /tmp/test1 | grep root
- name: fix /tmp/test1 perms
  file: name=/tmp/test1 state=directory owner=lp group=lp
EOF
$ cat > issue835/molecule.yml << EOF
driver:
  name: docker
docker:
  containers:
    - name: issue835
      image: centos/systemd
      image_version: latest
EOF
$ cat > issue835/playbook.yml << EOF
> - hosts: all
>   roles:
>     - role: issue835
> EOF
$ cd issue835/
$ molecule test
--> Destroying instances...
--> Checking playbook's syntax...

playbook: playbook.yml
--> Creating instances...
--> Creating Ansible compatible image of centos/systemd:latest ...
Creating container issue835 with base image centos/systemd:latest...
Container created.
--> Starting Ansible Run...

PLAY [all] *********************************************************************

TASK [Gathering Facts] *********************************************************
ok: [issue835]

TASK [issue835 : create /tmp/test1] ********************************************
--- before
+++ after
@@ -1,4 +1,4 @@
 {
     "path": "/tmp/test1",
-    "state": "absent"
+    "state": "directory"
 }

changed: [issue835]

TASK [issue835 : replace /tmp/test1 by /tmp/test2] *****************************
changed: [issue835]

TASK [issue835 : fix /tmp/test1 perms] *****************************************
--- before
+++ after
@@ -1,5 +1,5 @@
 {
-    "group": 0,
-    "owner": 0,
+    "group": 7,
+    "owner": 4,
     "path": "/tmp/test1"
 }

changed: [issue835]

PLAY RECAP *********************************************************************
issue835                   : ok=4    changed=3    unreachable=0    failed=0

--> Idempotence test in progress (can take a few minutes)...
--> Starting Ansible Run...
--> Skipping due to errors during converge.

[rgreinho]

In that case that's correct. Idempotence failed because converge did not pass, and it is telling you so.

The behavior of idempotence is the following:

1. converge reported a failure -> tell the user to go check the converge and ensure it passes
2. converge passed but some tasks reported a changed status -> give the name of the tasks to the user in order for him/her to fix them

If you need a special workflow where you want to run converge twice before idempotence, you can adjust the test[‘sequence’] option (http://molecule.readthedocs.io/en/stable-1.24/usage.html?highlight=sequence#usage).

[james-portman]

The problem for me is when using molecule from Jenkins.
Running commands in order: create, converge, idempotence, syntax, verify.
These are run as pipeline stages in Jenkins which gives a good overview of issues when looking back at past builds.
Making it run converge again after idempotence failing would take even more time up, when we could just make idempotence print the error output.

It is basically this I am talking about, or something similar:
https://github.com/james-portman/molecule/pull/1

[retr0h]

@james-portman Yeah, I think thats prob the way to go. If we get an error we report an error occured, exit 1, and print the entire stdout/err.

[retr0h]

@james-portman implemented in molecule 1.25. Your other change made it into that release as well.

[james-portman]

Ah brilliant, thank you!

[retr0h]

Forward ported to v2 @ 32916c7

[MarkusTeufelberger]

Would it be possible to rather see the last lines of stdout/stderr instead of the beginning?

For longer plays, it will be cut off quite soon with:

TASK [foo : bar] ********************************* ok: [default... (1337 more, please see e.stdout)

and is not very helpful to see which task caused an issue.

[retr0h]

@MarkusTeufelberger thanks for the great report. I have corrected this @ b2495b0bb4984022b15420ccc9e37a531b504834.

[f-lopes]

I'm still experiencing this issue with Molecule 3.0.0 (via the quay.io/ansible/molecule:3.0.0 Docker image): idempotent step fails without apparent reason, even with the --debug flag.

/usr/bin/ansible-playbook --skip-tags=molecule-notest,notest,molecule-idempotence-notest --diff --inventory=/root/.cache/molecule/configuration/default/inventory /tmp/configuration/molecule/default/converge.yml -vvv

ERROR: Idempotence test failed because of the following tasks:
* [instance -> 127.0.0.1] => configuration : Create temporary directory
* [instance -> 127.0.0.1] => configuration : Download configuration from repository at (/tmp/git/sample-repository.git)

I think it's related to the Ansible module I use in my role (tempfile): it always recreates a temporary directory, as it uses a random path.

Running converge step twice:

docker run -it -v $(pwd):/tmp/configuration -v /var/run/docker.sock:/var/run/docker.sock -w /tmp/configuration quay.io/ansible/molecule:3.0.0 sh -c "molecule destroy && molecule converge && molecule converge"

don't give me any error but clearly reports that the "create temporary directory" task is not idempotent (and that's why Molecule idempotence step is failing I think):

TASK [configuration : Create temporary directory] ******************************
    changed: [instance -> 127.0.0.1]

1. How would you ensure idempotence using this kind of task? Test a role using this kind of task?
2. In my opinion, Molecule idempotence step should clearly report underlying errors.

Thanks.

[MarkusTeufelberger]

I'd recommend to open a new issue for this, this issue has been closed for a few years now.