Apply Ansible Roles to content host not working

Support
,
1

Problem:
Ansible Roles wont get applied to content host
Expected outcome:
Apply corresponding ansible role

Foreman and Proxy versions:

  • ansible-collection-theforeman-foreman-3.0.0-1.el8.noarch
  • candlepin-4.1.8-1.el8.noarch
  • candlepin-selinux-4.1.8-1.el8.noarch
  • foreman-3.1.2-2.el8.noarch
  • foreman-cli-3.1.1-1.el8.noarch
  • foreman-debug-3.1.1-1.el8.noarch
  • foreman-dynflow-sidekiq-3.1.2-2.el8.noarch
  • foreman-installer-3.1.1-1.el8.noarch
  • foreman-installer-katello-3.1.1-1.el8.noarch
  • foreman-postgresql-3.1.2-2.el8.noarch
  • foreman-proxy-3.1.1-1.el8.noarch
  • foreman-release-3.1.1-1.el8.noarch
  • foreman-selinux-3.1.1-1.el8.noarch
  • foreman-service-3.1.2-2.el8.noarch
  • katello-4.3.0-1.el8.noarch
  • katello-ca-consumer-foreman.lfrz.at-1.0-3.noarch
  • katello-certs-tools-2.8.2-1.el8.noarch
  • katello-client-bootstrap-1.7.7-1.el8.noarch
  • katello-common-4.3.0-1.el8.noarch
  • katello-debug-4.3.0-1.el8.noarch
  • katello-repos-4.3.0-1.el8.noarch
  • katello-selinux-4.0.2-1.el8.noarch
  • pulpcore-selinux-1.2.6-2.el8.x86_64
  • python38-pulp-ansible-0.10.1-1.el8.noarch
  • python38-pulp-certguard-1.5.1-1.el8.noarch
  • python38-pulp-container-2.9.0-1.el8.noarch
  • python38-pulp-deb-2.16.1-1.el8.noarch
  • python38-pulp-file-1.10.1-1.el8.noarch
  • python38-pulp-python-3.5.2-1.el8.noarch
  • python38-pulp-rpm-3.16.1-2.el8.noarch
  • python38-pulpcore-3.16.1-1.el8.noarch
  • qpid-proton-c-0.35.0-1.el8.x86_64
  • rubygem-foreman-tasks-5.2.0-1.fm3_1.el8.noarch
  • rubygem-foreman_ansible-7.0.2-1.fm3_1.el8.noarch
  • rubygem-foreman_maintain-1.0.2-1.el8.noarch
  • rubygem-foreman_remote_execution-5.0.1-1.fm3_1.el8.noarch
  • rubygem-hammer_cli-3.1.0-1.el8.noarch
  • rubygem-hammer_cli_foreman-3.1.0-1.el8.noarch
  • rubygem-hammer_cli_foreman_remote_execution-0.2.2-1.fm3_0.el8.noarch
  • rubygem-hammer_cli_foreman_tasks-0.0.17-1.fm3_1.el8.noarch
  • rubygem-hammer_cli_katello-1.3.1-1.el8.noarch
  • rubygem-katello-4.3.0-1.el8.noarch
  • rubygem-pulp_ansible_client-0.10.1-1.el8.noarch
  • rubygem-pulp_certguard_client-1.5.0-1.el8.noarch
  • rubygem-pulp_container_client-2.9.0-1.el8.noarch
  • rubygem-pulp_deb_client-2.16.0-1.el8.noarch
  • rubygem-pulp_file_client-1.10.0-1.el8.noarch
  • rubygem-pulp_ostree_client-2.0.0-0.1.a1.el8.noarch
  • rubygem-pulp_python_client-3.5.2-1.el8.noarch
  • rubygem-pulp_rpm_client-3.16.1-1.el8.noarch
  • rubygem-pulpcore_client-3.16.0-1.el8.noarch
  • rubygem-qpid_proton-0.35.0-1.el8.x86_64
  • rubygem-smart_proxy_pulp-3.2.0-2.fm3_1.el8.noarch

Distribution and version:
RHEL 8.5

Other relevant data:
The role is executed based on the job-template which looks like as follows:

  • hosts: all
    pre_tasks:

    • name: Display all parameters known for the Foreman host
      debug:
      var: foreman
      tags:

      • always
        tasks:

    • debug:
      msg: “Verify role is applied to content host var: {{ role }}”
      loop: “{{ foreman_ansible_roles }}”
      loop_control:
      loop_var: role

    • name: Apply roles
      include_role:
      name: “{{ role }}”
      tags:

      • always
        loop: “{{ foreman_ansible_roles }}”
        loop_control:
        loop_var: role

For better debugging each role applied to the host is printed out. In this case “apply_chrony_conf” see below. This works so far.

However, when looking at the output the applied variables are resolved correctly. But the part where the role supposed to be applied is just skipped.

image
image890Ă—245 18.2 KB

What do I overlook here? Of course I verified that the role didnt get applied on the content host.

Thank you in advance!

2

Could you please format the playbook you posted properly? (Put three backticks on a single line, then the playbook, then three backticks again). Hard to say what’s going on as the playbook is currently malformed

3 
---
- hosts: all
  pre_tasks:
    - name: Display all parameters known for the Foreman host
      debug:
        var: foreman
      tags:
        - always
  tasks:
    - debug:
        msg: "Verify role is applied to content host var: {{ role }}"
      loop: "{{ foreman_ansible_roles }}"
      loop_control:
        loop_var: role
        
    - name: Apply roles
      include_role:
        name: "{{ role }}"
      tags:
        - always
      loop: "{{ foreman_ansible_roles }}"
      loop_control:
        loop_var: role
4

Hmm, that has a vaguely faimilar feel to it. What version fo smart_proxy_ansible do you have?

5

rubygem-smart_proxy_ansible-3.3.0-1.fm3_1.el8.noarch

6

So do you think its a bug or a config issue? Should I try another version of rubygem or do you have any hints regarding this topic otherwise I probably have to go along without ansible on foreman and setup a dedicated server only for ansible even though I would prefer to use it within the foreman framework.
Thank you for your advice!

7

I’d like to know more before I answer that. Could you bump log level to debug in /etc/foreman-proxy/settings.d/dynflow.yml , restart foreman-proxy, run the job again and then post whatever ends in /var/log/foreman-proxy/proxy.log?

8

Here the logs of the job after enabling debug-level logging and restarting service:

2022-03-07T12:36:23  [W] Could not open DB for dynflow at '', will keep data in memory. Restart will drop all dynflow data.
2022-03-07T12:36:23  [I] Execution plan cleaner removing 0 execution plans.
2022-03-07T12:36:23  [I] Successfully initialized 'dynflow'
2022-03-07T12:36:23  [I] Successfully initialized 'pulpcore'
2022-03-07T12:36:23  [I] Successfully initialized 'ssh'
2022-03-07T12:36:23  [I] Successfully initialized 'ansible'
2022-03-07T12:36:23  [I] Successfully initialized 'foreman_proxy'
2022-03-07T12:36:23  [I] Successfully initialized 'logs'
2022-03-07T12:36:23  [I] WEBrick 1.6.1
2022-03-07T12:36:23  [I] ruby 2.7.4 (2021-07-07) [x86_64-linux]
2022-03-07T12:36:23  [I]
Certificate:
    Data:
........
         55:00:5a:d0:45:dc:30:52

2022-03-07T12:36:23  [I] WEBrick::HTTPServer#start: pid=842422 port=9090
2022-03-07T12:36:23  [I] Smart proxy has launched on 1 socket(s), waiting for requests
2022-03-07T12:36:49 f3664206 [I] Started GET /dynflow/tasks/count state=running
2022-03-07T12:36:49 f3664206 [I] Finished GET /dynflow/tasks/count with 200 (4.52 ms)
2022-03-07T12:36:49 f3664206 [I] Started POST /dynflow/tasks/launch
2022-03-07T12:36:49 f3664206 [I] Finished POST /dynflow/tasks/launch with 200 (41.61 ms)
2022-03-07T12:39:17 692f35ee [I] Started GET /dynflow/tasks/count state=running
2022-03-07T12:39:17 692f35ee [I] Finished GET /dynflow/tasks/count with 200 (0.96 ms)
2022-03-07T12:39:18 692f35ee [I] Started POST /dynflow/tasks/launch
2022-03-07T12:39:18 692f35ee [I] Finished POST /dynflow/tasks/launch with 200 (36.88 ms)
9

Ermm, sorry. The log level needs to be bumped in /etc/foreman-proxy/settings.yml

11

Used template:

---
- hosts: all
  gather_facts: no

  tasks:
    - debug:
        msg: "Verify role is applied to content host var: {{ role }}"
      loop: "{{ foreman_ansible_roles }}"
      loop_control:
        loop_var: role
        
    - name: Apply roles
      include_role:
        name: "{{ role }}"
      tags:
        - always
      loop: "{{ foreman_ansible_roles }}"
      loop_control:
        loop_var: role

Output:

