Project

General

Profile

Bug #9779

first host creation submit doesn't work using VMWare compute resource

Added by Alexandre Barth over 6 years ago. Updated over 5 years ago.

Status:
Resolved
Priority:
Normal
Assignee:
-
Category:
Compute resources - VMware
Target version:
-
Difficulty:
Triaged:
No
Bugzilla link:
Pull request:
Fixed in Releases:
Found in Releases:

Description

When creating a host using VMWare compute resource, first submit attempt fails with the following error (on second submit, everything works as expected) :

Started GET "/tasks/6e22b606-4295-484d-b34d-96497cf95abf" for 192.168.0.10 at 2015-03-16 13:21:44 +0100
2015-03-16 13:21:44 [I] Processing by TasksController#show as */*
2015-03-16 13:21:44 [I] Parameters: {"id"=>"6e22b606-4295-484d-b34d-96497cf95abf"}
2015-03-16 13:21:44 [I] Rendered tasks/_list.html.erb (0.6ms)
2015-03-16 13:21:44 [I] Completed 200 OK in 10ms (Views: 4.2ms | ActiveRecord: 0.7ms)
2015-03-16 13:21:44 [I] Adding Compute instance for testvm.foo.com
2015-03-16 13:21:45 [W] Échec de création de l'instance testvm.foo.com sur la ressource d'ordinateur vCenter_Bruz (VMware) : failed to create vm: undefined method `resourcePool' for nil:NilClass
/opt/rh/ruby193/root/usr/share/gems/gems/fog-1.28.0/lib/fog/vsphere/requests/compute/create_vm.rb:28:in `rescue in create_vm'
/opt/rh/ruby193/root/usr/share/gems/gems/fog-1.28.0/lib/fog/vsphere/requests/compute/create_vm.rb:8:in `create_vm'
/opt/rh/ruby193/root/usr/share/gems/gems/fog-1.28.0/lib/fog/vsphere/models/compute/server.rb:232:in `save'
/usr/share/foreman/app/models/compute_resources/foreman/model/vmware.rb:317:in `create_vm'
/usr/share/foreman/app/models/concerns/orchestration/compute.rb:76:in `setCompute'
/usr/share/foreman/app/models/concerns/orchestration.rb:141:in `execute'
/usr/share/foreman/app/models/concerns/orchestration.rb:86:in `block in process'
/usr/share/foreman/app/models/concerns/orchestration.rb:78:in `each'
/usr/share/foreman/app/models/concerns/orchestration.rb:78:in `process'
/usr/share/foreman/app/models/concerns/orchestration.rb:19:in `on_save'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:649:in `_run__3015461754500110033__save__1613292232405276339__callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_save_callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/callbacks.rb:264:in `create_or_update'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/persistence.rb:84:in `save'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/validations.rb:50:in `save'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/attribute_methods/dirty.rb:22:in `save'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:241:in `block (2 levels) in save'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:295:in `block in with_transaction_returning_status'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/connection_adapters/abstract/database_statements.rb:192:in `transaction'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:208:in `transaction'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:293:in `with_transaction_returning_status'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:241:in `block in save'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:252:in `rollback_active_record_state!'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:240:in `save'
/usr/share/foreman/app/models/concerns/foreman/sti.rb:29:in `save_with_type'
/usr/share/foreman/app/controllers/hosts_controller.rb:83:in `create'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/implicit_render.rb:4:in `send_action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/base.rb:167:in `process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rendering.rb:10:in `process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/callbacks.rb:18:in `block in process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:627:in `block (4 levels) in run_2018903308988567360__process_action__1019564522648071116__callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in conditional_callback_around_7323'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:326:in `around'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:310:in `_callback_around_2197'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_7323'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:626:in `block (3 levels) in _run
_2018903308988567360__process_action__1019564522648071116__callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in conditional_callback_around_7322'
/usr/share/foreman/app/controllers/concerns/application_shared.rb:13:in `set_timezone'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_7322'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:625:in `block (2 levels) in _run
_2018903308988567360__process_action__1019564522648071116__callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in conditional_callback_around_7321'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_7321'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:448:in `block in _run
_2018903308988567360__process_action__1019564522648071116__callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in conditional_callback_around_7320'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:326:in `around'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:310:in `_callback_around_13'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_7320'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:414:in `_run
_2018903308988567360__process_action__1019564522648071116__callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_process_action_callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/callbacks.rb:17:in `process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rescue.rb:29:in `process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:30:in `block in process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `block in instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:29:in `process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/params_wrapper.rb:207:in `process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/railties/controller_runtime.rb:18:in `process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/base.rb:121:in `process'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/rendering.rb:45:in `process'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:203:in `dispatch'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rack_delegation.rb:14:in `dispatch'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:246:in `block in action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:in `dispatch'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:36:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:68:in `block in call'
/opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `each'
/opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:600:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/apipie-rails-0.2.6/lib/apipie/static_dispatcher.rb:65:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/apipie-rails-0.2.6/lib/apipie/extractor/recorder.rb:97:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/apipie-rails-0.2.6/lib/apipie/middleware/checksum_in_headers.rb:27:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/best_standards_support.rb:17:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/etag.rb:23:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/conditionalget.rb:35:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/head.rb:14:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/params_parser.rb:21:in `call'
/usr/share/foreman/lib/middleware/catch_json_parse_errors.rb:9:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/flash.rb:242:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:205:in `context'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:200:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/cookies.rb:339:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/query_cache.rb:64:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/connection_adapters/abstract/connection_pool.rb:473:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `_run__774207732255244246__call__1613292232405276339__callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_call_callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:27:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/remote_ip.rb:31:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/show_exceptions.rb:56:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:26:in `call_app'
/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:16:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/request_id.rb:22:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/methodoverride.rb:21:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/runtime.rb:17:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/cache/strategy/local_cache.rb:72:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/lock.rb:15:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:136:in `forward'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:143:in `pass'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:155:in `invalidate'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:71:in `call!'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:51:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/engine.rb:479:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/application.rb:223:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/railtie/configurable.rb:30:in `method_missing'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/builder.rb:134:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/urlmap.rb:64:in `block in call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/urlmap.rb:49:in `each'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/urlmap.rb:49:in `call'
/usr/share/gems/gems/passenger-4.0.18/lib/phusion_passenger/rack/thread_handler_extension.rb:77:in `process_request'
/usr/share/gems/gems/passenger-4.0.18/lib/phusion_passenger/request_handler/thread_handler.rb:140:in `accept_and_process_next_request'
/usr/share/gems/gems/passenger-4.0.18/lib/phusion_passenger/request_handler/thread_handler.rb:108:in `main_loop'
/usr/share/gems/gems/passenger-4.0.18/lib/phusion_passenger/request_handler.rb:441:in `block (3 levels) in start_threads'
2015-03-16 13:21:45 [W] Rolling back due to a problem: [Preparation de l'instance testvm.foo.com 2 failed [#<Host::Managed id: nil, name: "testvm.foo.com", last_compile: nil, last_freshcheck: nil, last_report: nil, updated_at: nil, source_file_id: nil, created_at: nil, root_pass: "$6$pbVjNggG$9tIfRzrmVn6tP8gAfOEOeH8htStB2Xtev8Q9gMp...", serial: nil, puppet_status: 0, architecture_id: 1, operatingsystem_id: 1, environment_id: 1, ptable_id: 19, medium_id: 8, build: true, comment: "", disk: "", installed_at: nil, model_id: nil, hostgroup_id: 1, owner_id: 4, owner_type: "User", enabled: true, puppet_ca_proxy_id: 1, managed: true, use_image: nil, image_file: nil, uuid: nil, compute_resource_id: 1, puppet_proxy_id: 1, certname: nil, image_id: nil, organization_id: nil, location_id: nil, type: "Host::Managed", otp: nil, realm_id: nil, compute_profile_id: nil, provision_method: "build", grub_pass: "$1$Z/41C1BA$RmT15mlGVwZjnNjLFqZVM.">, :setCompute]]
2015-03-16 13:21:45 [I] Failed to save: Échec de création de l'instance testvm.foo.com sur la ressource d'ordinateur vCenter_Bruz (VMware) : failed to create vm: undefined method `resourcePool' for nil:NilClass

