VirtDriverNotReady trace in _sync_power_states periodic from ironic nova-compute

Bug #1793768 reported by Matt Riedemann on 2018-09-21
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Medium
Matt Riedemann
Queens
Medium
Matt Riedemann
Rocky
Medium
Matt Riedemann

Bug Description

On nova-compute startup with the ironic driver, the _sync_power_states periodic can fail and trace with a VirtDriverNotReady error if ironic-api is not yet running. This is normal, and we shouldn't trace for it.

http://logs.openstack.org/27/602127/2/check/ironic-tempest-dsvm-ipa-wholedisk-bios-agent_ipmitool-tinyipa/4238d0f/controller/logs/screen-n-cpu.txt.gz?level=TRACE#_Sep_20_21_52_03_587436

Sep 20 21:52:03.587436 ubuntu-xenial-inap-mtl01-0002177186 nova-compute[14241]: ERROR oslo_service.periodic_task [None req-2339900e-55df-468b-95ff-b904d73d5728 None None] Error during ComputeManager._sync_power_states: VirtDriverNotReady: Virt driver is not ready.
Sep 20 21:52:03.587629 ubuntu-xenial-inap-mtl01-0002177186 nova-compute[14241]: ERROR oslo_service.periodic_task Traceback (most recent call last):
Sep 20 21:52:03.587816 ubuntu-xenial-inap-mtl01-0002177186 nova-compute[14241]: ERROR oslo_service.periodic_task File "/usr/local/lib/python2.7/dist-packages/oslo_service/periodic_task.py", line 220, in run_periodic_tasks
Sep 20 21:52:03.588019 ubuntu-xenial-inap-mtl01-0002177186 nova-compute[14241]: ERROR oslo_service.periodic_task task(self, context)
Sep 20 21:52:03.588182 ubuntu-xenial-inap-mtl01-0002177186 nova-compute[14241]: ERROR oslo_service.periodic_task File "/opt/stack/nova/nova/compute/manager.py", line 7462, in _sync_power_states
Sep 20 21:52:03.588344 ubuntu-xenial-inap-mtl01-0002177186 nova-compute[14241]: ERROR oslo_service.periodic_task num_vm_instances = self.driver.get_num_instances()
Sep 20 21:52:03.588517 ubuntu-xenial-inap-mtl01-0002177186 nova-compute[14241]: ERROR oslo_service.periodic_task File "/opt/stack/nova/nova/virt/driver.py", line 183, in get_num_instances
Sep 20 21:52:03.588714 ubuntu-xenial-inap-mtl01-0002177186 nova-compute[14241]: ERROR oslo_service.periodic_task return len(self.list_instances())
Sep 20 21:52:03.588885 ubuntu-xenial-inap-mtl01-0002177186 nova-compute[14241]: ERROR oslo_service.periodic_task File "/opt/stack/nova/nova/virt/ironic/driver.py", line 624, in list_instances
Sep 20 21:52:03.589071 ubuntu-xenial-inap-mtl01-0002177186 nova-compute[14241]: ERROR oslo_service.periodic_task fields=['instance_uuid'], limit=0)
Sep 20 21:52:03.589263 ubuntu-xenial-inap-mtl01-0002177186 nova-compute[14241]: ERROR oslo_service.periodic_task File "/opt/stack/nova/nova/virt/ironic/driver.py", line 611, in _get_node_list
Sep 20 21:52:03.589447 ubuntu-xenial-inap-mtl01-0002177186 nova-compute[14241]: ERROR oslo_service.periodic_task raise exception.VirtDriverNotReady()
Sep 20 21:52:03.589602 ubuntu-xenial-inap-mtl01-0002177186 nova-compute[14241]: ERROR oslo_service.periodic_task VirtDriverNotReady: Virt driver is not ready.
Sep 20 21:52:03.589770 ubuntu-xenial-inap-mtl01-0002177186 nova-compute[14241]: ERROR oslo_service.periodic_task