2022-03-08T08:28:00  [D] Executor heartbeat
2022-03-08T08:28:15  [D] Executor heartbeat
2022-03-08T08:28:30  [D] Executor heartbeat
2022-03-08T08:28:40  [D] accept: 172.27.10.80:55054
2022-03-08T08:28:40  [D] Rack::Handler::WEBrick is invoked.
2022-03-08T08:28:40 67c4682c [I] Started GET /dynflow/tasks/count state=running
2022-03-08T08:28:40 67c4682c [D] verifying remote client 172.27.10.80 against trusted_hosts ["formanserver.domain"]
2022-03-08T08:28:40 67c4682c [I] Finished GET /dynflow/tasks/count with 200 (0.94 ms)
2022-03-08T08:28:40  [D] close: 172.27.10.80:55054
2022-03-08T08:28:40  [D] accept: 172.27.10.80:55056
2022-03-08T08:28:40  [D] Rack::Handler::WEBrick is invoked.
2022-03-08T08:28:40 67c4682c [I] Started POST /dynflow/tasks/launch
2022-03-08T08:28:40 67c4682c [D] verifying remote client 172.27.10.80 against trusted_hosts ["formanserver.domain"]
2022-03-08T08:28:40 67c4682c [D] ExecutionPlan 09a6937e-5ab3-464a-9037-83f5e3c471a5      pending >>  planning
2022-03-08T08:28:40 67c4682c [D]          Step 09a6937e-5ab3-464a-9037-83f5e3c471a5: 1   pending >>   running in phase     Plan Proxy::Dynflow::Action::SingleRunnerBatch
2022-03-08T08:28:40 67c4682c [D] ExecutionPlan 7999adc7-1bb1-46c1-b4ef-b5b7417de1a9      pending >>  planning
2022-03-08T08:28:40 67c4682c [D]          Step 7999adc7-1bb1-46c1-b4ef-b5b7417de1a9: 1   pending >>   running in phase     Plan Proxy::Dynflow::Action::OutputCollector
2022-03-08T08:28:40 67c4682c [D]          Step 7999adc7-1bb1-46c1-b4ef-b5b7417de1a9: 1   running >>   success in phase     Plan Proxy::Dynflow::Action::OutputCollector
2022-03-08T08:28:40 67c4682c [D] ExecutionPlan 7999adc7-1bb1-46c1-b4ef-b5b7417de1a9     planning >>   planned
2022-03-08T08:28:40  [D] ExecutionPlan 7999adc7-1bb1-46c1-b4ef-b5b7417de1a9      planned >>   running
2022-03-08T08:28:40 67c4682c [D] ExecutionPlan 0e3786ba-2188-4deb-a0f3-ba66465b1410      pending >>  planning
2022-03-08T08:28:40 67c4682c [D]          Step 0e3786ba-2188-4deb-a0f3-ba66465b1410: 1   pending >>   running in phase     Plan Proxy::Dynflow::Action::BatchRunner
2022-03-08T08:28:40 67c4682c [D]          Step 0e3786ba-2188-4deb-a0f3-ba66465b1410: 1   running >>   success in phase     Plan Proxy::Dynflow::Action::BatchRunner
2022-03-08T08:28:40 67c4682c [D] ExecutionPlan 0e3786ba-2188-4deb-a0f3-ba66465b1410     planning >>   planned
2022-03-08T08:28:40  [D]          Step 7999adc7-1bb1-46c1-b4ef-b5b7417de1a9: 2   pending >>   running in phase      Run Proxy::Dynflow::Action::OutputCollector
2022-03-08T08:28:40 67c4682c [D]          Step 7999adc7-1bb1-46c1-b4ef-b5b7417de1a9: 2   running >> suspended in phase      Run Proxy::Dynflow::Action::OutputCollector
2022-03-08T08:28:40 67c4682c [D]          Step 09a6937e-5ab3-464a-9037-83f5e3c471a5: 4   pending >>   running in phase     Plan Proxy::Dynflow::Action::BatchCallback
2022-03-08T08:28:40 67c4682c [D]          Step 09a6937e-5ab3-464a-9037-83f5e3c471a5: 4   running >>   success in phase     Plan Proxy::Dynflow::Action::BatchCallback
2022-03-08T08:28:40 67c4682c [D]          Step 09a6937e-5ab3-464a-9037-83f5e3c471a5: 1   running >>   success in phase     Plan Proxy::Dynflow::Action::SingleRunnerBatch
2022-03-08T08:28:40 67c4682c [D] ExecutionPlan 09a6937e-5ab3-464a-9037-83f5e3c471a5     planning >>   planned
2022-03-08T08:28:40  [D] ExecutionPlan 0e3786ba-2188-4deb-a0f3-ba66465b1410      planned >>   running
2022-03-08T08:28:40 67c4682c [I] Finished POST /dynflow/tasks/launch with 200 (34.43 ms)
2022-03-08T08:28:40  [D]          Step 0e3786ba-2188-4deb-a0f3-ba66465b1410: 2   pending >>   running in phase      Run Proxy::Dynflow::Action::BatchRunner
2022-03-08T08:28:40  [D] ExecutionPlan 09a6937e-5ab3-464a-9037-83f5e3c471a5      planned >>   running
2022-03-08T08:28:40  [D]          Step 09a6937e-5ab3-464a-9037-83f5e3c471a5: 2   pending >>   running in phase      Run Proxy::Dynflow::Action::SingleRunnerBatch
2022-03-08T08:28:40 67c4682c [D]          Step 09a6937e-5ab3-464a-9037-83f5e3c471a5: 2   running >> suspended in phase      Run Proxy::Dynflow::Action::SingleRunnerBatch
2022-03-08T08:28:40  [D] close: 172.27.10.80:55056
2022-03-08T08:28:40 67c4682c [D]          Step 0e3786ba-2188-4deb-a0f3-ba66465b1410: 2   running >> suspended in phase      Run Proxy::Dynflow::Action::BatchRunner
2022-03-08T08:28:40  [D] start runner 86274b2f-9fa0-4201-85ad-d7d1b0974f77
2022-03-08T08:28:40  [D] [foreman_ansible] - Running command '{"FOREMAN_CALLBACK_DISABLE"=>"1"} ansible-runner run /tmp/d20220308-844213-1hl1839 -p playbook.yml'
2022-03-08T08:28:40  [D] refresh runner 86274b2f-9fa0-4201-85ad-d7d1b0974f77
2022-03-08T08:28:40  [D] refreshing runner
2022-03-08T08:28:40  [D] planning to refresh 86274b2f-9fa0-4201-85ad-d7d1b0974f77
2022-03-08T08:28:41  [D] Ticker ticking for 1 events
2022-03-08T08:28:41  [D] refresh runner 86274b2f-9fa0-4201-85ad-d7d1b0974f77
2022-03-08T08:28:41  [D] refreshing runner
2022-03-08T08:28:41  [D] [foreman_ansible] - processing event files: ["/tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/1-19c0fac2-faed-46a4-ad1a-d85861c11c34.json", "/tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/2-f1903f44-33f5-4e08-8ccf-b09646cd50e6.json"]}
2022-03-08T08:28:41  [D] [foreman_ansible] - parsing event file /tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/1-19c0fac2-faed-46a4-ad1a-d85861c11c34.json
2022-03-08T08:28:41  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "19c0fac2-faed-46a4-ad1a-d85861c11c34",
  "counter": 1,
  "stdout": "[WARNING]: Callback disabled by environment. Disabling the Foreman callback\r\nplugin.",
  "start_line": 0,
  "end_line": 2,
  "runner_ident": "566f9584-46aa-46c2-a131-411ea878a977",
  "event": "warning",
  "pid": 890437,
  "created": "2022-03-08T07:28:41.977812",
  "event_data": {
    "warning": true,
    "uuid": "19c0fac2-faed-46a4-ad1a-d85861c11c34"
  }
}
2022-03-08T08:28:41  [D] [foreman_ansible] - parsing event file /tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/2-f1903f44-33f5-4e08-8ccf-b09646cd50e6.json
2022-03-08T08:28:41  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "f1903f44-33f5-4e08-8ccf-b09646cd50e6",
  "counter": 2,
  "stdout": "",
  "start_line": 2,
  "end_line": 2,
  "runner_ident": "566f9584-46aa-46c2-a131-411ea878a977",
  "event": "playbook_on_start",
  "pid": 890437,
  "created": "2022-03-08T07:28:41.978403",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "f1903f44-33f5-4e08-8ccf-b09646cd50e6",
    "uuid": "f1903f44-33f5-4e08-8ccf-b09646cd50e6"
  }
}
2022-03-08T08:28:41  [D] planning to refresh 86274b2f-9fa0-4201-85ad-d7d1b0974f77
2022-03-08T08:28:41  [D]          Step 7999adc7-1bb1-46c1-b4ef-b5b7417de1a9: 2 got event #<Proxy::Dynflow::Runner::Update:0x0000559ced5f0bd8>
2022-03-08T08:28:41  [D]          Step 7999adc7-1bb1-46c1-b4ef-b5b7417de1a9: 2 suspended >>   running in phase      Run Proxy::Dynflow::Action::OutputCollector
2022-03-08T08:28:41 67c4682c [D]          Step 7999adc7-1bb1-46c1-b4ef-b5b7417de1a9: 2   running >> suspended in phase      Run Proxy::Dynflow::Action::OutputCollector
2022-03-08T08:28:42  [D] Ticker ticking for 1 events
2022-03-08T08:28:42  [D] refresh runner 86274b2f-9fa0-4201-85ad-d7d1b0974f77
2022-03-08T08:28:42  [D] refreshing runner
2022-03-08T08:28:42  [D] [foreman_ansible] - processing event files: ["/tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/3-005056b9-655c-8159-958f-000000000006.json", "/tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/4-005056b9-655c-8159-958f-000000000008.json", "/tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/5-3c992f36-d7f5-4a52-9eca-8cc5a385c011.json", "/tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/6-f9c33371-c2f6-4a83-be51-bad858413d16.json", "/tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/7-05371661-5479-4bfc-8d79-ed373ecf093c.json", "/tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/8-005056b9-655c-8159-958f-00000000000a.json", "/tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/9-29d9beb9-d276-4372-bccd-a1930b973350.json", "/tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/10-89beda09-7704-4e0a-9661-ae96644d3330.json", "/tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/11-b34832b0-df96-4ed7-b6f8-fd1c1e95527e.json", "/tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/12-51d4ee80-a3da-498a-bf71-f636d266c35c.json"]}
2022-03-08T08:28:42  [D] [foreman_ansible] - parsing event file /tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/3-005056b9-655c-8159-958f-000000000006.json
2022-03-08T08:28:42  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "005056b9-655c-8159-958f-000000000006",
  "counter": 3,
  "stdout": "\r\nPLAY [all] *********************************************************************",
  "start_line": 2,
  "end_line": 4,
  "runner_ident": "566f9584-46aa-46c2-a131-411ea878a977",
  "event": "playbook_on_play_start",
  "pid": 890437,
  "created": "2022-03-08T07:28:41.980553",
  "parent_uuid": "f1903f44-33f5-4e08-8ccf-b09646cd50e6",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "f1903f44-33f5-4e08-8ccf-b09646cd50e6",
    "play": "all",
    "play_uuid": "005056b9-655c-8159-958f-000000000006",
    "play_pattern": "all",
    "name": "all",
    "pattern": "all",
    "uuid": "005056b9-655c-8159-958f-000000000006"
  }
}
2022-03-08T08:28:42  [D] [foreman_ansible] - parsing event file /tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/4-005056b9-655c-8159-958f-000000000008.json
2022-03-08T08:28:42  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "005056b9-655c-8159-958f-000000000008",
  "counter": 4,
  "stdout": "\r\nTASK [debug] *******************************************************************",
  "start_line": 4,
  "end_line": 6,
  "runner_ident": "566f9584-46aa-46c2-a131-411ea878a977",
  "event": "playbook_on_task_start",
  "pid": 890437,
  "created": "2022-03-08T07:28:41.990812",
  "parent_uuid": "005056b9-655c-8159-958f-000000000006",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "f1903f44-33f5-4e08-8ccf-b09646cd50e6",
    "play": "all",
    "play_uuid": "005056b9-655c-8159-958f-000000000006",
    "play_pattern": "all",
    "task": "debug",
    "task_uuid": "005056b9-655c-8159-958f-000000000008",
    "task_action": "debug",
    "task_args": "",
    "task_path": "/tmp/d20220308-844213-1hl1839/project/playbook.yml:6",
    "name": "debug",
    "is_conditional": false,
    "uuid": "005056b9-655c-8159-958f-000000000008"
  }
}
2022-03-08T08:28:42  [D] [foreman_ansible] - parsing event file /tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/5-3c992f36-d7f5-4a52-9eca-8cc5a385c011.json
2022-03-08T08:28:42  [D] [foreman_ansible] - handling event for host: "<hostname -f>": {
  "uuid": "3c992f36-d7f5-4a52-9eca-8cc5a385c011",
  "counter": 5,
  "stdout": "",
  "start_line": 6,
  "end_line": 6,
  "runner_ident": "566f9584-46aa-46c2-a131-411ea878a977",
  "event": "runner_on_start",
  "pid": 890437,
  "created": "2022-03-08T07:28:41.991403",
  "parent_uuid": "005056b9-655c-8159-958f-000000000008",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "f1903f44-33f5-4e08-8ccf-b09646cd50e6",
    "play": "all",
    "play_uuid": "005056b9-655c-8159-958f-000000000006",
    "play_pattern": "all",
    "task": "debug",
    "task_uuid": "005056b9-655c-8159-958f-000000000008",
    "task_action": "debug",
    "task_args": "",
    "task_path": "/tmp/d20220308-844213-1hl1839/project/playbook.yml:6",
    "host": "<hostname -f>",
    "uuid": "3c992f36-d7f5-4a52-9eca-8cc5a385c011"
  }
}
2022-03-08T08:28:42  [D] [foreman_ansible] - parsing event file /tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/6-f9c33371-c2f6-4a83-be51-bad858413d16.json
2022-03-08T08:28:42  [D] [foreman_ansible] - handling event for host: "<hostname -f>": {
  "uuid": "f9c33371-c2f6-4a83-be51-bad858413d16",
  "counter": 6,
  "stdout": "ok: [<hostname -f>] => (item=apply_chrony_conf) => {\r\n    \"msg\": \"Verify role is applied to content host var: apply_chrony_conf\"\r\n}",
  "start_line": 6,
  "end_line": 9,
  "runner_ident": "566f9584-46aa-46c2-a131-411ea878a977",
  "event": "runner_item_on_ok",
  "pid": 890437,
  "created": "2022-03-08T07:28:42.053238",
  "parent_uuid": "005056b9-655c-8159-958f-000000000008",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "f1903f44-33f5-4e08-8ccf-b09646cd50e6",
    "play": "all",
    "play_uuid": "005056b9-655c-8159-958f-000000000006",
    "play_pattern": "all",
    "task": "debug",
    "task_uuid": "005056b9-655c-8159-958f-000000000008",
    "task_action": "debug",
    "task_args": "",
    "task_path": "/tmp/d20220308-844213-1hl1839/project/playbook.yml:6",
    "host": "<hostname -f>",
    "res": {
      "msg": "Verify role is applied to content host var: apply_chrony_conf",
      "_ansible_verbose_always": true,
      "_ansible_no_log": false,
      "changed": false,
      "role": "apply_chrony_conf",
      "ansible_loop_var": "role",
      "_ansible_item_label": "apply_chrony_conf"
    },
    "uuid": "f9c33371-c2f6-4a83-be51-bad858413d16"
  }
}
2022-03-08T08:28:42  [D] [foreman_ansible] - parsing event file /tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/7-05371661-5479-4bfc-8d79-ed373ecf093c.json
2022-03-08T08:28:42  [D] [foreman_ansible] - handling event for host: "<hostname -f>": {
  "uuid": "05371661-5479-4bfc-8d79-ed373ecf093c",
  "counter": 7,
  "stdout": "",
  "start_line": 9,
  "end_line": 9,
  "runner_ident": "566f9584-46aa-46c2-a131-411ea878a977",
  "event": "runner_on_ok",
  "pid": 890437,
  "created": "2022-03-08T07:28:42.054133",
  "parent_uuid": "005056b9-655c-8159-958f-000000000008",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "f1903f44-33f5-4e08-8ccf-b09646cd50e6",
    "play": "all",
    "play_uuid": "005056b9-655c-8159-958f-000000000006",
    "play_pattern": "all",
    "task": "debug",
    "task_uuid": "005056b9-655c-8159-958f-000000000008",
    "task_action": "debug",
    "task_args": "",
    "task_path": "/tmp/d20220308-844213-1hl1839/project/playbook.yml:6",
    "host": "<hostname -f>",
    "remote_addr": "<hostname -f>",
    "res": {
      "results": [
        {
          "msg": "Verify role is applied to content host var: apply_chrony_conf",
          "_ansible_verbose_always": true,
          "failed": false,
          "_ansible_no_log": false,
          "changed": false,
          "role": "apply_chrony_conf",
          "ansible_loop_var": "role",
          "_ansible_item_label": "apply_chrony_conf"
        }
      ],
      "msg": "All items completed",
      "changed": false
    },
    "start": "2022-03-08T07:28:41.991331",
    "end": "2022-03-08T07:28:42.054046",
    "duration": 0.062715,
    "event_loop": null,
    "uuid": "05371661-5479-4bfc-8d79-ed373ecf093c"
  }
}
2022-03-08T08:28:42  [D] [foreman_ansible] - parsing event file /tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/8-005056b9-655c-8159-958f-00000000000a.json
2022-03-08T08:28:42  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "005056b9-655c-8159-958f-00000000000a",
  "counter": 8,
  "stdout": "\r\nTASK [Apply roles] *************************************************************",
  "start_line": 9,
  "end_line": 11,
  "runner_ident": "566f9584-46aa-46c2-a131-411ea878a977",
  "event": "playbook_on_task_start",
  "pid": 890437,
  "created": "2022-03-08T07:28:42.056792",
  "parent_uuid": "005056b9-655c-8159-958f-000000000006",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "f1903f44-33f5-4e08-8ccf-b09646cd50e6",
    "play": "all",
    "play_uuid": "005056b9-655c-8159-958f-000000000006",
    "play_pattern": "all",
    "task": "Apply roles",
    "task_uuid": "005056b9-655c-8159-958f-00000000000a",
    "task_action": "include_role",
    "task_args": "",
    "task_path": "/tmp/d20220308-844213-1hl1839/project/playbook.yml:12",
    "name": "Apply roles",
    "is_conditional": false,
    "uuid": "005056b9-655c-8159-958f-00000000000a"
  }
}
2022-03-08T08:28:42  [D] [foreman_ansible] - parsing event file /tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/9-29d9beb9-d276-4372-bccd-a1930b973350.json
2022-03-08T08:28:42  [D] [foreman_ansible] - handling event for host: "<hostname -f>": {
  "uuid": "29d9beb9-d276-4372-bccd-a1930b973350",
  "counter": 9,
  "stdout": "",
  "start_line": 11,
  "end_line": 11,
  "runner_ident": "566f9584-46aa-46c2-a131-411ea878a977",
  "event": "runner_on_start",
  "pid": 890437,
  "created": "2022-03-08T07:28:42.057484",
  "parent_uuid": "005056b9-655c-8159-958f-00000000000a",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "f1903f44-33f5-4e08-8ccf-b09646cd50e6",
    "play": "all",
    "play_uuid": "005056b9-655c-8159-958f-000000000006",
    "play_pattern": "all",
    "task": "Apply roles",
    "task_uuid": "005056b9-655c-8159-958f-00000000000a",
    "task_action": "include_role",
    "task_args": "",
    "task_path": "/tmp/d20220308-844213-1hl1839/project/playbook.yml:12",
    "host": "<hostname -f>",
    "uuid": "29d9beb9-d276-4372-bccd-a1930b973350"
  }
}
2022-03-08T08:28:42  [D] [foreman_ansible] - parsing event file /tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/10-89beda09-7704-4e0a-9661-ae96644d3330.json
2022-03-08T08:28:42  [D] [foreman_ansible] - handling event for host: "<hostname -f>": {
  "uuid": "89beda09-7704-4e0a-9661-ae96644d3330",
  "counter": 10,
  "stdout": "",
  "start_line": 11,
  "end_line": 11,
  "runner_ident": "566f9584-46aa-46c2-a131-411ea878a977",
  "event": "runner_item_on_ok",
  "pid": 890437,
  "created": "2022-03-08T07:28:42.086165",
  "parent_uuid": "005056b9-655c-8159-958f-00000000000a",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "f1903f44-33f5-4e08-8ccf-b09646cd50e6",
    "play": "all",
    "play_uuid": "005056b9-655c-8159-958f-000000000006",
    "play_pattern": "all",
    "task": "Apply roles",
    "task_uuid": "005056b9-655c-8159-958f-00000000000a",
    "task_action": "include_role",
    "task_args": "",
    "task_path": "/tmp/d20220308-844213-1hl1839/project/playbook.yml:12",
    "host": "<hostname -f>",
    "res": {
      "include_args": {
        "name": "{{ role }}"
      },
      "role": "apply_chrony_conf",
      "ansible_loop_var": "role",
      "_ansible_item_label": "apply_chrony_conf"
    },
    "uuid": "89beda09-7704-4e0a-9661-ae96644d3330"
  }
}
2022-03-08T08:28:42  [D] [foreman_ansible] - parsing event file /tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/11-b34832b0-df96-4ed7-b6f8-fd1c1e95527e.json
2022-03-08T08:28:42  [D] [foreman_ansible] - handling event for host: "<hostname -f>": {
  "uuid": "b34832b0-df96-4ed7-b6f8-fd1c1e95527e",
  "counter": 11,
  "stdout": "",
  "start_line": 11,
  "end_line": 11,
  "runner_ident": "566f9584-46aa-46c2-a131-411ea878a977",
  "event": "runner_on_ok",
  "pid": 890437,
  "created": "2022-03-08T07:28:42.086886",
  "parent_uuid": "005056b9-655c-8159-958f-00000000000a",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "f1903f44-33f5-4e08-8ccf-b09646cd50e6",
    "play": "all",
    "play_uuid": "005056b9-655c-8159-958f-000000000006",
    "play_pattern": "all",
    "task": "Apply roles",
    "task_uuid": "005056b9-655c-8159-958f-00000000000a",
    "task_action": "include_role",
    "task_args": "",
    "task_path": "/tmp/d20220308-844213-1hl1839/project/playbook.yml:12",
    "host": "<hostname -f>",
    "remote_addr": "<hostname -f>",
    "res": {
      "results": [
        {
          "include_args": {
            "name": "{{ role }}"
          },
          "role": "apply_chrony_conf",
          "ansible_loop_var": "role",
          "_ansible_item_label": "apply_chrony_conf"
        }
      ],
      "msg": "All items completed",
      "changed": false
    },
    "start": "2022-03-08T07:28:42.057414",
    "end": "2022-03-08T07:28:42.086800",
    "duration": 0.029386,
    "event_loop": null,
    "uuid": "b34832b0-df96-4ed7-b6f8-fd1c1e95527e"
  }
}
2022-03-08T08:28:42  [D] [foreman_ansible] - parsing event file /tmp/d20220308-844213-1hl1839/artifacts/566f9584-46aa-46c2-a131-411ea878a977/job_events/12-51d4ee80-a3da-498a-bf71-f636d266c35c.json
2022-03-08T08:28:42  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "51d4ee80-a3da-498a-bf71-f636d266c35c",
  "counter": 12,
  "stdout": "\r\nPLAY RECAP *********************************************************************\r\n<hostname -f>      : ok=1    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0   \r\n",
  "start_line": 11,
  "end_line": 15,
  "runner_ident": "566f9584-46aa-46c2-a131-411ea878a977",
  "event": "playbook_on_stats",
  "pid": 890437,
  "created": "2022-03-08T07:28:42.107323",
  "parent_uuid": "f1903f44-33f5-4e08-8ccf-b09646cd50e6",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "f1903f44-33f5-4e08-8ccf-b09646cd50e6",
    "changed": {
    },
    "dark": {
    },
    "failures": {
    },
    "ignored": {
    },
    "ok": {
      "<hostname -f>": 1
    },
    "processed": {
      "<hostname -f>": 1
    },
    "rescued": {
    },
    "skipped": {
    },
    "artifact_data": {
    },
    "uuid": "51d4ee80-a3da-498a-bf71-f636d266c35c"
  }
}
2022-03-08T08:28:42  [D] planning to refresh 86274b2f-9fa0-4201-85ad-d7d1b0974f77
2022-03-08T08:28:42  [D]          Step 7999adc7-1bb1-46c1-b4ef-b5b7417de1a9: 2 got event #<Proxy::Dynflow::Runner::Update:0x0000559cee39d150>
2022-03-08T08:28:42  [D]          Step 7999adc7-1bb1-46c1-b4ef-b5b7417de1a9: 2 suspended >>   running in phase      Run Proxy::Dynflow::Action::OutputCollector
2022-03-08T08:28:42 67c4682c [D]          Step 7999adc7-1bb1-46c1-b4ef-b5b7417de1a9: 2   running >> suspended in phase      Run Proxy::Dynflow::Action::OutputCollector
2022-03-08T08:28:43  [D] Ticker ticking for 1 events
2022-03-08T08:28:43  [D] refresh runner 86274b2f-9fa0-4201-85ad-d7d1b0974f77
2022-03-08T08:28:43  [D] refreshing runner
2022-03-08T08:28:43  [D] finish runner 86274b2f-9fa0-4201-85ad-d7d1b0974f77
2022-03-08T08:28:43  [D] closing session for command [86274b2f-9fa0-4201-85ad-d7d1b0974f77],0 actors left
2022-03-08T08:28:43  [D] terminate 86274b2f-9fa0-4201-85ad-d7d1b0974f77
2022-03-08T08:28:43  [D]          Step 0e3786ba-2188-4deb-a0f3-ba66465b1410: 2 got event #<Proxy::Dynflow::Runner::Update:0x0000559cee14beb0>
2022-03-08T08:28:43  [D]          Step 0e3786ba-2188-4deb-a0f3-ba66465b1410: 2 suspended >>   running in phase      Run Proxy::Dynflow::Action::BatchRunner
2022-03-08T08:28:43 67c4682c [D]          Step 0e3786ba-2188-4deb-a0f3-ba66465b1410: 2   running >>   success in phase      Run Proxy::Dynflow::Action::BatchRunner
2022-03-08T08:28:43  [D]          Step 7999adc7-1bb1-46c1-b4ef-b5b7417de1a9: 2 got event #<Proxy::Dynflow::Runner::Update:0x0000559cee149778>
2022-03-08T08:28:44  [D]          Step 7999adc7-1bb1-46c1-b4ef-b5b7417de1a9: 2 suspended >>   running in phase      Run Proxy::Dynflow::Action::OutputCollector
2022-03-08T08:28:44 67c4682c [D]          Step 7999adc7-1bb1-46c1-b4ef-b5b7417de1a9: 2   running >>   success in phase      Run Proxy::Dynflow::Action::OutputCollector
2022-03-08T08:28:44  [D]          Step 0e3786ba-2188-4deb-a0f3-ba66465b1410: 3   pending >>   running in phase Finalize Proxy::Dynflow::Action::BatchRunner
2022-03-08T08:28:44 67c4682c [D]          Step 0e3786ba-2188-4deb-a0f3-ba66465b1410: 3   running >>   success in phase Finalize Proxy::Dynflow::Action::BatchRunner
2022-03-08T08:28:44  [D] ExecutionPlan 0e3786ba-2188-4deb-a0f3-ba66465b1410      running >>   stopped
2022-03-08T08:28:44  [D]          Step 7999adc7-1bb1-46c1-b4ef-b5b7417de1a9: 3   pending >>   running in phase Finalize Proxy::Dynflow::Action::OutputCollector
2022-03-08T08:28:44 67c4682c [D]          Step 7999adc7-1bb1-46c1-b4ef-b5b7417de1a9: 3   running >>   success in phase Finalize Proxy::Dynflow::Action::OutputCollector
2022-03-08T08:28:44  [D] ExecutionPlan 7999adc7-1bb1-46c1-b4ef-b5b7417de1a9      running >>   stopped
2022-03-08T08:28:44  [D] accept: 172.27.10.80:55058
2022-03-08T08:28:44  [D] Rack::Handler::WEBrick is invoked.
2022-03-08T08:28:44 d6e0a92c [I] Started GET /dynflow/tasks/7999adc7-1bb1-46c1-b4ef-b5b7417de1a9/status
2022-03-08T08:28:44 d6e0a92c [D] verifying remote client 172.27.10.80 against trusted_hosts ["formanserver.domain"]
2022-03-08T08:28:44 d6e0a92c [I] Finished GET /dynflow/tasks/7999adc7-1bb1-46c1-b4ef-b5b7417de1a9/status with 200 (8.23 ms)
2022-03-08T08:28:44  [D] close: 172.27.10.80:55058
2022-03-08T08:28:45  [D] Executor heartbeat
2022-03-08T08:28:46  [D] accept: 172.27.10.80:55060
2022-03-08T08:28:46  [D] Rack::Handler::WEBrick is invoked.
2022-03-08T08:28:46 8306fa9d [I] Started GET /dynflow/tasks/7999adc7-1bb1-46c1-b4ef-b5b7417de1a9/status
2022-03-08T08:28:46 8306fa9d [D] verifying remote client 172.27.10.80 against trusted_hosts ["formanserver.domain"]
2022-03-08T08:28:46 8306fa9d [I] Finished GET /dynflow/tasks/7999adc7-1bb1-46c1-b4ef-b5b7417de1a9/status with 200 (2.83 ms)
2022-03-08T08:28:46  [D] close: 172.27.10.80:55060
2022-03-08T08:28:47  [D] accept: 172.27.10.80:55062
2022-03-08T08:28:47  [D] Rack::Handler::WEBrick is invoked.
2022-03-08T08:28:47 67173874 [I] Started GET /dynflow/tasks/7999adc7-1bb1-46c1-b4ef-b5b7417de1a9/status
2022-03-08T08:28:47 67173874 [D] verifying remote client 172.27.10.80 against trusted_hosts ["formanserver.domain"]
2022-03-08T08:28:47 67173874 [I] Finished GET /dynflow/tasks/7999adc7-1bb1-46c1-b4ef-b5b7417de1a9/status with 200 (2.92 ms)
2022-03-08T08:28:47  [D] close: 172.27.10.80:55062
2022-03-08T08:28:48  [D] accept: 172.27.10.80:55064
2022-03-08T08:28:48  [D] Rack::Handler::WEBrick is invoked.
2022-03-08T08:28:48 a28019c8 [I] Started GET /dynflow/tasks/7999adc7-1bb1-46c1-b4ef-b5b7417de1a9/status
2022-03-08T08:28:48 a28019c8 [D] verifying remote client 172.27.10.80 against trusted_hosts ["formanserver.domain"]
2022-03-08T08:28:48 a28019c8 [I] Finished GET /dynflow/tasks/7999adc7-1bb1-46c1-b4ef-b5b7417de1a9/status with 200 (2.88 ms)
2022-03-08T08:28:48  [D] close: 172.27.10.80:55064
2022-03-08T08:28:49  [D] accept: 172.27.10.80:55066
2022-03-08T08:28:49  [D] Rack::Handler::WEBrick is invoked.
2022-03-08T08:28:49 ae385047 [I] Started GET /dynflow/tasks/7999adc7-1bb1-46c1-b4ef-b5b7417de1a9/status
2022-03-08T08:28:49 ae385047 [D] verifying remote client 172.27.10.80 against trusted_hosts ["formanserver.domain"]
2022-03-08T08:28:49 ae385047 [I] Finished GET /dynflow/tasks/7999adc7-1bb1-46c1-b4ef-b5b7417de1a9/status with 200 (2.88 ms)
2022-03-08T08:28:49  [D] close: 172.27.10.80:55066
2022-03-08T08:28:50  [D]          Step 09a6937e-5ab3-464a-9037-83f5e3c471a5: 2 got event Dynflow::Action::WithPollingSubPlans::Poll
2022-03-08T08:28:50  [D]          Step 09a6937e-5ab3-464a-9037-83f5e3c471a5: 2 suspended >>   running in phase      Run Proxy::Dynflow::Action::SingleRunnerBatch
2022-03-08T08:28:50 67c4682c [D]          Step 09a6937e-5ab3-464a-9037-83f5e3c471a5: 2   running >>   success in phase      Run Proxy::Dynflow::Action::SingleRunnerBatch
2022-03-08T08:28:50  [D]          Step 09a6937e-5ab3-464a-9037-83f5e3c471a5: 5   pending >>   running in phase      Run Proxy::Dynflow::Action::BatchCallback
2022-03-08T08:28:50 67c4682c [D]          Step 09a6937e-5ab3-464a-9037-83f5e3c471a5: 5   running >>   success in phase      Run Proxy::Dynflow::Action::BatchCallback
2022-03-08T08:28:50  [D]          Step 09a6937e-5ab3-464a-9037-83f5e3c471a5: 3   pending >>   running in phase Finalize Proxy::Dynflow::Action::SingleRunnerBatch
2022-03-08T08:28:50 67c4682c [D]          Step 09a6937e-5ab3-464a-9037-83f5e3c471a5: 3   running >>   success in phase Finalize Proxy::Dynflow::Action::SingleRunnerBatch
2022-03-08T08:28:50  [D] ExecutionPlan 09a6937e-5ab3-464a-9037-83f5e3c471a5      running >>   stopped
2022-03-08T08:29:00  [D] Executor heartbeat
12

