async_wrapper - fix race condition writing timeout result to job file (#87090) (#87158)

The async_wrapper now stops the module process before writing the timeout result to the async job file. This ensures a valid JSON file that async_status can parse.

Improve gather_facts parallel=true timeout responsiveness when gather_timeout is less than 10.

Fix integration tests.

(cherry picked from commit 3d3afdb34b)

changelogs/fragments/fix-short-timeout-async-wrapper.yml

@@ -0,0 +1,4 @@
+bugfixes:
+  - parallel fact gathering - fix hang caused by corrupt async job files.
+minor_changes:
+  - parallel fact gathering - the async wrapper now considers the timeout when determining whether to kill the process running the module. Previously, a 5 second sleep occurred twice before checking if the job had remaining time.

lib/ansible/modules/async_wrapper.py

@@ -310,24 +310,31 @@ def main():
                 os.setpgid(sub_pid, sub_pid)
 
                 notice("Start watching %s (%s)" % (sub_pid, remaining))
-                time.sleep(step)
-                while os.waitpid(sub_pid, os.WNOHANG) == (0, 0):
-                    notice("%s still running (%s)" % (sub_pid, remaining))
-                    time.sleep(step)
-                    remaining = remaining - step
-                    if remaining <= 0:
-                        # ensure we leave response in poll location
-                        res = {'msg': 'Timeout exceeded', 'failed': True, 'child_pid': sub_pid}
-                        jwrite(res)
 
+                if remaining != 0 and step >= remaining:
+                    step = remaining / 2
+
+                time.sleep(step)
+
+                while os.waitpid(sub_pid, os.WNOHANG) == (0, 0):
+                    remaining = remaining - step
+                    notice("%s still running (%s)" % (sub_pid, remaining))
+                    if remaining <= 0:
                         # actually kill it
                         notice("Timeout reached, now killing %s" % (sub_pid))
                         os.killpg(sub_pid, signal.SIGKILL)
                         notice("Sent kill to group %s " % sub_pid)
                         time.sleep(1)
+
+                        # ensure we leave response in poll location
+                        res = {'msg': 'Timeout exceeded', 'failed': True, 'child_pid': sub_pid}
+                        jwrite(res)
+
                         if not preserve_tmp:
                             shutil.rmtree(os.path.dirname(wrapped_module), True)
                         end(res)
+
+                    time.sleep(step)
                 notice("Done in kid B.")
                 if not preserve_tmp:
                     shutil.rmtree(os.path.dirname(wrapped_module), True)

test/integration/targets/gathering_facts/library/slow

@@ -1,6 +1,6 @@
 #!/bin/sh
 
-sleep 10
+sleep 3
 
 echo '{
     "changed": false,

test/integration/targets/gathering_facts/runme.sh

@@ -12,7 +12,7 @@ ANSIBLE_GATHERING=smart ansible-playbook test_run_once.yml -i inventory -v "$@"
 ansible-playbook test_prevent_injection.yml -i inventory -v "$@"
 
 # ensure fact merging is working properly
-ansible-playbook verify_merge_facts.yml -v "$@" -e 'ansible_facts_parallel: False'
+ansible-playbook verify_merge_facts.yml -v "$@" -e 'ansible_facts_parallel=False'
 
 # ensure we dont clobber facts in loop
 ansible-playbook prevent_clobbering.yml -v "$@"
@@ -33,10 +33,10 @@ ansible-playbook test_module_defaults.yml "$@" --tags templating
 ANSIBLE_FACTS_MODULES='ansible.legacy.slow' ansible -m gather_facts localhost --playbook-dir ./ "$@"
 
 # test that gather_facts will timeout parallel modules that dont support gather_timeout when using gather_Timeout
-ANSIBLE_FACTS_MODULES='ansible.legacy.slow' ansible -m gather_facts localhost --playbook-dir ./ -a 'gather_timeout=1 parallel=true' "$@" 2>&1 |grep 'Timeout exceeded'
+ANSIBLE_FACTS_MODULES='ansible.legacy.slow' ANSIBLE_TASK_TIMEOUT=5 ansible -m gather_facts localhost --playbook-dir ./ -a 'gather_timeout=1 parallel=true' "$@" 2>&1 |grep 'Timeout exceeded'
 
 # test that gather_facts parallel w/o timing out
-ANSIBLE_FACTS_MODULES='ansible.legacy.slow' ansible -m gather_facts localhost --playbook-dir ./ -a 'gather_timeout=30 parallel=true' "$@" 2>&1 |grep -v 'Timeout exceeded'
+ANSIBLE_FACTS_MODULES='ansible.legacy.slow' ansible -m gather_facts localhost --playbook-dir ./ -a 'gather_timeout=10 parallel=true' "$@" 2>&1 |grep 'Timeout exceeded' && exit 1
 
 
 # test parallelism