Error provisioning from template

[msmoritz]

I'm getting an error during an attempt to provision from a template/catalog item with the vSphere provider on Najdorf-1 after using pg_dump/pg_restore method to migrate historic data and automate domains from an existing Ivanchuk installation. I did a reset of the evm:automate domain, so I believe that this isn't coming from those sources.

I don't know if it worked before the pg_restore, since I didn't bother configuring the appliance before that.

Step [CheckProvisioned] Status [Error Creating VM] Message [[NoMethodError]: undefined method ems_ref_obj' for #Snapshot:0x00005583248c9338 Did you mean? ems_ref_was] `

evm.log shows a traceback as follows:

[----] E, [2022-09-22T14:36:22.675715 #8766:93a8] ERROR -- evm: Q-task_id([r3620_miq_provision_4841]) MIQ(ManageIQ::Providers::Vmware::InfraManager::Provision#provision_error) [[NoMethodError]: undefined method `ems_ref_obj' for #<Snapshot:0x00005583248c9338>
Did you mean?  ems_ref_was] encountered during phase [start_clone_task]
[----] E, [2022-09-22T14:36:22.675851 #8766:93a8] ERROR -- evm: Q-task_id([r3620_miq_provision_4841]) /opt/manageiq/manageiq-gemset/gems/activemodel-6.0.5.1/lib/active_model/attribute_methods.rb:432:in `method_missing'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-860d98b3f3d2/app/models/manageiq/providers/vmware/infra_manager/provision/cloning.rb:123:in `block in start_clone'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-860d98b3f3d2/app/models/manageiq/providers/vmware/infra_manager/provision/cloning.rb:120:in `each'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-860d98b3f3d2/app/models/manageiq/providers/vmware/infra_manager/provision/cloning.rb:120:in `start_clone'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-860d98b3f3d2/app/models/manageiq/providers/vmware/infra_manager/provision/state_machine.rb:23:in `start_clone_task'
/var/www/miq/vmdb/app/models/miq_request_task/state_machine.rb:22:in `signal'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-860d98b3f3d2/app/models/manageiq/providers/vmware/infra_manager/provision/state_machine.rb:12:in `determine_placement'
/var/www/miq/vmdb/app/models/miq_request_task/state_machine.rb:22:in `signal'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-860d98b3f3d2/app/models/manageiq/providers/vmware/infra_manager/provision/state_machine.rb:3:in `create_destination'
/var/www/miq/vmdb/app/models/miq_request_task/state_machine.rb:22:in `signal'
/var/www/miq/vmdb/app/models/miq_provision/state_machine.rb:4:in `run_provision'
/var/www/miq/vmdb/app/models/miq_request_task/state_machine.rb:22:in `signal'
/var/www/miq/vmdb/app/models/miq_provision_task.rb:14:in `do_request'
/var/www/miq/vmdb/app/models/miq_request_task.rb:206:in `execute'
/var/www/miq/vmdb/app/models/miq_queue.rb:484:in `block in dispatch_method'
/usr/share/ruby/timeout.rb:95:in `block in timeout'
/usr/share/ruby/timeout.rb:33:in `block in catch'
/usr/share/ruby/timeout.rb:33:in `catch'
/usr/share/ruby/timeout.rb:33:in `catch'
/usr/share/ruby/timeout.rb:110:in `timeout'
/var/www/miq/vmdb/app/models/miq_queue.rb:482:in `dispatch_method'
/var/www/miq/vmdb/app/models/miq_queue.rb:459:in `block in deliver'
/var/www/miq/vmdb/app/models/user.rb:382:in `with_user_group'
/var/www/miq/vmdb/app/models/miq_queue.rb:459:in `deliver'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:98:in `deliver_queue_message'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:124:in `deliver_message'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:146:in `block in do_work'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:142:in `loop'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:142:in `do_work'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:267:in `block in do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:264:in `loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:264:in `do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:114:in `run'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:96:in `start'
lib/workers/bin/run_single_worker.rb:128:in `<main>'

[msmoritz]

I just retried the pg_dump/pg_restore method of migration to a newly deployed Jansa vSphere appliance, and I get the same error message and a very similar backtrace. Looks like the gems are older versions in the backtrace (such as activemodel), but I think that is to be expected.

[agrare]

@msmoritz did you run the database migrations after restoring your database?

[msmoritz]

@agrare yes, I did the rake db:migrate step immediately after the import.

I've been experimenting, and I think I found the issue. All of the Catalog Items/Templates have "Linked Clone" mode enabled and the snapshot select is set to current active snapshot. Creating anew catalog item and to duplicate an imported entry didn't work, but when the linked clone checkbox is removed the provisioning request gets past the cloning stage and proceeds through the provisioning workflow. I haven't tried selecting a specific snapshot. I have been using Linked Clone mode just as a way to make the clone as fast as possible.

The error message including the text snapshot:0x00... got me thinking about that setting to experiment

[agrare]

Oh this looks like a good bug report, all of the vmware subclasses have ems_ref_obj defined as combining the ems_ref_type+ems_ref columns so that we don't have to store serialized classes in yaml in the database but ::Snapshot doesn't have this method.

[msmoritz]

Anything I need to do to help make this a bug report?

[agrare]

Nope I created a bug already from this discussion, #22121

[agrare]

@msmoritz I've pushed a pull request to fix this issue here ManageIQ/manageiq-providers-vmware#826 if you want to test it out

[Fryguy]

Merged ManageIQ/manageiq-providers-vmware#826

[msmoritz]

Confirmed @agrare, provisioning with a VMware linked clone snapshot works with that patch.