Nothing outstanding in there. It seems to run, until it reaches the point where it should apply the role and then it just does nothing?

Could you bump Administer > Settings > Ansible > Default verbosity level to 4, run the job again and post /var/log/foreman-proxy/proxy.log once more? If this doesn’t help then I’m out of ideas where to get more hints.

14

Yes quite strange. However, if i execute the plybk on the cli it works as expected:

root@foreman-test [Foreman-Test-Server] /etc/ansible # cat apply_chrony.yml
- name: Apply conform chronyd config in drop-in file
  hosts: all
  gather_facts: yes

  roles:
    - apply_chrony_conf


  tasks:

  - name: 1st task
    debug:
      msg: "1st task completed"

root@foreman-test [Foreman-Test-Server] /etc/ansible # ansible-playbook -i <hostname>, apply_chrony.yml -u root --ask-pass
SSH password:

PLAY [Apply conform chronyd config in drop-in file] ******************************************************************************************************************************************************

TASK [Gathering Facts] ****************************************************************************************************************************************************************************************
ok: [<hostname>]
HTTPSConnectionPool(host='foreman-test.domain', port=443): Max retries exceeded with url: /api/v2/hosts/facts (Caused by SSLError(SSLError(1, '[SSL: CERTIFICATE_VERIFY_FAILED] certificate verify failed (ssl.c:897)'),))