2015-03-16 13:21:45 [I]

Started GET "/tasks/6e22b606-4295-484d-b34d-96497cf95abf" for 192.168.0.10 at 2015-03-16 13:21:45 +0100
2015-03-16 13:21:45 [I] Processing by TasksController#show as */*
2015-03-16 13:21:45 [I] Parameters: {"id"=>"6e22b606-4295-484d-b34d-96497cf95abf"}
2015-03-16 13:21:45 [I] Rendered tasks/_list.html.erb (0.5ms)
2015-03-16 13:21:45 [I] Completed 200 OK in 6ms (Views: 1.2ms | ActiveRecord: 0.8ms)
2015-03-16 13:21:46 [I] Rendered hosts/_progress.html.erb (0.5ms)
2015-03-16 13:21:46 [I] Rendered puppetclasses/_selectedClasses.html.erb (0.0ms)
2015-03-16 13:21:46 [I] Rendered puppetclasses/_classes_in_groups.html.erb (0.0ms)
2015-03-16 13:21:46 [I] Rendered puppetclasses/_classes.html.erb (27.6ms)
2015-03-16 13:21:46 [I] Rendered puppetclasses/_class_selection.html.erb (114.2ms)
2015-03-16 13:21:47 [I]

Started GET "/tasks/6e22b606-4295-484d-b34d-96497cf95abf" for 192.168.0.10 at 2015-03-16 13:21:47 +0100
2015-03-16 13:21:47 [I] Processing by TasksController#show as */*
2015-03-16 13:21:47 [I] Parameters: {"id"=>"6e22b606-4295-484d-b34d-96497cf95abf"}
2015-03-16 13:21:47 [I] Rendered tasks/_list.html.erb (0.4ms)
2015-03-16 13:21:47 [I] Completed 200 OK in 4ms (Views: 0.9ms | ActiveRecord: 0.6ms)
2015-03-16 13:21:48 [I] Rendered compute_resources_vms/form/vmware/_base.html.erb (2556.5ms)
2015-03-16 13:21:49 [I]

