Plugin Job: All Jobs i run failed

[Susanne]

Hi all,

running in the following Problem and maybe someone found already a solution:

I like to use the Job-Plugin, sshkey is on the Server in the authorized_key
File.
The Command is executed as expected.

Output from Task Details:

···

------ Id: b6982a8f-f81c-44d3-8ba8-c351408e6e2f Label: Actions::RemoteExecution::RunHostJob Name: Remote action: Owner: Execution type: Delayed Start at: 2016-11-17 17:23:57 UTC Start before: - Started at: 2016-11-17 17:23:57 UTC Ended at: 2016-11-17 17:24:57 UTC State: stopped Result: error Params: Run ls /tmp on

Output:

Failed to initialize: Dynflow::ExecutionPlan::Steps::Error - ERF42-9522 [Foreman::Exception]: The smart proxy task c1e8e502-bcdc-4030-90a3-b3e7cd092067 failed.
< Output from ls /tmp Command>

Errors:

ERF42-9522 [Foreman::Exception]: The smart proxy task c1e8e502-bcdc-4030-90a3-b3e7cd092067 failed.

---

Error Tab shows:

Backtrace:

/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.8.2/app/lib/actions/proxy_action.rb:59:in check_task_status' /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.8.2/app/lib/actions/proxy_action.rb:37:inblock in run’
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.8.2/app/lib/actions/proxy_action.rb:159:in with_connection_error_handling' /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.8.2/app/lib/actions/proxy_action.rb:21:inrun’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action.rb:506:in block (3 levels) in execute_run' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/middleware/stack.rb:26:incall’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/middleware/stack.rb:26:in pass' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/middleware.rb:17:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action/progress.rb:30:in with_progress_calculation' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action/progress.rb:16:inrun’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/middleware/stack.rb:22:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/middleware/stack.rb:26:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/middleware.rb:17:in pass' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/middleware.rb:30:inrun’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/middleware/stack.rb:22:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/middleware/world.rb:30:inexecute’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action.rb:505:in block (2 levels) in execute_run' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action.rb:504:incatch’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action.rb:504:in block in execute_run' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action.rb:419:incall’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action.rb:419:in block in with_error_handling' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action.rb:419:incatch’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action.rb:419:in with_error_handling' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action.rb:499:inexecute_run’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action.rb:260:in execute' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:9:inblock (2 levels) in execute’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/execution_plan/steps/abstract.rb:155:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/execution_plan/steps/abstract.rb:155:inwith_meta_calculation’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:8:in block in execute' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:22:inopen_action’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:7:in execute' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/executors/parallel/worker.rb:15:inblock in on_message’
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:74:in block in assigns' /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:intap’
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:in assigns' /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:56:inmatch_value’
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:36:in block in match?' /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:ineach’
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:in match?' /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:23:inmatch’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/executors/parallel/worker.rb:12:in on_message' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/context.rb:46:inon_envelope’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/executes_context.rb:7:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/abstract.rb:25:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/actor.rb:26:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/abstract.rb:25:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/awaits.rb:15:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/abstract.rb:25:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/sets_results.rb:14:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/abstract.rb:25:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/buffer.rb:38:in process_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/buffer.rb:31:inprocess_envelopes?’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/buffer.rb:20:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/abstract.rb:25:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/termination.rb:55:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/abstract.rb:25:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/removes_child.rb:10:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/abstract.rb:25:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/sets_results.rb:14:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/core.rb:161:inprocess_envelope’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/core.rb:95:in block in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/core.rb:118:inblock (2 levels) in schedule_execution’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/synchronization/mri_lockable_object.rb:38:in block in synchronize' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/synchronization/mri_lockable_object.rb:38:insynchronize’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/synchronization/mri_lockable_object.rb:38:in synchronize' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/core.rb:115:inblock in schedule_execution’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/serialized_execution.rb:18:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/serialized_execution.rb:18:incall’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/serialized_execution.rb:96:in work' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/serialized_execution.rb:77:inblock in call_job’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/ruby_thread_pool_executor.rb:333:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/ruby_thread_pool_executor.rb:333:inrun_task’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/ruby_thread_pool_executor.rb:322:in block (3 levels) in create_worker' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/ruby_thread_pool_executor.rb:305:inloop’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/ruby_thread_pool_executor.rb:305:in block (2 levels) in create_worker' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/ruby_thread_pool_executor.rb:304:incatch’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/ruby_thread_pool_executor.rb:304:in block in create_worker' /opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:incall’
/opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context’

So it looks like the Command es executed. So the sshkey verification is
fine. Only the Communication to Dynflow seems to be failing. So maybe my
configuration is not correct…
Someone runs into the same problems and find the solution already? On my
other foreman installation it runs perfectly without any additional tasks
to do…
Already tried to install the Proxy plugin for dynflow, But it doesn’t
help… Maybe i missed something in the docu…