TASK [apply_chrony_conf : check if chrony is running] *********************************************************************************************************************************************************
skipping: [<hostname>]

The verbose output of job in foreman:

2022-03-08T10:33:57  [D]          Step 3d16db21-08a5-41ae-9677-a837b1d39dac: 2 suspended >>   running in phase      Run Proxy::Dynflow::Action::SingleRunnerBatch
2022-03-08T10:33:57 7b027d23 [D]          Step 3d16db21-08a5-41ae-9677-a837b1d39dac: 2   running >>   success in phase      Run Proxy::Dynflow::Action::SingleRunnerBatch
2022-03-08T10:33:57  [D]          Step 3d16db21-08a5-41ae-9677-a837b1d39dac: 5   pending >>   running in phase      Run Proxy::Dynflow::Action::BatchCallback
2022-03-08T10:33:57 7b027d23 [D]          Step 3d16db21-08a5-41ae-9677-a837b1d39dac: 5   running >>   success in phase      Run Proxy::Dynflow::Action::BatchCallback
2022-03-08T10:33:57  [D]          Step 3d16db21-08a5-41ae-9677-a837b1d39dac: 3   pending >>   running in phase Finalize Proxy::Dynflow::Action::SingleRunnerBatch
2022-03-08T10:33:57 7b027d23 [D]          Step 3d16db21-08a5-41ae-9677-a837b1d39dac: 3   running >>   success in phase Finalize Proxy::Dynflow::Action::SingleRunnerBatch
2022-03-08T10:33:57  [D] ExecutionPlan 3d16db21-08a5-41ae-9677-a837b1d39dac      running >>   stopped
2022-03-08T10:34:11  [D] Executor heartbeat
2022-03-08T10:34:26  [D] Executor heartbeat
2022-03-08T10:34:41  [D] Executor heartbeat
2022-03-08T10:34:55  [D] accept: 172.27.10.80:55708
2022-03-08T10:34:55  [D] Rack::Handler::WEBrick is invoked.
2022-03-08T10:34:55 61a76a20 [I] Started GET /dynflow/tasks/count state=running
2022-03-08T10:34:55 61a76a20 [D] verifying remote client 172.27.10.80 against trusted_hosts ["<foremanserver.fqdn>"]
2022-03-08T10:34:55 61a76a20 [I] Finished GET /dynflow/tasks/count with 200 (1.32 ms)
2022-03-08T10:34:55  [D] close: 172.27.10.80:55708
2022-03-08T10:34:55  [D] accept: 172.27.10.80:55710
2022-03-08T10:34:55  [D] Rack::Handler::WEBrick is invoked.
2022-03-08T10:34:55 61a76a20 [I] Started POST /dynflow/tasks/launch
2022-03-08T10:34:55 61a76a20 [D] verifying remote client 172.27.10.80 against trusted_hosts ["<foremanserver.fqdn>"]
2022-03-08T10:34:55 61a76a20 [D] ExecutionPlan f21e58c8-3f21-47b1-8a32-a868a48c2de3      pending >>  planning
2022-03-08T10:34:55 61a76a20 [D]          Step f21e58c8-3f21-47b1-8a32-a868a48c2de3: 1   pending >>   running in phase     Plan Proxy::Dynflow::Action::SingleRunnerBatch
2022-03-08T10:34:55 61a76a20 [D] ExecutionPlan f6376789-30bf-40a6-ae03-418cff5a836c      pending >>  planning
2022-03-08T10:34:55 61a76a20 [D]          Step f6376789-30bf-40a6-ae03-418cff5a836c: 1   pending >>   running in phase     Plan Proxy::Dynflow::Action::OutputCollector
2022-03-08T10:34:55 61a76a20 [D]          Step f6376789-30bf-40a6-ae03-418cff5a836c: 1   running >>   success in phase     Plan Proxy::Dynflow::Action::OutputCollector
2022-03-08T10:34:55 61a76a20 [D] ExecutionPlan f6376789-30bf-40a6-ae03-418cff5a836c     planning >>   planned
2022-03-08T10:34:55  [D] ExecutionPlan f6376789-30bf-40a6-ae03-418cff5a836c      planned >>   running
2022-03-08T10:34:55 61a76a20 [D] ExecutionPlan e672842d-1801-487c-98ea-416bc37d857a      pending >>  planning
2022-03-08T10:34:55 61a76a20 [D]          Step e672842d-1801-487c-98ea-416bc37d857a: 1   pending >>   running in phase     Plan Proxy::Dynflow::Action::BatchRunner
2022-03-08T10:34:55 61a76a20 [D]          Step e672842d-1801-487c-98ea-416bc37d857a: 1   running >>   success in phase     Plan Proxy::Dynflow::Action::BatchRunner
2022-03-08T10:34:55 61a76a20 [D] ExecutionPlan e672842d-1801-487c-98ea-416bc37d857a     planning >>   planned
2022-03-08T10:34:55  [D]          Step f6376789-30bf-40a6-ae03-418cff5a836c: 2   pending >>   running in phase      Run Proxy::Dynflow::Action::OutputCollector
2022-03-08T10:34:55 61a76a20 [D]          Step f6376789-30bf-40a6-ae03-418cff5a836c: 2   running >> suspended in phase      Run Proxy::Dynflow::Action::OutputCollector
2022-03-08T10:34:55 61a76a20 [D]          Step f21e58c8-3f21-47b1-8a32-a868a48c2de3: 4   pending >>   running in phase     Plan Proxy::Dynflow::Action::BatchCallback
2022-03-08T10:34:55 61a76a20 [D]          Step f21e58c8-3f21-47b1-8a32-a868a48c2de3: 4   running >>   success in phase     Plan Proxy::Dynflow::Action::BatchCallback
2022-03-08T10:34:55 61a76a20 [D]          Step f21e58c8-3f21-47b1-8a32-a868a48c2de3: 1   running >>   success in phase     Plan Proxy::Dynflow::Action::SingleRunnerBatch
2022-03-08T10:34:55 61a76a20 [D] ExecutionPlan f21e58c8-3f21-47b1-8a32-a868a48c2de3     planning >>   planned
2022-03-08T10:34:55  [D] ExecutionPlan e672842d-1801-487c-98ea-416bc37d857a      planned >>   running
2022-03-08T10:34:55  [D]          Step e672842d-1801-487c-98ea-416bc37d857a: 2   pending >>   running in phase      Run Proxy::Dynflow::Action::BatchRunner
2022-03-08T10:34:55 61a76a20 [D]          Step e672842d-1801-487c-98ea-416bc37d857a: 2   running >> suspended in phase      Run Proxy::Dynflow::Action::BatchRunner
2022-03-08T10:34:55 61a76a20 [I] Finished POST /dynflow/tasks/launch with 200 (51.89 ms)
2022-03-08T10:34:55  [D] ExecutionPlan f21e58c8-3f21-47b1-8a32-a868a48c2de3      planned >>   running
2022-03-08T10:34:55  [D] start runner b5fc2b7f-3342-4921-9e7b-479c82f555fc
2022-03-08T10:34:55  [D] close: 172.27.10.80:55710
2022-03-08T10:34:55  [D] [foreman_ansible] - Running command '{"FOREMAN_CALLBACK_DISABLE"=>"1"} ansible-runner run /tmp/d20220308-947457-133r1i1 -p playbook.yml -vvvv'
2022-03-08T10:34:55  [D] refresh runner b5fc2b7f-3342-4921-9e7b-479c82f555fc
2022-03-08T10:34:55  [D] refreshing runner
2022-03-08T10:34:55  [D]          Step f21e58c8-3f21-47b1-8a32-a868a48c2de3: 2   pending >>   running in phase      Run Proxy::Dynflow::Action::SingleRunnerBatch
2022-03-08T10:34:55 61a76a20 [D]          Step f21e58c8-3f21-47b1-8a32-a868a48c2de3: 2   running >> suspended in phase      Run Proxy::Dynflow::Action::SingleRunnerBatch
2022-03-08T10:34:55  [D] planning to refresh b5fc2b7f-3342-4921-9e7b-479c82f555fc
2022-03-08T10:34:56  [D] Ticker ticking for 1 events
2022-03-08T10:34:56  [D] refresh runner b5fc2b7f-3342-4921-9e7b-479c82f555fc
2022-03-08T10:34:56  [D] refreshing runner
2022-03-08T10:34:56  [D] [foreman_ansible] - processing event files: ["/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/1-f73ff9fd-c0b8-4025-afcf-3487878ad3e3.json", "/mp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/2-fb11714f-250b-446d-ab24-19e4ea782cb1.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067da/job_events/3-c820024f-2d09-4dcc-9844-ad7837abc29f.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/4-829d89e1-fab7-48e7-864b-038506545e54.json", "/tmp/d2022038-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/5-bc49420b-f5a9-4724-a92d-f7875dee0b0e.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_evens/6-588b3cba-4780-49d7-92b4-16e50a70a1c1.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/7-0155da01-c8f8-4f60-b3b0-3e7ea0800b9e.json", "/tmp/d20220308-947457-13r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/8-ba705861-9b8d-4999-9d2b-63350c2af8bb.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/9-f9678bf-467b-459b-b25d-afa23a92aed3.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/10-97f7c6f5-210f-411e-ac4e-387deacefb20.json"]}
2022-03-08T10:34:56  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/1-f73ff9fd-c0b8-4025-afcf-3487878ad3e3.json
2022-03-08T10:34:56  [D] [foreman_ansible] - handling event broadcast: {
  "event": "verbose",
  "uuid": "f73ff9fd-c0b8-4025-afcf-3487878ad3e3",
  "counter": 1,
  "stdout": "ansible-playbook 2.9.27",
  "start_line": 0,
  "end_line": 1,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa"
}
2022-03-08T10:34:56  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/2-fb11714f-250b-446d-ab24-19e4ea782cb1.json
2022-03-08T10:34:56  [D] [foreman_ansible] - handling event broadcast: {
  "event": "verbose",
  "uuid": "fb11714f-250b-446d-ab24-19e4ea782cb1",
  "counter": 2,
  "stdout": "  config file = /usr/share/foreman-proxy/.ansible.cfg",
  "start_line": 1,
  "end_line": 2,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa"
}
2022-03-08T10:34:56  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/3-c820024f-2d09-4dcc-9844-ad7837abc29f.json
2022-03-08T10:34:56  [D] [foreman_ansible] - handling event broadcast: {
  "event": "verbose",
  "uuid": "c820024f-2d09-4dcc-9844-ad7837abc29f",
  "counter": 3,
  "stdout": "  configured module search path = ['/usr/share/foreman-proxy/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']",
  "start_line": 2,
  "end_line": 3,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa"
}
2022-03-08T10:34:56  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/4-829d89e1-fab7-48e7-864b-038506545e54.json
2022-03-08T10:34:56  [D] [foreman_ansible] - handling event broadcast: {
  "event": "verbose",
  "uuid": "829d89e1-fab7-48e7-864b-038506545e54",
  "counter": 4,
  "stdout": "  ansible python module location = /usr/lib/python3.6/site-packages/ansible",
  "start_line": 3,
  "end_line": 4,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa"
}
2022-03-08T10:34:56  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/5-bc49420b-f5a9-4724-a92d-f7875dee0b0e.json
2022-03-08T10:34:56  [D] [foreman_ansible] - handling event broadcast: {
  "event": "verbose",
  "uuid": "bc49420b-f5a9-4724-a92d-f7875dee0b0e",
  "counter": 5,
  "stdout": "  executable location = /usr/bin/ansible-playbook",
  "start_line": 4,
  "end_line": 5,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa"
}
2022-03-08T10:34:56  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/6-588b3cba-4780-49d7-92b4-16e50a70a1c1.json
2022-03-08T10:34:56  [D] [foreman_ansible] - handling event broadcast: {
  "event": "verbose",
  "uuid": "588b3cba-4780-49d7-92b4-16e50a70a1c1",
  "counter": 6,
  "stdout": "  python version = 3.6.8 (default, Sep  9 2021, 07:49:02) [GCC 8.5.0 20210514 (Red Hat 8.5.0-3)]",
  "start_line": 5,
  "end_line": 6,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa"
}
2022-03-08T10:34:56  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/7-0155da01-c8f8-4f60-b3b0-3e7ea0800b9e.json
2022-03-08T10:34:56  [D] [foreman_ansible] - handling event broadcast: {
  "event": "verbose",
  "uuid": "0155da01-c8f8-4f60-b3b0-3e7ea0800b9e",
  "counter": 7,
  "stdout": "Using /usr/share/foreman-proxy/.ansible.cfg as config file",
  "start_line": 6,
  "end_line": 7,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa"
}
2022-03-08T10:34:56  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/8-ba705861-9b8d-4999-9d2b-63350c2af8bb.json
2022-03-08T10:34:56  [D] [foreman_ansible] - handling event broadcast: {
  "event": "verbose",
  "uuid": "ba705861-9b8d-4999-9d2b-63350c2af8bb",
  "counter": 8,
  "stdout": "setting up inventory plugins",
  "start_line": 7,
  "end_line": 8,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa"
}
2022-03-08T10:34:56  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/9-f9678b0f-467b-459b-b25d-afa23a92aed3.json
2022-03-08T10:34:56  [D] [foreman_ansible] - handling event broadcast: {
  "event": "verbose",
  "uuid": "f9678b0f-467b-459b-b25d-afa23a92aed3",
  "counter": 9,
  "stdout": "host_list declined parsing /tmp/d20220308-947457-133r1i1/inventory/hosts as it did not pass its verify_file() method",
  "start_line": 8,
  "end_line": 9,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa"
}
2022-03-08T10:34:56  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/10-97f7c6f5-210f-411e-ac4e-387deacefb20.json
2022-03-08T10:34:56  [D] [foreman_ansible] - handling event broadcast: {
  "event": "verbose",
  "uuid": "97f7c6f5-210f-411e-ac4e-387deacefb20",
  "counter": 10,
  "stdout": "Parsed /tmp/d20220308-947457-133r1i1/inventory/hosts inventory source with script plugin",
  "start_line": 9,
  "end_line": 10,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa"
}
2022-03-08T10:34:56  [D] planning to refresh b5fc2b7f-3342-4921-9e7b-479c82f555fc
2022-03-08T10:34:56  [D]          Step f6376789-30bf-40a6-ae03-418cff5a836c: 2 got event #<Proxy::Dynflow::Runner::Update:0x00005601c56189e8>
2022-03-08T10:34:56  [D]          Step f6376789-30bf-40a6-ae03-418cff5a836c: 2 suspended >>   running in phase      Run Proxy::Dynflow::Action::OutputCollector
2022-03-08T10:34:56 61a76a20 [D]          Step f6376789-30bf-40a6-ae03-418cff5a836c: 2   running >> suspended in phase      Run Proxy::Dynflow::Action::OutputCollector
2022-03-08T10:34:56  [D] Executor heartbeat
2022-03-08T10:34:57  [D] Ticker ticking for 1 events
2022-03-08T10:34:57  [D] refresh runner b5fc2b7f-3342-4921-9e7b-479c82f555fc
2022-03-08T10:34:57  [D] refreshing runner
2022-03-08T10:34:57  [D] [foreman_ansible] - processing event files: ["/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/11-4c87f394-c5cd-4fe0-a259-3dab5dbd14e2.json", "tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/12-d4225feb-aecc-47a2-aac2-9d5d0e00a796.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f06daa/job_events/13-7cda3eae-35f3-4176-89d4-f8d7c9a6bbc8.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/14-dd9f7383-4189-4327-8973-3c4bb0241d73.json", "/tmp/d2020308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/15-5c8f4fd0-8796-4665-b0b9-0030e6afa12d.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/jobevents/16-e63f60f7-3989-4186-a57a-67108f3b7144.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/17-55a571bb-0de4-4748-b050-5bfdf5da31ff.json", "/tmp/d20220308-97457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/18-59c7aa22-4f1f-4f87-b03a-54fd9bb62e15.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/9-bb2e1fbd-b3ad-4dcb-817f-511a0f077e85.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/20-5b5e14a7-1eed-4186-a4fd-81d1da95103a.json", "/tmp/d20220308-947457-13r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/21-b7ae0516-ec92-45ac-b8a6-84975eb3b9e7.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/22-28bfcbd-0f89-43e8-bdba-055002eea675.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/23-7ff8c94f-4475-4506-9730-d5a864c710b8.json", "/tmp/d20220308-947457-133r1i1/arifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/24-95dcfc13-d370-4790-a6c9-7f177e89ec70.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/25-a045a1a5-a7414627-85a1-6dc7836912e0.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/26-1f0d5937-0729-496f-a714-097796e4e3bc.json", "/tmp/d20220308-947457-133r1i1/artifacts/61dd45d-8833-438f-99b9-88715f067daa/job_events/27-b481a22f-6c43-43fd-ac38-2bb4b823d9b0.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/28-772a8f39-b7e5-44fb-854-f57b192025c8.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/29-ff537e91-c3a0-489b-831f-21d71030bb46.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d8833-438f-99b9-88715f067daa/job_events/30-b50e3773-27cb-4e02-b90b-dba447012408.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/31-10ebba3c-6034-4cf5-a415-04206771558.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/32-005056b9-655c-9445-ca1e-000000000006.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-43f-99b9-88715f067daa/job_events/33-7883bfa8-6cd3-48ae-8cb0-7ed22768f8b3.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/34-005056b9-655c-9445-ca1e-000000000008.son", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/35-80780e54-4d9f-4e00-8322-7ae86a7b5002.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-8715f067daa/job_events/36-7515c08f-b261-4ae1-b79d-10e5fb1baaba.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/37-48234757-61a9-446b-a56f-939e6310fbe6.json", "tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/38-005056b9-655c-9445-ca1e-00000000000a.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f06daa/job_events/39-82e9fd70-dab9-4d17-b4d0-3ba561417c5c.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/40-ca6d4c82-f9d1-482c-81d5-efd4a89d9ab1.json", "/tmp/d2020308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/41-83a5ebf6-8b3c-4938-a9e0-6b1499807e59.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/jobevents/42-79ec0012-e0ab-4bb8-929b-d327554dfa49.json", "/tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/43-447a2850-219a-4304-b544-71c1c84021cb.json", "/tmp/d20220308-97457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/44-ad54023b-ad00-45fb-9295-94eeed64f9d5.json"]}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/11-4c87f394-c5cd-4fe0-a259-3dab5dbd14e2.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "4c87f394-c5cd-4fe0-a259-3dab5dbd14e2",
  "counter": 11,
  "stdout": "Loading callback plugin awx_display of type stdout, v2.0 from /usr/lib/python3.6/site-packages/ansible_runner/callbacks/awx_display.py",
  "start_line": 10,
  "end_line": 11,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.537521",
  "verbosity": 4,
  "event_data": {
    "verbose": true,
    "uuid": "4c87f394-c5cd-4fe0-a259-3dab5dbd14e2"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/12-d4225feb-aecc-47a2-aac2-9d5d0e00a796.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "d4225feb-aecc-47a2-aac2-9d5d0e00a796",
  "counter": 12,
  "stdout": "Skipping callback 'actionable', as we already have a stdout callback.",
  "start_line": 11,
  "end_line": 12,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.578097",
  "verbosity": 2,
  "event_data": {
    "verbose": true,
    "uuid": "d4225feb-aecc-47a2-aac2-9d5d0e00a796"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/13-7cda3eae-35f3-4176-89d4-f8d7c9a6bbc8.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "7cda3eae-35f3-4176-89d4-f8d7c9a6bbc8",
  "counter": 13,
  "stdout": "Skipping callback 'awx_display', as we already have a stdout callback.",
  "start_line": 12,
  "end_line": 13,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.578477",
  "verbosity": 2,
  "event_data": {
    "verbose": true,
    "uuid": "7cda3eae-35f3-4176-89d4-f8d7c9a6bbc8"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/14-dd9f7383-4189-4327-8973-3c4bb0241d73.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "dd9f7383-4189-4327-8973-3c4bb0241d73",
  "counter": 14,
  "stdout": "Skipping callback 'counter_enabled', as we already have a stdout callback.",
  "start_line": 13,
  "end_line": 14,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.578759",
  "verbosity": 2,
  "event_data": {
    "verbose": true,
    "uuid": "dd9f7383-4189-4327-8973-3c4bb0241d73"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/15-5c8f4fd0-8796-4665-b0b9-0030e6afa12d.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "5c8f4fd0-8796-4665-b0b9-0030e6afa12d",
  "counter": 15,
  "stdout": "Skipping callback 'debug', as we already have a stdout callback.",
  "start_line": 14,
  "end_line": 15,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.578978",
  "verbosity": 2,
  "event_data": {
    "verbose": true,
    "uuid": "5c8f4fd0-8796-4665-b0b9-0030e6afa12d"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/16-e63f60f7-3989-4186-a57a-67108f3b7144.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "e63f60f7-3989-4186-a57a-67108f3b7144",
  "counter": 16,
  "stdout": "Skipping callback 'dense', as we already have a stdout callback.",
  "start_line": 15,
  "end_line": 16,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.579192",
  "verbosity": 2,
  "event_data": {
    "verbose": true,
    "uuid": "e63f60f7-3989-4186-a57a-67108f3b7144"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/17-55a571bb-0de4-4748-b050-5bfdf5da31ff.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "55a571bb-0de4-4748-b050-5bfdf5da31ff",
  "counter": 17,
  "stdout": "Skipping callback 'dense', as we already have a stdout callback.",
  "start_line": 16,
  "end_line": 17,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.579395",
  "verbosity": 2,
  "event_data": {
    "verbose": true,
    "uuid": "55a571bb-0de4-4748-b050-5bfdf5da31ff"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/18-59c7aa22-4f1f-4f87-b03a-54fd9bb62e15.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "59c7aa22-4f1f-4f87-b03a-54fd9bb62e15",
  "counter": 18,
  "stdout": "Skipping callback 'full_skip', as we already have a stdout callback.",
  "start_line": 17,
  "end_line": 18,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.579612",
  "verbosity": 2,
  "event_data": {
    "verbose": true,
    "uuid": "59c7aa22-4f1f-4f87-b03a-54fd9bb62e15"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/19-bb2e1fbd-b3ad-4dcb-817f-511a0f077e85.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "bb2e1fbd-b3ad-4dcb-817f-511a0f077e85",
  "counter": 19,
  "stdout": "Skipping callback 'json', as we already have a stdout callback.",
  "start_line": 18,
  "end_line": 19,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.579850",
  "verbosity": 2,
  "event_data": {
    "verbose": true,
    "uuid": "bb2e1fbd-b3ad-4dcb-817f-511a0f077e85"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/20-5b5e14a7-1eed-4186-a4fd-81d1da95103a.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "5b5e14a7-1eed-4186-a4fd-81d1da95103a",
  "counter": 20,
  "stdout": "Skipping callback 'minimal', as we already have a stdout callback.",
  "start_line": 19,
  "end_line": 20,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.580118",
  "verbosity": 2,
  "event_data": {
    "verbose": true,
    "uuid": "5b5e14a7-1eed-4186-a4fd-81d1da95103a"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/21-b7ae0516-ec92-45ac-b8a6-84975eb3b9e7.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "b7ae0516-ec92-45ac-b8a6-84975eb3b9e7",
  "counter": 21,
  "stdout": "Skipping callback 'null', as we already have a stdout callback.",
  "start_line": 20,
  "end_line": 21,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.580350",
  "verbosity": 2,
  "event_data": {
    "verbose": true,
    "uuid": "b7ae0516-ec92-45ac-b8a6-84975eb3b9e7"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/22-28bfcebd-0f89-43e8-bdba-055002eea675.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "28bfcebd-0f89-43e8-bdba-055002eea675",
  "counter": 22,
  "stdout": "Skipping callback 'oneline', as we already have a stdout callback.",
  "start_line": 21,
  "end_line": 22,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.580551",
  "verbosity": 2,
  "event_data": {
    "verbose": true,
    "uuid": "28bfcebd-0f89-43e8-bdba-055002eea675"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/23-7ff8c94f-4475-4506-9730-d5a864c710b8.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "7ff8c94f-4475-4506-9730-d5a864c710b8",
  "counter": 23,
  "stdout": "Skipping callback 'selective', as we already have a stdout callback.",
  "start_line": 22,
  "end_line": 23,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.580808",
  "verbosity": 2,
  "event_data": {
    "verbose": true,
    "uuid": "7ff8c94f-4475-4506-9730-d5a864c710b8"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/24-95dcfc13-d370-4790-a6c9-7f177e89ec70.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "95dcfc13-d370-4790-a6c9-7f177e89ec70",
  "counter": 24,
  "stdout": "Skipping callback 'skippy', as we already have a stdout callback.",
  "start_line": 23,
  "end_line": 24,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.581026",
  "verbosity": 2,
  "event_data": {
    "verbose": true,
    "uuid": "95dcfc13-d370-4790-a6c9-7f177e89ec70"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/25-a045a1a5-a741-4627-85a1-6dc7836912e0.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "a045a1a5-a741-4627-85a1-6dc7836912e0",
  "counter": 25,
  "stdout": "Skipping callback 'stderr', as we already have a stdout callback.",
  "start_line": 24,
  "end_line": 25,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.581251",
  "verbosity": 2,
  "event_data": {
    "verbose": true,
    "uuid": "a045a1a5-a741-4627-85a1-6dc7836912e0"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/26-1f0d5937-0729-496f-a714-097796e4e3bc.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "1f0d5937-0729-496f-a714-097796e4e3bc",
  "counter": 26,
  "stdout": "Skipping callback 'unixy', as we already have a stdout callback.",
  "start_line": 25,
  "end_line": 26,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.581495",
  "verbosity": 2,
  "event_data": {
    "verbose": true,
    "uuid": "1f0d5937-0729-496f-a714-097796e4e3bc"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/27-b481a22f-6c43-43fd-ac38-2bb4b823d9b0.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "b481a22f-6c43-43fd-ac38-2bb4b823d9b0",
  "counter": 27,
  "stdout": "Skipping callback 'yaml', as we already have a stdout callback.",
  "start_line": 26,
  "end_line": 27,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.581708",
  "verbosity": 2,
  "event_data": {
    "verbose": true,
    "uuid": "b481a22f-6c43-43fd-ac38-2bb4b823d9b0"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/28-772a8f39-b7e5-44fb-8554-f57b192025c8.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "772a8f39-b7e5-44fb-8554-f57b192025c8",
  "counter": 28,
  "stdout": "Loading callback plugin theforeman.foreman.foreman of type notification, v2.0 from /usr/share/ansible/collections/ansible_collections/theforeman/foreman/plugins/callback/foreman.py",
  "start_line": 27,
  "end_line": 28,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.581912",
  "verbosity": 4,
  "event_data": {
    "verbose": true,
    "uuid": "772a8f39-b7e5-44fb-8554-f57b192025c8"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/29-ff537e91-c3a0-489b-831f-21d71030bb46.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "ff537e91-c3a0-489b-831f-21d71030bb46",
  "counter": 29,
  "stdout": "[WARNING]: Callback disabled by environment. Disabling the Foreman callback\r\nplugin.",
  "start_line": 28,
  "end_line": 30,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "warning",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.582433",
  "event_data": {
    "warning": true,
    "uuid": "ff537e91-c3a0-489b-831f-21d71030bb46"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/30-b50e3773-27cb-4e02-b90b-dba447012408.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "b50e3773-27cb-4e02-b90b-dba447012408",
  "counter": 30,
  "stdout": "\r\nPLAYBOOK: playbook.yml *********************************************************\r\nPositional arguments: playbook.yml\r\nverbosity: 4\r\nconnection: smart\r\ntimeout: 10\r\nbecome_method: sdo\r\ntags: ('all',)\r\ninventory: ('/tmp/d20220308-947457-133r1i1/inventory',)\r\nforks: 5",
  "start_line": 30,
  "end_line": 40,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "playbook_on_start",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.582929",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "b50e3773-27cb-4e02-b90b-dba447012408",
    "uuid": "b50e3773-27cb-4e02-b90b-dba447012408"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/31-10ebba3c-6034-4cf5-a415-042060771558.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "10ebba3c-6034-4cf5-a415-042060771558",
  "counter": 31,
  "stdout": "1 plays in playbook.yml",
  "start_line": 40,
  "end_line": 41,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.583341",
  "parent_uuid": "b50e3773-27cb-4e02-b90b-dba447012408",
  "verbosity": 2,
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "b50e3773-27cb-4e02-b90b-dba447012408",
    "verbose": true,
    "uuid": "10ebba3c-6034-4cf5-a415-042060771558"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/32-005056b9-655c-9445-ca1e-000000000006.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "005056b9-655c-9445-ca1e-000000000006",
  "counter": 32,
  "stdout": "\r\nPLAY [all] *********************************************************************",
  "start_line": 41,
  "end_line": 43,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "playbook_on_play_start",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.585524",
  "parent_uuid": "b50e3773-27cb-4e02-b90b-dba447012408",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "b50e3773-27cb-4e02-b90b-dba447012408",
    "play": "all",
    "play_uuid": "005056b9-655c-9445-ca1e-000000000006",
    "play_pattern": "all",
    "name": "all",
    "pattern": "all",
    "uuid": "005056b9-655c-9445-ca1e-000000000006"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/33-7883bfa8-6cd3-48ae-8cb0-7ed22768f8b3.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "7883bfa8-6cd3-48ae-8cb0-7ed22768f8b3",
  "counter": 33,
  "stdout": "META: ran handlers",
  "start_line": 43,
  "end_line": 44,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.591180",
  "parent_uuid": "005056b9-655c-9445-ca1e-000000000006",
  "verbosity": 2,
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "b50e3773-27cb-4e02-b90b-dba447012408",
    "play": "all",
    "play_uuid": "005056b9-655c-9445-ca1e-000000000006",
    "play_pattern": "all",
    "verbose": true,
    "uuid": "7883bfa8-6cd3-48ae-8cb0-7ed22768f8b3"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/34-005056b9-655c-9445-ca1e-000000000008.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "005056b9-655c-9445-ca1e-000000000008",
  "counter": 34,
  "stdout": "\r\nTASK [debug] *******************************************************************\r\ntask path: /tmp/d20220308-947457-133r1i1/project/playbook.yml:6",
  "start_line": 44,
  "end_line": 47,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "playbook_on_task_start",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.595644",
  "parent_uuid": "005056b9-655c-9445-ca1e-000000000006",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "b50e3773-27cb-4e02-b90b-dba447012408",
    "play": "all",
    "play_uuid": "005056b9-655c-9445-ca1e-000000000006",
    "play_pattern": "all",
    "task": "debug",
    "task_uuid": "005056b9-655c-9445-ca1e-000000000008",
    "task_action": "debug",
    "task_args": "",
    "task_path": "/tmp/d20220308-947457-133r1i1/project/playbook.yml:6",
    "name": "debug",
    "is_conditional": false,
    "uuid": "005056b9-655c-9445-ca1e-000000000008"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/35-80780e54-4d9f-4e00-8322-7ae86a7b5002.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event for host: "<hostname -f>": {
  "uuid": "80780e54-4d9f-4e00-8322-7ae86a7b5002",
  "counter": 35,
  "stdout": "",
  "start_line": 47,
  "end_line": 47,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "runner_on_start",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.596240",
  "parent_uuid": "005056b9-655c-9445-ca1e-000000000008",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "b50e3773-27cb-4e02-b90b-dba447012408",
    "play": "all",
    "play_uuid": "005056b9-655c-9445-ca1e-000000000006",
    "play_pattern": "all",
    "task": "debug",
    "task_uuid": "005056b9-655c-9445-ca1e-000000000008",
    "task_action": "debug",
    "task_args": "",
    "task_path": "/tmp/d20220308-947457-133r1i1/project/playbook.yml:6",
    "host": "<hostname -f>",
    "uuid": "80780e54-4d9f-4e00-8322-7ae86a7b5002"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/36-7515c08f-b261-4ae1-b79d-10e5fb1baaba.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event for host: "<hostname -f>": {
  "uuid": "7515c08f-b261-4ae1-b79d-10e5fb1baaba",
  "counter": 36,
  "stdout": "ok: [<hostname -f>] => (item=apply_chrony_conf) => {\r\n    \"msg\": \"Verify role is applied to content host var: apply_chrony_conf\"\r\n}",
  "start_line": 47,
  "end_line": 50,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "runner_item_on_ok",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.671445",
  "parent_uuid": "005056b9-655c-9445-ca1e-000000000008",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "b50e3773-27cb-4e02-b90b-dba447012408",
    "play": "all",
    "play_uuid": "005056b9-655c-9445-ca1e-000000000006",
    "play_pattern": "all",
    "task": "debug",
    "task_uuid": "005056b9-655c-9445-ca1e-000000000008",
    "task_action": "debug",
    "task_args": "",
    "task_path": "/tmp/d20220308-947457-133r1i1/project/playbook.yml:6",
    "host": "<hostname -f>",
    "res": {
      "msg": "Verify role is applied to content host var: apply_chrony_conf",
      "_ansible_verbose_always": true,
      "_ansible_no_log": false,
      "changed": false,
      "role": "apply_chrony_conf",
      "ansible_loop_var": "role",
      "_ansible_item_label": "apply_chrony_conf"
    },
    "uuid": "7515c08f-b261-4ae1-b79d-10e5fb1baaba"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/37-48234757-61a9-446b-a56f-939e6310fbe6.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event for host: "<hostname -f>": {
  "uuid": "48234757-61a9-446b-a56f-939e6310fbe6",
  "counter": 37,
  "stdout": "",
  "start_line": 50,
  "end_line": 50,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "runner_on_ok",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.672292",
  "parent_uuid": "005056b9-655c-9445-ca1e-000000000008",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "b50e3773-27cb-4e02-b90b-dba447012408",
    "play": "all",
    "play_uuid": "005056b9-655c-9445-ca1e-000000000006",
    "play_pattern": "all",
    "task": "debug",
    "task_uuid": "005056b9-655c-9445-ca1e-000000000008",
    "task_action": "debug",
    "task_args": "",
    "task_path": "/tmp/d20220308-947457-133r1i1/project/playbook.yml:6",
    "host": "<hostname -f>",
    "remote_addr": "<hostname -f>",
    "res": {
      "results": [
        {
          "msg": "Verify role is applied to content host var: apply_chrony_conf",
          "_ansible_verbose_always": true,
          "failed": false,
          "_ansible_no_log": false,
          "changed": false,
          "role": "apply_chrony_conf",
          "ansible_loop_var": "role",
          "_ansible_item_label": "apply_chrony_conf"
        }
      ],
      "msg": "All items completed",
      "changed": false
    },
    "start": "2022-03-08T09:34:56.596175",
    "end": "2022-03-08T09:34:56.672207",
    "duration": 0.076032,
    "event_loop": null,
    "uuid": "48234757-61a9-446b-a56f-939e6310fbe6"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/38-005056b9-655c-9445-ca1e-00000000000a.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "005056b9-655c-9445-ca1e-00000000000a",
  "counter": 38,
  "stdout": "\r\nTASK [Apply roles] *************************************************************\r\ntask path: /tmp/d20220308-947457-133r1i1/project/playbook.yml:12",
  "start_line": 50,
  "end_line": 53,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "playbook_on_task_start",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.674905",
  "parent_uuid": "005056b9-655c-9445-ca1e-000000000006",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "b50e3773-27cb-4e02-b90b-dba447012408",
    "play": "all",
    "play_uuid": "005056b9-655c-9445-ca1e-000000000006",
    "play_pattern": "all",
    "task": "Apply roles",
    "task_uuid": "005056b9-655c-9445-ca1e-00000000000a",
    "task_action": "include_role",
    "task_args": "",
    "task_path": "/tmp/d20220308-947457-133r1i1/project/playbook.yml:12",
    "name": "Apply roles",
    "is_conditional": false,
    "uuid": "005056b9-655c-9445-ca1e-00000000000a"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/39-82e9fd70-dab9-4d17-b4d0-3ba561417c5c.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event for host: "<hostname -f>": {
  "uuid": "82e9fd70-dab9-4d17-b4d0-3ba561417c5c",
  "counter": 39,
  "stdout": "",
  "start_line": 53,
  "end_line": 53,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "runner_on_start",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.675575",
  "parent_uuid": "005056b9-655c-9445-ca1e-00000000000a",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "b50e3773-27cb-4e02-b90b-dba447012408",
    "play": "all",
    "play_uuid": "005056b9-655c-9445-ca1e-000000000006",
    "play_pattern": "all",
    "task": "Apply roles",
    "task_uuid": "005056b9-655c-9445-ca1e-00000000000a",
    "task_action": "include_role",
    "task_args": "",
    "task_path": "/tmp/d20220308-947457-133r1i1/project/playbook.yml:12",
    "host": "<hostname -f>",
    "uuid": "82e9fd70-dab9-4d17-b4d0-3ba561417c5c"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/40-ca6d4c82-f9d1-482c-81d5-efd4a89d9ab1.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event for host: "<hostname -f>": {
  "uuid": "ca6d4c82-f9d1-482c-81d5-efd4a89d9ab1",
  "counter": 40,
  "stdout": "",
  "start_line": 53,
  "end_line": 53,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "runner_item_on_ok",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.705181",
  "parent_uuid": "005056b9-655c-9445-ca1e-00000000000a",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "b50e3773-27cb-4e02-b90b-dba447012408",
    "play": "all",
    "play_uuid": "005056b9-655c-9445-ca1e-000000000006",
    "play_pattern": "all",
    "task": "Apply roles",
    "task_uuid": "005056b9-655c-9445-ca1e-00000000000a",
    "task_action": "include_role",
    "task_args": "",
    "task_path": "/tmp/d20220308-947457-133r1i1/project/playbook.yml:12",
    "host": "<hostname -f>",
    "res": {
      "include_args": {
        "name": "{{ role }}"
      },
      "role": "apply_chrony_conf",
      "ansible_loop_var": "role",
      "_ansible_item_label": "apply_chrony_conf"
    },
    "uuid": "ca6d4c82-f9d1-482c-81d5-efd4a89d9ab1"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/41-83a5ebf6-8b3c-4938-a9e0-6b1499807e59.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event for host: "<hostname -f>": {
  "uuid": "83a5ebf6-8b3c-4938-a9e0-6b1499807e59",
  "counter": 41,
  "stdout": "",
  "start_line": 53,
  "end_line": 53,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "runner_on_ok",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.705925",
  "parent_uuid": "005056b9-655c-9445-ca1e-00000000000a",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "b50e3773-27cb-4e02-b90b-dba447012408",
    "play": "all",
    "play_uuid": "005056b9-655c-9445-ca1e-000000000006",
    "play_pattern": "all",
    "task": "Apply roles",
    "task_uuid": "005056b9-655c-9445-ca1e-00000000000a",
    "task_action": "include_role",
    "task_args": "",
    "task_path": "/tmp/d20220308-947457-133r1i1/project/playbook.yml:12",
    "host": "<hostname -f>",
    "remote_addr": "<hostname -f>",
    "res": {
      "results": [
        {
          "include_args": {
            "name": "{{ role }}"
          },
          "role": "apply_chrony_conf",
          "ansible_loop_var": "role",
          "_ansible_item_label": "apply_chrony_conf"
        }
      ],
      "msg": "All items completed",
      "changed": false
    },
    "start": "2022-03-08T09:34:56.675509",
    "end": "2022-03-08T09:34:56.705841",
    "duration": 0.030332,
    "event_loop": null,
    "uuid": "83a5ebf6-8b3c-4938-a9e0-6b1499807e59"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/42-79ec0012-e0ab-4bb8-929b-d327554dfa49.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "79ec0012-e0ab-4bb8-929b-d327554dfa49",
  "counter": 42,
  "stdout": "META: ran handlers",
  "start_line": 53,
  "end_line": 54,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.725101",
  "parent_uuid": "005056b9-655c-9445-ca1e-00000000000a",
  "verbosity": 2,
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "b50e3773-27cb-4e02-b90b-dba447012408",
    "play": "all",
    "play_uuid": "005056b9-655c-9445-ca1e-000000000006",
    "play_pattern": "all",
    "task": "Apply roles",
    "task_uuid": "005056b9-655c-9445-ca1e-00000000000a",
    "task_action": "include_role",
    "task_args": "",
    "task_path": "/tmp/d20220308-947457-133r1i1/project/playbook.yml:12",
    "verbose": true,
    "uuid": "79ec0012-e0ab-4bb8-929b-d327554dfa49"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/43-447a2850-219a-4304-b544-71c1c84021cb.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "447a2850-219a-4304-b544-71c1c84021cb",
  "counter": 43,
  "stdout": "META: ran handlers",
  "start_line": 54,
  "end_line": 55,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "verbose",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.725716",
  "parent_uuid": "005056b9-655c-9445-ca1e-00000000000a",
  "verbosity": 2,
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "b50e3773-27cb-4e02-b90b-dba447012408",
    "play": "all",
    "play_uuid": "005056b9-655c-9445-ca1e-000000000006",
    "play_pattern": "all",
    "task": "Apply roles",
    "task_uuid": "005056b9-655c-9445-ca1e-00000000000a",
    "task_action": "include_role",
    "task_args": "",
    "task_path": "/tmp/d20220308-947457-133r1i1/project/playbook.yml:12",
    "verbose": true,
    "uuid": "447a2850-219a-4304-b544-71c1c84021cb"
  }
}
2022-03-08T10:34:57  [D] [foreman_ansible] - parsing event file /tmp/d20220308-947457-133r1i1/artifacts/d61dd45d-8833-438f-99b9-88715f067daa/job_events/44-ad54023b-ad00-45fb-9295-94eeed64f9d5.json
2022-03-08T10:34:57  [D] [foreman_ansible] - handling event broadcast: {
  "uuid": "ad54023b-ad00-45fb-9295-94eeed64f9d5",
  "counter": 44,
  "stdout": "\r\nPLAY RECAP *********************************************************************\r\n<hostname -f>      : ok=1    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0  \r\n",
  "start_line": 55,
  "end_line": 59,
  "runner_ident": "d61dd45d-8833-438f-99b9-88715f067daa",
  "event": "playbook_on_stats",
  "pid": 948086,
  "created": "2022-03-08T09:34:56.726674",
  "parent_uuid": "b50e3773-27cb-4e02-b90b-dba447012408",
  "event_data": {
    "playbook": "playbook.yml",
    "playbook_uuid": "b50e3773-27cb-4e02-b90b-dba447012408",
    "changed": {
    },
    "dark": {
    },
    "failures": {
    },
    "ignored": {
    },
    "ok": {
      "<hostname -f>": 1
    },
    "processed": {
      "<hostname -f>": 1
    },
    "rescued": {
    },
    "skipped": {
    },
    "artifact_data": {
    },
    "uuid": "ad54023b-ad00-45fb-9295-94eeed64f9d5"
  }
}
2022-03-08T10:34:57  [D] planning to refresh b5fc2b7f-3342-4921-9e7b-479c82f555fc
2022-03-08T10:34:57  [D]          Step f6376789-30bf-40a6-ae03-418cff5a836c: 2 got event #<Proxy::Dynflow::Runner::Update:0x00005601c61403c0>
2022-03-08T10:34:57  [D]          Step f6376789-30bf-40a6-ae03-418cff5a836c: 2 suspended >>   running in phase      Run Proxy::Dynflow::Action::OutputCollector
2022-03-08T10:34:57 61a76a20 [D]          Step f6376789-30bf-40a6-ae03-418cff5a836c: 2   running >> suspended in phase      Run Proxy::Dynflow::Action::OutputCollector
2022-03-08T10:34:58  [D] Ticker ticking for 1 events
2022-03-08T10:34:58  [D] refresh runner b5fc2b7f-3342-4921-9e7b-479c82f555fc
2022-03-08T10:34:58  [D] refreshing runner
2022-03-08T10:34:58  [D] finish runner b5fc2b7f-3342-4921-9e7b-479c82f555fc
2022-03-08T10:34:58  [D] closing session for command [b5fc2b7f-3342-4921-9e7b-479c82f555fc],0 actors left
2022-03-08T10:34:58  [D] terminate b5fc2b7f-3342-4921-9e7b-479c82f555fc
2022-03-08T10:34:58  [D]          Step e672842d-1801-487c-98ea-416bc37d857a: 2 got event #<Proxy::Dynflow::Runner::Update:0x00005601c5a19998>
2022-03-08T10:34:58  [D]          Step e672842d-1801-487c-98ea-416bc37d857a: 2 suspended >>   running in phase      Run Proxy::Dynflow::Action::BatchRunner
2022-03-08T10:34:58 61a76a20 [D]          Step e672842d-1801-487c-98ea-416bc37d857a: 2   running >>   success in phase      Run Proxy::Dynflow::Action::BatchRunner
2022-03-08T10:34:58  [D]          Step f6376789-30bf-40a6-ae03-418cff5a836c: 2 got event #<Proxy::Dynflow::Runner::Update:0x00005601c5a09d68>
2022-03-08T10:34:58  [D]          Step f6376789-30bf-40a6-ae03-418cff5a836c: 2 suspended >>   running in phase      Run Proxy::Dynflow::Action::OutputCollector
2022-03-08T10:34:58 61a76a20 [D]          Step f6376789-30bf-40a6-ae03-418cff5a836c: 2   running >>   success in phase      Run Proxy::Dynflow::Action::OutputCollector
2022-03-08T10:34:58  [D]          Step e672842d-1801-487c-98ea-416bc37d857a: 3   pending >>   running in phase Finalize Proxy::Dynflow::Action::BatchRunner
2022-03-08T10:34:58 61a76a20 [D]          Step e672842d-1801-487c-98ea-416bc37d857a: 3   running >>   success in phase Finalize Proxy::Dynflow::Action::BatchRunner
2022-03-08T10:34:58  [D]          Step f6376789-30bf-40a6-ae03-418cff5a836c: 3   pending >>   running in phase Finalize Proxy::Dynflow::Action::OutputCollector
2022-03-08T10:34:58 61a76a20 [D]          Step f6376789-30bf-40a6-ae03-418cff5a836c: 3   running >>   success in phase Finalize Proxy::Dynflow::Action::OutputCollector
2022-03-08T10:34:58  [D] ExecutionPlan e672842d-1801-487c-98ea-416bc37d857a      running >>   stopped
2022-03-08T10:34:58  [D] ExecutionPlan f6376789-30bf-40a6-ae03-418cff5a836c      running >>   stopped
2022-03-08T10:35:05  [D]          Step f21e58c8-3f21-47b1-8a32-a868a48c2de3: 2 got event Dynflow::Action::WithPollingSubPlans::Poll
2022-03-08T10:35:05  [D]          Step f21e58c8-3f21-47b1-8a32-a868a48c2de3: 2 suspended >>   running in phase      Run Proxy::Dynflow::Action::SingleRunnerBatch
2022-03-08T10:35:05 61a76a20 [D]          Step f21e58c8-3f21-47b1-8a32-a868a48c2de3: 2   running >>   success in phase      Run Proxy::Dynflow::Action::SingleRunnerBatch
2022-03-08T10:35:05  [D]          Step f21e58c8-3f21-47b1-8a32-a868a48c2de3: 5   pending >>   running in phase      Run Proxy::Dynflow::Action::BatchCallback
2022-03-08T10:35:05 61a76a20 [D]          Step f21e58c8-3f21-47b1-8a32-a868a48c2de3: 5   running >>   success in phase      Run Proxy::Dynflow::Action::BatchCallback
2022-03-08T10:35:05  [D]          Step f21e58c8-3f21-47b1-8a32-a868a48c2de3: 3   pending >>   running in phase Finalize Proxy::Dynflow::Action::SingleRunnerBatch
2022-03-08T10:35:05 61a76a20 [D]          Step f21e58c8-3f21-47b1-8a32-a868a48c2de3: 3   running >>   success in phase Finalize Proxy::Dynflow::Action::SingleRunnerBatch
2022-03-08T10:35:05  [D] ExecutionPlan f21e58c8-3f21-47b1-8a32-a868a48c2de3      running >>   stopped
2022-03-08T10:35:11  [D] Executor heartbeat
15

That is not a fair comparison now, is it? In the example you posted you’re running ansible-playbook (not ansible-runner) as root (not as foreman-proxy) and you’re running a different playbook (you’re using declarative roles statement instead of dynamically including roles at runtime).

That being said, I must admit I don’t have any leads. @ezr-ondrej any ideas?

16

Well, yes! Just wanted to make clear that the role is valid. Thank you very much for your help!

17

Ok, problem solved. Obviously this was a permission problem on the role itself. I never suspected that since the role was just copypasted from ansible-server and in the logs there was no hint which pointed to a perm-problem. Everything was more obvious than that… thanks for help!

1 Like