Matt Riedemann (mriedem) on 2018-09-21
Changed in nova:
assignee: nobody → Matt Riedemann (mriedem)

Fix proposed to branch: master
Review: https://review.openstack.org/604376

Changed in nova:
status: Triaged → In Progress

Reviewed: https://review.openstack.org/604376
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=6eb32bc40340fed631b9fce1245326e0ebc1c540
Submitter: Zuul
Branch: master

commit 6eb32bc40340fed631b9fce1245326e0ebc1c540
Author: Matt Riedemann <email address hidden>
Date: Fri Sep 21 10:44:51 2018 -0400

    Ignore VirtDriverNotReady in _sync_power_states periodic task

    Change Ib0ec1012b74e9a9e74c8879f3feed5f9332b711f introduced
    a new VirtDriverNotReady exception which the ironic driver raises
    when asked to retrieve a list of nodes and ironic-api is not
    available, like if nova-compute is started before ironic-api.
    This is normal and meant to be self-healing, but we can get it
    in other periodic tasks besides update_available_resource which
    leads to ugly exception traces on startup in the logs. This adds
    handling for the exception in the _sync_power_states periodic
    task.

    Change-Id: Iaf29b9e7a92705ac8a2e7ef338b92f7f1203506d
    Closes-Bug: #1793768

Changed in nova:
status: In Progress → Fix Released

Reviewed: https://review.openstack.org/605533
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=220796807396ad6aa8cc8f1fc9ff905253681896
Submitter: Zuul
Branch: stable/rocky

commit 220796807396ad6aa8cc8f1fc9ff905253681896
Author: Matt Riedemann <email address hidden>
Date: Fri Sep 21 10:44:51 2018 -0400

    Ignore VirtDriverNotReady in _sync_power_states periodic task

    Change Ib0ec1012b74e9a9e74c8879f3feed5f9332b711f introduced
    a new VirtDriverNotReady exception which the ironic driver raises
    when asked to retrieve a list of nodes and ironic-api is not
    available, like if nova-compute is started before ironic-api.
    This is normal and meant to be self-healing, but we can get it
    in other periodic tasks besides update_available_resource which
    leads to ugly exception traces on startup in the logs. This adds
    handling for the exception in the _sync_power_states periodic
    task.

    Change-Id: Iaf29b9e7a92705ac8a2e7ef338b92f7f1203506d
    Closes-Bug: #1793768
    (cherry picked from commit 6eb32bc40340fed631b9fce1245326e0ebc1c540)

This issue was fixed in the openstack/nova 18.0.2 release.

Reviewed: https://review.openstack.org/607730
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=0163783382c4825a6f18e346d17b9e67e98ed1a2
Submitter: Zuul
Branch: stable/queens

commit 0163783382c4825a6f18e346d17b9e67e98ed1a2
Author: Matt Riedemann <email address hidden>
Date: Fri Sep 21 10:44:51 2018 -0400

    Ignore VirtDriverNotReady in _sync_power_states periodic task

    Change Ib0ec1012b74e9a9e74c8879f3feed5f9332b711f introduced
    a new VirtDriverNotReady exception which the ironic driver raises
    when asked to retrieve a list of nodes and ironic-api is not
    available, like if nova-compute is started before ironic-api.
    This is normal and meant to be self-healing, but we can get it
    in other periodic tasks besides update_available_resource which
    leads to ugly exception traces on startup in the logs. This adds
    handling for the exception in the _sync_power_states periodic
    task.

    Change-Id: Iaf29b9e7a92705ac8a2e7ef338b92f7f1203506d
    Closes-Bug: #1793768
    (cherry picked from commit 6eb32bc40340fed631b9fce1245326e0ebc1c540)
    (cherry picked from commit 220796807396ad6aa8cc8f1fc9ff905253681896)

This issue was fixed in the openstack/nova 17.0.9 release.

This issue was fixed in the openstack/nova 19.0.0.0rc1 release candidate.

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

Other bug subscribers