Comment 1 for bug 1243488

Revision history for this message
Davanum Srinivas (DIMS) (dims-v) wrote :

Taking this example:
logs.openstack.org/92/54092/1/gate/gate-tempest-devstack-vm-neutron-pg-isolated/d7ae6d4/logs/screen-n-cpu.txt.gz

we see the following problem:
2013-10-30 22:01:46.059 DEBUG nova.openstack.common.processutils [req-624df130-b4cd-4e2e-bd9a-cfcbe0b502a8 ServerActionsTestXML-tempest-1320742179-user ServerActionsTestXML-tempest-1320742179-tenant] Running cmd (subprocess): sudo nova-rootwrap /etc/nova/rootwrap.conf brctl delif qbrf4e6ce85-9f qvbf4e6ce85-9f execute /opt/stack/new/nova/nova/openstack/common/processutils.py:147
2013-10-30 22:01:46.122 DEBUG nova.openstack.common.processutils [req-624df130-b4cd-4e2e-bd9a-cfcbe0b502a8 ServerActionsTestXML-tempest-1320742179-user ServerActionsTestXML-tempest-1320742179-tenant] Result was 1 execute /opt/stack/new/nova/nova/openstack/common/processutils.py:172
2013-10-30 22:01:46.123 ERROR nova.virt.libvirt.vif [req-624df130-b4cd-4e2e-bd9a-cfcbe0b502a8 ServerActionsTestXML-tempest-1320742179-user ServerActionsTestXML-tempest-1320742179-tenant] [instance: d39887ee-f76f-4682-b51a-06dcd3a6ea4f] Failed while unplugging vif
2013-10-30 22:01:46.123 2087 TRACE nova.virt.libvirt.vif [instance: d39887ee-f76f-4682-b51a-06dcd3a6ea4f] Traceback (most recent call last):
2013-10-30 22:01:46.123 2087 TRACE nova.virt.libvirt.vif [instance: d39887ee-f76f-4682-b51a-06dcd3a6ea4f] File "/opt/stack/new/nova/nova/virt/libvirt/vif.py", line 636, in unplug_ovs_hybrid
2013-10-30 22:01:46.123 2087 TRACE nova.virt.libvirt.vif [instance: d39887ee-f76f-4682-b51a-06dcd3a6ea4f] utils.execute('brctl', 'delif', br_name, v1_name, run_as_root=True)
2013-10-30 22:01:46.123 2087 TRACE nova.virt.libvirt.vif [instance: d39887ee-f76f-4682-b51a-06dcd3a6ea4f] File "/opt/stack/new/nova/nova/utils.py", line 174, in execute
2013-10-30 22:01:46.123 2087 TRACE nova.virt.libvirt.vif [instance: d39887ee-f76f-4682-b51a-06dcd3a6ea4f] return processutils.execute(*cmd, **kwargs)
2013-10-30 22:01:46.123 2087 TRACE nova.virt.libvirt.vif [instance: d39887ee-f76f-4682-b51a-06dcd3a6ea4f] File "/opt/stack/new/nova/nova/openstack/common/processutils.py", line 178, in execute
2013-10-30 22:01:46.123 2087 TRACE nova.virt.libvirt.vif [instance: d39887ee-f76f-4682-b51a-06dcd3a6ea4f] cmd=' '.join(cmd))
2013-10-30 22:01:46.123 2087 TRACE nova.virt.libvirt.vif [instance: d39887ee-f76f-4682-b51a-06dcd3a6ea4f] ProcessExecutionError: Unexpected error while running command.
2013-10-30 22:01:46.123 2087 TRACE nova.virt.libvirt.vif [instance: d39887ee-f76f-4682-b51a-06dcd3a6ea4f] Command: sudo nova-rootwrap /etc/nova/rootwrap.conf brctl delif qbrf4e6ce85-9f qvbf4e6ce85-9f
2013-10-30 22:01:46.123 2087 TRACE nova.virt.libvirt.vif [instance: d39887ee-f76f-4682-b51a-06dcd3a6ea4f] Exit code: 1
2013-10-30 22:01:46.123 2087 TRACE nova.virt.libvirt.vif [instance: d39887ee-f76f-4682-b51a-06dcd3a6ea4f] Stdout: ''
2013-10-30 22:01:46.123 2087 TRACE nova.virt.libvirt.vif [instance: d39887ee-f76f-4682-b51a-06dcd3a6ea4f] Stderr: 'interface qvbf4e6ce85-9f does not exist!\n'
2013-10-30 22:01:46.123 2087 TRACE nova.virt.libvirt.vif [instance: d39887ee-f76f-4682-b51a-06dcd3a6ea4f]

If you grep for req-624df130-b4cd-4e2e-bd9a-cfcbe0b502a8 you can see that it is a terminate_instance

If you see who did a brctl delif just before this failed, you find:
dims@dims-laptop:~/junk$ grep "brctl delif qbrf4e6ce85-9f" screen-n-cpu.txt.gz
2013-10-30 21:48:26.574 DEBUG nova.openstack.common.processutils [req-72ee662b-b1ed-47b6-b4aa-b880530629e9 ServerActionsTestXML-tempest-1320742179-user ServerActionsTestXML-tempest-1320742179-tenant] Running cmd (subprocess): sudo nova-rootwrap /etc/nova/rootwrap.conf brctl delif qbrf4e6ce85-9f qvbf4e6ce85-9f execute /opt/stack/new/nova/nova/openstack/common/processutils.py:147
2013-10-30 22:01:46.059 DEBUG nova.openstack.common.processutils [req-624df130-b4cd-4e2e-bd9a-cfcbe0b502a8 ServerActionsTestXML-tempest-1320742179-user ServerActionsTestXML-tempest-1320742179-tenant] Running cmd (subprocess): sudo nova-rootwrap /etc/nova/rootwrap.conf brctl delif qbrf4e6ce85-9f qvbf4e6ce85-9f execute /opt/stack/new/nova/nova/openstack/common/processutils.py:147
2013-10-30 22:01:46.123 2087 TRACE nova.virt.libvirt.vif [instance: d39887ee-f76f-4682-b51a-06dcd3a6ea4f] Command: sudo nova-rootwrap /etc/nova/rootwrap.conf brctl delif qbrf4e6ce85-9f qvbf4e6ce85-9f

so looking for req-72ee662b-b1ed-47b6-b4aa-b880530629e9 you will see that it is a rebuild_instance

SO, a rebuild_instance is going on which has just issued delif and we get a terminate_instance which also tries to cleanup the same thing and ends up with the trace shown in the bug report