Bug 1314330

Summary: Job invocation failed for selected host when remote-execution feature is enabled on proxy
Product: Red Hat Satellite 6 Reporter: Sachin Ghai <sghai>
Component: Remote ExecutionAssignee: Marek Hulan <mhulan>
Status: CLOSED ERRATA QA Contact: Lukas Pramuk <lpramuk>
Severity: high Docs Contact:
Priority: unspecified    
Version: 6.2.0CC: bbuckingham, ehelms, lpramuk, mhulan
Target Milestone: UnspecifiedKeywords: Triaged
Target Release: Unused   
Hardware: Unspecified   
OS: Unspecified   
URL: http://projects.theforeman.org/issues/14037
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-07-27 09:25:14 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:

Description Sachin Ghai 2016-03-03 12:23:48 UTC
Description of problem: I was trying to install/configure remote execution feature. I installed following packages:

tfm-rubygem-foreman_remote_execution-0.3.0.0-1.el7sat.noarch
rubygem-smart_proxy_remote_execution_ssh-0.0.13-1.el7sat.noarch

Packages were installed and feature got enabled on proxy and can see ssh as feature under proxy. I configured the ssh-keys as well. However when I invoke a job for selected host, it got failed with below error:

from production.log

 2016-03-03 07:08:14 [app] [I] Started POST "/job_invocations" for 10.65.193.200 at 2016-03-03 07:08:14 -0500
2016-03-03 07:08:14 [app] [I] Processing by JobInvocationsController#create as HTML
2016-03-03 07:08:14 [app] [I]   Parameters: {"utf8"=>"✓", "authenticity_token"=>"PMct6/YHQbLXPT5vwXxojca17Bq20Fbu42zcmxNX6rI=", "job_invocation"=>{"job_category"=>"Commands", "providers"=>{"SSH"=>{"job_template_id"=>"76", "job_templates"=>{"76"=>{"input_values"=>"[FILTERED]", "effective_user"=>""}}}}, "description"=>"Run date", "description_override"=>"Run %{command}", "description_format"=>"Run %{command}", "concurrency_level"=>"", "time_span"=>""}, "targeting"=>{"bookmark_id"=>"", "search_query"=>"name = shost.idmqe.lab.eng.bos.redhat.com", "targeting_type"=>"static_query"}, "triggering"=>{"mode"=>"immediate", "start_at_raw"=>"2016-03-03 07:08", "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)"=>"3", "time(3i)"=>"3", "time(4i)"=>"17", "time(5i)"=>"38"}, "max_iteration"=>"", "end_time_limited"=>"false", "end_time"=>{"end_time(1i)"=>"2016", "end_time(2i)"=>"3", "end_time(3i)"=>"3", "end_time(4i)"=>"17", "end_time(5i)"=>"38"}}, "commit"=>"Submit"}
2016-03-03 07:08:14 [app] [I] Redirected to https://cloud-qe-7.idmqe.lab.eng.bos.redhat.com/job_invocations/7
2016-03-03 07:08:14 [app] [I] Completed 302 Found in 213ms (ActiveRecord: 64.2ms)
2016-03-03 07:08:15 [app] [W] Could not fetch task counts from cloud-qe-7.idmqe.lab.eng.bos.redhat.com, skipped.
 | RestClient::InternalServerError: 500 Internal Server Error
 | /opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-1.6.7/lib/restclient/abstract_response.rb:48:in `return!'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:230:in `process_result'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/rbovirt-0.0.35/lib/restclient_ext/request.rb:50:in `block in transmit'
 | /opt/rh/rh-ruby22/root/usr/share/ruby/net/http.rb:853:in `start'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/rbovirt-0.0.35/lib/restclient_ext/request.rb:44:in `transmit'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:64:in `execute'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:33:in `execute'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-1.6.7/lib/restclient/resource.rb:51:in `get'
 | /usr/share/foreman/lib/proxy_api/resource.rb:67:in `get'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.7.14.0/app/lib/proxy_api/foreman_dynflow/dynflow_proxy.rb:35:in `tasks_count'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-0.3.0.0/app/services/proxy_load_balancer.rb:22:in `block in get_counts'

from proxy.log:
===============

