Bugzilla (bugzilla.redhat.com) will be under maintenance for infrastructure upgrades and will not be available on July 31st between 12:30 AM - 05:30 AM UTC. We appreciate your understanding and patience. You can follow status.redhat.com for details.
Bug 1343223 - Capture errors when discovery fails to reboot a discovered host during provisioning.
Summary: Capture errors when discovery fails to reboot a discovered host during provis...
Keywords:
Status: CLOSED WONTFIX
Alias: None
Product: Red Hat Quickstart Cloud Installer
Classification: Red Hat
Component: Installation - RHEV
Version: 1.0
Hardware: Unspecified
OS: Linux
unspecified
medium
Target Milestone: ---
: 1.1
Assignee: Jesus M. Rodriguez
QA Contact: Dave Johnson
Dan Macpherson
URL:
Whiteboard:
Depends On:
Blocks: qci-sprint-17
TreeView+ depends on / blocked
 
Reported: 2016-06-06 20:36 UTC by James Olin Oden
Modified: 2016-10-10 13:03 UTC (History)
5 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2016-10-07 19:35:58 UTC
Target Upstream Version:


Attachments (Terms of Use)
Foreman production.log (3.30 MB, text/plain)
2016-06-06 20:46 UTC, John Matthews
no flags Details

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 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.


Note You need to log in before you can comment on or make changes to this bug.