Started GET "/tasks/6e22b606-4295-484d-b34d-96497cf95abf" for 192.168.0.10 at 2015-03-16 13:21:49 +0100
2015-03-16 13:21:49 [I] Processing by TasksController#show as */*
2015-03-16 13:21:49 [I] Parameters: {"id"=>"6e22b606-4295-484d-b34d-96497cf95abf"}
2015-03-16 13:21:49 [I] Rendered tasks/_list.html.erb (0.4ms)
2015-03-16 13:21:49 [I] Completed 200 OK in 4ms (Views: 0.9ms | ActiveRecord: 0.6ms)
2015-03-16 13:21:50 [I]

Started GET "/tasks/6e22b606-4295-484d-b34d-96497cf95abf" for 192.168.0.10 at 2015-03-16 13:21:50 +0100
2015-03-16 13:21:50 [I] Processing by TasksController#show as */*
2015-03-16 13:21:50 [I] Parameters: {"id"=>"6e22b606-4295-484d-b34d-96497cf95abf"}
2015-03-16 13:21:50 [I] Rendered tasks/_list.html.erb (0.4ms)
2015-03-16 13:21:50 [I] Completed 200 OK in 5ms (Views: 1.1ms | ActiveRecord: 0.5ms)
2015-03-16 13:21:51 [I] Rendered compute_resources_vms/form/vmware/_volume.html.erb (2903.1ms)
2015-03-16 13:21:52 [I]

Started GET "/tasks/6e22b606-4295-484d-b34d-96497cf95abf" for 192.168.0.10 at 2015-03-16 13:21:52 +0100
2015-03-16 13:21:52 [I] Processing by TasksController#show as */*
2015-03-16 13:21:52 [I] Parameters: {"id"=>"6e22b606-4295-484d-b34d-96497cf95abf"}
2015-03-16 13:21:52 [I] Rendered tasks/_list.html.erb (0.7ms)
2015-03-16 13:21:52 [I] Completed 200 OK in 6ms (Views: 1.3ms | ActiveRecord: 0.9ms)
2015-03-16 13:21:54 [I]

