Bug 1343223

Summary: Capture errors when discovery fails to reboot a discovered host during provisioning.
Product: Red Hat Quickstart Cloud Installer Reporter: James Olin Oden <joden>
Component: Installation - RHEVAssignee: Jesus M. Rodriguez <jesusr>
Status: CLOSED WONTFIX QA Contact: Dave Johnson <dajohnso>
Severity: medium Docs Contact: Dan Macpherson <dmacpher>
Priority: unspecified    
Version: 1.0CC: arubin, bthurber, jesusr, lzap, tsanders
Target Milestone: ---Keywords: Triaged
Target Release: 1.1   
Hardware: Unspecified   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-10-07 19:35:58 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:
Embargoed:
Bug Depends On:    
Bug Blocks: 1342594    
Attachments:
Description Flags
Foreman production.log none

Description James Olin Oden 2016-06-06 20:36:15 UTC 
Description of problem:

Was trying to do RHEV deployment with QCI 1.2.   It had gotten past the satellite repo sync, and then at some point it timed out waiting for the VM's to PXE boot.  When I looked at the VM's they both had timed out trying to PXE boot, and the deployment log just showed that it was waiting on the two VM's.

I was able to get the deployment going again by rebooting both of the VM's and re-starting the RHEV deployment task, and the deployment task.

This was done in a libvirt environment.

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

1.2

How reproducible:

Only time I have seen this.

Steps to Reproduce:
1.   Try to deploy RHEV with QCI 1.2 in a libvirt environment. 

Actual results:

Deployment failed with timeout.

Expected results:

Deployment succeeds.
Comment 1 James Olin Oden 2016-06-06 20:37:35 UTC 
Here is the pertinent part of one of the logs:

2016-06-03 11:39:54 [app] [I] Starting host 2 deployment...
2016-06-03 11:39:55 [app] [I] Create DHCP reservation for mac5254009dc284.example.com-52:54:00:9d:c2:84/192.168.175.15
2016-06-03 11:39:55 [app] [I] Add DNS A record for mac5254009dc284.example.com/192.168.175.15
2016-06-03 11:39:55 [app] [I] Add DNS PTR record for 192.168.175.15/mac5254009dc284.example.com
2016-06-03 11:39:56 [app] [I] Started GET "/api/v21/foreman_tasks?search=parent_task_id+%3D+2e557945-2067-4d17-852f-d9bd99ea1457" for 10.3.112.64 at 2016-06-03 11:39:56 -0400
2016-06-03 11:39:56 [app] [I] Started GET "/api/v21/foreman_tasks/2e557945-2067-4d17-852f-d9bd99ea1457" for 10.3.112.64 at 2016-06-03 11:39:56 -0400
2016-06-03 11:39:56 [app] [I] Processing by Api::V21::ForemanTasksController#index as JSON
2016-06-03 11:39:56 [app] [I]   Parameters: {"search"=>"parent_task_id = 2e557945-2067-4d17-852f-d9bd99ea1457", "apiv"=>"v21"}
2016-06-03 11:39:56 [app] [I] Processing by Api::V21::ForemanTasksController#show as JSON
2016-06-03 11:39:56 [app] [I]   Parameters: {"apiv"=>"v21", "id"=>"2e557945-2067-4d17-852f-d9bd99ea1457"}
2016-06-03 11:39:56 [app] [I] Completed 200 OK in 105ms (Views: 92.6ms | ActiveRecord: 3.0ms)
2016-06-03 11:39:56 [app] [I] Completed 200 OK in 379ms (Views: 366.4ms | ActiveRecord: 5.1ms)
2016-06-03 11:39:58 [app] [W] Unable to reboot mac5254009dc284
 | Errno::EHOSTUNREACH: No route to host - connect(2) for "192.168.175.15" port 8443
 | /opt/rh/rh-ruby22/root/usr/share/ruby/net/http.rb:879:in `initialize'
 | /opt/rh/rh-ruby22/root/usr/share/ruby/net/http.rb:879:in `open'
 | /opt/rh/rh-ruby22/root/usr/share/ruby/net/http.rb:879:in `block 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:878:in `connect'
 | /opt/rh/rh-ruby22/root/usr/share/ruby/net/http.rb:863:in `do_start'
 | /opt/rh/rh-ruby22/root/usr/share/ruby/net/http.rb:852:in `start'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/rbovirt-0.0.37/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:76:in `put'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_discovery-5.0.0.4/app/services/foreman_discovery/node_api/node_resource.rb:102:in `put'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_discovery-5.0.0.4/app/services/foreman_discovery/node_api/power_service.rb:8:in `reboot'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_discovery-5.0.0.4/app/models/host/discovered.rb:153:in `reboot'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_discovery-5.0.0.4/app/models/host/managed_extensions.rb:29:in `setReboot'
 | /usr/share/foreman/app/models/concerns/orchestration.rb:162:in `execute'
 | /usr/share/foreman/app/models/concerns/orchestration.rb:107:in `block in process'
 | /usr/share/foreman/app/models/concerns/orchestration.rb:99:in `each'
 | /usr/share/foreman/app/models/concerns/orchestration.rb:99:in `process'
 | /usr/share/foreman/app/models/concerns/orchestration.rb:39:in `post_commit'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:424:in `block in make_lambda'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:253:in `call'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:253:in `block in simple'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:252:in `call'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:252:in `block in simple'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:239:in `call'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:239:in `block in conditional'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:86:in `call'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:86:in `run_callbacks'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/transactions.rb:296:in `committed!'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/abstract/transaction.rb:147:in `block in commit_records'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/abstract/transaction.rb:145:in `each'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/abstract/transaction.rb:145:in `commit_records'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/abstract/transaction.rb:181:in `perform_commit'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/abstract/transaction.rb:120:in `commit'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/abstract/database_statements.rb:235:in `commit_transaction'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/abstract/database_statements.rb:215:in `ensure in within_new_transaction'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/abstract/database_statements.rb:214:in `within_new_transaction'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/abstract/database_statements.rb:201:in `transaction'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/transactions.rb:208:in `transaction'
 | /usr/share/foreman/app/models/host.rb:15:in `method_missing'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/fusor_server-1.0.0/app/lib/actions/fusor/host/trigger_provisioning.rb:78:in `assign_host_to_hostgroup'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/fusor_server-1.0.0/app/lib/actions/fusor/host/trigger_provisioning.rb:34:in `run'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/action.rb:506:in `block (3 levels) in execute_run'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/middleware/stack.rb:26:in `call'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/middleware/stack.rb:26:in `pass'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/middleware.rb:17:in `pass'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/action/progress.rb:30:in `with_progress_calculation'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/action/progress.rb:16:in `run'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/middleware/stack.rb:22:in `call'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/middleware/stack.rb:26:in `pass'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/middleware.rb:17:in `pass'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.24/app/lib/actions/middleware/keep_locale.rb:11:in `block in run'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.24/app/lib/actions/middleware/keep_locale.rb:22:in `with_locale'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.24/app/lib/actions/middleware/keep_locale.rb:11:in `run'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/middleware/stack.rb:22:in `call'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/middleware/stack.rb:26:in `pass'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/middleware.rb:17:in `pass'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/middleware.rb:30:in `run'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/middleware/stack.rb:22:in `call'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/middleware/world.rb:30:in `execute'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/action.rb:505:in `block (2 levels) in execute_run'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/action.rb:504:in `catch'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/action.rb:504:in `block in execute_run'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/action.rb:419:in `call'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/action.rb:419:in `block in with_error_handling'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/action.rb:419:in `catch'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/action.rb:419:in `with_error_handling'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/action.rb:499:in `execute_run'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/action.rb:260:in `execute'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:9:in `block (2 levels) in execute'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/execution_plan/steps/abstract.rb:155:in `call'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/execution_plan/steps/abstract.rb:155:in `with_meta_calculation'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/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.10/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:22:in `open_action'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:7:in `execute'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/lib/dynflow/executors/parallel/worker.rb:15:in `block 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:in `tap'
 | /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:in `match_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:in `each'
 | /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:in `match'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/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:in `on_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:in `pass'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.10/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:in `pass'
 | /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:in `pass'
 | /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:in `pass'
 | /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:in `process_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:in `pass'
 | /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:in `pass'
 | /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:in `pass'
 | /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:in `process_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:in `block (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:in `synchronize'
 | /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:in `block 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:in `call'
 | /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:in `block 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:in `run_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:in `loop'
 | /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:in `catch'
 | /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:in `call'
 | /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'
2016-06-03 11:39:59 [app] [I] Waiting for host mac5254009dc284.example.com's deployment to complete...
2016-06-03 11:40:02 [app] [I] Started GET "/api/v21/foreman_tasks?search=parent_task_id+%3D+2e557945-2067-4d17-852f-d9bd99ea1457" for 10.3.112.64 at 2016-06-03 11:40:02 -0400
2016-06-03 11:40:02 [app] [I] Processing by Api::V21::ForemanTasksController#index as JSON


<snip>


2016-06-03 13:39:59 [foreman-tasks/action] [E] ERF42-7017 [Foreman::Exception]: You've reached the timeout set for this action. If the action is still ongoing, you can click on the "Resume Deployment" button to continue. (Foreman::Exception)
Comment 2 John Matthews 2016-06-06 20:46:39 UTC 
Created attachment 1165402 [details]
Foreman production.log
Comment 3 John Matthews 2016-06-06 20:49:38 UTC 
Intent of this Bugzilla is to add the means for detecting when a host isn't able to provision.

We currently assign the host to a hostgroup, changed it to managed and save it.
A series of callbacks execute, during which the host will be reboot and provisioning will start.

The issue is that during those callbacks sometimes an error happens...when an error does happen fusor_server does not know about it....so it continues it's workflow of waiting for the host to provision and come back.

Relevant code:
https://github.com/fusor/fusor/blob/master/server/app/lib/actions/fusor/host/trigger_provisioning.rb#L96


Desired behavior is for fusor_server to detect the error and fail the task, return error back to user in WebUI.
Comment 9 Jesus M. Rodriguez 2016-10-04 14:30:12 UTC 
https://github.com/fusor/fusor/blob/master/server/app/lib/actions/fusor/host/trigger_provisioning.rb#L111-L114
Comment 10 Jesus M. Rodriguez 2016-10-07 19:35:30 UTC 
After much digging and talking folks on katello, the discovery plugin users the activerecord after_commit callback to trigger the reboot, and other actions queued on the host.

It is actually documented that after_commit swallows exceptions in order to allow all the callbacks to fire.

https://raw.githubusercontent.com/rails/rails/3-2-stable/railties/guides/source/active_record_validations_callbacks.textile

"The +after_commit+ and +after_rollback+ callbacks are guaranteed to be called for all models created, updated, or destroyed within a transaction block. If any exceptions are raised within one of these callbacks, they will be ignored so that they don't interfere with the other callbacks. As such, if your callback code could raise an exception, you'll need to rescue it and handle it appropriately within the callback."

So when a reboot fails in the after_commit, there is no way for us to be notified that this failed.

There are at least 3 PRs attempting to fix the problem and all of them have been closed for various reasons:

https://github.com/rails/rails/pull/11123
https://github.com/rails/rails/issues/13460
https://github.com/rails/rails/pull/14488

All of the above have been closed and not committed.

And in Rails 4.2 after_commit has been deprecated, https://github.com/thoughtbot/paperclip/issues/1933

This means it will never get fixed. We will be dependent on a different mechanism and that depends on foreman_discovery.
Comment 11 Lukas Zapletal 2016-10-10 13:03:33 UTC 
Hello,

AFAIK Discovery uses after_validation for the reboot action and not after_commit. More than that, our orchestration engine swallows exceptions itself and logs them into the Rails log calling compensation methods automatically (for setReboot it's the delReboot method) which is a noop actually. By default all exceptions are also added to the model "errors" array and these are available for further use.