Sequenced include_tasks can silently crash the current play without error

[cboylan]

SUMMARY

Certain sequences of include_tasks can crash the current play. This crashing comes without error and ansible happily stops running the current play then starts the next play.

ISSUE TYPE

• Bug Report

COMPONENT NAME

include_tasks

ANSIBLE VERSION

ansible 2.7.3
  config file = None
  configured module search path = ['/home/clark/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /home/clark/tmp/ansibledebug/venv/lib/python3.6/site-packages/ansible
  executable location = venv/bin/ansible
  python version = 3.6.5 (default, Mar 31 2018, 19:45:04) [GCC]

CONFIGURATION

ANSIBLE_NOCOWS(env: ANSIBLE_NOCOWS) = True

OS / ENVIRONMENT

This was first observed on host running Ubuntu Bionic but reproduced in this simpler case on openSUSE tumbleweed.

STEPS TO REPRODUCE

The basic reproduction is to have a playbook run two plays. In the first play run two roles. In the first role include_tasks some tasks so that you have a task file that runs on hostsX and another task file that runs on hostsY. In the task file for hostsY include_tasks the tasks for hostsX. At this point the entire play stops running successfully. The second role in this play is not run and the second play is started. No indication of failure is given.

I've put all of this together at https://github.com/cboylan/ansible_include_tasks_crash as it isn't the smallest reproduction case.

EXPECTED RESULTS

At the very least I would expect the first role to fail, ansible to report failure and stop running the playbook. I think my biggest concern is that ansible silently fails here and will continue running subsequent plays, skipping and additional work in the first play that may be necessary for the next.

Ideally I would expect the second include_tasks to run those additional tasks as well. There are other ways to structure things if this was a clear failure/error though so I don't think this is absolutely required.

ACTUAL RESULTS

clark@nibbler:~/tmp/ansibledebug (master)$ venv/bin/ansible-playbook -vvv -i ./inventory.ini play.yaml 
ansible-playbook 2.7.3
  config file = None
  configured module search path = ['/home/clark/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /home/clark/tmp/ansibledebug/venv/lib/python3.6/site-packages/ansible
  executable location = venv/bin/ansible-playbook
  python version = 3.6.5 (default, Mar 31 2018, 19:45:04) [GCC]
No config file found; using defaults
/home/clark/tmp/ansibledebug/inventory.ini did not meet host_list requirements, check plugin documentation if this is unexpected
/home/clark/tmp/ansibledebug/inventory.ini did not meet script requirements, check plugin documentation if this is unexpected
/home/clark/tmp/ansibledebug/inventory.ini did not meet yaml requirements, check plugin documentation if this is unexpected
Parsed /home/clark/tmp/ansibledebug/inventory.ini inventory source with ini plugin

PLAYBOOK: play.yaml ******************************************************************************************************************************************************************************************************************************************
2 plays in play.yaml

PLAY [Try to crash this play] ********************************************************************************************************************************************************************************************************************************

TASK [Gathering Facts] ***************************************************************************************************************************************************************************************************************************************
task path: /home/clark/tmp/ansibledebug/play.yaml:1
<host1> ESTABLISH LOCAL CONNECTION FOR USER: clark
<host1> EXEC /bin/sh -c 'echo ~clark && sleep 0'
<host1> EXEC /bin/sh -c '( umask 77 && mkdir -p "` echo /home/clark/.ansible/tmp/ansible-tmp-1544830418.7665591-136401761016914 `" && echo ansible-tmp-1544830418.7665591-136401761016914="` echo /home/clark/.ansible/tmp/ansible-tmp-1544830418.7665591-136401761016914 `" ) && sleep 0'
<host2> ESTABLISH LOCAL CONNECTION FOR USER: clark
<host2> EXEC /bin/sh -c 'echo ~clark && sleep 0'
<host2> EXEC /bin/sh -c '( umask 77 && mkdir -p "` echo /home/clark/.ansible/tmp/ansible-tmp-1544830418.7800646-19550730307766 `" && echo ansible-tmp-1544830418.7800646-19550730307766="` echo /home/clark/.ansible/tmp/ansible-tmp-1544830418.7800646-19550730307766 `" ) && sleep 0'
Using module file /home/clark/tmp/ansibledebug/venv/lib/python3.6/site-packages/ansible/modules/system/setup.py
Using module file /home/clark/tmp/ansibledebug/venv/lib/python3.6/site-packages/ansible/modules/system/setup.py
<host1> PUT /home/clark/.ansible/tmp/ansible-local-29022lyugfr0h/tmp__l_h6ql TO /home/clark/.ansible/tmp/ansible-tmp-1544830418.7665591-136401761016914/AnsiballZ_setup.py
<host2> PUT /home/clark/.ansible/tmp/ansible-local-29022lyugfr0h/tmp9pq93nf6 TO /home/clark/.ansible/tmp/ansible-tmp-1544830418.7800646-19550730307766/AnsiballZ_setup.py
<host1> EXEC /bin/sh -c 'chmod u+x /home/clark/.ansible/tmp/ansible-tmp-1544830418.7665591-136401761016914/ /home/clark/.ansible/tmp/ansible-tmp-1544830418.7665591-136401761016914/AnsiballZ_setup.py && sleep 0'
<host2> EXEC /bin/sh -c 'chmod u+x /home/clark/.ansible/tmp/ansible-tmp-1544830418.7800646-19550730307766/ /home/clark/.ansible/tmp/ansible-tmp-1544830418.7800646-19550730307766/AnsiballZ_setup.py && sleep 0'
<host2> EXEC /bin/sh -c '/usr/bin/python /home/clark/.ansible/tmp/ansible-tmp-1544830418.7800646-19550730307766/AnsiballZ_setup.py && sleep 0'
<host1> EXEC /bin/sh -c '/usr/bin/python /home/clark/.ansible/tmp/ansible-tmp-1544830418.7665591-136401761016914/AnsiballZ_setup.py && sleep 0'
<host2> EXEC /bin/sh -c 'rm -f -r /home/clark/.ansible/tmp/ansible-tmp-1544830418.7800646-19550730307766/ > /dev/null 2>&1 && sleep 0'
<host1> EXEC /bin/sh -c 'rm -f -r /home/clark/.ansible/tmp/ansible-tmp-1544830418.7665591-136401761016914/ > /dev/null 2>&1 && sleep 0'
ok: [host2]
ok: [host1]
META: ran handlers

TASK [crasher : Include host-specific tasks] *****************************************************************************************************************************************************************************************************************
task path: /home/clark/tmp/ansibledebug/roles/crasher/tasks/main.yaml:1
included: /home/clark/tmp/ansibledebug/roles/crasher/tasks/host1.yaml for host1
included: /home/clark/tmp/ansibledebug/roles/crasher/tasks/host2.yaml for host2

TASK [crasher : Run on host1] ********************************************************************************************************************************************************************************************************************************
task path: /home/clark/tmp/ansibledebug/roles/crasher/tasks/host1.yaml:1
META: noop
ok: [host1] => {
    "msg": "System host1 ran host1"
}
META: noop

TASK [crasher : Run on host2] ********************************************************************************************************************************************************************************************************************************
task path: /home/clark/tmp/ansibledebug/roles/crasher/tasks/host2.yaml:1
ok: [host2] => {
    "msg": "System host2 ran host2"
}
META: noop

TASK [crasher : Include host1 tasks] *************************************************************************************************************************************************************************************************************************
task path: /home/clark/tmp/ansibledebug/roles/crasher/tasks/host2.yaml:6

PLAY [This play always runs] *********************************************************************************************************************************************************************************************************************************

TASK [Gathering Facts] ***************************************************************************************************************************************************************************************************************************************
task path: /home/clark/tmp/ansibledebug/play.yaml:7
<host1> ESTABLISH LOCAL CONNECTION FOR USER: clark
<host1> EXEC /bin/sh -c 'echo ~clark && sleep 0'
<host1> EXEC /bin/sh -c '( umask 77 && mkdir -p "` echo /home/clark/.ansible/tmp/ansible-tmp-1544830420.338711-50463944956077 `" && echo ansible-tmp-1544830420.338711-50463944956077="` echo /home/clark/.ansible/tmp/ansible-tmp-1544830420.338711-50463944956077 `" ) && sleep 0'
Using module file /home/clark/tmp/ansibledebug/venv/lib/python3.6/site-packages/ansible/modules/system/setup.py
<host1> PUT /home/clark/.ansible/tmp/ansible-local-29022lyugfr0h/tmpo1zos12g TO /home/clark/.ansible/tmp/ansible-tmp-1544830420.338711-50463944956077/AnsiballZ_setup.py
<host1> EXEC /bin/sh -c 'chmod u+x /home/clark/.ansible/tmp/ansible-tmp-1544830420.338711-50463944956077/ /home/clark/.ansible/tmp/ansible-tmp-1544830420.338711-50463944956077/AnsiballZ_setup.py && sleep 0'
<host1> EXEC /bin/sh -c '/usr/bin/python /home/clark/.ansible/tmp/ansible-tmp-1544830420.338711-50463944956077/AnsiballZ_setup.py && sleep 0'
<host2> ESTABLISH LOCAL CONNECTION FOR USER: clark
<host2> EXEC /bin/sh -c 'echo ~clark && sleep 0'
<host2> EXEC /bin/sh -c '( umask 77 && mkdir -p "` echo /home/clark/.ansible/tmp/ansible-tmp-1544830420.3912437-122075859010900 `" && echo ansible-tmp-1544830420.3912437-122075859010900="` echo /home/clark/.ansible/tmp/ansible-tmp-1544830420.3912437-122075859010900 `" ) && sleep 0'
Using module file /home/clark/tmp/ansibledebug/venv/lib/python3.6/site-packages/ansible/modules/system/setup.py
<host2> PUT /home/clark/.ansible/tmp/ansible-local-29022lyugfr0h/tmpt6ftf23e TO /home/clark/.ansible/tmp/ansible-tmp-1544830420.3912437-122075859010900/AnsiballZ_setup.py
<host2> EXEC /bin/sh -c 'chmod u+x /home/clark/.ansible/tmp/ansible-tmp-1544830420.3912437-122075859010900/ /home/clark/.ansible/tmp/ansible-tmp-1544830420.3912437-122075859010900/AnsiballZ_setup.py && sleep 0'
<host2> EXEC /bin/sh -c '/usr/bin/python /home/clark/.ansible/tmp/ansible-tmp-1544830420.3912437-122075859010900/AnsiballZ_setup.py && sleep 0'
<host1> EXEC /bin/sh -c 'rm -f -r /home/clark/.ansible/tmp/ansible-tmp-1544830420.338711-50463944956077/ > /dev/null 2>&1 && sleep 0'
ok: [host1]
<host2> EXEC /bin/sh -c 'rm -f -r /home/clark/.ansible/tmp/ansible-tmp-1544830420.3912437-122075859010900/ > /dev/null 2>&1 && sleep 0'
ok: [host2]
META: ran handlers

TASK [This play always runs in subsequent play] **************************************************************************************************************************************************************************************************************
task path: /home/clark/tmp/ansibledebug/play.yaml:10
ok: [host1] => {
    "msg": "I ran"
}
ok: [host2] => {
    "msg": "I ran"
}
META: ran handlers
META: ran handlers

PLAY RECAP ***************************************************************************************************************************************************************************************************************************************************
host1                      : ok=5    changed=0    unreachable=0    failed=0   
host2                      : ok=5    changed=0    unreachable=0    failed=0   

[cboylan]

Seems this issue is present in 2.5, 2.6, and tip of devel (as of a few minutes ago) as well.

[sivel]

The underlying error that is causing this behavior is:

An unhandled exception occurred while running the lookup plugin 'first_found'. Error was a <class 'ansible.errors.AnsibleLookupError'>, original message: No file was found when using first_found. Use the 'skip: true' option to allow this task to be skipped if no files are found

This is encountered, and then the include is effectively skipped.

The reason this happens, is that the first_found lookup is re-evaluated so that we can determine relative pathing, based on the parent include, however we don't give the same context to the templating in IncludedFile.process_include_results that we do in TaskExecutor, so we aren't looking inside of tasks.

We need to duplicate the logic in TaskExecutor into IncludedFile.process_include_results.

[cboylan]

Fixing the include tasks piece is great. Thank you for that.

Is there another bug here where the unhandled exception doesn't result in the playbook run failing and stopping immediately? It seem that it is undesireable to fail to record the error and could be dangerous to keep running subsequent plays?

[sivel]

I am trying to handle both issues in my forthcoming PR.

At current, it still won't fail immediately on the templating error of the parent, but will provide a warning letting the user know the subsequent include may fail to find the file, and then it continues on.

Which, as the warning will state, may result in a failure to find the file.

[sivel]

I've just submitted #50045 which should take care of these issues.