Started GET "/tasks/6e22b606-4295-484d-b34d-96497cf95abf" for 192.168.0.10 at 2015-03-16 13:21:54 +0100
2015-03-16 13:21:54 [I] Processing by TasksController#show as */*
2015-03-16 13:21:54 [I] Parameters: {"id"=>"6e22b606-4295-484d-b34d-96497cf95abf"}
2015-03-16 13:21:54 [I] Rendered tasks/_list.html.erb (0.4ms)
2015-03-16 13:21:54 [I] Completed 200 OK in 4ms (Views: 0.9ms | ActiveRecord: 0.6ms)
2015-03-16 13:21:54 [I] Rendered compute_resources_vms/form/vmware/_volume.html.erb (3025.4ms)
2015-03-16 13:21:54 [I] Rendered compute_resources_vms/form/_volumes.html.erb (5931.8ms)
2015-03-16 13:21:54 [I] Rendered hosts/_compute_detail.html.erb (8490.8ms)
2015-03-16 13:21:54 [I] Rendered hosts/_compute.html.erb (8496.2ms)
2015-03-16 13:21:54 [I] Rendered nic/_base_form.html.erb (15.5ms)
2015-03-16 13:21:54 [I] Rendered nic/_virtual_form.html.erb (1.8ms)
2015-03-16 13:21:55 [I] Rendered compute_resources_vms/form/vmware/_network.html.erb (777.0ms)
2015-03-16 13:21:55 [I] Rendered nic/_provider_specific_form.html.erb (779.0ms)
2015-03-16 13:21:55 [I] Rendered nic/manageds/_managed.html.erb (801.1ms)
2015-03-16 13:21:55 [I] Rendered nic/_base_form.html.erb (12.7ms)
2015-03-16 13:21:55 [I] Rendered nic/_virtual_form.html.erb (1.1ms)
2015-03-16 13:21:55 [I]

Started GET "/tasks/6e22b606-4295-484d-b34d-96497cf95abf" for 192.168.0.10 at 2015-03-16 13:21:55 +0100
2015-03-16 13:21:55 [I] Processing by TasksController#show as */*
2015-03-16 13:21:55 [I] Parameters: {"id"=>"6e22b606-4295-484d-b34d-96497cf95abf"}
2015-03-16 13:21:55 [I] Rendered tasks/_list.html.erb (0.4ms)
2015-03-16 13:21:55 [I] Completed 200 OK in 5ms (Views: 1.0ms | ActiveRecord: 0.7ms)
2015-03-16 13:21:56 [I] Rendered compute_resources_vms/form/vmware/_network.html.erb (704.4ms)
2015-03-16 13:21:56 [I] Rendered nic/_provider_specific_form.html.erb (705.3ms)
2015-03-16 13:21:56 [I] Rendered nic/manageds/_managed.html.erb (722.5ms)
2015-03-16 13:21:56 [I] Rendered hosts/_interfaces.html.erb (1528.0ms)
2015-03-16 13:21:56 [I] Rendered common/os_selection/_architecture.html.erb (5.8ms)
2015-03-16 13:21:56 [I] Rendered common/os_selection/_operatingsystem.html.erb (8.7ms)
2015-03-16 13:21:56 [I] Rendered hosts/_operating_system.html.erb (23.0ms)
2015-03-16 13:21:56 [I] Rendered hosts/_unattended.html.erb (10050.1ms)
2015-03-16 13:21:57 [I] Rendered puppetclasses/_class_parameters.html.erb (1035.2ms)
2015-03-16 13:21:57 [I] Rendered puppetclasses/_classes_parameters.html.erb (1050.7ms)
2015-03-16 13:21:57 [I] Rendered common_parameters/_inherited_parameters.html.erb (10.6ms)
2015-03-16 13:21:57 [I] Rendered common_parameters/_puppetclass_parameter.html.erb (4.3ms)
2015-03-16 13:21:57 [I] Rendered common_parameters/_puppetclasses_parameters.html.erb (18.5ms)
2015-03-16 13:21:57 [I] Rendered common_parameters/_parameter.html.erb (3.5ms)
2015-03-16 13:21:57 [I] Rendered common_parameters/_parameters.html.erb (136.6ms)
2015-03-16 13:21:57 [I]

