yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1819374] [NEW] test_interface_detach_with_port_with_bandwidth_request intermittently fails

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Matt Riedemann <mriedem.os@xxxxxxxxx>
Date: Sun, 10 Mar 2019 20:15:59 -0000
Reply-to: Bug 1819374 <1819374@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

Seen here:

http://logs.openstack.org/21/641021/1/gate/nova-tox-functional-
py35/b057262/job-output.txt.gz#_2019-03-09_17_01_22_053827

2019-03-09 17:01:22.053827 | ubuntu-xenial | {1} nova.tests.functional.test_servers.PortResourceRequestBasedSchedulingTest.test_interface_detach_with_port_with_bandwidth_request [3.961215s] ... FAILED
2019-03-09 17:01:22.053957 | ubuntu-xenial |
2019-03-09 17:01:22.053999 | ubuntu-xenial | Captured pythonlogging:
2019-03-09 17:01:22.054050 | ubuntu-xenial | ~~~~~~~~~~~~~~~~~~~~~~~
2019-03-09 17:01:22.054142 | ubuntu-xenial |     b'2019-03-09 17:01:18,266 WARNING [placement.db_api] TransactionFactory already started, not reconfiguring.'
2019-03-09 17:01:22.054231 | ubuntu-xenial |     b'2019-03-09 17:01:19,023 INFO [nova.service] Starting conductor node (version 18.1.0)'
2019-03-09 17:01:22.054328 | ubuntu-xenial |     b'2019-03-09 17:01:19,046 INFO [nova.service] Starting scheduler node (version 18.1.0)'
2019-03-09 17:01:22.054415 | ubuntu-xenial |     b"2019-03-09 17:01:19,073 INFO [nova.virt.driver] Loading compute driver 'fake.FakeDriverWithPciResources'"
2019-03-09 17:01:22.054558 | ubuntu-xenial |     b'2019-03-09 17:01:19,073 WARNING [nova.compute.monitors] Excluding nova.compute.monitors.cpu monitor virt_driver. Not in the list of enabled monitors (CONF.compute_monitors).'
2019-03-09 17:01:22.054651 | ubuntu-xenial |     b'2019-03-09 17:01:19,075 INFO [nova.service] Starting compute node (version 18.1.0)'
2019-03-09 17:01:22.054800 | ubuntu-xenial |     b'2019-03-09 17:01:19,104 WARNING [nova.compute.manager] No compute node record found for host host1. If this is the first time this service is starting on this host, then you can ignore this warning.'
2019-03-09 17:01:22.054886 | ubuntu-xenial |     b'2019-03-09 17:01:19,110 WARNING [nova.compute.resource_tracker] No compute node record for host1:host1'
2019-03-09 17:01:22.055002 | ubuntu-xenial |     b'2019-03-09 17:01:19,115 INFO [nova.compute.resource_tracker] Compute node record created for host1:host1 with uuid: 0e59ca49-7858-479c-8b7c-13a78199a981'
2019-03-09 17:01:22.055174 | ubuntu-xenial |     b'2019-03-09 17:01:19,167 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers?in_tree=0e59ca49-7858-479c-8b7c-13a78199a981" status: 200 len: 26 microversion: 1.14'
2019-03-09 17:01:22.055329 | ubuntu-xenial |     b'2019-03-09 17:01:19,178 INFO [placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 200 len: 828 microversion: 1.20'
2019-03-09 17:01:22.055522 | ubuntu-xenial |     b'2019-03-09 17:01:19,179 INFO [nova.scheduler.client.report] [req-40799b9c-9042-4da4-bd70-e4afd7bc1632] Created resource provider record via placement API for resource provider with UUID 0e59ca49-7858-479c-8b7c-13a78199a981 and name host1.'
2019-03-09 17:01:22.055677 | ubuntu-xenial |     b'2019-03-09 17:01:19,196 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/0e59ca49-7858-479c-8b7c-13a78199a981/inventories" status: 200 len: 399 microversion: 1.26'
2019-03-09 17:01:22.055888 | ubuntu-xenial |     b'2019-03-09 17:01:19,204 INFO [placement.requestlog] 127.0.0.1 "GET /placement/traits?name=in:COMPUTE_VOLUME_MULTI_ATTACH,COMPUTE_TRUSTED_CERTS,COMPUTE_NET_ATTACH_INTERFACE_WITH_TAG,COMPUTE_VOLUME_EXTEND,COMPUTE_VOLUME_ATTACH_WITH_TAG,COMPUTE_NET_ATTACH_INTERFACE" status: 200 len: 200 microversion: 1.6'
2019-03-09 17:01:22.056067 | ubuntu-xenial |     b'2019-03-09 17:01:19,222 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/0e59ca49-7858-479c-8b7c-13a78199a981/traits" status: 200 len: 235 microversion: 1.6'
2019-03-09 17:01:22.056176 | ubuntu-xenial |     b'2019-03-09 17:01:19,268 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1" status: 204 len: 0 microversion: - time: 0.000463'
2019-03-09 17:01:22.056355 | ubuntu-xenial |     b'2019-03-09 17:01:19,311 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/os-hypervisors?hypervisor_hostname_pattern=host1" status: 200 len: 133 microversion: 2.72 time: 0.040365'
2019-03-09 17:01:22.056549 | ubuntu-xenial |     b'2019-03-09 17:01:19,331 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/flavors/detail" status: 200 len: 3043 microversion: 2.72 time: 0.015999'
2019-03-09 17:01:22.056691 | ubuntu-xenial |     b'2019-03-09 17:01:19,351 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/flavors/detail" status: 200 len: 3043 microversion: 2.72 time: 0.015321'
2019-03-09 17:01:22.056833 | ubuntu-xenial |     b'2019-03-09 17:01:19,379 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/flavors/2/os-extra_specs" status: 200 len: 44 microversion: 2.72 time: 0.024595'
2019-03-09 17:01:22.056948 | ubuntu-xenial |     b'2019-03-09 17:01:19,392 INFO [placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 200 len: 893 microversion: 1.20'
2019-03-09 17:01:22.057055 | ubuntu-xenial |     b'2019-03-09 17:01:19,403 INFO [placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 200 len: 893 microversion: 1.20'
2019-03-09 17:01:22.057182 | ubuntu-xenial |     b'2019-03-09 17:01:19,412 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/e409c184-d60f-4770-a8b0-5a40b50f1b1c" status: 200 len: 437 microversion: 1.0'
2019-03-09 17:01:22.057332 | ubuntu-xenial |     b'2019-03-09 17:01:19,425 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/e409c184-d60f-4770-a8b0-5a40b50f1b1c/inventories" status: 200 len: 338 microversion: 1.0'
2019-03-09 17:01:22.057450 | ubuntu-xenial |     b'2019-03-09 17:01:19,433 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/traits/CUSTOM_VNIC_TYPE_NORMAL" status: 201 len: 0 microversion: 1.6'
2019-03-09 17:01:22.057557 | ubuntu-xenial |     b'2019-03-09 17:01:19,440 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/traits/CUSTOM_PHYSNET2" status: 201 len: 0 microversion: 1.6'
2019-03-09 17:01:22.057683 | ubuntu-xenial |     b'2019-03-09 17:01:19,448 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/e409c184-d60f-4770-a8b0-5a40b50f1b1c" status: 200 len: 437 microversion: 1.0'
2019-03-09 17:01:22.057813 | ubuntu-xenial |     b'2019-03-09 17:01:19,465 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/e409c184-d60f-4770-a8b0-5a40b50f1b1c/traits" status: 200 len: 93 microversion: 1.6'
2019-03-09 17:01:22.057971 | ubuntu-xenial |     b'2019-03-09 17:01:19,479 INFO [placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 200 len: 910 microversion: 1.20'
2019-03-09 17:01:22.058088 | ubuntu-xenial |     b'2019-03-09 17:01:19,491 INFO [placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 200 len: 915 microversion: 1.20'
2019-03-09 17:01:22.058219 | ubuntu-xenial |     b'2019-03-09 17:01:19,500 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/f92fd9c1-c5b8-4195-beeb-f2c94bd245c1" status: 200 len: 459 microversion: 1.0'
2019-03-09 17:01:22.058372 | ubuntu-xenial |     b'2019-03-09 17:01:19,514 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/f92fd9c1-c5b8-4195-beeb-f2c94bd245c1/inventories" status: 200 len: 340 microversion: 1.0'
2019-03-09 17:01:22.058489 | ubuntu-xenial |     b'2019-03-09 17:01:19,522 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/traits/CUSTOM_VNIC_TYPE_DIRECT" status: 201 len: 0 microversion: 1.6'
2019-03-09 17:01:22.058619 | ubuntu-xenial |     b'2019-03-09 17:01:19,529 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/traits/CUSTOM_PHYSNET1" status: 201 len: 0 microversion: 1.6'
2019-03-09 17:01:22.058754 | ubuntu-xenial |     b'2019-03-09 17:01:19,538 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/f92fd9c1-c5b8-4195-beeb-f2c94bd245c1" status: 200 len: 459 microversion: 1.0'
2019-03-09 17:01:22.058885 | ubuntu-xenial |     b'2019-03-09 17:01:19,555 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/f92fd9c1-c5b8-4195-beeb-f2c94bd245c1/traits" status: 200 len: 93 microversion: 1.6'
2019-03-09 17:01:22.058991 | ubuntu-xenial |     b'2019-03-09 17:01:19,566 INFO [placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 200 len: 915 microversion: 1.20'
2019-03-09 17:01:22.059119 | ubuntu-xenial |     b'2019-03-09 17:01:19,576 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/214f1a72-51c0-45af-b958-12f568c77be5" status: 200 len: 459 microversion: 1.0'
2019-03-09 17:01:22.059272 | ubuntu-xenial |     b'2019-03-09 17:01:19,589 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/214f1a72-51c0-45af-b958-12f568c77be5/inventories" status: 200 len: 340 microversion: 1.0'
2019-03-09 17:01:22.059402 | ubuntu-xenial |     b'2019-03-09 17:01:19,597 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/traits/CUSTOM_VNIC_TYPE_DIRECT" status: 204 len: 0 microversion: 1.6'
2019-03-09 17:01:22.059509 | ubuntu-xenial |     b'2019-03-09 17:01:19,604 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/traits/CUSTOM_PHYSNET2" status: 204 len: 0 microversion: 1.6'
2019-03-09 17:01:22.059636 | ubuntu-xenial |     b'2019-03-09 17:01:19,613 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/214f1a72-51c0-45af-b958-12f568c77be5" status: 200 len: 459 microversion: 1.0'
2019-03-09 17:01:22.059772 | ubuntu-xenial |     b'2019-03-09 17:01:19,630 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/214f1a72-51c0-45af-b958-12f568c77be5/traits" status: 200 len: 93 microversion: 1.6'
2019-03-09 17:01:22.059878 | ubuntu-xenial |     b'2019-03-09 17:01:19,642 INFO [placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 200 len: 915 microversion: 1.20'
2019-03-09 17:01:22.060005 | ubuntu-xenial |     b'2019-03-09 17:01:19,651 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/74dcdd80-1057-4aef-9cfd-e4014af28b8e" status: 200 len: 459 microversion: 1.0'
2019-03-09 17:01:22.060139 | ubuntu-xenial |     b'2019-03-09 17:01:19,664 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/74dcdd80-1057-4aef-9cfd-e4014af28b8e/inventories" status: 200 len: 54 microversion: 1.0'
2019-03-09 17:01:22.060263 | ubuntu-xenial |     b'2019-03-09 17:01:19,672 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/traits/CUSTOM_VNIC_TYPE_DIRECT" status: 204 len: 0 microversion: 1.6'
2019-03-09 17:01:22.060408 | ubuntu-xenial |     b'2019-03-09 17:01:19,680 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/traits/CUSTOM_PHYSNET2" status: 204 len: 0 microversion: 1.6'
2019-03-09 17:01:22.060543 | ubuntu-xenial |     b'2019-03-09 17:01:19,690 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/74dcdd80-1057-4aef-9cfd-e4014af28b8e" status: 200 len: 459 microversion: 1.0'
2019-03-09 17:01:22.060675 | ubuntu-xenial |     b'2019-03-09 17:01:19,709 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/74dcdd80-1057-4aef-9cfd-e4014af28b8e/traits" status: 200 len: 93 microversion: 1.6'
2019-03-09 17:01:22.060812 | ubuntu-xenial |     b'2019-03-09 17:01:19,823 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/servers" status: 202 len: 480 microversion: 2.72 time: 0.110436'
2019-03-09 17:01:22.060965 | ubuntu-xenial |     b'2019-03-09 17:01:19,851 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/b6655647-658e-412d-89cb-33b61e731bcc" status: 200 len: 1846 microversion: 2.72 time: 0.023979'
2019-03-09 17:01:22.061266 | ubuntu-xenial |     b'2019-03-09 17:01:19,966 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocation_candidates?limit=1000&required1=CUSTOM_PHYSNET2%2CCUSTOM_VNIC_TYPE_NORMAL&resources=DISK_GB%3A1%2CMEMORY_MB%3A512%2CVCPU%3A1&resources1=NET_BW_EGR_KILOBIT_PER_SEC%3A1000%2CNET_BW_IGR_KILOBIT_PER_SEC%3A1000" status: 200 len: 2510 microversion: 1.29'
2019-03-09 17:01:22.061421 | ubuntu-xenial |     b'2019-03-09 17:01:20,006 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/b6655647-658e-412d-89cb-33b61e731bcc" status: 200 len: 19 microversion: 1.28'
2019-03-09 17:01:22.061564 | ubuntu-xenial |     b'2019-03-09 17:01:20,043 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/allocations/b6655647-658e-412d-89cb-33b61e731bcc" status: 204 len: 0 microversion: 1.29'
2019-03-09 17:01:22.061692 | ubuntu-xenial |     b'2019-03-09 17:01:20,136 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/b6655647-658e-412d-89cb-33b61e731bcc" status: 200 len: 376 microversion: 1.28'
2019-03-09 17:01:22.061829 | ubuntu-xenial |     b'2019-03-09 17:01:20,146 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/e409c184-d60f-4770-a8b0-5a40b50f1b1c/traits" status: 200 len: 93 microversion: 1.6'
2019-03-09 17:01:22.062005 | ubuntu-xenial |     b'2019-03-09 17:01:20,157 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/0e59ca49-7858-479c-8b7c-13a78199a981/traits" status: 200 len: 235 microversion: 1.6'
2019-03-09 17:01:22.062102 | ubuntu-xenial |     b'2019-03-09 17:01:20,308 INFO [nova.compute.claims] Attempting claim on node host1: memory 512 MB, disk 1 GB, vcpus 1 CPU'
2019-03-09 17:01:22.062202 | ubuntu-xenial |     b'2019-03-09 17:01:20,309 INFO [nova.compute.claims] Total memory: 8192 MB, used: 512.00 MB'
2019-03-09 17:01:22.062307 | ubuntu-xenial |     b'2019-03-09 17:01:20,309 INFO [nova.compute.claims] memory limit not specified, defaulting to unlimited'
2019-03-09 17:01:22.062388 | ubuntu-xenial |     b'2019-03-09 17:01:20,310 INFO [nova.compute.claims] Total disk: 1028 GB, used: 0.00 GB'
2019-03-09 17:01:22.062473 | ubuntu-xenial |     b'2019-03-09 17:01:20,310 INFO [nova.compute.claims] disk limit not specified, defaulting to unlimited'
2019-03-09 17:01:22.062546 | ubuntu-xenial |     b'2019-03-09 17:01:20,310 INFO [nova.compute.claims] Total vcpu: 2 VCPU, used: 0.00 VCPU'
2019-03-09 17:01:22.062629 | ubuntu-xenial |     b'2019-03-09 17:01:20,311 INFO [nova.compute.claims] vcpu limit not specified, defaulting to unlimited'
2019-03-09 17:01:22.062699 | ubuntu-xenial |     b'2019-03-09 17:01:20,311 INFO [nova.compute.claims] Claim successful on node host1'
2019-03-09 17:01:22.062855 | ubuntu-xenial |     b'2019-03-09 17:01:20,632 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/b6655647-658e-412d-89cb-33b61e731bcc" status: 200 len: 1923 microversion: 2.72 time: 0.236979'
2019-03-09 17:01:22.063000 | ubuntu-xenial |     b'2019-03-09 17:01:20,655 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/b6655647-658e-412d-89cb-33b61e731bcc" status: 200 len: 376 microversion: 1.28'
2019-03-09 17:01:22.063096 | ubuntu-xenial |     b'2019-03-09 17:01:20,715 INFO [nova.compute.manager] Took 0.00 seconds to spawn the instance on the hypervisor.'
2019-03-09 17:01:22.063172 | ubuntu-xenial |     b'2019-03-09 17:01:20,783 INFO [nova.compute.manager] Took 0.49 seconds to build instance.'
2019-03-09 17:01:22.063291 | ubuntu-xenial |     b"2019-03-09 17:01:20,831 INFO [nova.scheduler.host_manager] Received an update from an unknown host 'host1'. Re-created its InstanceList."
2019-03-09 17:01:22.063451 | ubuntu-xenial |     b'2019-03-09 17:01:21,234 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/b6655647-658e-412d-89cb-33b61e731bcc" status: 200 len: 2203 microversion: 2.72 time: 0.096455'
2019-03-09 17:01:22.063575 | ubuntu-xenial |     b'2019-03-09 17:01:21,246 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/b6655647-658e-412d-89cb-33b61e731bcc" status: 200 len: 280 microversion: 1.0'
2019-03-09 17:01:22.063758 | ubuntu-xenial |     b'2019-03-09 17:01:21,304 INFO [nova.api.openstack.requestlog] 127.0.0.1 "DELETE /v2.1/6f70656e737461636b20342065766572/servers/b6655647-658e-412d-89cb-33b61e731bcc/os-interface/2f2613ce-95a9-490a-b3c4-5f1c28c1f886" status: 202 len: 0 microversion: 2.72 time: 0.054990'
2019-03-09 17:01:22.063911 | ubuntu-xenial |     b'2019-03-09 17:01:21,406 INFO [nova.network.neutronv2.api] Port 2f2613ce-95a9-490a-b3c4-5f1c28c1f886 from network info_cache is no longer associated with instance in Neutron. Removing from network info_cache.'
2019-03-09 17:01:22.064059 | ubuntu-xenial |     b'2019-03-09 17:01:21,859 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/b6655647-658e-412d-89cb-33b61e731bcc" status: 200 len: 376 microversion: 1.28'
2019-03-09 17:01:22.064188 | ubuntu-xenial |     b'2019-03-09 17:01:21,877 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/b6655647-658e-412d-89cb-33b61e731bcc" status: 200 len: 280 microversion: 1.0'
2019-03-09 17:01:22.064325 | ubuntu-xenial |     b'2019-03-09 17:01:21,897 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/allocations/b6655647-658e-412d-89cb-33b61e731bcc" status: 204 len: 0 microversion: 1.28'
2019-03-09 17:01:22.064413 | ubuntu-xenial |     b'2019-03-09 17:01:22,019 INFO [oslo_db.sqlalchemy.provision] DROP ALL OBJECTS, BACKEND sqlite://'
2019-03-09 17:01:22.064492 | ubuntu-xenial |     b'2019-03-09 17:01:22,040 INFO [oslo_db.sqlalchemy.provision] DISPOSE ENGINE Engine(sqlite://)'
2019-03-09 17:01:22.064514 | ubuntu-xenial |     b''
2019-03-09 17:01:22.064554 | ubuntu-xenial |
2019-03-09 17:01:22.064589 | ubuntu-xenial | Captured traceback:
2019-03-09 17:01:22.064635 | ubuntu-xenial | ~~~~~~~~~~~~~~~~~~~
2019-03-09 17:01:22.064684 | ubuntu-xenial |     b'Traceback (most recent call last):'
2019-03-09 17:01:22.064816 | ubuntu-xenial |     b'  File "/home/zuul/src/git.openstack.org/openstack/nova/nova/tests/functional/test_servers.py", line 6478, in test_interface_detach_with_port_with_bandwidth_request'
2019-03-09 17:01:22.064895 | ubuntu-xenial |     b'    self.assertEqual(1, len(allocations))'
2019-03-09 17:01:22.065016 | ubuntu-xenial |     b'  File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional-py35/lib/python3.5/site-packages/testtools/testcase.py", line 411, in assertEqual'
2019-03-09 17:01:22.065068 | ubuntu-xenial |     b'    self.assertThat(observed, matcher, message)'
2019-03-09 17:01:22.065181 | ubuntu-xenial |     b'  File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional-py35/lib/python3.5/site-packages/testtools/testcase.py", line 498, in assertThat'
2019-03-09 17:01:22.065218 | ubuntu-xenial |     b'    raise mismatch_error'
2019-03-09 17:01:22.065299 | ubuntu-xenial |     b'testtools.matchers._impl.MismatchError: 1 != 2'
2019-03-09 17:01:22.065331 | ubuntu-xenial |     b''


