ANSIBLE_VERBOSITY>=3 does not work with ansible 2.14 and ansible-runner

[rabi]

Playbook run gets stuck when running with ansible 2.14 and ansible-runner 2.3.1 with verbosity>=3. This seems to be due to a regression in awx_display.py after ansible PR ansible/ansible#77056.

$cat test.yaml 
- hosts: all
  connection: local
  tasks:
    - name: check file
      ansible.builtin.file:
        path: /etc/foo.conf
        state: absent

$ cat inventory.yaml
[all]
test-[1:48].example.com

$export ANSIBLE_INVENTORY=inventory.yaml
$export ANSIBLE_VERBOSITY="3"
$ansible-runner run -p test.yaml $HOME

traceback:
.....
<test-19.example.com> EXEC /bin/sh -c 'echo ~ramishra && sleep 0'
Using module file /home/ramishra/.local/lib/python3.10/site-packages/ansible/modules/file.py
<test-19.example.com> EXEC /bin/sh -c '( umask 77 && mkdir -p "` echo /home/ramishra/.ansible/tmp `"&& mkdir "` echo /home/ramishra/.ansible/tmp/ansible-tmp-1668673584.1542976-1435398-231198689550583 `" && echo ansible-tmp-1668673584.1542976-1435398-231198689550583="` echo /home/ramishra/.ansible/tmp/ansible-tmp-1668673584.1542976-1435398-231198689550583 `" ) && sleep 0'
<test-17.example.com> PUT /home/ramishra/.ansible/tmp/ansible-local-14328044ytahafl/tmpawosdm87 TO /home/ramishra/.ansible/tmp/ansible-tmp-1668673584.0746303-1435377-8803172912834/AnsiballZ_file.py
<test-17.example.com> EXEC /bin/sh -c 'chmod u+x /home/ramishra/.ansible/tmp/ansible-tmp-1668673584.0746303-1435377-8803172912834/ /home/ramishra/.ansible/tmp/ansible-tmp-1668673584.0746303-1435377-8803172912834/AnsiballZ_file.py && sleep 0'
<test-16.example.com> EXEC /bin/sh -c '/usr/bin/python3 /home/ramishra/.ansible/tmp/ansible-tmp-1668673584.0498953-1435368-188608545559309/AnsiballZ_file.py && sleep 0'
<test-20.example.com> ESTABLISH LOCAL CONNECTION FOR USER: ramishra
<test-20.example.com> EXEC /bin/sh -c 'echo ~ramishra && sleep 0'
Using module file /home/ramishra/.local/lib/python3.10/site-packages/ansible/modules/file.py
<test-21.example.com> ESTABLISH LOCAL CONNECTION FOR USER: ramishra
<test-21.example.com> EXEC /bin/sh -c 'echo ~ramishra && sleep 0'
<test-17.example.com> EXEC /bin/sh -c '/usr/bin/python3 /home/ramishra/.ansible/tmp/ansible-tmp-1668673584.0746303-1435377-8803172912834/AnsiballZ_file.py && sleep 0'
<test-18.example.com> PUT /home/ramishra/.ansible/tmp/ansible-local-14328044ytahafl/tmpl2xxribm TO /home/ramishra/.ansible/tmp/ansible-tmp-1668673584.1266525-1435390-274928110267104/AnsiballZ_file.py
...

[rabi]

Related tripleo bug: https://bugs.launchpad.net/tripleo/+bug/1996612

[Akasurde]

resolved_by_pr #1165

[nitzmahone]

This one is nasty- took several iterations to get to the true root cause. It's looking like we're going to fix it directly in core, at least for the short-term. The underlying problem is really around core's usage of fork- it's just exacerbated by the way runner does its context capture and what I dubbed "event steganography" in stdout, in combination with core 2.14 issuing most of its stdout writes from a non-main thread.

Watch ansible/ansible#79522 for updates- I'm first posting a new integration test that triggers this behavior extremely reliably, then once we're sure it's failing properly in CI, I'll add the fix.

[rabi]

Unfortunately I'm still not clear why we can't merge the the current proposed PR to provide a short term fix with ansible-runner which actually works fine in all my testing.

Sorry to say this, but the PR has been there since 3 weeks. We all know the issue happens when using Display and stdout flush with threading which happens to be the case with ansible-runner and what this test patch is also doing. Would not it be appropriate to merge the PR and then revert in the future if and when there is a permanent fix to ansible-core is available. I still don't understand the little alacrity shown to fix such critical bugs and provide ansible-runner consumers a better experience.

[nitzmahone]

The final fix is available at ansible/ansible#79522 are you able to verify that it works for you? We'll probably be releasing this in 2.14.1 within the next couple of days...

[Akasurde]

I am going ahead and closing this issue since the fix is applied in the Ansible repo using ansible/ansible#79522. Please feel free to reopen if the problem persists. Thanks

[Akasurde]

resolved_by_pr ansible/ansible#79522