Question - Command/Shell module stdout logged

[debow77]

I've noticed with ansible-runner that it appears to display command/shell module stdout to the screen by default but if I run ansible-playbook only it doesn't. Is there a way or something to suppress that without having to add no_log: true to those tasks? Just trying to understand why ansible-runner is displaying this and ansible-playbook doesn't.

Ansible version - 2.16.3 Ansible Runner - 2.3.4

[sivel]

You are likely going to need to provide more information, like what command you are running, the playbook, and the output. I cannot reproduce with this simple reproducer:

- hosts: localhost
  gather_facts: false
  tasks:
    - command: whoami

$ ansible-runner run -p playbooks/playbook.yml pdd
PLAY [localhost] ***************************************************************

TASK [command] *****************************************************************
changed: [localhost]

PLAY RECAP *********************************************************************
localhost                  : ok=1    changed=1    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0   

[debow77]

One example of the task is...

    - name: Get active cert info
      ansible.builtin.shell:
        set -o pipefail && echo | openssl s_client -servername {{ item }} -connect {{ item }}:{{ websphere_odr_port }} -showcerts  2>/dev/null | openssl x509 -noout -subject -dates -fingerprint -issuer
      register: cur_certs_info
      changed_when: true
      loop:
        - "{{ dmgr_node }}"
        - "{{ sec_dmgr_node }}"

The output when running just ansible-playbook is

TASK [Get active cert info] **************************************************************************************************************************************************************************************************************************************************
changed: [node1.domain.com] => (item=node1.domain.com)
changed: [node1.domain.com] => (item=node2.domain.com)

The output when running with ansible-runner

TASK [Get active cert info] ****************************************************
changed: [node1.domain.com] => (item=node1.domain.com)subject= /C=US/ST=State/L=City/O=Company/CN=node1.domain.com
notBefore=Mar  1 18:56:36 2024 GMT
notAfter=Mar  1 18:56:36 2025 GMT
SHA1 Fingerprint=F8:34:0E:98:06:A7:87:C9:32:12:86:2D:40:EF:04:FC:B0:F2:C7:4F
issuer= /C=US/ST=State/L=City/O=Company/CN=Issuing 29
changed: [node1.domain.com] => (item=node2.domain.com)subject= /C=US/ST=State/L=City/O=Company/CN=node2.domain.com
notBefore=Mar  1 18:56:39 2024 GMT
notAfter=Mar  1 18:56:39 2025 GMT
SHA1 Fingerprint=A3:33:4A:BF:67:6E:A0:59:78:54:39:E9:BE:8D:73:64:2D:2D:53:80
issuer= /C=US/ST=State/L=City/O=Company/CN=Issuing 29

[debow77]

I added no_log: true to make ansible-runner's output look like ansible-playbook.

[sivel]

Can you please include the full ansible-runner command you are running?

[debow77]

This is the command.

ansible-runner run /tmp/3c8a67cc-76b5-421e-89d2-7acea8f90a21/project -p playbooks/playbook-websphere-odr-cleanup.yml -i 383c78ef-5226-47ff-ab96-8cffafd1b6a0

[sivel]

Do you have an env/settings file in your project dir? Can you run with --debug?

I am still unable to reproduce this.

What you are seeing is unexpected behavior, and so far I am only able to assume that it is an environmental configuration causing the problem. Somehow the stdout from the openssl command is directly bleeding through. It is not the standard callback doing it, as the output format doesn't match.

So potentially something may be causing openssl to write to /dev/tty, or something custom is causing stdout from the result to directly print to stdout in an unexpected way, such as a custom callback plugin.

[debow77]

Here's all files in /env. I'll try and run with debug ASAP. Have to get my servers back to their original state before cleanup.

sh-5.1$ cat cmdline
--forks=10

sh-5.1$ cat envvars
---
ANSIBLE_CALLBACKS_ENABLED: ansible.posix.profile_tasks
ANSIBLE_SHOW_CUSTOM_STATS: true

sh-5.1$ cat extravars
{
  "websphere_odr_cleanup_report": false
}

sh-5.1$ cat settings
{
  "job_timeout": 28800,
  "suppress_output_file": false,
  "suppress_ansible_output": true
}

[debow77]

I just thought about something, I am pulling the output from the events stdout not from the screen. I'm testing now with not suppressing the output to screen and see if it looks ok. If it does, then its how we're pulling from the artifacts/json's.

[debow77]

That's it. I'll look at that on our end, obviously not an issue with ansible-runner.

[sh-5.1$ ansible-playbook -i/tmp/b1ebc86f-ffbe-4320-840f-ef200909e5cf/project/inventory -e @/tmp/b1ebc86f-ffbe-4320-840f-ef200909e5cf/project/env/extravars playbooks/testing_output.yml

PLAY [Long runner] **********************************************************************************************************************************************************************************************

TASK [Get active cert info] *************************************************************************************************************************************************************************************
changed: [node01.domain.com] => (item=node01.domain.com)
changed: [node01.domain.com] => (item=node02.domain.com)

PLAY RECAP ******************************************************************************************************************************************************************************************************
node01.domain.com : ok=1    changed=1    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
]

[sh-5.1$ ansible-runner run /tmp/b1ebc86f-ffbe-4320-840f-ef200909e5cf/project -p playbooks/testing_output.yml -i d33b1e18-8484-471c-911c-da8f5f773906

PLAY [Long runner] *************************************************************

TASK [Get active cert info] ****************************************************
changed: [node01.domain.com] => (item=node01.domain.com)
changed: [node01.domain.com] => (item=node02.domain.com)

PLAY RECAP *********************************************************************
node01.domain.com : ok=1    changed=1    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
sh-5.1$]

[debow77]

Looking at the artifact event stdout it has all the extra details.

playbook: "testing_output.yml",
  stdout:
   "changed: [node01.domain.com] => (item=node01.domain.com)subject= /C=US/ST=State/L=City/O=Company/CN=node01.domain.com\nnotBefore=Mar  1 18:56:36 2024 GMT\nnotAfter=Mar  1 18:56:36 2025 GMT
  verbosity: 0,

The screen output only outputs the below line, but runner updates stdout with additional output.

changed: [node01.domain.com] => (item=node01.domain.com)

[debow77]

So I understand where its coming from now but is that expected of ansible-runner/artifacts stdout?

[sivel]

Can you show the path and contents of the artifact event you are referring to? I don't have any event data that is like that.

Based on what you are describing the stdout of the event is also including the event_data.res.stdout? My event data has the separated.

{
    ...
    "event": "runner_item_on_ok",
    "event_data": {
       ...
        "res": {
            ...
            "stdout": "subject= /CN=...",
            ...
        },
        ...
    },
    "stdout": "\u001b[0;33mchanged: [localhost] => (item=google.com)\u001b[0m",
    ...
}

[debow77]

I think the artifacts are ok, I think the issue is with my side where I'm parsing the json files and storing the events. I see the correct/expected stdout in one of the json files. That's not the stdout we're pulling from. I'll dig in more on my side where the issue is. Thanks for all the help/responses.

[debow77]

I was combining the stdout field with the event_data->stdout