Started GET "/tasks/6e22b606-4295-484d-b34d-96497cf95abf" for 192.168.0.10 at 2015-03-16 13:21:57 +0100
2015-03-16 13:21:57 [I] Processing by TasksController#show as */*
2015-03-16 13:21:57 [I] Parameters: {"id"=>"6e22b606-4295-484d-b34d-96497cf95abf"}
2015-03-16 13:21:57 [I] Rendered hosts/_form.html.erb (11505.7ms)
2015-03-16 13:21:57 [I] Rendered hosts/new.html.erb within layouts/application (11507.2ms)
2015-03-16 13:21:57 [I] Rendered tasks/_list.html.erb (0.5ms)
2015-03-16 13:21:57 [I] Completed 200 OK in 4ms (Views: 0.9ms | ActiveRecord: 0.5ms)
2015-03-16 13:21:57 [I] Rendered home/_user_dropdown.html.erb (2.4ms)
2015-03-16 13:21:57 [I] Read fragment views/tabs_and_title_records-4 (0.2ms)
2015-03-16 13:21:57 [I] Rendered home/_topbar.html.erb (8.6ms)
2015-03-16 13:21:57 [I] Rendered layouts/base.html.erb (11.9ms)
2015-03-16 13:21:57 [I] Completed 200 OK in 14706ms (Views: 11568.9ms | ActiveRecord: 100.7ms)
2015-03-16 13:21:59 [I]

Started GET "/tasks/6e22b606-4295-484d-b34d-96497cf95abf" for 192.168.0.10 at 2015-03-16 13:21:59 +0100
2015-03-16 13:21:59 [I] Processing by TasksController#show as */*
2015-03-16 13:21:59 [I] Parameters: {"id"=>"6e22b606-4295-484d-b34d-96497cf95abf"}
2015-03-16 13:21:59 [I] Rendered tasks/_list.html.erb (108.9ms)
2015-03-16 13:21:59 [I] Completed 200 OK in 118ms (Views: 112.1ms | ActiveRecord: 0.6ms)

Foreman-9779-Example.log Foreman-9779-Example.log 17.5 KB Matt Chesler, 05/07/2015 11:17 AM

Related issues

Related to Foreman - Bug #2696: Failed to create a compute vmware (VMWare) instance test12.local.domain: failed to create vm: undefined method `resourcePool' for nil:NilClassRejected2013-06-22
Related to Foreman - Bug #10336: foreman-rake prints "Workaround for RbVmomi may not work as ComputeResource is already loaded: #{ComputeResource}"Closed2015-04-30
Related to Foreman - Bug #10912: failed to create vm: undefined method `resourcePool' for nil:NilClassRejected2015-06-23

History

#1 Updated by Dominic Cleal over 6 years ago

  • Related to Bug #2696: Failed to create a compute vmware (VMWare) instance test12.local.domain: failed to create vm: undefined method `resourcePool' for nil:NilClass added

#2 Updated by Dominic Cleal over 6 years ago

  • Category set to Compute resources - VMware
  • Legacy Backlogs Release (now unused) set to 28

Unfortunately I haven't had many thoughts since my comments in #2696, and I don't know why this is occurring again now (just had another report from lotherk on IRC).

It would be valuable if you can add some sort of debug logging into /opt/rh/ruby193/root/usr/share/gems/gems/fog-1.28.0/lib/fog/vsphere/requests/compute/create_vm.rb before line 19 (the resource_pool =), e.g.

Rails.logger.warn("cluster=#{attributes[:cluster]}")
Rails.logger.warn("datacenter=#{attributes[:datacenter]}")
Rails.logger.warn("raw_cluster=#{get_raw_cluster(attributes[:cluster], attributes[:datacenter])}")