Looks like the test is racing with a port detach cleaning up the vif entry from the network info cache:

2019-03-09 17:01:22.063911 | ubuntu-xenial |     b'2019-03-09
17:01:21,406 INFO [nova.network.neutronv2.api] Port 2f2613ce-95a9-490a-
b3c4-5f1c28c1f886 from network info_cache is no longer associated with
instance in Neutron. Removing from network info_cache.'

http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22Port%5C%22%20AND%20message%3A%5C%22from%20network%20info_cache%20is%20no%20longer%20associated%20with%20instance%20in%20Neutron.%20Removing%20from%20network%20info_cache.'%5C%22%20AND%20tags%3A%5C%22console%5C%22&from=7d

18 hits in 7 days, check and gate, all failures.

** Affects: nova
     Importance: Medium
         Status: Confirmed


** Tags: gate-failure stein-rc-potential

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1819374

Title:
  test_interface_detach_with_port_with_bandwidth_request intermittently
  fails

Status in OpenStack Compute (nova):
  Confirmed

Bug description:
  Seen here:

  http://logs.openstack.org/21/641021/1/gate/nova-tox-functional-
  py35/b057262/job-output.txt.gz#_2019-03-09_17_01_22_053827

  2019-03-09 17:01:22.053827 | ubuntu-xenial | {1} nova.tests.functional.test_servers.PortResourceRequestBasedSchedulingTest.test_interface_detach_with_port_with_bandwidth_request [3.961215s] ... FAILED
  2019-03-09 17:01:22.053957 | ubuntu-xenial |
  2019-03-09 17:01:22.053999 | ubuntu-xenial | Captured pythonlogging:
  2019-03-09 17:01:22.054050 | ubuntu-xenial | ~~~~~~~~~~~~~~~~~~~~~~~
  2019-03-09 17:01:22.054142 | ubuntu-xenial |     b'2019-03-09 17:01:18,266 WARNING [placement.db_api] TransactionFactory already started, not reconfiguring.'
  2019-03-09 17:01:22.054231 | ubuntu-xenial |     b'2019-03-09 17:01:19,023 INFO [nova.service] Starting conductor node (version 18.1.0)'
  2019-03-09 17:01:22.054328 | ubuntu-xenial |     b'2019-03-09 17:01:19,046 INFO [nova.service] Starting scheduler node (version 18.1.0)'
  2019-03-09 17:01:22.054415 | ubuntu-xenial |     b"2019-03-09 17:01:19,073 INFO [nova.virt.driver] Loading compute driver 'fake.FakeDriverWithPciResources'"
  2019-03-09 17:01:22.054558 | ubuntu-xenial |     b'2019-03-09 17:01:19,073 WARNING [nova.compute.monitors] Excluding nova.compute.monitors.cpu monitor virt_driver. Not in the list of enabled monitors (CONF.compute_monitors).'
  2019-03-09 17:01:22.054651 | ubuntu-xenial |     b'2019-03-09 17:01:19,075 INFO [nova.service] Starting compute node (version 18.1.0)'
  2019-03-09 17:01:22.054800 | ubuntu-xenial |     b'2019-03-09 17:01:19,104 WARNING [nova.compute.manager] No compute node record found for host host1. If this is the first time this service is starting on this host, then you can ignore this warning.'
  2019-03-09 17:01:22.054886 | ubuntu-xenial |     b'2019-03-09 17:01:19,110 WARNING [nova.compute.resource_tracker] No compute node record for host1:host1'
  2019-03-09 17:01:22.055002 | ubuntu-xenial |     b'2019-03-09 17:01:19,115 INFO [nova.compute.resource_tracker] Compute node record created for host1:host1 with uuid: 0e59ca49-7858-479c-8b7c-13a78199a981'
  2019-03-09 17:01:22.055174 | ubuntu-xenial |     b'2019-03-09 17:01:19,167 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers?in_tree=0e59ca49-7858-479c-8b7c-13a78199a981" status: 200 len: 26 microversion: 1.14'
  2019-03-09 17:01:22.055329 | ubuntu-xenial |     b'2019-03-09 17:01:19,178 INFO [placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 200 len: 828 microversion: 1.20'
  2019-03-09 17:01:22.055522 | ubuntu-xenial |     b'2019-03-09 17:01:19,179 INFO [nova.scheduler.client.report] [req-40799b9c-9042-4da4-bd70-e4afd7bc1632] Created resource provider record via placement API for resource provider with UUID 0e59ca49-7858-479c-8b7c-13a78199a981 and name host1.'
  2019-03-09 17:01:22.055677 | ubuntu-xenial |     b'2019-03-09 17:01:19,196 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/0e59ca49-7858-479c-8b7c-13a78199a981/inventories" status: 200 len: 399 microversion: 1.26'
  2019-03-09 17:01:22.055888 | ubuntu-xenial |     b'2019-03-09 17:01:19,204 INFO [placement.requestlog] 127.0.0.1 "GET /placement/traits?name=in:COMPUTE_VOLUME_MULTI_ATTACH,COMPUTE_TRUSTED_CERTS,COMPUTE_NET_ATTACH_INTERFACE_WITH_TAG,COMPUTE_VOLUME_EXTEND,COMPUTE_VOLUME_ATTACH_WITH_TAG,COMPUTE_NET_ATTACH_INTERFACE" status: 200 len: 200 microversion: 1.6'
  2019-03-09 17:01:22.056067 | ubuntu-xenial |     b'2019-03-09 17:01:19,222 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/0e59ca49-7858-479c-8b7c-13a78199a981/traits" status: 200 len: 235 microversion: 1.6'
  2019-03-09 17:01:22.056176 | ubuntu-xenial |     b'2019-03-09 17:01:19,268 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1" status: 204 len: 0 microversion: - time: 0.000463'
  2019-03-09 17:01:22.056355 | ubuntu-xenial |     b'2019-03-09 17:01:19,311 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/os-hypervisors?hypervisor_hostname_pattern=host1" status: 200 len: 133 microversion: 2.72 time: 0.040365'
  2019-03-09 17:01:22.056549 | ubuntu-xenial |     b'2019-03-09 17:01:19,331 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/flavors/detail" status: 200 len: 3043 microversion: 2.72 time: 0.015999'
  2019-03-09 17:01:22.056691 | ubuntu-xenial |     b'2019-03-09 17:01:19,351 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/flavors/detail" status: 200 len: 3043 microversion: 2.72 time: 0.015321'
  2019-03-09 17:01:22.056833 | ubuntu-xenial |     b'2019-03-09 17:01:19,379 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/flavors/2/os-extra_specs" status: 200 len: 44 microversion: 2.72 time: 0.024595'
  2019-03-09 17:01:22.056948 | ubuntu-xenial |     b'2019-03-09 17:01:19,392 INFO [placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 200 len: 893 microversion: 1.20'
  2019-03-09 17:01:22.057055 | ubuntu-xenial |     b'2019-03-09 17:01:19,403 INFO [placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 200 len: 893 microversion: 1.20'
  2019-03-09 17:01:22.057182 | ubuntu-xenial |     b'2019-03-09 17:01:19,412 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/e409c184-d60f-4770-a8b0-5a40b50f1b1c" status: 200 len: 437 microversion: 1.0'
  2019-03-09 17:01:22.057332 | ubuntu-xenial |     b'2019-03-09 17:01:19,425 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/e409c184-d60f-4770-a8b0-5a40b50f1b1c/inventories" status: 200 len: 338 microversion: 1.0'
  2019-03-09 17:01:22.057450 | ubuntu-xenial |     b'2019-03-09 17:01:19,433 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/traits/CUSTOM_VNIC_TYPE_NORMAL" status: 201 len: 0 microversion: 1.6'
  2019-03-09 17:01:22.057557 | ubuntu-xenial |     b'2019-03-09 17:01:19,440 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/traits/CUSTOM_PHYSNET2" status: 201 len: 0 microversion: 1.6'
  2019-03-09 17:01:22.057683 | ubuntu-xenial |     b'2019-03-09 17:01:19,448 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/e409c184-d60f-4770-a8b0-5a40b50f1b1c" status: 200 len: 437 microversion: 1.0'
  2019-03-09 17:01:22.057813 | ubuntu-xenial |     b'2019-03-09 17:01:19,465 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/e409c184-d60f-4770-a8b0-5a40b50f1b1c/traits" status: 200 len: 93 microversion: 1.6'
  2019-03-09 17:01:22.057971 | ubuntu-xenial |     b'2019-03-09 17:01:19,479 INFO [placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 200 len: 910 microversion: 1.20'
  2019-03-09 17:01:22.058088 | ubuntu-xenial |     b'2019-03-09 17:01:19,491 INFO [placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 200 len: 915 microversion: 1.20'
  2019-03-09 17:01:22.058219 | ubuntu-xenial |     b'2019-03-09 17:01:19,500 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/f92fd9c1-c5b8-4195-beeb-f2c94bd245c1" status: 200 len: 459 microversion: 1.0'
  2019-03-09 17:01:22.058372 | ubuntu-xenial |     b'2019-03-09 17:01:19,514 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/f92fd9c1-c5b8-4195-beeb-f2c94bd245c1/inventories" status: 200 len: 340 microversion: 1.0'
  2019-03-09 17:01:22.058489 | ubuntu-xenial |     b'2019-03-09 17:01:19,522 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/traits/CUSTOM_VNIC_TYPE_DIRECT" status: 201 len: 0 microversion: 1.6'
  2019-03-09 17:01:22.058619 | ubuntu-xenial |     b'2019-03-09 17:01:19,529 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/traits/CUSTOM_PHYSNET1" status: 201 len: 0 microversion: 1.6'
  2019-03-09 17:01:22.058754 | ubuntu-xenial |     b'2019-03-09 17:01:19,538 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/f92fd9c1-c5b8-4195-beeb-f2c94bd245c1" status: 200 len: 459 microversion: 1.0'
  2019-03-09 17:01:22.058885 | ubuntu-xenial |     b'2019-03-09 17:01:19,555 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/f92fd9c1-c5b8-4195-beeb-f2c94bd245c1/traits" status: 200 len: 93 microversion: 1.6'
  2019-03-09 17:01:22.058991 | ubuntu-xenial |     b'2019-03-09 17:01:19,566 INFO [placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 200 len: 915 microversion: 1.20'
  2019-03-09 17:01:22.059119 | ubuntu-xenial |     b'2019-03-09 17:01:19,576 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/214f1a72-51c0-45af-b958-12f568c77be5" status: 200 len: 459 microversion: 1.0'
  2019-03-09 17:01:22.059272 | ubuntu-xenial |     b'2019-03-09 17:01:19,589 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/214f1a72-51c0-45af-b958-12f568c77be5/inventories" status: 200 len: 340 microversion: 1.0'
  2019-03-09 17:01:22.059402 | ubuntu-xenial |     b'2019-03-09 17:01:19,597 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/traits/CUSTOM_VNIC_TYPE_DIRECT" status: 204 len: 0 microversion: 1.6'
  2019-03-09 17:01:22.059509 | ubuntu-xenial |     b'2019-03-09 17:01:19,604 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/traits/CUSTOM_PHYSNET2" status: 204 len: 0 microversion: 1.6'
  2019-03-09 17:01:22.059636 | ubuntu-xenial |     b'2019-03-09 17:01:19,613 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/214f1a72-51c0-45af-b958-12f568c77be5" status: 200 len: 459 microversion: 1.0'
  2019-03-09 17:01:22.059772 | ubuntu-xenial |     b'2019-03-09 17:01:19,630 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/214f1a72-51c0-45af-b958-12f568c77be5/traits" status: 200 len: 93 microversion: 1.6'
  2019-03-09 17:01:22.059878 | ubuntu-xenial |     b'2019-03-09 17:01:19,642 INFO [placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 200 len: 915 microversion: 1.20'
  2019-03-09 17:01:22.060005 | ubuntu-xenial |     b'2019-03-09 17:01:19,651 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/74dcdd80-1057-4aef-9cfd-e4014af28b8e" status: 200 len: 459 microversion: 1.0'
  2019-03-09 17:01:22.060139 | ubuntu-xenial |     b'2019-03-09 17:01:19,664 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/74dcdd80-1057-4aef-9cfd-e4014af28b8e/inventories" status: 200 len: 54 microversion: 1.0'
  2019-03-09 17:01:22.060263 | ubuntu-xenial |     b'2019-03-09 17:01:19,672 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/traits/CUSTOM_VNIC_TYPE_DIRECT" status: 204 len: 0 microversion: 1.6'
  2019-03-09 17:01:22.060408 | ubuntu-xenial |     b'2019-03-09 17:01:19,680 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/traits/CUSTOM_PHYSNET2" status: 204 len: 0 microversion: 1.6'
  2019-03-09 17:01:22.060543 | ubuntu-xenial |     b'2019-03-09 17:01:19,690 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/74dcdd80-1057-4aef-9cfd-e4014af28b8e" status: 200 len: 459 microversion: 1.0'
  2019-03-09 17:01:22.060675 | ubuntu-xenial |     b'2019-03-09 17:01:19,709 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/74dcdd80-1057-4aef-9cfd-e4014af28b8e/traits" status: 200 len: 93 microversion: 1.6'
  2019-03-09 17:01:22.060812 | ubuntu-xenial |     b'2019-03-09 17:01:19,823 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/servers" status: 202 len: 480 microversion: 2.72 time: 0.110436'
  2019-03-09 17:01:22.060965 | ubuntu-xenial |     b'2019-03-09 17:01:19,851 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/b6655647-658e-412d-89cb-33b61e731bcc" status: 200 len: 1846 microversion: 2.72 time: 0.023979'
  2019-03-09 17:01:22.061266 | ubuntu-xenial |     b'2019-03-09 17:01:19,966 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocation_candidates?limit=1000&required1=CUSTOM_PHYSNET2%2CCUSTOM_VNIC_TYPE_NORMAL&resources=DISK_GB%3A1%2CMEMORY_MB%3A512%2CVCPU%3A1&resources1=NET_BW_EGR_KILOBIT_PER_SEC%3A1000%2CNET_BW_IGR_KILOBIT_PER_SEC%3A1000" status: 200 len: 2510 microversion: 1.29'
  2019-03-09 17:01:22.061421 | ubuntu-xenial |     b'2019-03-09 17:01:20,006 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/b6655647-658e-412d-89cb-33b61e731bcc" status: 200 len: 19 microversion: 1.28'
  2019-03-09 17:01:22.061564 | ubuntu-xenial |     b'2019-03-09 17:01:20,043 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/allocations/b6655647-658e-412d-89cb-33b61e731bcc" status: 204 len: 0 microversion: 1.29'
  2019-03-09 17:01:22.061692 | ubuntu-xenial |     b'2019-03-09 17:01:20,136 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/b6655647-658e-412d-89cb-33b61e731bcc" status: 200 len: 376 microversion: 1.28'
  2019-03-09 17:01:22.061829 | ubuntu-xenial |     b'2019-03-09 17:01:20,146 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/e409c184-d60f-4770-a8b0-5a40b50f1b1c/traits" status: 200 len: 93 microversion: 1.6'
  2019-03-09 17:01:22.062005 | ubuntu-xenial |     b'2019-03-09 17:01:20,157 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/0e59ca49-7858-479c-8b7c-13a78199a981/traits" status: 200 len: 235 microversion: 1.6'
  2019-03-09 17:01:22.062102 | ubuntu-xenial |     b'2019-03-09 17:01:20,308 INFO [nova.compute.claims] Attempting claim on node host1: memory 512 MB, disk 1 GB, vcpus 1 CPU'
  2019-03-09 17:01:22.062202 | ubuntu-xenial |     b'2019-03-09 17:01:20,309 INFO [nova.compute.claims] Total memory: 8192 MB, used: 512.00 MB'
  2019-03-09 17:01:22.062307 | ubuntu-xenial |     b'2019-03-09 17:01:20,309 INFO [nova.compute.claims] memory limit not specified, defaulting to unlimited'
  2019-03-09 17:01:22.062388 | ubuntu-xenial |     b'2019-03-09 17:01:20,310 INFO [nova.compute.claims] Total disk: 1028 GB, used: 0.00 GB'
  2019-03-09 17:01:22.062473 | ubuntu-xenial |     b'2019-03-09 17:01:20,310 INFO [nova.compute.claims] disk limit not specified, defaulting to unlimited'
  2019-03-09 17:01:22.062546 | ubuntu-xenial |     b'2019-03-09 17:01:20,310 INFO [nova.compute.claims] Total vcpu: 2 VCPU, used: 0.00 VCPU'
  2019-03-09 17:01:22.062629 | ubuntu-xenial |     b'2019-03-09 17:01:20,311 INFO [nova.compute.claims] vcpu limit not specified, defaulting to unlimited'
  2019-03-09 17:01:22.062699 | ubuntu-xenial |     b'2019-03-09 17:01:20,311 INFO [nova.compute.claims] Claim successful on node host1'
  2019-03-09 17:01:22.062855 | ubuntu-xenial |     b'2019-03-09 17:01:20,632 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/b6655647-658e-412d-89cb-33b61e731bcc" status: 200 len: 1923 microversion: 2.72 time: 0.236979'
  2019-03-09 17:01:22.063000 | ubuntu-xenial |     b'2019-03-09 17:01:20,655 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/b6655647-658e-412d-89cb-33b61e731bcc" status: 200 len: 376 microversion: 1.28'
  2019-03-09 17:01:22.063096 | ubuntu-xenial |     b'2019-03-09 17:01:20,715 INFO [nova.compute.manager] Took 0.00 seconds to spawn the instance on the hypervisor.'
  2019-03-09 17:01:22.063172 | ubuntu-xenial |     b'2019-03-09 17:01:20,783 INFO [nova.compute.manager] Took 0.49 seconds to build instance.'
  2019-03-09 17:01:22.063291 | ubuntu-xenial |     b"2019-03-09 17:01:20,831 INFO [nova.scheduler.host_manager] Received an update from an unknown host 'host1'. Re-created its InstanceList."
  2019-03-09 17:01:22.063451 | ubuntu-xenial |     b'2019-03-09 17:01:21,234 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/b6655647-658e-412d-89cb-33b61e731bcc" status: 200 len: 2203 microversion: 2.72 time: 0.096455'
  2019-03-09 17:01:22.063575 | ubuntu-xenial |     b'2019-03-09 17:01:21,246 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/b6655647-658e-412d-89cb-33b61e731bcc" status: 200 len: 280 microversion: 1.0'
  2019-03-09 17:01:22.063758 | ubuntu-xenial |     b'2019-03-09 17:01:21,304 INFO [nova.api.openstack.requestlog] 127.0.0.1 "DELETE /v2.1/6f70656e737461636b20342065766572/servers/b6655647-658e-412d-89cb-33b61e731bcc/os-interface/2f2613ce-95a9-490a-b3c4-5f1c28c1f886" status: 202 len: 0 microversion: 2.72 time: 0.054990'
  2019-03-09 17:01:22.063911 | ubuntu-xenial |     b'2019-03-09 17:01:21,406 INFO [nova.network.neutronv2.api] Port 2f2613ce-95a9-490a-b3c4-5f1c28c1f886 from network info_cache is no longer associated with instance in Neutron. Removing from network info_cache.'
  2019-03-09 17:01:22.064059 | ubuntu-xenial |     b'2019-03-09 17:01:21,859 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/b6655647-658e-412d-89cb-33b61e731bcc" status: 200 len: 376 microversion: 1.28'
  2019-03-09 17:01:22.064188 | ubuntu-xenial |     b'2019-03-09 17:01:21,877 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/b6655647-658e-412d-89cb-33b61e731bcc" status: 200 len: 280 microversion: 1.0'
  2019-03-09 17:01:22.064325 | ubuntu-xenial |     b'2019-03-09 17:01:21,897 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/allocations/b6655647-658e-412d-89cb-33b61e731bcc" status: 204 len: 0 microversion: 1.28'
  2019-03-09 17:01:22.064413 | ubuntu-xenial |     b'2019-03-09 17:01:22,019 INFO [oslo_db.sqlalchemy.provision] DROP ALL OBJECTS, BACKEND sqlite://'
  2019-03-09 17:01:22.064492 | ubuntu-xenial |     b'2019-03-09 17:01:22,040 INFO [oslo_db.sqlalchemy.provision] DISPOSE ENGINE Engine(sqlite://)'
  2019-03-09 17:01:22.064514 | ubuntu-xenial |     b''
  2019-03-09 17:01:22.064554 | ubuntu-xenial |
  2019-03-09 17:01:22.064589 | ubuntu-xenial | Captured traceback:
  2019-03-09 17:01:22.064635 | ubuntu-xenial | ~~~~~~~~~~~~~~~~~~~
  2019-03-09 17:01:22.064684 | ubuntu-xenial |     b'Traceback (most recent call last):'
  2019-03-09 17:01:22.064816 | ubuntu-xenial |     b'  File "/home/zuul/src/git.openstack.org/openstack/nova/nova/tests/functional/test_servers.py", line 6478, in test_interface_detach_with_port_with_bandwidth_request'
  2019-03-09 17:01:22.064895 | ubuntu-xenial |     b'    self.assertEqual(1, len(allocations))'
  2019-03-09 17:01:22.065016 | ubuntu-xenial |     b'  File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional-py35/lib/python3.5/site-packages/testtools/testcase.py", line 411, in assertEqual'
  2019-03-09 17:01:22.065068 | ubuntu-xenial |     b'    self.assertThat(observed, matcher, message)'
  2019-03-09 17:01:22.065181 | ubuntu-xenial |     b'  File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional-py35/lib/python3.5/site-packages/testtools/testcase.py", line 498, in assertThat'
  2019-03-09 17:01:22.065218 | ubuntu-xenial |     b'    raise mismatch_error'
  2019-03-09 17:01:22.065299 | ubuntu-xenial |     b'testtools.matchers._impl.MismatchError: 1 != 2'
  2019-03-09 17:01:22.065331 | ubuntu-xenial |     b''

  
  Looks like the test is racing with a port detach cleaning up the vif entry from the network info cache:

  2019-03-09 17:01:22.063911 | ubuntu-xenial |     b'2019-03-09
  17:01:21,406 INFO [nova.network.neutronv2.api] Port 2f2613ce-95a9
  -490a-b3c4-5f1c28c1f886 from network info_cache is no longer
  associated with instance in Neutron. Removing from network
  info_cache.'

  http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22Port%5C%22%20AND%20message%3A%5C%22from%20network%20info_cache%20is%20no%20longer%20associated%20with%20instance%20in%20Neutron.%20Removing%20from%20network%20info_cache.'%5C%22%20AND%20tags%3A%5C%22console%5C%22&from=7d

  18 hits in 7 days, check and gate, all failures.

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

[Bug 1819374] Re: test_interface_detach_with_port_with_bandwidth_request intermittently fails
From: OpenStack Infra, 2019-03-11