E, [2016-03-03T07:06:19.638102 #27820] ERROR -- : SQLite3::CantOpenException: unable to open database file (Sequel::DatabaseConnectionError)
/usr/share/gems/gems/sequel-4.20.0/lib/sequel/adapters/sqlite.rb:107:in `initialize'
/usr/share/gems/gems/sequel-4.20.0/lib/sequel/adapters/sqlite.rb:107:in `new'
/usr/share/gems/gems/sequel-4.20.0/lib/sequel/adapters/sqlite.rb:107:in `connect'
/usr/share/gems/gems/sequel-4.20.0/lib/sequel/connection_pool.rb:101:in `make_new'
/usr/share/gems/gems/sequel-4.20.0/lib/sequel/connection_pool/threaded.rb:160:in `make_new'
/usr/share/gems/gems/sequel-4.20.0/lib/sequel/connection_pool/threaded.rb:137:in `available'
/usr/share/gems/gems/sequel-4.20.0/lib/sequel/connection_pool/threaded.rb:127:in `block in acquire'
/usr/share/gems/gems/sequel-4.20.0/lib/sequel/connection_pool/threaded.rb:201:in `block in sync'
/usr/share/gems/gems/sequel-4.20.0/lib/sequel/connection_pool/threaded.rb:201:in `synchronize'


Version-Release number of selected component (if applicable):
Sat 6.2 snap2

How reproducible:
always

Steps to Reproduce:
1. try to run job on selected content-host from host details page
2.
3.

Actual results:


Expected results:
job should succeed

Additional info:

Comment 2 Marek Hulan 2016-03-03 12:54:02 UTC
Created redmine issue http://projects.theforeman.org/issues/14037 from this bug

Comment 3 Marek Hulan 2016-03-03 16:36:24 UTC
A simple workaround is to
  mkdir -p /var/lib/foreman-proxy/dynflow
  chown foreman-proxy /var/lib/foreman-proxy/dynflow
  service foreman-proxy restart

There were spec changes in 0.0.6 that would create missing directory during rpm install which needs to be CPed - https://github.com/theforeman/foreman-packaging/commit/d8e74dce5f560829dcbd6ded545a8541e802585c

Comment 5 Lukas Pramuk 2016-04-06 08:34:47 UTC
VERIFIED.

@Sat6.2.0-Beta-Snap6

Used reproducer in comment #0:

2016-04-06 04:29:40 [app] [I] Started POST "/job_invocations/refresh" for <CLIENT_IP> at 2016-04-06 04:29:40 -0400
2016-04-06 04:29:40 [app] [I] Processing by JobInvocationsController#refresh as JS
2016-04-06 04:29:40 [app] [I]   Parameters: {"utf8"=>"✓", "authenticity_token"=>"Ee5ioc2C8ytSfFilzJPgpR6Fof7addCFzVNdOW+ouGw=", "job_invocation"=>{"job_category"=>"Commands", "providers"=>{"SSH"=>{"job_template_id"=>"77", "job_templates"=>{"77"=>{"input_values"=>"[FILTERED]", "effective_user"=>""}}}}, "description"=>"Run ", "description_override"=>"Run %{command}", "description_format"=>"Run %{command}", "concurrency_level"=>"", "time_span"=>""}, "targeting"=>{"bookmark_id"=>"", "search_query"=>"name ~3250", "targeting_type"=>"static_query"}, "triggering"=>{"mode"=>"immediate", "start_at_raw"=>"2016-04-06 04:29", "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)"=>"4", "time(3i)"=>"6", "time(4i)"=>"10", "time(5i)"=>"29"}, "max_iteration"=>"", "end_time_limited"=>"false", "end_time"=>{"end_time(1i)"=>"2016", "end_time(2i)"=>"4", "end_time(3i)"=>"6", "end_time(4i)"=>"10", "end_time(5i)"=>"29"}}}
2016-04-06 04:29:40 [app] [I]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-0.3.0.2/app/views/template_inputs/_invocation_form.html.erb (1.2ms)
2016-04-06 04:29:40 [app] [I]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-0.3.0.2/app/views/job_invocations/_description_fields.html.erb (1.6ms)
2016-04-06 04:29:40 [app] [I]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.7.14.1/app/views/common/_trigger_form.html.erb (20.1ms)
2016-04-06 04:29:40 [app] [I]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-0.3.0.2/app/views/job_invocations/_preview_hosts_modal.html.erb (0.5ms)
2016-04-06 04:29:40 [app] [I]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-0.3.0.2/app/views/job_invocations/_form.html.erb (73.3ms)
2016-04-06 04:29:40 [app] [I]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-0.3.0.2/app/views/job_invocations/refresh.js.erb (77.7ms)
2016-04-06 04:29:40 [app] [I] Completed 200 OK in 116ms (Views: 76.8ms | ActiveRecord: 5.9ms)
2016-04-06 04:30:07 [app] [I] Started POST "/job_invocations" for <CLIENT_IP> at 2016-04-06 04:30:07 -0400
2016-04-06 04:30:07 [app] [I] Processing by JobInvocationsController#create as HTML
2016-04-06 04:30:07 [app] [I]   Parameters: {"utf8"=>"✓", "authenticity_token"=>"Ee5ioc2C8ytSfFilzJPgpR6Fof7addCFzVNdOW+ouGw=", "job_invocation"=>{"job_category"=>"Commands", "providers"=>{"SSH"=>{"job_template_id"=>"77", "job_templates"=>{"77"=>{"input_values"=>"[FILTERED]", "effective_user"=>""}}}}, "description"=>"Run date", "description_override"=>"Run %{command}", "description_format"=>"Run %{command}", "concurrency_level"=>"", "time_span"=>""}, "targeting"=>{"bookmark_id"=>"", "search_query"=>"name ~3250", "targeting_type"=>"static_query"}, "triggering"=>{"mode"=>"immediate", "start_at_raw"=>"2016-04-06 04:29", "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)"=>"4", "time(3i)"=>"6", "time(4i)"=>"10", "time(5i)"=>"29"}, "max_iteration"=>"", "end_time_limited"=>"false", "end_time"=>{"end_time(1i)"=>"2016", "end_time(2i)"=>"4", "end_time(3i)"=>"6", "end_time(4i)"=>"10", "end_time(5i)"=>"29"}}, "commit"=>"Submit"}
2016-04-06 04:30:07 [app] [I] Redirected to https://<SAT_FQDN>/job_invocations/2
2016-04-06 04:30:07 [app] [I] Completed 302 Found in 168ms (ActiveRecord: 18.9ms)
2016-04-06 04:30:08 [app] [I] Started GET "/job_invocations/2" for <CLIENT_IP> at 2016-04-06 04:30:08 -0400
2016-04-06 04:30:08 [app] [I] Processing by JobInvocationsController#show as HTML
2016-04-06 04:30:08 [app] [I]   Parameters: {"id"=>"2"}
2016-04-06 04:30:08 [app] [I]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-0.3.0.2/app/views/job_invocations/_tab_overview.html.erb (45.8ms)
2016-04-06 04:30:08 [app] [I]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-0.3.0.2/app/views/job_invocations/_host_name_td.html.erb (2.3ms)
2016-04-06 04:30:08 [app] [I]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-0.3.0.2/app/views/job_invocations/_host_status_td.html.erb (1.9ms)
2016-04-06 04:30:08 [app] [I]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-0.3.0.2/app/views/job_invocations/_host_actions_td.html.erb (4.8ms)
2016-04-06 04:30:08 [app] [I]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-0.3.0.2/app/views/job_invocations/_tab_hosts.html.erb (24.7ms)
2016-04-06 04:30:08 [app] [I]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-0.3.0.2/app/views/job_invocations/show.html.erb within layouts/application (107.0ms)
2016-04-06 04:30:08 [app] [I]   Rendered layouts/_application_content.html.erb (0.4ms)
2016-04-06 04:30:08 [app] [I]   Rendered home/_submenu.html.erb (2.2ms)
2016-04-06 04:30:08 [app] [I]   Rendered home/_user_dropdown.html.erb (4.2ms)
2016-04-06 04:30:08 [app] [I] Read fragment views/tabs_and_title_records-3 (0.2ms)
2016-04-06 04:30:08 [app] [I]   Rendered home/_topbar.html.erb (7.8ms)
2016-04-06 04:30:08 [app] [I]   Rendered layouts/base.html.erb (9.6ms)
2016-04-06 04:30:08 [app] [I] Completed 200 OK in 162ms (Views: 116.7ms | ActiveRecord: 7.4ms)

Comment 6 Lukas Pramuk 2016-04-06 09:14:50 UTC
Verified with these rpm versions 

# rpm -qa *remote_execution*
rubygem-smart_proxy_remote_execution_ssh-0.0.13-1.el7sat.noarch
tfm-rubygem-foreman_remote_execution-0.3.0.2-1.el7sat.noarch

Comment 8 errata-xmlrpc 2016-07-27 09:25:14 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2016:1501