Unable to clone VM - Server Error "undefined method `[]=' for nil:NilClass [miq_request/prov_field_changed"

[mschmitt-nasuni]

Description of issue

Steps to reproduce

1. go to Compute > Infrastructure > Virtual Machines
2. select any VM
3. go to Lifecycle > Clone selected item
4. fill in Request information, or not, doesn't matter
5. click over to any other tab in the Clone Virtual Machine dialog
6. get above error message, unable to continue.

Environment

• Version: quinteros-1
• Environment:
  • VMWare appliance, Build: 20240402225756_f6add08
  • Infrastructure provider: VMWare vCenter

[kbrock]

I think this is related to ManageIQ/manageiq-ui-classic#9078

Are you able to provide us with the backtrace from the logs?

[mschmitt-nasuni]

Sure, here you go -- I pulled this with journalctl --no-pager --since "30 seconds ago" after hitting the same error.

Let me know if there's any other info I can provide.

Aug 21 13:51:33 itmiq002.DOMAIN.com audit[10036]:  INFO -- audit: <AuditSuccess> Username [admin], Role [EvmRole-super_administrator], Session [e5c60310877279310a50b64838d69aa4], Request [651f3137-76d4-4f53-b3b7-fee6fae231af], Method [POST], Path [/miq_request/prov_field_changed?tab_id=requester&edit_mode=true] Features checked: miq_request_edit
Aug 21 13:51:33 itmiq002.DOMAIN.com evm[10036]:  INFO -- evm: MIQ(ManageIQ::Providers::Vmware::InfraManager::ProvisionWorkflow#allowed_hosts_obj) allowed_hosts_obj returned [10] objects in [0.002211237] seconds
Aug 21 13:51:33 itmiq002.DOMAIN.com evm[10036]:  INFO -- evm: MIQ(ManageIQ::Providers::Vmware::InfraManager::ProvisionWorkflow#allowed_hosts_obj) allowed_hosts_obj returned [10] objects in [0.001483559] seconds
Aug 21 13:51:33 itmiq002.DOMAIN.com evm[10036]:  INFO -- evm: MIQ(ManageIQ::Providers::Vmware::InfraManager::ProvisionWorkflow#allowed_hosts_obj) allowed_hosts_obj returned [10] objects in [0.00141086] seconds
Aug 21 13:51:33 itmiq002.DOMAIN.com evm[10036]:  INFO -- evm: MIQ(ManageIQ::Providers::Vmware::InfraManager::ProvisionWorkflow#allowed_storages) allowed_storages returned [19] objects in [0.033589832] seconds
Aug 21 13:51:33 itmiq002.DOMAIN.com evm[10036]:  INFO -- evm: MIQ(ManageIQ::Providers::Vmware::InfraManager::ProvisionWorkflow#allowed_hosts_obj) allowed_hosts_obj returned [10] objects in [0.001954117] seconds
Aug 21 13:51:33 itmiq002.DOMAIN.com evm[10036]:  INFO -- evm: MIQ(ManageIQ::Providers::Vmware::InfraManager::ProvisionWorkflow#allowed_hosts_obj) allowed_hosts_obj returned [10] objects in [0.001703082] seconds
Aug 21 13:51:33 itmiq002.DOMAIN.com evm[10036]:  INFO -- evm: MIQ(ManageIQ::Providers::Vmware::InfraManager::ProvisionWorkflow#refresh_field_values) provision refresh completed in [0.056162075] seconds
Aug 21 13:51:33 itmiq002.DOMAIN.com evm[10036]:  INFO -- evm: MIQ(ManageIQ::Providers::Vmware::InfraManager::ProvisionWorkflow#allowed_hosts_obj) allowed_hosts_obj returned [10] objects in [0.001818212] seconds
Aug 21 13:51:33 itmiq002.DOMAIN.com evm[10036]:  INFO -- evm: MIQ(ManageIQ::Providers::Vmware::InfraManager::ProvisionWorkflow#allowed_hosts_obj) allowed_hosts_obj returned [10] objects in [0.001567089] seconds
Aug 21 13:51:33 itmiq002.DOMAIN.com evm[10036]:  INFO -- evm: MIQ(ManageIQ::Providers::Vmware::InfraManager::ProvisionWorkflow#allowed_hosts_obj) allowed_hosts_obj returned [10] objects in [0.001502577] seconds
Aug 21 13:51:33 itmiq002.DOMAIN.com evm[10036]:  INFO -- evm: MIQ(ManageIQ::Providers::Vmware::InfraManager::ProvisionWorkflow#allowed_storages) allowed_storages returned [19] objects in [0.02673851] seconds
Aug 21 13:51:33 itmiq002.DOMAIN.com evm[10036]:  INFO -- evm: MIQ(ManageIQ::Providers::Vmware::InfraManager::ProvisionWorkflow#allowed_hosts_obj) allowed_hosts_obj returned [10] objects in [0.001907279] seconds
Aug 21 13:51:33 itmiq002.DOMAIN.com evm[10036]:  INFO -- evm: MIQ(ManageIQ::Providers::Vmware::InfraManager::ProvisionWorkflow#allowed_hosts_obj) allowed_hosts_obj returned [10] objects in [0.001580245] seconds
Aug 21 13:51:33 itmiq002.DOMAIN.com evm[10036]:  INFO -- evm: MIQ(ManageIQ::Providers::Vmware::InfraManager::ProvisionWorkflow#allowed_hosts_obj) allowed_hosts_obj returned [10] objects in [0.001552497] seconds
Aug 21 13:51:33 itmiq002.DOMAIN.com production[10036]: FATAL -- production: Error caught: [NoMethodError] undefined method `[]=' for nil:NilClass
                                                              /opt/manageiq/manageiq-gemset/bundler/gems/manageiq-ui-classic-033da54a2d1f/app/controllers/application_controller/miq_request_methods.rb:42:in `prov_field_changed'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/abstract_controller/base.rb:228:in `process_action'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_controller/metal/rendering.rb:30:in `process_action'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/abstract_controller/callbacks.rb:42:in `block in process_action'
                                                              /opt/manageiq/manageiq-gemset/gems/activesupport-6.1.7.6/lib/active_support/callbacks.rb:106:in `run_callbacks'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/abstract_controller/callbacks.rb:41:in `process_action'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_controller/metal/rescue.rb:22:in `process_action'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_controller/metal/instrumentation.rb:34:in `block in process_action'
                                                              /opt/manageiq/manageiq-gemset/gems/activesupport-6.1.7.6/lib/active_support/notifications.rb:203:in `block in instrument'
                                                              /opt/manageiq/manageiq-gemset/gems/activesupport-6.1.7.6/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
                                                              /opt/manageiq/manageiq-gemset/gems/activesupport-6.1.7.6/lib/active_support/notifications.rb:203:in `instrument'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_controller/metal/instrumentation.rb:33:in `process_action'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_controller/metal/params_wrapper.rb:249:in `process_action'
                                                              /opt/manageiq/manageiq-gemset/gems/activerecord-6.1.7.6/lib/active_record/railties/controller_runtime.rb:27:in `process_action'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/abstract_controller/base.rb:165:in `process'
                                                              /opt/manageiq/manageiq-gemset/gems/actionview-6.1.7.6/lib/action_view/rendering.rb:39:in `process'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_controller/metal.rb:190:in `dispatch'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_controller/metal.rb:254:in `dispatch'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_dispatch/routing/route_set.rb:50:in `dispatch'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_dispatch/routing/route_set.rb:33:in `serve'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_dispatch/journey/router.rb:50:in `block in serve'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_dispatch/journey/router.rb:32:in `each'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_dispatch/journey/router.rb:32:in `serve'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_dispatch/routing/route_set.rb:842:in `call'
                                                              /var/www/miq/vmdb/lib/request_started_on_middleware.rb:12:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/rack-2.2.9/lib/rack/tempfile_reaper.rb:15:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/rack-2.2.9/lib/rack/etag.rb:27:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/rack-2.2.9/lib/rack/conditional_get.rb:40:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/rack-2.2.9/lib/rack/head.rb:12:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_dispatch/http/permissions_policy.rb:22:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_dispatch/http/content_security_policy.rb:19:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/rack-2.2.9/lib/rack/session/abstract/id.rb:266:in `context'
                                                              /opt/manageiq/manageiq-gemset/gems/rack-2.2.9/lib/rack/session/abstract/id.rb:260:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/cookies.rb:697:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/callbacks.rb:27:in `block in call'
                                                              /opt/manageiq/manageiq-gemset/gems/activesupport-6.1.7.6/lib/active_support/callbacks.rb:98:in `run_callbacks'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/actionable_exceptions.rb:18:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/debug_exceptions.rb:29:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/railties-6.1.7.6/lib/rails/rack/logger.rb:37:in `call_app'
                                                              /opt/manageiq/manageiq-gemset/gems/railties-6.1.7.6/lib/rails/rack/logger.rb:28:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/request_id.rb:26:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/rack-2.2.9/lib/rack/method_override.rb:24:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/rack-2.2.9/lib/rack/runtime.rb:22:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/activesupport-6.1.7.6/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/executor.rb:14:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/rack-2.2.9/lib/rack/sendfile.rb:110:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/host_authorization.rb:142:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/secure_headers-3.9.0/lib/secure_headers/middleware.rb:12:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/railties-6.1.7.6/lib/rails/engine.rb:539:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/puma-6.4.2/lib/puma/configuration.rb:272:in `call'
                                                              /opt/manageiq/manageiq-gemset/gems/puma-6.4.2/lib/puma/request.rb:100:in `block in handle_request'
                                                              /opt/manageiq/manageiq-gemset/gems/puma-6.4.2/lib/puma/thread_pool.rb:378:in `with_force_shutdown'
                                                              /opt/manageiq/manageiq-gemset/gems/puma-6.4.2/lib/puma/request.rb:99:in `handle_request'
                                                              /opt/manageiq/manageiq-gemset/gems/puma-6.4.2/lib/puma/server.rb:464:in `process_client'
                                                              /opt/manageiq/manageiq-gemset/gems/puma-6.4.2/lib/puma/server.rb:245:in `block in run'
                                                              /opt/manageiq/manageiq-gemset/gems/puma-6.4.2/lib/puma/thread_pool.rb:155:in `block in spawn_thread'
Aug 21 13:51:33 itmiq002.DOMAIN.com production[10036]:  INFO -- production: Completed 200 OK in 125ms (Views: 0.4ms | ActiveRecord: 10.0ms | Allocations: 80443)
Aug 21 13:51:36 itmiq002.DOMAIN.com evm[10025]:  INFO -- evm: MIQ(MiqQueue.put) Message id: [571543], Zone: [default], Role: [], Server: [74f07c64-2c0e-4f8a-ae77-7bb92815118c], MiqTask id: [], Handler id: [], Ident: [miq_server], Target id: [], Instance id: [], Task id: [], Command: [MiqServer.status_update], Timeout: [600], Priority: [20], State: [ready], Deliver On: [], Data: [], Args: []
Aug 21 13:51:36 itmiq002.DOMAIN.com evm[10025]:  INFO -- evm: MIQ(MiqQueue.put) Message id: [571544], Zone: [default], Role: [], Server: [], MiqTask id: [], Handler id: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [Job.check_jobs_for_timeout], Timeout: [600], Priority: [50], State: [ready], Deliver On: [], Data: [], Args: []
Aug 21 13:51:36 itmiq002.DOMAIN.com evm[10025]:  INFO -- evm: MIQ(MiqQueue.put) Message id: [571545], Zone: [], Role: [], Server: [], MiqTask id: [], Handler id: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqQueue.check_for_timeout], Timeout: [600], Priority: [50], State: [ready], Deliver On: [], Data: [], Args: []
Aug 21 13:51:37 itmiq002.DOMAIN.com evm[9949]:  INFO -- evm: MIQ(MiqQueue.get) Message id: [571543], Zone: [default], Role: [], Server: [74f07c64-2c0e-4f8a-ae77-7bb92815118c], MiqTask id: [], Handler id: [MiqServer 1], Ident: [miq_server], Target id: [], Instance id: [], Task id: [], Command: [MiqServer.status_update], Timeout: [600], Priority: [20], State: [dequeue], Deliver On: [], Data: [], Args: [], Dequeued in: [1.064420654] seconds
Aug 21 13:51:37 itmiq002.DOMAIN.com evm[9949]:  INFO -- evm: MIQ(MiqQueue#deliver) Message id: [571543], Delivering...
Aug 21 13:51:37 itmiq002.DOMAIN.com evm[9949]:  INFO -- evm: MIQ(MiqQueue#delivered) Message id: [571543], State: [ok], Delivered in [0.026267258] seconds

[miq-bot]

This issue has been automatically marked as stale because it has not been updated for at least 3 months.

If you can still reproduce this issue on the current release or on master, please reply with all of the information you have about it in order to keep the issue open.