Maybe we can identify some difference in what's being passed in the first time.

#3 Updated by Dominic Cleal over 6 years ago

The second piece of debug that'd be useful is the initial POST /hosts request from when the form is submitted, as that should contain the VMware cluster ID - we should check it was set in HTTP request in the first place.

#4 Updated by Alexandre Barth over 6 years ago

I've upgraded to 1.8.0 RC2 and i can't reproduce this atm (5 hosts creation and no problem)
Where can i find changelog from 1.8.0 RC1 to 1.8.0 RC2 plz ?

#5 Updated by Dominic Cleal over 6 years ago

Alexandre Barth wrote:

I've upgraded to 1.8.0 RC2 and i can't reproduce this atm (5 hosts creation and no problem)
Where can i find changelog from 1.8.0 RC1 to 1.8.0 RC2 plz ?

https://github.com/theforeman/foreman/compare/1.8.0-RC1...1.8.0-RC2 or https://github.com/theforeman/foreman/commits/1.8-stable

However nothing I've merged really rings a bell as to fixing this unfortunately... it might be luck.

#6 Updated by Alexandre Barth over 6 years ago

Ok, i've added your debug logging lines into fog code. As soon as i can reproduce, i'll join the full log.

#7 Updated by Dominic Cleal over 6 years ago

Thank you!

#8 Updated by Dominic Cleal over 6 years ago

  • Status changed from New to Need more information

#9 Updated by Francois Herbert over 6 years ago

I'm having this issue, but it's not a one time thing, happens all the time and can't create a new host using the vmware compute resource. I can create one when deploying from template.
My output from the debug logging is:


2015-04-14 08:30:16 [W] cluster=Turitea/Turitea RHEL 1
2015-04-14 08:30:16 [W] datacenter=Turitea ITS
2015-04-14 08:30:16 [W] resource_pool=

I've tried to enable EXCON_DEBUG (using setenv EXCON_DEBUG in httpd conf file - I'm running passenger) but I'm getting no extra info in production.log

#10 Updated by Francois Herbert over 6 years ago

Please ignore my last post, just checked our vsphere environment and we don't have any resource pools!! Now to figure out how to create a machine when there are no resource pools...

#11 Updated by Dominic Cleal over 6 years ago

  • Status changed from Need more information to Feedback
  • Legacy Backlogs Release (now unused) deleted (28)

Dropping from the release until we get any further clues about it.

#12 Updated by Josh Baird over 6 years ago

I'm having this problem in 1.8. What kind of info/logs/etc do you need from me? This is a somewhat high priority in our environment since we exclusively use VMWare.

#13 Updated by Matt Chesler over 6 years ago

I'm having this same problem with 1.8.0.

#14 Updated by Dominic Cleal over 6 years ago

  • Status changed from Feedback to Need more information

If you can first add the logging mentioned in comment #2 above, then when you're able to reproduce it, please include the production.log covering the whole period - both the first and second submission. Hopefully we'll see a difference between the two attempts.

#15 Updated by Matt Chesler over 6 years ago

Log output attached from an occurrence of this issue

#16 Updated by Dominic Cleal over 6 years ago

  • Related to Bug #10336: foreman-rake prints "Workaround for RbVmomi may not work as ComputeResource is already loaded: #{ComputeResource}" added

#17 Updated by Dominic Cleal over 6 years ago

#10336 reports + fixes an issue with a workaround we put in for the same bug in an old version. You can apply this locally simply by running: mv ~foreman/config/initializers/{,2_}rbvmomi.rb and then restarting Apache. It'll also be in 1.8.1, hopefully this will help fix this ticket.

#18 Updated by Dominic Cleal over 6 years ago

  • Related to Bug #10912: failed to create vm: undefined method `resourcePool' for nil:NilClass added

#19 Updated by Tomer Brisker over 5 years ago

  • Status changed from Need more information to Resolved

Seems to have been resolved for 1.8.1. Closing, please reopen if this is still an issue in current versions.

Also available in: Atom PDF