Ok
But one thing - there’s nothing in proxy’s log, everything is in foremans production log. I’m running playbooks on the same machine foreman resides in.
2018-02-25 02:30:57 3c1ced0a [app] [D] Task 'Deploy TFTP PXEGrub2 config for mac001a0000072d.krtech.loc' *completed*
2018-02-25 02:30:57 3c1ced0a [app] [D] Task 'Deploy TFTP PXELinux config for mac001a0000072d.krtech.loc' *completed*
2018-02-25 02:30:57 3c1ced0a [app] [D] Task 'Deploy TFTP PXEGrub config for mac001a0000072d.krtech.loc' *completed*
2018-02-25 02:30:57 3c1ced0a [app] [D] Task 'Delete PuppetCA autosign entry for mac001a0000072d.krtech.loc' *completed*
2018-02-25 02:30:57 3c1ced0a [dynflow] [D] ExecutionPlan 49630ea4-6b8c-4225-844f-b96ad1cbab37 pending >> planning
2018-02-25 02:30:57 3c1ced0a [dynflow] [D] Step 49630ea4-6b8c-4225-844f-b96ad1cbab37: 1 pending >> running in phase Plan Actions::ForemanAnsible::P$2018-02-25 02:30:57 3c1ced0a [dynflow] [D] Step 49630ea4-6b8c-4225-844f-b96ad1cbab37: 2 pending >> running in phase Plan Actions::ProxyAction
2018-02-25 02:30:57 3c1ced0a [dynflow] [D] Step 49630ea4-6b8c-4225-844f-b96ad1cbab37: 2 running >> success in phase Plan Actions::ProxyAction
2018-02-25 02:30:57 3c1ced0a [dynflow] [D] Step 49630ea4-6b8c-4225-844f-b96ad1cbab37: 1 running >> success in phase Plan Actions::ForemanAnsible::P$2018-02-25 02:30:57 3c1ced0a [dynflow] [D] ExecutionPlan 49630ea4-6b8c-4225-844f-b96ad1cbab37 planning >> planned
2018-02-25 02:30:57 3c1ced0a [app] [I] Task for Ansible roles on mac001a0000072d.krtech.loc before_provision: /tasks/b269a378-9c78-4f93-a17d-f9c3e168c5de.
2018-02-25 02:30:57 3c1ced0a [app] [D] custom hook before_provision on mac001a0000072d.krtech.loc will be executed if defined.
2018-02-25 02:30:57 3c1ced0a [notifications] [D] Notification event: Hosts::BuildCompleted - checking for notifications
2018-02-25 02:30:57 [dynflow] [D] ExecutionPlan 49630ea4-6b8c-4225-844f-b96ad1cbab37 planned >> running
2018-02-25 02:30:57 [dynflow] [D] Step 49630ea4-6b8c-4225-844f-b96ad1cbab37: 3 pending >> running in phase Run Actions::ProxyAction
2018-02-25 02:30:57 3c1ced0a [app] [I] Completed 201 Created in 1115ms (ActiveRecord: 66.7ms)
2018-02-25 02:30:57 aa49033e [app] [I] Started GET "/notification_recipients" for 10.150.250.81 at 2018-02-25 02:30:57 +0300
2018-02-25 02:30:57 aa49033e [app] [I] Processing by NotificationRecipientsController#index as JSON
2018-02-25 02:30:57 aa49033e [app] [I] Current user: admin (administrator)
2018-02-25 02:30:57 aa49033e [app] [D] Setting current user thread-local variable to admin
2018-02-25 02:30:57 aa49033e [notifications] [D] Cache Miss: notification, writing cache for notification-4
2018-02-25 02:30:57 aa49033e [notifications] [D] Expiring notification cache notification-4 in 3600 seconds
2018-02-25 02:30:57 aa49033e [app] [D] Body: {"notifications":[]}
2018-02-25 02:30:57 aa49033e [app] [I] Completed 200 OK in 16ms (Views: 0.2ms | ActiveRecord: 2.6ms)
2018-02-25 02:30:58 [dynflow] [D] Step 49630ea4-6b8c-4225-844f-b96ad1cbab37: 3 running >> suspended in phase Run Actions::ProxyAction
2018-02-25 02:30:59 0dc196b7 [app] [I] Started POST "/api/v2/reports" for ::1 at 2018-02-25 02:30:59 +0300
2018-02-25 02:30:59 0dc196b7 [app] [I] Processing by Api::V2::ReportsController#create as JSON
2018-02-25 02:30:59 0dc196b7 [app] [I] Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
2018-02-25 02:30:59 0dc196b7 [app] [D] Examining client certificate to extract dn and sans
2018-02-25 02:30:59 0dc196b7 [app] [D] Client sent certificate with subject 'deploy.krtech.loc' and subject alt names '["deploy.krtech.loc", "puppet", "puppet.krtec$$"deploy.krtech.loc"]
2018-02-25 02:30:59 0dc196b7 [app] [I] Current user: foreman_api_admin (administrator)
2018-02-25 02:30:59 0dc196b7 [app] [D] Setting current user thread-local variable to foreman_api_admin
2018-02-25 02:30:59 0dc196b7 [app] [D] Processing report: {"reported_at"=>"2018-02-25 02:30:59 841840", "metrics"=>{"time"=>{"total"=>0}}, "host"=>"mac001a0000072d.$2018-02-25 02:31:00 0dc196b7 [app] [D] no owner or recipients for alert on mac001a0000072d.krtech.loc
2018-02-25 02:31:00 0dc196b7 [app] [I] Imported report for mac001a0000072d.krtech.loc in 0.07 seconds, status refreshed in 0.02 seconds
2018-02-25 02:31:00 0dc196b7 [app] [I] Rendered api/v2/reports/create.json.rabl (13.5ms)
2018-02-25 02:31:00 0dc196b7 [app] [D] Body: {"metrics":{"time":{"total":0}},"created_at":"2018-02-24 23:30:59 UTC","updated_at":"2018-02-24 23:30:59 UTC","id":139,$2018-02-25 02:31:00 0dc196b7 [app] [I] Completed 201 Created in 137ms (Views: 21.0ms | ActiveRecord: 26.9ms)
2018-02-25 02:31:00 1d19a617 [app] [I] Started POST "/api/v2/reports" for ::1 at 2018-02-25 02:31:00 +0300
2018-02-25 02:31:00 1d19a617 [app] [I] Processing by Api::V2::ReportsController#create as JSON
2018-02-25 02:31:00 1d19a617 [app] [I] Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
2018-02-25 02:31:00 1d19a617 [app] [D] Examining client certificate to extract dn and sans
2018-02-25 02:31:00 1d19a617 [app] [D] Client sent certificate with subject 'deploy.krtech.loc' and subject alt names '["deploy.krtech.loc", "puppet", "puppet.krtec$2018-02-25 02:31:00 1d19a617 [app] [D] Verifying request from ["deploy.krtech.loc", "puppet", "puppet.krtech.loc"] against ["deploy.krtech.loc", "localhost", "deplo$2018-02-25 02:31:00 1d19a617 [app] [I] Current user: foreman_api_admin (administrator)
2018-02-25 02:31:00 1d19a617 [app] [D] Setting current user thread-local variable to foreman_api_admin
2018-02-25 02:31:00 1d19a617 [app] [D] Processing report: {"reported_at"=>"2018-02-25 02:31:00 075129", "metrics"=>{"time"=>{"total"=>1}}, "host"=>"mac001a0000072d.$2018-02-25 02:31:00 1d19a617 [app] [D] no owner or recipients for alert on mac001a0000072d.krtech.loc
2018-02-25 02:31:00 1d19a617 [app] [D] Body: {"metrics":{"time":{"total":1}},"created_at":"2018-02-24 23:31:00 UTC","updated_at":"2018-02-24 23:31:00 UTC","id":140,$2018-02-25 02:31:00 1d19a617 [app] [I] Completed 201 Created in 96ms (Views: 15.4ms | ActiveRecord: 19.5ms)
2018-02-25 02:31:01 5841fea7 [app] [I] Started POST "/foreman_tasks/api/tasks/callback" for 10.0.152.10 at 2018-02-25 02:31:01 +0300
2018-02-25 02:31:01 5841fea7 [app] [I] Processing by ForemanTasks::Api::TasksController#callback as */*
2018-02-25 02:31:01 5841fea7 [app] [I] Parameters: {"callback"=>{"task_id"=>"b269a378-9c78-4f93-a17d-f9c3e168c5de", "step_id"=>3}, "data"=>{"result"=>[{"output_ty$2018-02-25 02:31:01 5841fea7 [app] [D] Examining client certificate to extract dn and sans
2018-02-25 02:31:01 5841fea7 [app] [D] Client sent certificate with subject 'deploy.krtech.loc' and subject alt names '["deploy.krtech.loc", "puppet", "puppet.krtec$2018-02-25 02:31:01 5841fea7 [app] [D] Verifying request from ["deploy.krtech.loc", "puppet", "puppet.krtech.loc"] against ["deploy.krtech.loc", "localhost", "deplo$2018-02-25 02:31:01 5841fea7 [app] [I] Current user: foreman_api_admin (administrator)
2018-02-25 02:31:01 5841fea7 [app] [D] Setting current user thread-local variable to foreman_api_admin
2018-02-25 02:31:01 5841fea7 [app] [D] Body: {"message":"processing"}
2018-02-25 02:31:01 5841fea7 [app] [I] Completed 200 OK in 12ms (Views: 0.3ms | ActiveRecord: 1.6ms)
2018-02-25 02:31:01 [dynflow] [D] Step 49630ea4-6b8c-4225-844f-b96ad1cbab37: 3 got event #<Actions::ProxyAction::CallbackData:0x007f01582f46e8>
2018-02-25 02:31:01 [dynflow] [D] Step 49630ea4-6b8c-4225-844f-b96ad1cbab37: 3 suspended >> running in phase Run Actions::ProxyAction
2018-02-25 02:31:01 [dynflow] [D] Step 49630ea4-6b8c-4225-844f-b96ad1cbab37: 3 running >> success in phase Run Actions::ProxyAction
2018-02-25 02:31:01 [dynflow] [D] Step 49630ea4-6b8c-4225-844f-b96ad1cbab37: 4 pending >> running in phase Finalize Actions::ForemanAnsible::PlayHostR$
2018-02-25 02:31:01 [background] [E] Playbook execution failed
2018-02-25 02:31:01 [dynflow] [D] Step 49630ea4-6b8c-4225-844f-b96ad1cbab37: 4 running >> error in phase Finalize Actions::ForemanAnsible::PlayHostR$2018-02-25 02:31:01 [dynflow] [D] ExecutionPlan 49630ea4-6b8c-4225-844f-b96ad1cbab37 running >> paused
2018-02-25 02:31:01 [dynflow] [D] ExecutionPlan 49630ea4-6b8c-4225-844f-b96ad1cbab37 paused >> stopped
2018-02-25 02:31:05 [app] [I] Current user: foreman_admin (administrator)
2018-02-25 02:31:05 [app] [D] Setting current user thread-local variable to foreman_admin
2018-02-25 02:31:05 [app] [D] Setting current user thread-local variable to nil
2018-02-25 02:31:05 [app] [I] Current user: foreman_admin (administrator)
2018-02-25 02:31:05 [app] [D] Setting current user thread-local variable to foreman_admin
2018-02-25 02:31:05 [app] [D] Setting current user thread-local variable to nil
2018-02-25 02:31:05 [app] [D] Registering 6 assets for plugin foreman-tasks precompilation
2018-02-25 02:31:05 [app] [I] Current user: foreman_admin (administrator)
2018-02-25 02:31:05 [app] [D] Setting current user thread-local variable to foreman_admin
2018-02-25 02:31:05 [app] [D] Setting current user thread-local variable to nil
2018-02-25 02:31:05 [app] [D] Registering 2 assets for plugin foreman_ansible precompilation
2018-02-25 02:31:06 [app] [I] Current user: foreman_admin (administrator)
2018-02-25 02:31:06 [app] [D] Setting current user thread-local variable to foreman_admin
2018-02-25 02:31:06 [app] [D] Setting current user thread-local variable to nil
2018-02-25 02:31:06 [app] [I] Current user: foreman_admin (administrator)
This is what could be found in foremans webui task logs:
[WARNING]: SSL verification of https://localhost:443 disabled
PLAY [all] *********************************************************************
TASK [Gathering Facts] *********************************************************
fatal: [mac001a0000072d.krtech.loc]: UNREACHABLE! => {“changed”: false, “msg”: “Failed to connect to the host via ssh: ssh: connect to host mac001a0000072d.krtech.loc port 22: Connection refused\r\n”, “unreachable”: true}
to retry, use: --limit @/tmp/foreman-playbook-6deb1d9f-50db-4f95-8fde-a276196b9a66.retry
PLAY RECAP *********************************************************************
mac001a0000072d.krtech.loc : ok=0 changed=0 unreachable=1 failed=0