Environment:
Foreman 1.13.0 (–> already Update to the latest Level, but Problem was
still the same. So i go back to the “older” one
Foreman-tasks 0.8.2
foreman-remote_execution 1.2.1

foreman-installer -i

Main Config Menu

1. [✓] Configure foreman
2. [✓] Configure foreman_cli
3. [✓] Configure foreman_proxy
4. [✗] Configure puppet
5. [✗] Configure foreman_plugin_ansible
6. [✗] Configure foreman_plugin_azure
7. [✗] Configure foreman_plugin_bootdisk
8. [✗] Configure foreman_plugin_chef
9. [✗] Configure foreman_plugin_cockpit
10. [✓] Configure foreman_plugin_default_hostgroup
11. [✓] Configure foreman_plugin_dhcp_browser
12. [✗] Configure foreman_plugin_digitalocean
13. [✓] Configure foreman_plugin_discovery
14. [✗] Configure foreman_plugin_docker
15. [✓] Configure foreman_plugin_expire_hosts
16. [✓] Configure foreman_plugin_hooks
17. [✗] Configure foreman_plugin_host_extra_validator
18. [✓] Configure foreman_plugin_memcache
19. [✗] Configure foreman_plugin_openscap
20. [✗] Configure foreman_plugin_ovirt_provision
21. [✗] Configure foreman_plugin_puppetdb
22. [✓] Configure foreman_plugin_remote_execution
23. [✗] Configure foreman_plugin_salt
24. [✓] Configure foreman_plugin_setup
25. [✓] Configure foreman_plugin_tasks
26. [✓] Configure foreman_plugin_templates
27. [✗] Configure foreman_compute_ec2
28. [✗] Configure foreman_compute_gce
29. [✗] Configure foreman_compute_libvirt
30. [✗] Configure foreman_compute_openstack
31. [✗] Configure foreman_compute_ovirt
32. [✗] Configure foreman_compute_rackspace
33. [✗] Configure foreman_compute_vmware
34. [✗] Configure foreman_proxy_plugin_abrt
35. [✗] Configure foreman_proxy_plugin_chef
36. [✗] Configure foreman_proxy_plugin_discovery
37. [✗] Configure foreman_proxy_plugin_dns_powerdns
38. [✓] Configure foreman_proxy_plugin_dynflow
39. [✗] Configure foreman_proxy_plugin_openscap
40. [✗] Configure foreman_proxy_plugin_pulp
41. [✓] Configure foreman_proxy_plugin_remote_execution_ssh
42. [✗] Configure foreman_proxy_plugin_salt

Thanks

Susanne

[aruzicka]

Hello Susanne,
if you check the production log, I guess you should have a line looking
similar to this one

[app] [W] No smart proxy server found on ["localhost",
"localhost.localdomain", "localhost4", "localhost4.localdomain4"] and is
not in trusted_puppetmaster_hosts

It means that the smart proxy tried to report back to Foreman, but Foreman
rejected it. If this is the case, you could fix this by logging into
Foreman, going into Administration > Settings > Authentication and adding
one of the names listed in the warning to the Trusted puppetmaster hosts
array.

Hope this helps, let us know how it goes

Adam

···

On Mon, Nov 21, 2016 at 10:46 AM, susanne.bachmann5 via Foreman users < foreman-users@googlegroups.com> wrote:

proxy_action

[Susanne]

Hi Adam,

i checked to logs, but i didn't find the entry.
Here are an outlook from the production.log:

2016-11-21 16:28:28 e00d853a [app] [I] Started GET "/job_invocations/new"
for … at 2016-11-21 16:28:28 +0100
2016-11-21 16:28:28 e00d853a [app] [I] Processing by
JobInvocationsController#new as HTML
2016-11-21 16:28:29 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.2.1/app/views/template_inputs/_invocation_form.html.erb
(1.6ms)
2016-11-21 16:28:29 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.2.1/app/views/job_invocations/_description_fields.html.erb
(2.0ms)
2016-11-21 16:28:29 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.8.2/app/views/common/_trigger_form.html.erb
(12.8ms)
2016-11-21 16:28:29 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.2.1/app/views/job_invocations/_preview_hosts_modal.html.erb
(0.9ms)
2016-11-21 16:28:29 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.2.1/app/views/job_invocations/_form.html.erb
(46.7ms)
2016-11-21 16:28:29 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.2.1/app/views/job_invocations/new.html.erb
within layouts/application (48.5ms)
2016-11-21 16:28:29 e00d853a [app] [I] Rendered
layouts/_application_content.html.erb (0.3ms)
2016-11-21 16:28:29 e00d853a [app] [I] Rendered
home/_user_dropdown.html.erb (2.1ms)
2016-11-21 16:28:29 e00d853a [app] [I] Read fragment
views/tabs_and_title_records-4 (0.3ms)
2016-11-21 16:28:29 e00d853a [app] [I] Rendered home/_topbar.html.erb
(6.2ms)
2016-11-21 16:28:29 e00d853a [app] [I] Rendered layouts/base.html.erb
(7.8ms)
2016-11-21 16:28:29 e00d853a [app] [I] Completed 200 OK in 71ms (Views:
56.4ms | ActiveRecord: 3.8ms)
2016-11-21 16:28:29 e00d853a [app] [I] Started GET
"/assets/template_invocation-bf20f4154d0c5fb85a297aa4b930a73bc8bbfde6d77962de84d883686ac2f323.css"
for …
2016-11-21 16:28:29 e00d853a [app] [I] Started GET
"/assets/foreman_tasks/trigger_form-d7cb707d980496ae04aadc63bfe6812f9e596f6cef83253df91ee4f4a11c57c7.css"
for …
2016-11-21 16:28:29 e00d853a [app] [I] Started GET
"/assets/modal_window-7117ccc83cf81f90d031ea2faeba27ddaefe176603551d25e300b59c2fdd947b.css"
for …
2016-11-21 16:28:29 e00d853a [app] [I] Started GET
"/assets/template_invocation-9117a6b7dcc7ac0b02f590094eea767faa2568d6a58e497eb9543477b7eece76.js"
for …
2016-11-21 16:28:29 e00d853a [app] [I] Started GET
"/assets/trigger_form-9434ffad72fa0fc76bfd09f66a0fc4710a24b243aa57d3cd954ada6852552162.js"
for …
2016-11-21 16:28:33 e00d853a [app] [I] Started POST
"/job_invocations/refresh" for …
2016-11-21 16:28:33 e00d853a [app] [I] Processing by
JobInvocationsController#refresh as JS
2016-11-21 16:28:33 e00d853a [app] [I] Parameters: {"utf8"=>"✓",
"authenticity_token"=>"<long string>",
"job_invocation"=>{"job_category"=>"Commands",
"providers"=>{"SSH"=>{"job_template_id"=>"144",
"job_templates"=>{"144"=>{"input_values"=>"[FILTERED]",
"effective_user"=>""}}}}, "description"=>"Run ",
"description_override"=>"Run %{command}", "description_format"=>"Run
%{command}", "concurrency_level"=>"", "time_span"=>""},
"targeting"=>{"bookmark_id"=>"", "search_query"=>"<our Server search
>", "targeting_type"=>"static_query"},
"triggering"=>{"mode"=>"immediate", "start_at_raw"=>"2016-11-21 15:28",
"start_before_raw"=>"", "input_type"=>"daily", "cronline"=>"", "days"=>"",
"days_of_week"=>{"1"=>"0", "2"=>"0", "3"=>"0", "4"=>"0", "5"=>"0",
"6"=>"0", "7"=>"0"}, "time"=>{"time(1i)"=>"2016", "time(2i)"=>"11",
"time(3i)"=>"21", "time(4i)"=>"15", "time(5i)"=>"28"}, "max_iteration"=>"",
"end_time_limited"=>"false", "end_time"=>{"end_time(1i)"=>"2016",
"end_time(2i)"=>"11", "end_time(3i)"=>"21", "end_time(4i)"=>"15",
"end_time(5i)"=>"28"}}}
2016-11-21 16:28:33 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.2.1/app/views/template_inputs/_invocation_form.html.erb
(1.5ms)
2016-11-21 16:28:33 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.2.1/app/views/job_invocations/_description_fields.html.erb
(1.6ms)
2016-11-21 16:28:33 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.8.2/app/views/common/_trigger_form.html.erb
(12.8ms)
2016-11-21 16:28:33 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.2.1/app/views/job_invocations/_preview_hosts_modal.html.erb
(0.5ms)
2016-11-21 16:28:33 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.2.1/app/views/job_invocations/_form.html.erb
(96.9ms)
2016-11-21 16:28:33 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.2.1/app/views/job_invocations/refresh.js.erb
(100.3ms)
2016-11-21 16:28:33 e00d853a [app] [I] Completed 200 OK in 124ms (Views:
56.2ms | ActiveRecord: 47.4ms)
2016-11-21 16:28:44 e00d853a [app] [I] Started POST "/job_invocations" for
…
2016-11-21 16:28:44 e00d853a [app] [I] Processing by
JobInvocationsController#create as HTML
2016-11-21 16:28:44 e00d853a [app] [I] Parameters: {"utf8"=>"✓",
"authenticity_token"=>"<long string>",
"job_invocation"=>{"job_category"=>"Commands",
"providers"=>{"SSH"=>{"job_template_id"=>"144",
"job_templates"=>{"144"=>{"input_values"=>"[FILTERED]",
"effective_user"=>""}}}}, "description"=>"Run echo job_run",
"description_override"=>"Run %{command}", "description_format"=>"Run
%{command}", "concurrency_level"=>"", "time_span"=>""},
"targeting"=>{"bookmark_id"=>"", "search_query"=>"<our server search query
>", "targeting_type"=>"static_query"},
"triggering"=>{"mode"=>"immediate", "start_at_raw"=>"2016-11-21 15:28",
"start_before_raw"=>"", "input_type"=>"daily", "cronline"=>"", "days"=>"",
"days_of_week"=>{"1"=>"0", "2"=>"0", "3"=>"0", "4"=>"0", "5"=>"0",
"6"=>"0", "7"=>"0"}, "time"=>{"time(1i)"=>"2016", "time(2i)"=>"11",
"time(3i)"=>"21", "time(4i)"=>"15", "time(5i)"=>"28"}, "max_iteration"=>"",
"end_time_limited"=>"false", "end_time"=>{"end_time(1i)"=>"2016",
"end_time(2i)"=>"11", "end_time(3i)"=>"21", "end_time(4i)"=>"15",
"end_time(5i)"=>"28"}}, "commit"=>"Submit"}
2016-11-21 16:28:44 e00d853a [app] [I] Redirected to https://<your foreman
>/job_invocations/33
2016-11-21 16:28:44 e00d853a [app] [I] Completed 302 Found in 190ms
(ActiveRecord: 66.4ms)
2016-11-21 16:28:44 [foreman-tasks/dynflow] [D] ExecutionPlan
ee51fdbb-5c6e-45d4-92c0-2749c45c0c90 planned >> running
2016-11-21 16:28:44 e00d853a [app] [I] Started GET "/job_invocations/33"
for …
2016-11-21 16:28:44 e00d853a [app] [I] Processing by
JobInvocationsController#show as HTML
2016-11-21 16:28:44 e00d853a [app] [I] Parameters: {"id"=>"33"}
2016-11-21 16:28:44 [foreman-tasks/dynflow] [D] Step
ee51fdbb-5c6e-45d4-92c0-2749c45c0c90: 2 pending >> running in
phase Run Actions::RemoteExecution::RunHostsJob
2016-11-21 16:28:44 [app] [D] Setting current user thread-local variable
to <user that is logged in>
2016-11-21 16:28:45 [foreman-tasks/dynflow] [D] ExecutionPlan
d3d3c62c-217a-4884-b5ce-8e1349a26ea2 pending >> planning
2016-11-21 16:28:45 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.2.1/app/views/job_invocations/_tab_overview.html.erb
(22.9ms)
2016-11-21 16:28:45 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.2.1/app/views/job_invocations/_host_name_td.html.erb
(0.7ms)
2016-11-21 16:28:45 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.2.1/app/views/job_invocations/_host_status_td.html.erb
(0.5ms)
2016-11-21 16:28:45 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.2.1/app/views/job_invocations/_host_actions_td.html.erb
(2.2ms)
2016-11-21 16:28:45 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.2.1/app/views/job_invocations/_tab_hosts.html.erb
(7.3ms)
2016-11-21 16:28:45 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.2.1/app/views/job_invocations/show.html.erb
within layouts/application (40.1ms)
2016-11-21 16:28:45 e00d853a [app] [I] Rendered
layouts/_application_content.html.erb (0.4ms)
2016-11-21 16:28:45 [foreman-tasks/dynflow] [D] Step
d3d3c62c-217a-4884-b5ce-8e1349a26ea2: 1 pending >> running in phase
Plan Actions::RemoteExecution::RunHostJob
2016-11-21 16:28:45 e00d853a [app] [I] Rendered
home/user_dropdown.html.erb (2.1ms)
2016-11-21 16:28:45 e00d853a [app] [I] Read fragment
views/tabs_and_title_records-4 (0.3ms)
2016-11-21 16:28:45 e00d853a [app] [I] Rendered home/topbar.html.erb
(7.9ms)
2016-11-21 16:28:45 e00d853a [app] [I] Rendered layouts/base.html.erb
(9.5ms)
2016-11-21 16:28:45 e00d853a [app] [I] Completed 200 OK in 63ms (Views:
47.2ms | ActiveRecord: 5.3ms)
2016-11-21 16:28:45 e00d853a [app] [I] Started GET
"/assets/job_invocations-f079e92744b55af1d247e064a15a9711f56c06165fea3cd2a7724ef2bf5b011a.css"
for …
2016-11-21 16:28:45 e00d853a [app] [I] Started GET
"/assets/template_invocation-9117a6b7dcc7ac0b02f590094eea767faa2568d6a58e497eb9543477b7eece76.js"
for …
2016-11-21 16:28:45 [app] [D] Cache read: remote_execution_fallback_proxy
2016-11-21 16:28:45 [app] [D] Cache read: remote_execution_global_proxy
2016-11-21 16:28:45 [app] [D] Cache read: proxy_request_timeout
2016-11-21 16:28:45 [app] [D] Cache read: ssl_certificate
2016-11-21 16:28:45 [app] [D] Cache read: ssl_ca_file
2016-11-21 16:28:45 [app] [D] Cache read: ssl_priv_key
2016-11-21 16:28:45 [app] [D] Cache read: safemode_render
2016-11-21 16:28:45 [app] [D] Cache read: Enable_Smart_Variables_in_ENC
2016-11-21 16:28:45 [app] [D] Cache read: remote_execution_fallback_proxy
2016-11-21 16:28:45 [app] [D] Cache read: remote_execution_global_proxy
2016-11-21 16:28:45 [app] [D] Cache read: remote_execution_ssh_user
2016-11-21 16:28:45 [app] [D] Cache read:
remote_execution_effective_user_method
2016-11-21 16:28:45 [app] [D] Cache read: Enable_Smart_Variables_in_ENC
2016-11-21 16:28:45 [app] [D] Cache read: remote_execution_fallback_proxy
2016-11-21 16:28:45 [app] [D] Cache read: remote_execution_global_proxy
2016-11-21 16:28:45 [foreman-tasks/dynflow] [D] Step
d3d3c62c-217a-4884-b5ce-8e1349a26ea2: 2 pending >> running in phase
Plan Actions::ProxyAction
2016-11-21 16:28:45 [app] [D] Cache read:
foreman_tasks_proxy_action_retry_interval
2016-11-21 16:28:45 [app] [D] Cache read:
foreman_tasks_proxy_action_retry_count
2016-11-21 16:28:45 [app] [D] Cache read:
foreman_tasks_proxy_action_start_timeout
2016-11-21 16:28:45 [foreman-tasks/dynflow] [D] Step
d3d3c62c-217a-4884-b5ce-8e1349a26ea2: 2 running >> success in phase
Plan Actions::ProxyAction
2016-11-21 16:28:45 [foreman-tasks/dynflow] [D] Step
d3d3c62c-217a-4884-b5ce-8e1349a26ea2: 1 running >> success in phase
Plan Actions::RemoteExecution::RunHostJob
2016-11-21 16:28:45 [foreman-tasks/dynflow] [D] ExecutionPlan
d3d3c62c-217a-4884-b5ce-8e1349a26ea2 planning >> planned
2016-11-21 16:28:45 [app] [D] Setting current user thread-local variable
to nil
2016-11-21 16:28:45 [foreman-tasks/dynflow] [D] Step
ee51fdbb-5c6e-45d4-92c0-2749c45c0c90: 2 running >> suspended in
phase Run Actions::RemoteExecution::RunHostsJob
2016-11-21 16:28:45 [foreman-tasks/dynflow] [D] ExecutionPlan
d3d3c62c-217a-4884-b5ce-8e1349a26ea2 planned >> running
2016-11-21 16:28:45 [foreman-tasks/dynflow] [D] Step
d3d3c62c-217a-4884-b5ce-8e1349a26ea2: 3 pending >> running in
phase Run Actions::ProxyAction
2016-11-21 16:28:45 [app] [D] Cache read: proxy_request_timeout
2016-11-21 16:28:45 [app] [D] Cache read: ssl_certificate
2016-11-21 16:28:45 [app] [D] Cache read: ssl_ca_file
2016-11-21 16:28:45 [app] [D] Cache read: ssl_priv_key
2016-11-21 16:28:45 [foreman-tasks/dynflow] [D] Step
d3d3c62c-217a-4884-b5ce-8e1349a26ea2: 3 running >> suspended in
phase Run Actions::ProxyAction
2016-11-21 16:28:46 e00d853a [app] [I] Started GET
"/job_invocations/33?hosts_needs_refresh=&host_ids_needing_name_update%5B%5D=336&host_ids_needing_status_update%5B%5D=336&=1479742125314"
…
2016-11-21 16:28:46 e00d853a [app] [I] Processing by
JobInvocationsController#show as JS
2016-11-21 16:28:46 e00d853a [app] [I] Parameters:
{"hosts_needs_refresh"=>"", "host_ids_needing_name_update"=>["336"],
"host_ids_needing_status_update"=>["336"], ""=>"1479742125314", "id"=>"33"}
2016-11-21 16:28:46 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.2.1/app/views/job_invocations/_host_name_td.html.erb
(0.8ms)
2016-11-21 16:28:46 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.2.1/app/views/job_invocations/_host_status_td.html.erb
(0.6ms)
2016-11-21 16:28:46 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.2.1/app/views/job_invocations/show.js.erb
(19.1ms)
2016-11-21 16:28:46 e00d853a [app] [I] Completed 200 OK in 34ms (Views:
19.0ms | ActiveRecord: 2.6ms)
…
last 5 lines are repeated every second
…

2016-11-21 16:29:45 [foreman-tasks/dynflow] [D] Step
d3d3c62c-217a-4884-b5ce-8e1349a26ea2: 3 got event
Dynflow::Action::Timeouts::Timeout
2016-11-21 16:29:45 [foreman-tasks/dynflow] [D] Step
d3d3c62c-217a-4884-b5ce-8e1349a26ea2: 3 suspended >> running in
phase Run Actions::ProxyAction
2016-11-21 16:29:45 [app] [D] Cache read: proxy_request_timeout
2016-11-21 16:29:45 [app] [D] Cache read: ssl_certificate
2016-11-21 16:29:45 [app] [D] Cache read: ssl_ca_file
2016-11-21 16:29:45 [app] [D] Cache read: ssl_priv_key
2016-11-21 16:29:45 [foreman-tasks/action] [E] ERF42-6299
[Foreman::Exception]: The smart proxy task
a017ac8b-07c7-4772-9d16-dee3d69b375f failed. (Foreman::Exception)
>
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.8.2/app/lib/actions/proxy_action.rb:59:in
check_task_status' > /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.8.2/app/lib/actions/proxy_action.rb:37:inblock in run'
>
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.8.2/app/lib/actions/proxy_action.rb:159:in
with_connection_error_handling' > /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.8.2/app/lib/actions/proxy_action.rb:21:inrun'
>
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action.rb:506:in
block (3 levels) in execute_run' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/middleware/stack.rb:26:incall'
>
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/middleware/stack.rb:26:in
pass' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/middleware.rb:17:inpass'
>
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action/progress.rb:30:in
with_progress_calculation' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action/progress.rb:16:inrun'
>
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/middleware/stack.rb:22:in
call' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/middleware/stack.rb:26:inpass'
>
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/middleware.rb:17:in
pass' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/middleware.rb:30:inrun'
>
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/middleware/stack.rb:22:in
call' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/middleware/world.rb:30:inexecute'
>
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action.rb:505:in
block (2 levels) in execute_run' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action.rb:504:incatch'
>
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action.rb:504:in
block in execute_run' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action.rb:419:incall'
>
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action.rb:419:in
block in with_error_handling' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action.rb:419:incatch'
>
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action.rb:419:in
with_error_handling' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action.rb:499:inexecute_run'
>
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/action.rb:260:in
execute' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:9:inblock (2 levels) in execute'
>
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/execution_plan/steps/abstract.rb:155:in
call' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/execution_plan/steps/abstract.rb:155:inwith_meta_calculation'
>
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:8:in
block in execute' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:22:inopen_action'
>
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:7:in
execute' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.15/lib/dynflow/executors/parallel/worker.rb:15:inblock in on_message'
>
/opt/theforeman/tfm/root/usr/share/gems/gems/alg

[aruzicka]

Hello,
it seems that when the proxy is making a callback to Foreman, it doesn't
reach Foreman at all. Could you please set set log_level to DEBUG in
/etc/smart_proxy_dynflow_core/settings.yml, watch the log
in /var/log/foreman-proxy/smart_proxy_dynflow_core.log and try to rerun the
job? Some useful information might show up there.

Adam

···

On Mon, Nov 21, 2016 at 5:25 PM, susanne.bachmann5 via Foreman users < foreman-users@googlegroups.com> wrote:

Hi Adam,

i checked to logs, but i didn’t find the entry.
Here are an outlook from the production.log:

2016-11-21 16:28:28 e00d853a [app] [I] Started GET “/job_invocations/new"
for … at 2016-11-21 16:28:28 +0100
2016-11-21 16:28:28 e00d853a [app] [I] Processing by
JobInvocationsController#new as HTML
2016-11-21 16:28:29 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_
remote_execution-1.2.1/app/views/template_inputs/invocation_form.html.erb
(1.6ms)
2016-11-21 16:28:29 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman
remote_execution-1.2.1/app/views/job_invocations/_description_fields.html.erb
(2.0ms)
2016-11-21 16:28:29 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-
0.8.2/app/views/common/trigger_form.html.erb (12.8ms)
2016-11-21 16:28:29 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman
remote_execution-1.2.1/app/views/job_invocations/preview_hosts_modal.html.erb
(0.9ms)
2016-11-21 16:28:29 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman
remote_execution-1.2.1/app/views/job_invocations/form.html.erb (46.7ms)
2016-11-21 16:28:29 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman
remote_execution-1.2.1/app/views/job_invocations/new.html.erb within
layouts/application (48.5ms)
2016-11-21 16:28:29 e00d853a [app] [I] Rendered
layouts/_application_content.html.erb (0.3ms)
2016-11-21 16:28:29 e00d853a [app] [I] Rendered
home/_user_dropdown.html.erb (2.1ms)
2016-11-21 16:28:29 e00d853a [app] [I] Read fragment
views/tabs_and_title_records-4 (0.3ms)
2016-11-21 16:28:29 e00d853a [app] [I] Rendered home/_topbar.html.erb
(6.2ms)
2016-11-21 16:28:29 e00d853a [app] [I] Rendered layouts/base.html.erb
(7.8ms)
2016-11-21 16:28:29 e00d853a [app] [I] Completed 200 OK in 71ms (Views:
56.4ms | ActiveRecord: 3.8ms)
2016-11-21 16:28:29 e00d853a [app] [I] Started GET
”/assets/template_invocation-bf20f4154d0c5fb85a297aa4b930a7
3bc8bbfde6d77962de84d883686ac2f323.css" for …
2016-11-21 16:28:29 e00d853a [app] [I] Started GET “/assets/foreman_tasks/
trigger_form-d7cb707d980496ae04aadc63bfe6812f9e596f6cef83253df91ee4f4a11c57c7.css"
for …
2016-11-21 16:28:29 e00d853a [app] [I] Started GET “/assets/modal_window-
7117ccc83cf81f90d031ea2faeba27ddaefe176603551d25e300b59c2fdd947b.css” for
…
2016-11-21 16:28:29 e00d853a [app] [I] Started GET
”/assets/template_invocation-9117a6b7dcc7ac0b02f590094eea76
7faa2568d6a58e497eb9543477b7eece76.js" for …
2016-11-21 16:28:29 e00d853a [app] [I] Started GET “/assets/trigger_form-
9434ffad72fa0fc76bfd09f66a0fc4710a24b243aa57d3cd954ada6852552162.js” for
…
2016-11-21 16:28:33 e00d853a [app] [I] Started POST
"/job_invocations/refresh" for …
2016-11-21 16:28:33 e00d853a [app] [I] Processing by
JobInvocationsController#refresh as JS
2016-11-21 16:28:33 e00d853a [app] [I] Parameters: {“utf8”=>“✓”,
“authenticity_token”=>"", “job_invocation”=>{“job_category”=>“Commands”,
“providers”=>{“SSH”=>{“job_template_id”=>“144”,
“job_templates”=>{“144”=>{“input_values”=>"[FILTERED]",
“effective_user”=>""}}}}, “description”=>“Run “,
“description_override”=>“Run %{command}”, “description_format”=>“Run
%{command}”, “concurrency_level”=>””, “time_span”=>""},
“targeting”=>{“bookmark_id”=>"", “search_query”=>"<our Server search

“, “targeting_type”=>“static_query”}, “triggering”=>{“mode”=>“immediate”,
“start_at_raw”=>“2016-11-21 15:28”, “start_before_raw”=>”",
“input_type”=>“daily”, “cronline”=>"", “days”=>"",
“days_of_week”=>{“1”=>“0”, “2”=>“0”, “3”=>“0”, “4”=>“0”, “5”=>“0”,
“6”=>“0”, “7”=>“0”}, “time”=>{“time(1i)”=>“2016”, “time(2i)”=>“11”,
“time(3i)”=>“21”, “time(4i)”=>“15”, “time(5i)”=>“28”}, “max_iteration”=>"",
“end_time_limited”=>“false”, “end_time”=>{“end_time(1i)”=>“2016”,
“end_time(2i)”=>“11”, “end_time(3i)”=>“21”, “end_time(4i)”=>“15”,
“end_time(5i)”=>“28”}}}
2016-11-21 16:28:33 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_
remote_execution-1.2.1/app/views/template_inputs/invocation_form.html.erb
(1.5ms)
2016-11-21 16:28:33 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman
remote_execution-1.2.1/app/views/job_invocations/description_fields.html.erb
(1.6ms)
2016-11-21 16:28:33 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-
0.8.2/app/views/common/trigger_form.html.erb (12.8ms)
2016-11-21 16:28:33 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman
remote_execution-1.2.1/app/views/job_invocations/preview_hosts_modal.html.erb
(0.5ms)
2016-11-21 16:28:33 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman
remote_execution-1.2.1/app/views/job_invocations/form.html.erb (96.9ms)
2016-11-21 16:28:33 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman
remote_execution-1.2.1/app/views/job_invocations/refresh.js.erb (100.3ms)
2016-11-21 16:28:33 e00d853a [app] [I] Completed 200 OK in 124ms (Views:
56.2ms | ActiveRecord: 47.4ms)
2016-11-21 16:28:44 e00d853a [app] [I] Started POST “/job_invocations” for
…
2016-11-21 16:28:44 e00d853a [app] [I] Processing by
JobInvocationsController#create as HTML
2016-11-21 16:28:44 e00d853a [app] [I] Parameters: {“utf8”=>“✓”,
“authenticity_token”=>"", “job_invocation”=>{“job_category”=>“Commands”,
“providers”=>{“SSH”=>{“job_template_id”=>“144”,
“job_templates”=>{“144”=>{“input_values”=>"[FILTERED]",
“effective_user”=>""}}}}, “description”=>“Run echo job_run”,
“description_override”=>“Run %{command}”, “description_format”=>“Run
%{command}”, “concurrency_level”=>"", “time_span”=>""},
“targeting”=>{“bookmark_id”=>"", “search_query”=>"", “targeting_type”=>“static_query”},
“triggering”=>{“mode”=>“immediate”, “start_at_raw”=>“2016-11-21 15:28”,
“start_before_raw”=>"", “input_type”=>“daily”, “cronline”=>"", “days”=>"",
“days_of_week”=>{“1”=>“0”, “2”=>“0”, “3”=>“0”, “4”=>“0”, “5”=>“0”,
“6”=>“0”, “7”=>“0”}, “time”=>{“time(1i)”=>“2016”, “time(2i)”=>“11”,
“time(3i)”=>“21”, “time(4i)”=>“15”, “time(5i)”=>“28”}, “max_iteration”=>"",
“end_time_limited”=>“false”, “end_time”=>{“end_time(1i)”=>“2016”,
“end_time(2i)”=>“11”, “end_time(3i)”=>“21”, “end_time(4i)”=>“15”,
“end_time(5i)”=>“28”}}, “commit”=>“Submit”}
2016-11-21 16:28:44 e00d853a [app] [I] Redirected to https:///job_invocations/33
2016-11-21 16:28:44 e00d853a [app] [I] Completed 302 Found in 190ms
(ActiveRecord: 66.4ms)
2016-11-21 16:28:44 [foreman-tasks/dynflow] [D] ExecutionPlan
ee51fdbb-5c6e-45d4-92c0-2749c45c0c90 planned >> running
2016-11-21 16:28:44 e00d853a [app] [I] Started GET "/job_invocations/33"
for …
2016-11-21 16:28:44 e00d853a [app] [I] Processing by
JobInvocationsController#show as HTML
2016-11-21 16:28:44 e00d853a [app] [I] Parameters: {“id”=>“33”}
2016-11-21 16:28:44 [foreman-tasks/dynflow] [D] Step
ee51fdbb-5c6e-45d4-92c0-2749c45c0c90: 2 pending >> running in
phase Run Actions::RemoteExecution::RunHostsJob
2016-11-21 16:28:44 [app] [D] Setting current user thread-local variable
to
2016-11-21 16:28:45 [foreman-tasks/dynflow] [D] ExecutionPlan
d3d3c62c-217a-4884-b5ce-8e1349a26ea2 pending >> planning
2016-11-21 16:28:45 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman
remote_execution-1.2.1/app/views/job_invocations/tab_overview.html.erb
(22.9ms)
2016-11-21 16:28:45 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman
remote_execution-1.2.1/app/views/job_invocations/host_name_td.html.erb
(0.7ms)
2016-11-21 16:28:45 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman
remote_execution-1.2.1/app/views/job_invocations/host_status_td.html.erb
(0.5ms)
2016-11-21 16:28:45 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman
remote_execution-1.2.1/app/views/job_invocations/host_actions_td.html.erb
(2.2ms)
2016-11-21 16:28:45 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman
remote_execution-1.2.1/app/views/job_invocations/tab_hosts.html.erb
(7.3ms)
2016-11-21 16:28:45 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman
remote_execution-1.2.1/app/views/job_invocations/show.html.erb within
layouts/application (40.1ms)
2016-11-21 16:28:45 e00d853a [app] [I] Rendered
layouts/application_content.html.erb (0.4ms)
2016-11-21 16:28:45 [foreman-tasks/dynflow] [D] Step
d3d3c62c-217a-4884-b5ce-8e1349a26ea2: 1 pending >> running in
phase Plan Actions::RemoteExecution::RunHostJob
2016-11-21 16:28:45 e00d853a [app] [I] Rendered
home/user_dropdown.html.erb (2.1ms)
2016-11-21 16:28:45 e00d853a [app] [I] Read fragment
views/tabs_and_title_records-4 (0.3ms)
2016-11-21 16:28:45 e00d853a [app] [I] Rendered home/topbar.html.erb
(7.9ms)
2016-11-21 16:28:45 e00d853a [app] [I] Rendered layouts/base.html.erb
(9.5ms)
2016-11-21 16:28:45 e00d853a [app] [I] Completed 200 OK in 63ms (Views:
47.2ms | ActiveRecord: 5.3ms)
2016-11-21 16:28:45 e00d853a [app] [I] Started GET
"/assets/job_invocations-f079e92744b55af1d247e064a15a97
11f56c06165fea3cd2a7724ef2bf5b011a.css" for …
2016-11-21 16:28:45 e00d853a [app] [I] Started GET
"/assets/template_invocation-9117a6b7dcc7ac0b02f590094eea76
7faa2568d6a58e497eb9543477b7eece76.js" for …
2016-11-21 16:28:45 [app] [D] Cache read: remote_execution_fallback_proxy
2016-11-21 16:28:45 [app] [D] Cache read: remote_execution_global_proxy
2016-11-21 16:28:45 [app] [D] Cache read: proxy_request_timeout
2016-11-21 16:28:45 [app] [D] Cache read: ssl_certificate
2016-11-21 16:28:45 [app] [D] Cache read: ssl_ca_file
2016-11-21 16:28:45 [app] [D] Cache read: ssl_priv_key
2016-11-21 16:28:45 [app] [D] Cache read: safemode_render
2016-11-21 16:28:45 [app] [D] Cache read: Enable_Smart_Variables_in_ENC
2016-11-21 16:28:45 [app] [D] Cache read: remote_execution_fallback_proxy
2016-11-21 16:28:45 [app] [D] Cache read: remote_execution_global_proxy
2016-11-21 16:28:45 [app] [D] Cache read: remote_execution_ssh_user
2016-11-21 16:28:45 [app] [D] Cache read: remote_execution_effective
user_method
2016-11-21 16:28:45 [app] [D] Cache read: Enable_Smart_Variables_in_ENC
2016-11-21 16:28:45 [app] [D] Cache read: remote_execution_fallback_proxy
2016-11-21 16:28:45 [app] [D] Cache read: remote_execution_global_proxy
2016-11-21 16:28:45 [foreman-tasks/dynflow] [D] Step
d3d3c62c-217a-4884-b5ce-8e1349a26ea2: 2 pending >> running in
phase Plan Actions::ProxyAction
2016-11-21 16:28:45 [app] [D] Cache read: foreman_tasks_proxy_action
retry_interval
2016-11-21 16:28:45 [app] [D] Cache read: foreman_tasks_proxy_action
retry_count
2016-11-21 16:28:45 [app] [D] Cache read: foreman_tasks_proxy_action_
start_timeout
2016-11-21 16:28:45 [foreman-tasks/dynflow] [D] Step
d3d3c62c-217a-4884-b5ce-8e1349a26ea2: 2 running >> success in
phase Plan Actions::ProxyAction
2016-11-21 16:28:45 [foreman-tasks/dynflow] [D] Step
d3d3c62c-217a-4884-b5ce-8e1349a26ea2: 1 running >> success in
phase Plan Actions::RemoteExecution::RunHostJob
2016-11-21 16:28:45 [foreman-tasks/dynflow] [D] ExecutionPlan
d3d3c62c-217a-4884-b5ce-8e1349a26ea2 planning >> planned
2016-11-21 16:28:45 [app] [D] Setting current user thread-local variable
to nil
2016-11-21 16:28:45 [foreman-tasks/dynflow] [D] Step
ee51fdbb-5c6e-45d4-92c0-2749c45c0c90: 2 running >> suspended in
phase Run Actions::RemoteExecution::RunHostsJob
2016-11-21 16:28:45 [foreman-tasks/dynflow] [D] ExecutionPlan
d3d3c62c-217a-4884-b5ce-8e1349a26ea2 planned >> running
2016-11-21 16:28:45 [foreman-tasks/dynflow] [D] Step
d3d3c62c-217a-4884-b5ce-8e1349a26ea2: 3 pending >> running in
phase Run Actions::ProxyAction
2016-11-21 16:28:45 [app] [D] Cache read: proxy_request_timeout
2016-11-21 16:28:45 [app] [D] Cache read: ssl_certificate
2016-11-21 16:28:45 [app] [D] Cache read: ssl_ca_file
2016-11-21 16:28:45 [app] [D] Cache read: ssl_priv_key
2016-11-21 16:28:45 [foreman-tasks/dynflow] [D] Step
d3d3c62c-217a-4884-b5ce-8e1349a26ea2: 3 running >> suspended in
phase Run Actions::ProxyAction
2016-11-21 16:28:46 e00d853a [app] [I] Started GET
"/job_invocations/33?hosts_needs_refresh=&host_ids_
needing_name_update%5B%5D=336&host_ids_needing_status_update%5B%5D=336&=1479742125314"
…
2016-11-21 16:28:46 e00d853a [app] [I] Processing by
JobInvocationsController#show as JS
2016-11-21 16:28:46 e00d853a [app] [I] Parameters:
{“hosts_needs_refresh”=>"", “host_ids_needing_name_update”=>[“336”],
“host_ids_needing_status_update”=>[“336”], ""=>“1479742125314”,
“id”=>“33”}
2016-11-21 16:28:46 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_
remote_execution-1.2.1/app/views/job_invocations/host_name_td.html.erb
(0.8ms)
2016-11-21 16:28:46 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman
remote_execution-1.2.1/app/views/job_invocations/host_status_td.html.erb
(0.6ms)
2016-11-21 16:28:46 e00d853a [app] [I] Rendered
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman
remote_execution-1.2.1/app/views/job_invocations/show.js.erb (19.1ms)
2016-11-21 16:28:46 e00d853a [app] [I] Completed 200 OK in 34ms (Views:
19.0ms | ActiveRecord: 2.6ms)
…
last 5 lines are repeated every second
…

2016-11-21 16:29:45 [foreman-tasks/dynflow] [D] Step
d3d3c62c-217a-4884-b5ce-8e1349a26ea2: 3 got event
Dynflow::Action::Timeouts::Timeout
2016-11-21 16:29:45 [foreman-tasks/dynflow] [D] Step
d3d3c62c-217a-4884-b5ce-8e1349a26ea2: 3 suspended >> running in
phase Run Actions::ProxyAction
2016-11-21 16:29:45 [app] [D] Cache read: proxy_request_timeout
2016-11-21 16:29:45 [app] [D] Cache read: ssl_certificate
2016-11-21 16:29:45 [app] [D] Cache read: ssl_ca_file
2016-11-21 16:29:45 [app] [D] Cache read: ssl_priv_key
2016-11-21 16:29:45 [foreman-tasks/action] [E] ERF42-6299
[Foreman::Exception]: The smart proxy task a017ac8b-07c7-4772-9d16-dee3d69b375f
failed. (Foreman::Exception)

/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-
0.8.2/app/lib/actions/proxy_action.rb:59:in check_task_status' /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks- 0.8.2/app/lib/actions/proxy_action.rb:37:inblock in run’
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-
0.8.2/app/lib/actions/proxy_action.rb:159:in with_connection_error_ handling' /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks- 0.8.2/app/lib/actions/proxy_action.rb:21:inrun’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.
15/lib/dynflow/action.rb:506:in block (3 levels) in execute_run' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8. 15/lib/dynflow/middleware/stack.rb:26:incall’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.
15/lib/dynflow/middleware/stack.rb:26:in pass' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8. 15/lib/dynflow/middleware.rb:17:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.
15/lib/dynflow/action/progress.rb:30:in with_progress_calculation' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8. 15/lib/dynflow/action/progress.rb:16:inrun’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.
15/lib/dynflow/middleware/stack.rb:22:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8. 15/lib/dynflow/middleware/stack.rb:26:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.
15/lib/dynflow/middleware.rb:17:in pass' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8. 15/lib/dynflow/middleware.rb:30:inrun’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.
15/lib/dynflow/middleware/stack.rb:22:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8. 15/lib/dynflow/middleware/world.rb:30:inexecute’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.
15/lib/dynflow/action.rb:505:in block (2 levels) in execute_run' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8. 15/lib/dynflow/action.rb:504:incatch’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.

[Susanne]

Hi Adam,

you give me the right hint to find the solution and your first idea was the
right one…

[2016-11-22 14:38:01.861 #119088] ERROR – action: SSL_connect returned=1
errno=0 state=SSLv3 read server session ticket A: tlsv1 alert unknown ca
(OpenSSL::SSL::SSLError)
/opt/rh/rh-ruby22/root/usr/share/ruby/net/http.rb:923:in connect' /opt/rh/rh-ruby22/root/usr/share/ruby/net/http.rb:923:inblock in connect'
/opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:74:in timeout' /opt/rh/rh-ruby22/root/usr/share/ruby/net/http.rb:923:inconnect'
…
[2016-11-22 15:08:54.849 #2491] FATAL – SIGTERM
[2016-11-22 15:08:54.877 #2491] ERROR – dynflow: … core terminated.

i already had that problem once with the unknown ca error. i had to update
the crl-File for the ca to fix that behavior. I already done this on the
other Foreman Installations to be able to import the facts from our puppet
server.

Thx for the help and the final hint.

Susanne

···

On Tuesday, November 22, 2016 at 10:10:35 AM UTC+1, Adam Ruzicka wrote: > > Hello, > it seems that when the proxy is making a callback to Foreman, it doesn't > reach Foreman at all. Could you please set set log_level to DEBUG in > /etc/smart_proxy_dynflow_core/settings.yml, watch the log > in /var/log/foreman-proxy/smart_proxy_dynflow_core.log and try to rerun the > job? Some useful information might show up there. > > Adam > >

[aruzicka]

Glad to hear you got that working.

Adam

···

On Tue, Nov 22, 2016 at 4:00 PM, susanne.bachmann5 via Foreman users < foreman-users@googlegroups.com> wrote:

Hi Adam,

you give me the right hint to find the solution and your first idea was
the right one…

[2016-11-22 14:38:01.861 #119088] ERROR – action: SSL_connect returned=1
errno=0 state=SSLv3 read server session ticket A: tlsv1 alert unknown ca
(OpenSSL::SSL::SSLError)
/opt/rh/rh-ruby22/root/usr/share/ruby/net/http.rb:923:in connect' /opt/rh/rh-ruby22/root/usr/share/ruby/net/http.rb:923:inblock in
connect’
/opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:74:in timeout' /opt/rh/rh-ruby22/root/usr/share/ruby/net/http.rb:923:inconnect’
…
[2016-11-22 15:08:54.849 #2491] FATAL – SIGTERM
[2016-11-22 15:08:54.877 #2491] ERROR – dynflow: … core terminated.

i already had that problem once with the unknown ca error. i had to update
the crl-File for the ca to fix that behavior. I already done this on the
other Foreman Installations to be able to import the facts from our puppet
server.

Thx for the help and the final hint.

Susanne

On Tuesday, November 22, 2016 at 10:10:35 AM UTC+1, Adam Ruzicka wrote:

Hello,
it seems that when the proxy is making a callback to Foreman, it doesn’t
reach Foreman at all. Could you please set set log_level to DEBUG in
/etc/smart_proxy_dynflow_core/settings.yml, watch the log
in /var/log/foreman-proxy/smart_proxy_dynflow_core.log and try to rerun
the job? Some useful information might show up there.

Adam

–
You received this message because you are subscribed to the Google Groups
"Foreman users" group.
To unsubscribe from this group and stop receiving emails from it, send an
email to foreman-users+unsubscribe@googlegroups.com.
To post to this group, send email to foreman-users@googlegroups.com.
Visit this group at https://groups.google.com/group/foreman-users.
For more options, visit https://groups.google.com/d/optout.