[Bug 1829828] Re: instance became error after a set-password failure

Brin Zhang 1829828 at bugs.launchpad.net
Fri May 24 10:08:13 UTC 2019


** Package changed: nova (Ubuntu) => ubuntu

** Package changed: ubuntu => nova

-- 
You received this bug notification because you are a member of Ubuntu
OpenStack, which is subscribed to nova in Ubuntu.
https://bugs.launchpad.net/bugs/1829828

Title:
  instance became error after a set-password failure

Status in OpenStack Compute (nova):
  Confirmed

Bug description:
  Description
  ===========
  Hi guys, i ran into a problem in our OpenStack Ocata/Rocky clusters:
  When i was trying to use `set-password` subcommand of nova CLI to reset
  root password for my VM, it failed and my VM became error.

  I searched launchpad for similar issues, but got nothing. I believe the
  problem may also exist in latest OpenStack distro.

  Steps to reproduce
  ==================
  * Upload any image(without QGA inside), e.g: cirros
  * Update the image with property: hw_qemu_guest_agent=yes
    $ glance image-update --property hw_qemu_guest_agent=yes <UUID of cirros>
  * Boot new instance (e.g: QGA) with image cirros and ensure instance is active/running.
  * Use cli `nova set-password <UUID of QGA>` to reset password for the instance.

  Expected result
  ===============
  Error Messages like 'QGA not running' occur.
  Instance becomes active/ruuning again from task_state `updating_password`.

  Actual result
  =============
  CLI returns with: Failed to set admin password on XXXXXX became error setting admin password
  (HTTP 409)(Request-ID: req-XXXXX)
  And instance became error.

  Environment
  ===========
  1. version: OpenStack Ocata/Rocky + centOS7
  2. hypervisor: Libvirt + KVM
  3. storage: Ceph
  4. networking Neutron with OpenVSwitch

  Logs & Configs
  ==============

  #### Nova CLI error #####
  [root at node159 ~]# nova set-password f355e4d0-574c-4792-bbbd-04ad03ce6066
  New password: 
  Again: 
  ERROR (Conflict): Failed to set admin password on f355e4d0-574c-4792-bbbd-04ad03ce6066 because error setting 
  admin password (HTTP 409) (Request-ID: req-34715791-f42a-4235-98d5-f69680440fc8)

  ##### Grep nova-compute errors by Instance UUID #############
  23698  2019-05-21 14:53:50.355 7 INFO nova.compute.manager [req-6ec684e7-ee6e-47a4-8f75-53cccc235d86 9fef2099c3254226a96e48311d124131 380f701f5575430195526229dc143a1f - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] Enter manager build_and_run_instance
  23699  2019-05-21 14:53:50.521 7 INFO nova.compute.manager [req-6ec684e7-ee6e-47a4-8f75-53cccc235d86 9fef2099c3254226a96e48311d124131 380f701f5575430195526229dc143a1f - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] Enter manager _build_and_run_instance
  23700  2019-05-21 14:53:50.546 7 INFO nova.compute.claims [req-6ec684e7-ee6e-47a4-8f75-53cccc235d86 9fef2099c3254226a96e48311d124131 380f701f5575430195526229dc143a1f - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] Attempting claim: memory 2048 MB, disk 1 GB, vcpus 2 CPU
  23701  2019-05-21 14:53:50.547 7 INFO nova.compute.claims [req-6ec684e7-ee6e-47a4-8f75-53cccc235d86 9fef2099c3254226a96e48311d124131 380f701f5575430195526229dc143a1f - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] Total memory: 65417 MB, used: 37568.00 MB
  23702  2019-05-21 14:53:50.548 7 INFO nova.compute.claims [req-6ec684e7-ee6e-47a4-8f75-53cccc235d86 9fef2099c3254226a96e48311d124131 380f701f5575430195526229dc143a1f - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] memory limit: 52333.60 MB, free: 14765.60 MB
  23703  2019-05-21 14:53:50.548 7 INFO nova.compute.claims [req-6ec684e7-ee6e-47a4-8f75-53cccc235d86 9fef2099c3254226a96e48311d124131 380f701f5575430195526229dc143a1f - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] Total disk: 3719 GB, used: 285.00 GB
  23704  2019-05-21 14:53:50.549 7 INFO nova.compute.claims [req-6ec684e7-ee6e-47a4-8f75-53cccc235d86 9fef2099c3254226a96e48311d124131 380f701f5575430195526229dc143a1f - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] disk limit: 3719.00 GB, free: 3434.00 GB
  23705  2019-05-21 14:53:50.550 7 INFO nova.compute.claims [req-6ec684e7-ee6e-47a4-8f75-53cccc235d86 9fef2099c3254226a96e48311d124131 380f701f5575430195526229dc143a1f - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] Total vcpu: 16 VCPU, used: 41.00 VCPU
  23706  2019-05-21 14:53:50.550 7 INFO nova.compute.claims [req-6ec684e7-ee6e-47a4-8f75-53cccc235d86 9fef2099c3254226a96e48311d124131 380f701f5575430195526229dc143a1f - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] vcpu limit not specified, defaulting to unlimited
  23707  2019-05-21 14:53:50.552 7 INFO nova.compute.claims [req-6ec684e7-ee6e-47a4-8f75-53cccc235d86 9fef2099c3254226a96e48311d124131 380f701f5575430195526229dc143a1f - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] Claim successful
  23708  2019-05-21 14:53:50.762 7 INFO nova.scheduler.client.report [req-6ec684e7-ee6e-47a4-8f75-53cccc235d86 9fef2099c3254226a96e48311d124131 380f701f5575430195526229dc143a1f - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] Submitted allocation for instance
  23709  2019-05-21 14:53:50.913 7 INFO nova.compute.manager [req-6ec684e7-ee6e-47a4-8f75-53cccc235d86 9fef2099c3254226a96e48311d124131 380f701f5575430195526229dc143a1f - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] Enter manager _build_resources
  23713  2019-05-21 14:53:51.430 7 INFO nova.virt.libvirt.driver [req-6ec684e7-ee6e-47a4-8f75-53cccc235d86 9fef2099c3254226a96e48311d124131 380f701f5575430195526229dc143a1f - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] Creating image
  23727  2019-05-21 14:54:01.087 7 INFO nova.compute.manager [req-a476ad61-30e0-4b25-98b2-e25a5028f4e2 - - - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] VM Started (Lifecycle Event)
  23728  2019-05-21 14:54:01.137 7 INFO nova.compute.manager [req-a476ad61-30e0-4b25-98b2-e25a5028f4e2 - - - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] VM Paused (Lifecycle Event)
  23729  2019-05-21 14:54:01.232 7 INFO nova.compute.manager [req-a476ad61-30e0-4b25-98b2-e25a5028f4e2 - - - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] During sync_power_state the instance has a pending task (spawning). Skip.
  23730  2019-05-21 14:54:03.872 7 INFO nova.compute.manager [req-a476ad61-30e0-4b25-98b2-e25a5028f4e2 - - - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] VM Resumed (Lifecycle Event)
  23731  2019-05-21 14:54:03.877 7 INFO nova.virt.driver [-] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] Instance spawned successfully.
  23732  2019-05-21 14:54:03.878 7 INFO nova.compute.manager [req-6ec684e7-ee6e-47a4-8f75-53cccc235d86 9fef2099c3254226a96e48311d124131 380f701f5575430195526229dc143a1f - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] Took 12.45 seconds to spawn the instance on the hypervisor.
  23733  2019-05-21 14:54:03.971 7 INFO nova.compute.manager [req-a476ad61-30e0-4b25-98b2-e25a5028f4e2 - - - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] During sync_power_state the instance has a pending task (spawning). Skip.
  23734  2019-05-21 14:54:03.972 7 INFO nova.compute.manager [req-a476ad61-30e0-4b25-98b2-e25a5028f4e2 - - - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] VM Resumed (Lifecycle Event)
  23735  2019-05-21 14:54:04.029 7 INFO nova.compute.manager [req-6ec684e7-ee6e-47a4-8f75-53cccc235d86 9fef2099c3254226a96e48311d124131 380f701f5575430195526229dc143a1f - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] Took 13.54 seconds to build instance.
  23736  2019-05-21 14:54:49.985 7 ERROR nova.compute.manager [req-34715791-f42a-4235-98d5-f69680440fc8 9fef2099c3254226a96e48311d124131 380f701f5575430195526229dc143a1f - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] set_admin_password failed
  23737  2019-05-21 14:54:49.985 7 ERROR nova.compute.manager [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] Traceback (most recent call last):
  23738  2019-05-21 14:54:49.985 7 ERROR nova.compute.manager [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066]   File "/var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/manager.py", line 3266, in set_admin_password
  23739  2019-05-21 14:54:49.985 7 ERROR nova.compute.manager [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066]     self.driver.set_admin_password(instance, new_pass)
  23740  2019-05-21 14:54:49.985 7 ERROR nova.compute.manager [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066]   File "/var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 1719, in set_admin_password
  23741  2019-05-21 14:54:49.985 7 ERROR nova.compute.manager [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066]     raise exception.InternalError(msg)
  23742  2019-05-21 14:54:49.985 7 ERROR nova.compute.manager [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] InternalError: Error from libvirt while set password for username "root": [Error Code 86] Guest agent is not responding: QEMU guest agent is not connected
  23743  2019-05-21 14:54:49.985 7 ERROR nova.compute.manager [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] 
  23744  2019-05-21 14:54:50.493 7 INFO nova.compute.manager [req-34715791-f42a-4235-98d5-f69680440fc8 9fef2099c3254226a96e48311d124131 380f701f5575430195526229dc143a1f - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] Successfully reverted task state from updating_password on failure for instance.
  23781  2019-05-21 14:54:50.498 7 ERROR oslo_messaging.rpc.server InstancePasswordSetFailed: Failed to set admin password on f355e4d0-574c-4792-bbbd-04ad03ce6066 because error setting admin password

  
  ###### Grep nova-compute errors by requrest UUID ####
  23736  2019-05-21 14:54:49.985 7 ERROR nova.compute.manager [req-34715791-f42a-4235-98d5-f69680440fc8 9fef2099c3254226a96e48311d124131 380f701f5575430195526229dc143a1f - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] set_admin_password failed
  23744  2019-05-21 14:54:50.493 7 INFO nova.compute.manager [req-34715791-f42a-4235-98d5-f69680440fc8 9fef2099c3254226a96e48311d124131 380f701f5575430195526229dc143a1f - - -] [instance: f355e4d0-574c-4792-bbbd-04ad03ce6066] Successfully reverted task state from updating_password on failure for instance.
  23745  2019-05-21 14:54:50.498 7 ERROR oslo_messaging.rpc.server [req-34715791-f42a-4235-98d5-f69680440fc8 9fef2099c3254226a96e48311d124131 380f701f5575430195526229dc143a1f - - -] Exception during message handling

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1829828/+subscriptions



More information about the Ubuntu-openstack-bugs mailing list