Unable to create host with VMware after 1.18.0 upgrade (undefined method `volumes' for nil:NilClass)

Support
,
1

Problem:
Unable to create new hosts after 1.18.0 upgrade with VMware compute resource. After clicking the Submit button for creating a new host, I get a toast error “Failed to create a compute vCSA (VMware) instance test03.example.com: undefined method `volumes’ for nil:NilClass”.

Foreman and Proxy versions:
1.18.0 (CentOS 7)

Other relevant data:

This was working before the upgrade with version 1.17.1. I also noticed that storage configuration in Foreman get reset after clicking submit.

Relevant bits from production.log: 2018-07-18T18:14:51 [I|app|] Started POST "/hosts" for 192.168.0.167 at 2018-07- - Pastebin.com

Screen shot:

foreman_error
foreman_error1699×336 34.4 KB

Let me know if I can provide any more useful info.

Thanks!
-Jason

2

Here’s the log so you don’t have to go to Pastebin (still figuring out Discourse):

2018-07-18T18:14:51 [I|app|] Started POST "/hosts" for 192.168.0.167 at 2018-07-18 18:14:51 -0700
2018-07-18T18:14:51 [I|app|ed7d7] Processing by HostsController#create as */*
2018-07-18T18:14:51 [I|app|ed7d7]   Parameters: {"utf8"=>"✓", "authenticity_token"=>"<token>", "host"=>{"name"=>"test03", "hostgroup_id"=>"3", "compute_resource_id"=>"1", "puppetclass_ids"=>[""], "managed"=>"true", "progress_report_id"=>"[FILTERED]", "type"=>"Host::Managed", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"test03", "domain_id"=>"1", "subnet_id"=>"2", "ip"=>"10.255.0.234", "ip6"=>"", "managed"=>"1", "primary"=>"1", "provision"=>"1", "virtual"=>"0", "tag"=>"", "attached_to"=>"", "compute_attributes"=>{"type"=>"VirtualVmxnet3", "network"=>"network-27"}}}, "compute_attributes"=>{"cpus"=>"1", "corespersocket"=>"1", "memory_mb"=>"2048", "firmware"=>"bios", "cluster"=>"Cluster01", "resource_pool"=>"Resources", "path"=>"/Datacenters/Cirrus/vm", "guest_id"=>"centos7_64Guest", "hardware_version"=>"Default", "memoryHotAddEnabled"=>"1", "cpuHotAddEnabled"=>"1", "add_cdrom"=>"0", "start"=>"1", "annotation"=>""}, "architecture_id"=>"1", "operatingsystem_id"=>"4", "provision_method"=>"build", "build"=>"1", "medium_id"=>"1", "ptable_id"=>"90", "pxe_loader"=>"PXELinux BIOS", "disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"3-Users", "enabled"=>"1", "model_id"=>"", "comment"=>"", "overwrite"=>"false"}}
2018-07-18T18:14:51 [I|app|ed7d7] Current user: admin (administrator)
2018-07-18T18:14:52 [I|app|ed7d7] Adding Compute instance for test03.example.com
2018-07-18T18:14:52 [W|app|ed7d7] Failed to create a compute vCSA (VMware) instance test03.example.com: undefined method `volumes' for nil:NilClass

NoMethodError: undefined method `volumes' for nil:NilClass
/opt/theforeman/tfm/root/usr/share/gems/gems/fog-vsphere-2.1.1/lib/fog/vsphere/models/compute/volume.rb:142:in `calculate_free_unit_number'
/opt/theforeman/tfm/root/usr/share/gems/gems/fog-vsphere-2.1.1/lib/fog/vsphere/models/compute/volume.rb:107:in `set_unit_number'
/opt/theforeman/tfm/root/usr/share/gems/gems/fog-vsphere-2.1.1/lib/fog/vsphere/requests/compute/create_vm.rb:241:in `create_disk'
/opt/theforeman/tfm/root/usr/share/gems/gems/fog-vsphere-2.1.1/lib/fog/vsphere/requests/compute/create_vm.rb:105:in `block in device_change'
/opt/theforeman/tfm/root/usr/share/gems/gems/fog-vsphere-2.1.1/lib/fog/vsphere/requests/compute/create_vm.rb:105:in `map'
/opt/theforeman/tfm/root/usr/share/gems/gems/fog-vsphere-2.1.1/lib/fog/vsphere/requests/compute/create_vm.rb:105:in `device_change'
/opt/theforeman/tfm/root/usr/share/gems/gems/fog-vsphere-2.1.1/lib/fog/vsphere/requests/compute/create_vm.rb:17:in `create_vm'
/opt/theforeman/tfm/root/usr/share/gems/gems/fog-vsphere-2.1.1/lib/fog/vsphere/models/compute/server.rb:303:in `save'
/usr/share/foreman/app/models/compute_resources/foreman/model/vmware.rb:443:in `create_vm'
/usr/share/foreman/app/models/concerns/orchestration/compute.rb:78:in `setCompute'
/usr/share/foreman/app/models/concerns/orchestration.rb:222:in `execute'
/usr/share/foreman/app/models/concerns/orchestration.rb:145:in `block in process'
/usr/share/foreman/app/models/concerns/orchestration.rb:137:in `each'
/usr/share/foreman/app/models/concerns/orchestration.rb:137:in `process'
/usr/share/foreman/app/models/concerns/orchestration.rb:44:in `around_save_orchestration'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:135:in `run_callbacks'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:827:in `_run_save_callbacks'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/callbacks.rb:336:in `create_or_update'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/persistence.rb:129:in `save'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/validations.rb:44:in `save'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/attribute_methods/dirty.rb:35:in `save'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/transactions.rb:308:in `block (2 levels) in save'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/transactions.rb:384:in `block in with_transaction_returning_status'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/database_statements.rb:235:in `block in transaction'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/transaction.rb:194:in `block in within_new_transaction'
/opt/rh/rh-ruby24/root/usr/share/ruby/monitor.rb:214:in `mon_synchronize'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/transaction.rb:191:in `within_new_transaction'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/database_statements.rb:235:in `transaction'/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/transactions.rb:210:in `transaction'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/transactions.rb:381:in `with_transaction_returning_status'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/transactions.rb:308:in `block in save'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/transactions.rb:323:in `rollback_active_record_state!'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/transactions.rb:307:in `save'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/suppressor.rb:42:in `save'
/usr/share/foreman/app/models/concerns/foreman/sti.rb:26:in `save'
/usr/share/foreman/app/controllers/hosts_controller.rb:104:in `create'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/basic_implicit_render.rb:4:in `send_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/abstract_controller/base.rb:186:in `process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/rendering.rb:30:in `process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/abstract_controller/callbacks.rb:20:in `block in process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:108:in `block in run_callbacks'
/usr/share/foreman/app/controllers/concerns/application_shared.rb:15:in `set_timezone'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
/usr/share/foreman/app/controllers/concerns/foreman/controller/topbar_sweeper.rb:12:in `set_topbar_sweeper_controller'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
/opt/theforeman/tfm/root/usr/share/gems/gems/audited-4.7.0/lib/audited/sweeper.rb:14:in `around'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
/opt/theforeman/tfm/root/usr/share/gems/gems/audited-4.7.0/lib/audited/sweeper.rb:14:in `around'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:135:in `run_callbacks'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/abstract_controller/callbacks.rb:19:in `process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/rescue.rb:20:in `process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/notifications.rb:166:in `block in instrument'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/notifications.rb:166:in `instrument'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/params_wrapper.rb:252:in `process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/railties/controller_runtime.rb:22:in `process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/abstract_controller/base.rb:124:in `process'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionview-5.1.6/lib/action_view/rendering.rb:30:in `process'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal.rb:189:in `dispatch'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal.rb:253:in `dispatch'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/routing/route_set.rb:49:in `dispatch'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/routing/route_set.rb:31:in `serve'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/journey/router.rb:50:in `block in serve'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/journey/router.rb:33:in `each'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/journey/router.rb:33:in `serve'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/routing/route_set.rb:844:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.9/lib/apipie/static_dispatcher.rb:65:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.9/lib/apipie/extractor/recorder.rb:136:in `call'
/usr/share/foreman/lib/middleware/telemetry.rb:9:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.9/lib/apipie/middleware/checksum_in_headers.rb:27:in `call'
/usr/share/foreman/lib/middleware/catch_json_parse_errors.rb:8:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/etag.rb:25:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/conditional_get.rb:38:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/head.rb:12:in `call'
/usr/share/foreman/lib/middleware/logging_context.rb:23:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/session/abstract/id.rb:232:in `context'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/session/abstract/id.rb:226:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/cookies.rb:613:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/callbacks.rb:26:in `block in call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:97:in `run_callbacks'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/callbacks.rb:24:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/debug_exceptions.rb:59:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/show_exceptions.rb:31:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/rack/logger.rb:36:in `call_app'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/rack/logger.rb:26:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/sprockets-rails-3.2.1/lib/sprockets/rails/quiet_assets.rb:13:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/remote_ip.rb:79:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/request_id.rb:25:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/method_override.rb:22:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/runtime.rb:22:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/cache/strategy/local_cache_middleware.rb:27:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/executor.rb:12:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/sendfile.rb:111:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/secure_headers-5.0.5/lib/secure_headers/middleware.rb:13:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/engine.rb:522:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/railtie.rb:185:in `public_send'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/railtie.rb:185:in `method_missing'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/urlmap.rb:68:in `block in call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/urlmap.rb:53:in `each'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/urlmap.rb:53:in `call'
/usr/share/passenger/phusion_passenger/rack/thread_handler_extension.rb:74:in `process_request'
/usr/share/passenger/phusion_passenger/request_handler/thread_handler.rb:141:in `accept_and_process_next_request'
/usr/share/passenger/phusion_passenger/request_handler/thread_handler.rb:109:in `main_loop'
/usr/share/passenger/phusion_passenger/request_handler.rb:455:in `block (3 levels) in start_threads'
/opt/theforeman/tfm/root/usr/share/gems/gems/logging-2.2.2/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2018-07-18T18:14:52 [W|app|ed7d7] Rolling back due to a problem: [#<Orchestration::Task:0x00007fb4a2e66398 @name="Set up compute instance test03.example.com", @id="Set up compute instance test03.example.com", @status="failed", @priority=2, @action=[#<Host::Managed id: nil, name: "test03.example.com", last_compile: nil, last_report: nil, updated_at: nil, created_at: nil, root_pass: "<hash>", architecture_id: 1, operatingsystem_id: 4, environment_id: 1, ptable_id: 90, medium_id: 1, build: true, comment: "", disk: "", installed_at: nil, model_id: nil, hostgroup_id: 3, owner_id: 3, 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: 5, provision_method: "build", grub_pass: "<hash>", global_status: 0, lookup_value_matcher: "fqdn=test03.example.com", pxe_loader: "PXELinux BIOS">, :setCompute], @created=1531962891.9317605, @timestamp=2018-07-19 01:14:52 UTC>]
2018-07-18T18:14:52 [I|app|ed7d7] Processed 1 tasks from queue 'Host::Managed Main', completed 0/9
2018-07-18T18:14:52 [E|app|ed7d7] Task 'Set up compute instance test03.example.com' *failed*
2018-07-18T18:14:52 [E|app|ed7d7] Task 'Query instance details for test03.example.com' *canceled*
2018-07-18T18:14:52 [E|app|ed7d7] Task 'Create DHCP Settings for test03.example.com' *canceled*
2018-07-18T18:14:52 [E|app|ed7d7] Task 'Create Reverse IPv4 DNS record for test03.example.com' *canceled*
2018-07-18T18:14:52 [E|app|ed7d7] Task 'Deploy TFTP PXELinux config for test03.example.com' *canceled*
2018-07-18T18:14:52 [E|app|ed7d7] Task 'Deploy TFTP PXEGrub2 config for test03.example.com' *canceled*
2018-07-18T18:14:52 [E|app|ed7d7] Task 'Deploy TFTP PXEGrub config for test03.example.com' *canceled*
2018-07-18T18:14:52 [E|app|ed7d7] Task 'Fetch TFTP boot files for test03.example.com' *canceled*
2018-07-18T18:14:52 [E|app|ed7d7] Task 'Power up compute instance test03.example.com' *canceled*
2018-07-18T18:14:52 [E|app|ed7d7] Failed to save: Failed to create a compute vCSA (VMware) instance test03.example.com: undefined method `volumes' for nil:NilClass

2018-07-18T18:14:52 [I|app|ed7d7]   Rendering hosts/new.html.erb within layouts/application
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered hosts/_progress.html.erb (1.3ms)
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered hosts/puppet/_main_tab_fields.html.erb (5.8ms)
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered collection of puppetclasses/_selectedClasses.html.erb [0 times] (0.0ms)
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered collection of puppetclasses/_classes_in_groups.html.erb [0 times] (0.0ms)
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered puppetclasses/_classes.html.erb (115.5ms)
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered puppetclasses/_class_selection.html.erb (310.5ms)
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered hosts/puppet/_puppet_classes_tab.html.erb (317.9ms)
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered nic/_base_form.html.erb (34.1ms)
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered nic/_virtual_form.html.erb (3.7ms)
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered compute_resources_vms/form/vmware/_network.html.erb (3.3ms)
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered nic/_provider_specific_form.html.erb (6.6ms)
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered nic/manageds/_managed.html.erb (49.2ms)
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered nic/_base_form.html.erb (44.3ms)
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered nic/_virtual_form.html.erb (3.5ms)
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered compute_resources_vms/form/vmware/_network.html.erb (2.1ms)
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered nic/_provider_specific_form.html.erb (5.4ms)
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered nic/manageds/_managed.html.erb (58.1ms)
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered hosts/_interfaces.html.erb (114.0ms)
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered compute_resources_vms/form/vmware/_base.html.erb (218.0ms)
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered compute_resources_vms/form/_volumes.html.erb (0.3ms)
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered hosts/_compute_detail.html.erb (220.5ms)
2018-07-18T18:14:52 [I|app|ed7d7]   Rendered hosts/_compute.html.erb (225.3ms)
2018-07-18T18:14:52 [I|app|] Started GET "/tasks/47341449-a9af-4bb6-b999-06179762567d" for 192.168.0.167 at 2018-07-18 18:14:52 -0700
2018-07-18T18:14:52 [I|app|d808a] Processing by TasksController#show as */*
2018-07-18T18:14:52 [I|app|d808a]   Parameters: {"id"=>"47341449-a9af-4bb6-b999-06179762567d"}
2018-07-18T18:14:52 [I|app|d808a] Current user: admin (administrator)
2018-07-18T18:14:53 [I|app|d808a]   Rendered tasks/_list.html.erb (2.6ms)
2018-07-18T18:14:53 [I|app|d808a] Completed 200 OK in 14ms (Views: 4.0ms | ActiveRecord: 2.0ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered common/os_selection/_architecture.html.erb (12.2ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered common/os_selection/_pxe_loader.html.erb (3.6ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered common/os_selection/_operatingsystem.html.erb (29.7ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered hosts/provision_method/build/_form.html.erb (39.6ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered hosts/provision_method/image/_form.html.erb (1.0ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered hosts/_operating_system.html.erb (82.2ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered hosts/_unattended.html.erb (319.9ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered collection of puppetclasses/_class_parameters.html.erb [6 times] (272.6ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered puppetclasses/_classes_parameters.html.erb (309.9ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered common_parameters/_inherited_parameters.html.erb (3.3ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered common_parameters/_parameter.html.erb (4.6ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered common_parameters/_parameters.html.erb (35.2ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered hosts/_form.html.erb (1343.1ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered hosts/new.html.erb within layouts/application (1350.2ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered layouts/_application_content.html.erb (3.8ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendering layouts/base.html.erb
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered home/_org_switcher.html.erb (1.0ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered home/_user_dropdown.html.erb (27.3ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered home/_topbar.html.erb (43.3ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered home/_vertical_menu.html.erb (5.1ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered home/_vertical_menu.html.erb (3.7ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered home/_vertical_menu.html.erb (3.1ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered home/_vertical_menu.html.erb (3.3ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered home/_vertical_menu.html.erb (3.2ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered home/_vertical_menu.html.erb (1.7ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered home/_navbar.html.erb (37.3ms)
2018-07-18T18:14:53 [I|app|ed7d7]   Rendered layouts/base.html.erb (99.1ms)
2018-07-18T18:14:53 [I|app|ed7d7] Completed 200 OK in 2140ms (Views: 1384.5ms | ActiveRecord: 155.3ms)
2018-07-18T18:14:54 [I|app|] Started GET "/notification_recipients" for 192.168.0.167 at 2018-07-18 18:14:54 -0700
2018-07-18T18:14:54 [I|app|14c30] Processing by NotificationRecipientsController#index as JSON
2018-07-18T18:14:54 [I|app|14c30] Current user: admin (administrator)
2018-07-18T18:14:54 [I|app|14c30] Completed 200 OK in 7ms (Views: 0.3ms | ActiveRecord: 0.7ms)
2018-07-18T18:14:54 [I|app|] Started GET "/tasks/47341449-a9af-4bb6-b999-06179762567d" for 192.168.0.167 at 2018-07-18 18:14:54 -0700
2018-07-18T18:14:54 [I|app|93c83] Processing by TasksController#show as */*
2018-07-18T18:14:54 [I|app|93c83]   Parameters: {"id"=>"47341449-a9af-4bb6-b999-06179762567d"}
2018-07-18T18:14:54 [I|app|93c83] Current user: admin (administrator)
2018-07-18T18:14:54 [I|app|93c83]   Rendered tasks/_list.html.erb (2.0ms)
2018-07-18T18:14:54 [I|app|93c83] Completed 200 OK in 19ms (Views: 8.7ms | ActiveRecord: 1.5ms)
1 Like
3

Interesting, as https://projects.theforeman.org/issues/23335 was expected to fix precisely that.

4

Hi,

Can you provide more info on how you are building the VM. For the storage are you using a storage pod or selecting the individual datastore? Also does it work using an image/template?

1 Like
5

note that trace looks differently now

6

Hi @cintrix84. I’m using a compute profile when building the VM. The compute profile is selecting the individual datastore:

foreman_before_submit
foreman_before_submit1069×646 27.7 KB

7

After clicking the submit button, I notice that the datastore settings are wiped out:

foreman_after_submit
foreman_after_submit1051×637 26.7 KB

Sorry for two posts. Since I’m new, I can only post one image per post.

8

Hey,

I have tried to reproduce this, but failed to do so.
Can you help me by patching your foreman instance a bit. The patch just adds some more logging statements.

yum install patch -y
wget https://gist.github.com/timogoebel/5fb28601d3722c538cc2dddab80d668c/raw/b9c7b781524f659b6ff44a7f2e3fb3e1a2422292/0001-add-vmware-debug-commands.patch
cd /usr/share/foreman
patch -p1 < ~/0001-add-vmware-debug-commands.patch
systemctl restart httpd.service

And then reproduce the error again. Please provide the logs of the failed request. Thanks.

Timo

9

@Marek_Hulan and I researched this a bit more. It looks like the volumes aren’t passed to the controller and therefore not passed to fog-vsphere. We will continue our research tomorrow.

10

@TimoGoebel , would you still like me to patch and reproduce the error with your new findings? If so, I can do that in a little bit.

11

It‘s allright for now. Thanks. :slight_smile:

12

I found the change that caused the regression. Since it’s pretty straightforward to reproduce, I opened redmine issue at Bug #24320: Unable to provision on Vmware, no storage data submitted - Foreman to track the progress. Please continue monitoring there.

1 Like