Created attachment 1601779 [details] playbook to reproduce the problem Description of problem: The output from some playbooks is not parsed correctly by Ansible::Runner::Response#parse_stdout. The attached playbook illustrates the problem. Version-Release number of selected component (if applicable): 5.11.0.18 How reproducible: Every time Steps to Reproduce: 1. Import the attached playbook into a repository, add to an appliance, and synchronise the repo. 2. Create an embedded Ansible playbook method to run the playbook. Set "Logging Output" to "Always" 3. Run the method from simulation. Actual results: A long list of error lines in evm.log, starting: [----] W, [2019-08-08T11:14:44.336638 #32452:2b118ebf85b8] WARN -- : Q-task_id([e0dca415-34a9-425a-a806-1886b951dda1]) MIQ(Ansible::Runner::Response#parse_stdout) Couldn't parse JSON from: 765: unexpected token at ': "00:1a:4a:a0:15:2f", ' [----] W, [2019-08-08T11:14:44.336815 #32452:2b118ebf85b8] WARN -- : Q-task_id([e0dca415-34a9-425a-a806-1886b951dda1]) MIQ(Ansible::Runner::Response#parse_stdout) Couldn't parse JSON from: 765: unexpected token at ': 1500, ... and terminating with: [----] E, [2019-08-08T11:15:01.060863 #32452:2b118ebf85b8] ERROR -- : MIQ(ManageIQ::Providers::EmbeddedAnsible::AutomationManager::PlaybookRunner#log_stdout) Failed to get stdout from playbook listvars.yml [----] E, [2019-08-08T11:15:01.061207 #32452:2b118ebf85b8] ERROR -- : [TypeError]: no implicit conversion of String into Integer Method:[block (2 levels) in <class:LogProxy>] [----] E, [2019-08-08T11:15:01.061344 #32452:2b118ebf85b8] ERROR -- : /var/www/miq/vmdb/app/models/manageiq/providers/embedded_ansible/automation_manager/job.rb:115:in `[]' /var/www/miq/vmdb/app/models/manageiq/providers/embedded_ansible/automation_manager/job.rb:115:in `block in raw_stdout_txt' /var/www/miq/vmdb/app/models/manageiq/providers/embedded_ansible/automation_manager/job.rb:115:in `collect' /var/www/miq/vmdb/app/models/manageiq/providers/embedded_ansible/automation_manager/job.rb:115:in `raw_stdout_txt' /var/www/miq/vmdb/app/models/manageiq/providers/embedded_ansible/automation_manager/job.rb:47:in `raw_stdout' /var/www/miq/vmdb/app/models/manageiq/providers/embedded_ansible/automation_manager/playbook_runner.rb:189:in `log_stdout' /var/www/miq/vmdb/app/models/manageiq/providers/embedded_ansible/automation_manager/playbook_runner.rb:82:in `poll_ansible_tower_job_status' /var/www/miq/vmdb/app/models/job/state_machine.rb:34:in `signal' /var/www/miq/vmdb/app/models/miq_queue.rb:460:in `block in dispatch_method' /usr/share/ruby/timeout.rb:93:in `block in timeout' /usr/share/ruby/timeout.rb:33:in `block in catch' /usr/share/ruby/timeout.rb:33:in `catch' /usr/share/ruby/timeout.rb:33:in `catch' /usr/share/ruby/timeout.rb:108:in `timeout' /var/www/miq/vmdb/app/models/miq_queue.rb:458:in `dispatch_method' /var/www/miq/vmdb/app/models/miq_queue.rb:435:in `block in deliver' /var/www/miq/vmdb/app/models/user.rb:290:in `with_user_group' /var/www/miq/vmdb/app/models/miq_queue.rb:435:in `deliver' /var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:104:in `deliver_queue_message' /var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:137:in `deliver_message' /var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:155:in `block in do_work' /var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:149:in `loop' /var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:149:in `do_work' /var/www/miq/vmdb/app/models/miq_worker/runner.rb:329:in `block in do_work_loop' /var/www/miq/vmdb/app/models/miq_worker/runner.rb:326:in `loop' /var/www/miq/vmdb/app/models/miq_worker/runner.rb:326:in `do_work_loop' /var/www/miq/vmdb/app/models/miq_worker/runner.rb:153:in `run' /var/www/miq/vmdb/app/models/miq_worker/runner.rb:127:in `start' /var/www/miq/vmdb/app/models/miq_worker/runner.rb:22:in `start_worker' /var/www/miq/vmdb/app/models/miq_worker.rb:398:in `block in start_runner_via_fork' /opt/rh/cfme-gemset/gems/nakayoshi_fork-0.0.4/lib/nakayoshi_fork.rb:23:in `fork' /opt/rh/cfme-gemset/gems/nakayoshi_fork-0.0.4/lib/nakayoshi_fork.rb:23:in `fork' /var/www/miq/vmdb/app/models/miq_worker.rb:396:in `start_runner_via_fork' /var/www/miq/vmdb/app/models/miq_worker.rb:386:in `start_runner' /var/www/miq/vmdb/app/models/miq_worker.rb:437:in `start' /var/www/miq/vmdb/app/models/miq_worker.rb:269:in `start_worker' /var/www/miq/vmdb/app/models/miq_worker.rb:147:in `block in sync_workers' /var/www/miq/vmdb/app/models/miq_worker.rb:147:in `times' /var/www/miq/vmdb/app/models/miq_worker.rb:147:in `sync_workers' /var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:54:in `block in sync_workers' /var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:50:in `each' /var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:50:in `sync_workers' /var/www/miq/vmdb/app/models/miq_server.rb:154:in `start' /var/www/miq/vmdb/app/models/miq_server.rb:245:in `start' /var/www/miq/vmdb/lib/workers/evm_server.rb:27:in `start' /var/www/miq/vmdb/lib/workers/evm_server.rb:48:in `start' /var/www/miq/vmdb/lib/workers/bin/evm_server.rb:4:in `<main>' Expected results: The playbook output should be printed to evm.log. For example on CFME 5.10.6.1 the following is listed for the same playbook: [----] I, [2019-08-08T06:20:04.648237 #3526:d50f5c] INFO -- : MIQ(ManageIQ::Providers::EmbeddedAnsible::AutomationManager::PlaybookRunner#log_stdout) Stdout from playbook listvars.yml: PLAY [List Variables] ********************************************************** TASK [Gathering Facts] ********************************************************* ok: [localhost] TASK [Display all variables/facts known for a host] **************************** ok: [localhost] => { "hostvars[inventory_hostname]": { "ansible_all_ipv4_addresses": [ "10.19.136.230" ], "ansible_all_ipv6_addresses": [ "2620:52:0:1388:bcef:feff:feed:73", "fe80::bcef:feff:feed:73" ], ... Additional info: This is regression from CFME 5.10 where this playbook runs and displays output successfully
Woops, sorry for not updating this BZ, but this has been fixed here: https://github.com/ManageIQ/manageiq/pull/19147 Also forgot to update the commit messages to include this BZ, so I will move the to POST when it is backported to ivanchuk.
Also https://github.com/ManageIQ/manageiq/pull/19160
New commits detected on ManageIQ/manageiq/ivanchuk: https://github.com/ManageIQ/manageiq/commit/2c765d8da64f799cba169a0843c45a0f354c7602 commit 2c765d8da64f799cba169a0843c45a0f354c7602 Author: Nick Carboni <ncarboni> AuthorDate: Thu Aug 15 15:05:15 2019 -0400 Commit: Nick Carboni <ncarboni> CommitDate: Thu Aug 15 15:05:15 2019 -0400 Merge pull request #19147 from NickLaMuro/fix_borked_ansible_runner_output_rendering [Ansible::Runner] Handle edge cases from poor `stdout` data from `ansible-runner` (cherry picked from commit 2f571a4183e7c857bfb5643d8ae80d7fa0feceb0) https://bugzilla.redhat.com/show_bug.cgi?id=1739015 lib/ansible/runner/response.rb | 35 +- spec/lib/ansible/runner/response_spec.rb | 81 + 2 files changed, 114 insertions(+), 2 deletions(-) https://github.com/ManageIQ/manageiq/commit/c854fe97cf44d922e5b2e4961aba2ecdd5c1e2f5 commit c854fe97cf44d922e5b2e4961aba2ecdd5c1e2f5 Author: Nick Carboni <ncarboni> AuthorDate: Fri Aug 16 09:04:28 2019 -0400 Commit: Nick Carboni <ncarboni> CommitDate: Fri Aug 16 09:04:28 2019 -0400 Merge pull request #19160 from NickLaMuro/fix_ident_with_ansible_runner_stdout [Ansible::Runner::Response] Fix ident for stdout (cherry picked from commit eefbc338bea4bf7312459d2342ed2daefa93cec3) https://bugzilla.redhat.com/show_bug.cgi?id=1739015 lib/ansible/runner/response.rb | 2 +- spec/lib/ansible/runner/response_spec.rb | 21 +- 2 files changed, 20 insertions(+), 3 deletions(-)
Able to see proper output after running attached playbook. Verified Version: 5.11.0.21.20190821214526_b0060d0
Just as an FYI, I did propose a fix to `ansible-runner` to fix this: https://github.com/ansible/ansible-runner/pull/335 but need to work through some CI failures that weren't present in my local environment. Anyway, we have already worked around this with my patch, but just providing this as a note for the future. -Nick LaMuro