Rally test fails after instance takes ~7 minutes to launch

Bug #1925825 reported by Michael Skalka
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Nova Compute Charm
New
Undecided
Unassigned

Bug Description

As seen in this test run: https://solutions.qa.canonical.com/testruns/testRun/8f6a1f4e-b84f-4859-8685-915757cb62fb
Crashdump: https://oil-jenkins.canonical.com/artifacts/8f6a1f4e-b84f-4859-8685-915757cb62fb/generated/generated/openstack/juju-crashdump-openstack-2021-04-23-12.14.35.tar.gz
Bundle: https://oil-jenkins.canonical.com/artifacts/8f6a1f4e-b84f-4859-8685-915757cb62fb/generated/generated/openstack/bundle.yaml

We see the rally test nova.boot_servers time out after 300 seconds due the instance being stuck in the BUILD state. However looking at the node the instance did finally successfully launch after 421 seconds. The nova-compute logs on the unit don't indicate what the issue may have been, nor do the neutron logs from what I can tell.

From the crashdump:
2/baremetal/var/log/nova/nova-compute.log:

...
2021-04-23 10:07:06.369 1404680 INFO nova.compute.claims [req-f9433b87-e406-4a8a-bc5e-af852b62d053 4e603e3bdfb14a41b55b754b4bb04df2 55517d4baf9c42f0a751a2bace3fb9c3 - 3ecf49adfba74958871581ad4411b594 3ecf49adfba74958871581ad4411b594] [instance: 0f05fbb8-db0b-4d4c-87e6-aa753eb88393] Claim successful on node meowth.prodymcprodface.solutionsqa
2021-04-23 10:07:06.692 1404680 INFO nova.virt.osinfo [req-f9433b87-e406-4a8a-bc5e-af852b62d053 4e603e3bdfb14a41b55b754b4bb04df2 55517d4baf9c42f0a751a2bace3fb9c3 - 3ecf49adfba74958871581ad4411b594 3ecf49adfba74958871581ad4411b594] Cannot load Libosinfo: (cannot import name Libosinfo, introspection typelib not found)
2021-04-23 10:07:06.964 1404680 INFO nova.virt.libvirt.driver [req-f9433b87-e406-4a8a-bc5e-af852b62d053 4e603e3bdfb14a41b55b754b4bb04df2 55517d4baf9c42f0a751a2bace3fb9c3 - 3ecf49adfba74958871581ad4411b594 3ecf49adfba74958871581ad4411b594] [instance: 0f05fbb8-db0b-4d4c-87e6-aa753eb88393] Creating image
2021-04-23 10:10:43.721 1404680 WARNING nova.compute.manager [req-28e6d258-502a-4025-b9de-1853d7e5f144 - - - - -] While synchronizing instance power states, found 1 instances in the database and 0 instances on the hypervisor.
2021-04-23 10:14:04.202 1404680 INFO oslo.privsep.daemon [req-f9433b87-e406-4a8a-bc5e-af852b62d053 4e603e3bdfb14a41b55b754b4bb04df2 55517d4baf9c42f0a751a2bace3fb9c3 - 3ecf49adfba74958871581ad4411b594 3ecf49adfba74958871581ad4411b594] Running privsep helper: ['sudo', 'nova-rootwrap', '/etc/nova/rootwrap.conf', 'privsep-helper', '--config-file', '/etc/nova/nova.conf', '--config-file', '/etc/nova/nova-compute.conf', '--privsep_context', 'nova.privsep.sys_admin_pctxt', '--privsep_sock_path', '/tmp/tmp_sl91byn/privsep.sock']
2021-04-23 10:14:05.299 1404680 WARNING oslo.privsep.daemon [-] privsep log: Deprecated: Option "logdir" from group "DEFAULT" is deprecated. Use option "log-dir" from group "DEFAULT".
2021-04-23 10:14:05.469 1404680 INFO oslo.privsep.daemon [req-f9433b87-e406-4a8a-bc5e-af852b62d053 4e603e3bdfb14a41b55b754b4bb04df2 55517d4baf9c42f0a751a2bace3fb9c3 - 3ecf49adfba74958871581ad4411b594 3ecf49adfba74958871581ad4411b594] Spawned new privsep daemon via rootwrap
2021-04-23 10:14:05.348 1649403 INFO oslo.privsep.daemon [-] privsep daemon starting
2021-04-23 10:14:05.354 1649403 INFO oslo.privsep.daemon [-] privsep process running with uid/gid: 0/0
2021-04-23 10:14:05.358 1649403 INFO oslo.privsep.daemon [-] privsep process running with capabilities (eff/prm/inh): CAP_CHOWN|CAP_DAC_OVERRIDE|CAP_DAC_READ_SEARCH|CAP_FOWNER|CAP_NET_ADMIN|CAP_SYS_ADMIN/CAP_CHOWN|CAP_DAC_OVERRIDE|CAP_DAC_READ_SEARCH|CAP_FOWNER|CAP_NET_ADMIN|CAP_SYS_ADMIN/none
2021-04-23 10:14:05.359 1649403 INFO oslo.privsep.daemon [-] privsep daemon running as pid 1649403
2021-04-23 10:14:06.010 1404680 WARNING nova.virt.libvirt.driver [req-f9433b87-e406-4a8a-bc5e-af852b62d053 4e603e3bdfb14a41b55b754b4bb04df2 55517d4baf9c42f0a751a2bace3fb9c3 - 3ecf49adfba74958871581ad4411b594 3ecf49adfba74958871581ad4411b594] USB tablet requested for guests by host configuration. In order to accept this request VNC should be enabled or SPICE and SPICE agent disabled on host.
2021-04-23 10:14:08.145 1404680 INFO nova.compute.manager [-] [instance: 0f05fbb8-db0b-4d4c-87e6-aa753eb88393] VM Resumed (Lifecycle Event)
2021-04-23 10:14:08.153 1404680 INFO nova.virt.libvirt.driver [-] [instance: 0f05fbb8-db0b-4d4c-87e6-aa753eb88393] Instance spawned successfully.
2021-04-23 10:14:08.154 1404680 INFO nova.compute.manager [req-f9433b87-e406-4a8a-bc5e-af852b62d053 4e603e3bdfb14a41b55b754b4bb04df2 55517d4baf9c42f0a751a2bace3fb9c3 - 3ecf49adfba74958871581ad4411b594 3ecf49adfba74958871581ad4411b594] [instance: 0f05fbb8-db0b-4d4c-87e6-aa753eb88393] Took 421.19 seconds to spawn the instance on the hypervisor.

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.