OpenStack Compute (nova)

ServerGroupTestV21.test_evacuate_with_anti_affinity_no_valid_host intermittently fails with "Instance compute service state on host2 expected to be down, but it was up."

Bug #1783565 reported by Matt Riedemann
14
This bug affects 2 people
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Fix Released
Low
melanie witt
Rocky
Fix Committed
Low
melanie witt
Stein
Fix Committed
Low
Unassigned
Train
Fix Released
Low
Unassigned

Bug Description

http://logs.openstack.org/32/584032/5/check/nova-tox-functional-py35/7061ec1/job-output.txt.gz#_2018-07-25_03_16_46_462415

18-07-25 03:16:46.418499 | ubuntu-xenial | {5} nova.tests.functional.test_server_group.ServerGroupTestV21.test_evacuate_with_anti_affinity_no_valid_host [14.070214s] ... FAILED
2018-07-25 03:16:46.418582 | ubuntu-xenial |
2018-07-25 03:16:46.418645 | ubuntu-xenial | Captured traceback:
2018-07-25 03:16:46.418705 | ubuntu-xenial | ~~~~~~~~~~~~~~~~~~~
2018-07-25 03:16:46.418798 | ubuntu-xenial | b'Traceback (most recent call last):'
2018-07-25 03:16:46.419095 | ubuntu-xenial | b' File "/home/zuul/src/git.openstack.org/openstack/nova/nova/tests/functional/test_server_group.py", line 456, in test_evacuate_with_anti_affinity_no_valid_host'
2018-07-25 03:16:46.419232 | ubuntu-xenial | b" self.admin_api.post_server_action(servers[1]['id'], post)"
2018-07-25 03:16:46.419471 | ubuntu-xenial | b' File "/home/zuul/src/git.openstack.org/openstack/nova/nova/tests/functional/api/client.py", line 294, in post_server_action'
2018-07-25 03:16:46.419602 | ubuntu-xenial | b" '/servers/%s/action' % server_id, data, **kwargs).body"
2018-07-25 03:16:46.419841 | ubuntu-xenial | b' File "/home/zuul/src/git.openstack.org/openstack/nova/nova/tests/functional/api/client.py", line 235, in api_post'
2018-07-25 03:16:46.419975 | ubuntu-xenial | b' return APIResponse(self.api_request(relative_uri, **kwargs))'
2018-07-25 03:16:46.420187 | ubuntu-xenial | b' File "/home/zuul/src/git.openstack.org/openstack/nova/nova/tests/functional/api/client.py", line 213, in api_request'
2018-07-25 03:16:46.420263 | ubuntu-xenial | b' response=response)'
2018-07-25 03:16:46.420545 | ubuntu-xenial | b'nova.tests.functional.api.client.OpenStackApiException: Unexpected status code: {"badRequest": {"message": "Compute service of host2 is still in use.", "code": 400}}'
2018-07-25 03:16:46.420581 | ubuntu-xenial | b''
2018-07-25 03:16:46.420606 | ubuntu-xenial |
2018-07-25 03:16:46.420654 | ubuntu-xenial | Captured stderr:
2018-07-25 03:16:46.420702 | ubuntu-xenial | ~~~~~~~~~~~~~~~~
2018-07-25 03:16:46.421102 | ubuntu-xenial | b'/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional-py35/lib/python3.5/site-packages/oslo_db/sqlalchemy/enginefacade.py:350: OsloDBDeprecationWarning: EngineFacade is deprecated; please use oslo_db.sqlalchemy.enginefacade'
2018-07-25 03:16:46.421240 | ubuntu-xenial | b' self._legacy_facade = LegacyEngineFacade(None, _factory=self)'
2018-07-25 03:16:46.421623 | ubuntu-xenial | b'/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional-py35/lib/python3.5/site-packages/oslo_db/sqlalchemy/enginefacade.py:350: OsloDBDeprecationWarning: EngineFacade is deprecated; please use oslo_db.sqlalchemy.enginefacade'
2018-07-25 03:16:46.421751 | ubuntu-xenial | b' self._legacy_facade = LegacyEngineFacade(None, _factory=self)'
2018-07-25 03:16:46.422054 | ubuntu-xenial | b"/home/zuul/src/git.openstack.org/openstack/nova/nova/test.py:323: DeprecationWarning: Using class 'MoxStubout' (either directly or via inheritance) is deprecated in version '3.5.0'"
2018-07-25 03:16:46.422174 | ubuntu-xenial | b' mox_fixture = self.useFixture(moxstubout.MoxStubout())'
2018-07-25 03:16:46.422537 | ubuntu-xenial | b'/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional-py35/lib/python3.5/site-packages/paste/deploy/loadwsgi.py:22: DeprecationWarning: Parameters to load are deprecated. Call .resolve and .require separately.'
2018-07-25 03:16:46.422664 | ubuntu-xenial | b' return pkg_resources.EntryPoint.parse("x=" + s).load(False)'
2018-07-25 03:16:46.422928 | ubuntu-xenial | b"/home/zuul/src/git.openstack.org/openstack/nova/nova/db/sqlalchemy/api.py:205: DeprecationWarning: Property 'async_compat' has moved to 'function.async_'"
2018-07-25 03:16:46.423038 | ubuntu-xenial | b' reader_mode = get_context_manager(context).async'
2018-07-25 03:16:46.423301 | ubuntu-xenial | b"/home/zuul/src/git.openstack.org/openstack/nova/nova/db/sqlalchemy/api.py:205: DeprecationWarning: Property 'async_compat' has moved to 'function.async_'"
2018-07-25 03:16:46.423418 | ubuntu-xenial | b' reader_mode = get_context_manager(context).async'
2018-07-25 03:16:46.423455 | ubuntu-xenial | b''
2018-07-25 03:16:46.423479 | ubuntu-xenial |
2018-07-25 03:16:46.423537 | ubuntu-xenial | Captured pythonlogging:
2018-07-25 03:16:46.423595 | ubuntu-xenial | ~~~~~~~~~~~~~~~~~~~~~~~
2018-07-25 03:16:46.430983 | ubuntu-xenial | b"2018-07-25 03:16:32,525 INFO [nova.api.openstack.placement.objects.resource_provider] Synced traits from os_traits into API DB: {'HW_GPU_API_OPENCL_V1_1', 'HW_GPU_API_DIRECTX_V12', 'HW_CPU_X86_AVX512PF', 'HW_GPU_API_DIRECT3D_V11_1', 'HW_CPU_X86_BMI', 'HW_GPU_RESOLUTION_W1280H800', 'HW_GPU_API_CUDA_V2_0', 'HW_GPU_RESOLUTION_W1280H720', 'HW_CPU_X86_MMX', 'COMPUTE_VOLUME_EXTEND', 'HW_GPU_API_CUDA_V1_2', 'HW_NIC_OFFLOAD_FDF', 'HW_CPU_AARCH64_SHA512', 'HW_CPU_AARCH64_ATOMICS', 'HW_GPU_RESOLUTION_W1680H1050', 'HW_GPU_RESOLUTION_W7680H4320', 'HW_NIC_OFFLOAD_LRO', 'HW_CPU_AARCH64_CPUID', 'HW_GPU_API_DIRECT3D_V10_0', 'HW_CPU_X86_FMA3', 'HW_CPU_X86_ASF', 'HW_GPU_API_CUDA_V5_0', 'HW_CPU_X86_AVX', 'COMPUTE_VOLUME_ATTACH_WITH_TAG', 'COMPUTE_NET_ATTACH_INTERFACE_WITH_TAG', 'HW_CPU_X86_AVX2', 'HW_CPU_X86_MPX', 'HW_GPU_API_CUDA_V1_0', 'HW_GPU_RESOLUTION_W1024H768', 'HW_NIC_OFFLOAD_GENEVE', 'HW_GPU_RESOLUTION_W320H240', 'HW_GPU_API_CUDA_V3_0', 'HW_GPU_API_OPENGL_V1_2', 'HW_CPU_X86_AESNI', 'HW_CPU_AARCH64_ASIMDDP', 'HW_GPU_RESOLUTION_W2560H1440', 'HW_CPU_AARCH64_DCPOP', 'HW_GPU_RESOLUTION_W1920H1200', 'HW_GPU_RESOLUTION_W3840H2160', 'HW_CPU_X86_TSX', 'HW_GPU_API_CUDA_V3_5', 'HW_NIC_OFFLOAD_QINQ', 'HW_CPU_X86_BMI2', 'HW_CPU_X86_SGX', 'HW_NIC_OFFLOAD_UCS', 'HW_GPU_API_OPENGL_V3_2', 'HW_CPU_AARCH64_JSCVT', 'HW_GPU_MAX_DISPLAY_HEADS_4', 'HW_CPU_X86_SSE42', 'HW_NIC_ACCEL_DEFLATE', 'HW_GPU_API_OPENGL_V4_5', 'HW_NIC_OFFLOAD_L2CRC', 'HW_NIC_SRIOV_TRUSTED', 'HW_CPU_HYPERTHREADING', 'HW_NIC_SRIOV_MULTIQUEUE', 'HW_GPU_API_DIRECT3D_V11_2', 'HW_GPU_API_OPENGL_V1_5', 'HW_GPU_API_OPENGL_V2_1', 'HW_GPU_API_OPENGL_V1_4', 'HW_CPU_X86_SHA', 'HW_GPU_RESOLUTION_W1280H1024', 'HW_NIC_ACCEL_LZS', 'HW_GPU_RESOLUTION_W1360H768', 'HW_NIC_ACCEL_TLS', 'HW_CPU_AARCH64_SM4', 'HW_GPU_API_OPENCL_V2_2', 'COMPUTE_VOLUME_MULTI_ATTACH', 'HW_GPU_RESOLUTION_W1024H600', 'HW_GPU_API_CUDA_V5_3', 'HW_NIC_OFFLOAD_TSO', 'HW_CPU_AARCH64_SM3', 'HW_CPU_X86_XOP', 'HW_GPU_RESOLUTION_W1152H864', 'HW_NIC_MULTIQUEUE', 'HW_GPU_API_CUDA_V7_0', 'HW_GPU_API_DIRECT3D_V10_1', 'HW_NIC_OFFLOAD_GRE', 'HW_NIC_ACCEL_IPSEC', 'HW_GPU_API_DIRECT3D_V11_3', 'HW_CPU_X86_FMA4', 'HW_NIC_DCB_PFC', 'HW_CPU_X86_AVX512ER', 'HW_NIC_OFFLOAD_TXUDP', 'STORAGE_DISK_SSD', 'HW_NIC_OFFLOAD_RX', 'HW_GPU_API_DIRECT3D_V9_0C', 'HW_CPU_X86_SSE41', 'HW_NIC_OFFLOAD_GSO', 'HW_CPU_AARCH64_FPHP', 'HW_CPU_AARCH64_SHA2', 'HW_NIC_ACCEL_ECC', 'HW_GPU_MAX_DISPLAY_HEADS_6', 'HW_CPU_AARCH64_SVE', 'HW_CPU_AARCH64_AES', 'HW_GPU_RESOLUTION_W1920H1080', 'HW_CPU_X86_SSE4A', 'HW_CPU_X86_SVM', 'HW_GPU_MAX_DISPLAY_HEADS_8', 'HW_CPU_X86_SSE3', 'HW_NIC_OFFLOAD_VXLAN', 'HW_NIC_OFFLOAD_TX', 'HW_CPU_AARCH64_ASIMD', 'HW_NIC_OFFLOAD_TCS', 'HW_GPU_API_CUDA_V6_2', 'HW_GPU_API_DIRECT3D_V9_0L', 'HW_CPU_X86_AVX512VL', 'HW_GPU_API_CUDA_V3_7', 'HW_NIC_DCB_ETS', 'HW_CPU_AARCH64_FCMA', 'HW_GPU_API_CUDA_V6_1', 'HW_GPU_API_DIRECT3D_V6_0', 'HW_GPU_RESOLUTION_W1600H1200', 'HW_NIC_ACCEL_SSL', 'HW_GPU_API_DIRECT3D_V12_0', 'HW_GPU_API_OPENCL_V1_0', 'HW_GPU_API_CUDA_V1_3', 'HW_NIC_SRIOV_QOS_RX', 'HW_GPU_API_DIRECT3D_V9_0B', 'HW_NIC_OFFLOAD_RXHASH', 'COMPUTE_TRUSTED_CERTS', 'HW_GPU_API_CUDA_V7_1', 'HW_GPU_API_CUDA_V1_1', 'HW_GPU_API_DIRECT3D_V9_0', 'HW_GPU_RESOLUTION_W1366H768', 'HW_NIC_ACCEL_DIFFIEH', 'HW_NIC_OFFLOAD_RXVLAN', 'HW_CPU_X86_3DNOW', 'HW_GPU_API_OPENGL_V1_3', 'HW_GPU_RESOLUTION_W1600H900', 'HW_GPU_API_OPENGL_V3_3', 'HW_GPU_API_CUDA_V3_2', 'HW_NIC_DCB_QCN', 'HW_GPU_API_CUDA_V2_1', 'HW_GPU_API_DXVA', 'HW_GPU_API_DIRECTX_V10', 'HW_NIC_OFFLOAD_LSO', 'HW_CPU_AARCH64_PMULL', 'HW_GPU_API_OPENGL_V1_1', 'HW_NIC_OFFLOAD_GRO', 'HW_GPU_API_DIRECT3D_V8_1', 'HW_GPU_API_DIRECT2D', 'HW_GPU_MAX_DISPLAY_HEADS_2', 'HW_GPU_API_OPENGL_V4_2', 'HW_NIC_OFFLOAD_UFO', 'HW_GPU_API_OPENGL_V3_1', 'HW_CPU_AARCH64_LRCPC', 'COMPUTE_DEVICE_TAGGING', 'HW_CPU_AARCH64_EVTSTRM', 'HW_CPU_AARCH64_ASIMDHP', 'HW_GPU_API_DIRECT3D_V7_0', 'HW_CPU_X86_SSSE3', 'HW_CPU_AARCH64_FP', 'HW_GPU_API_OPENGL_V4_4', 'HW_GPU_API_DIRECTX_V11', 'STORAGE_DISK_HDD', 'HW_CPU_AARCH64_ASIMDRDM', 'HW_NIC_OFFLOAD_TXVLAN', 'HW_GPU_API_OPENCL_V1_2', 'HW_GPU_API_OPENCL_V2_0', 'COMPUTE_VOLUME_ATTACH', 'HW_CPU_X86_AVX512DQ', 'HW_NIC_OFFLOAD_SG', 'HW_CPU_X86_SSE', 'HW_NIC_SRIOV', 'COMPUTE_NET_ATTACH_INTERFACE', 'HW_CPU_X86_VMX', 'HW_NIC_OFFLOAD_RDMA', 'HW_GPU_API_OPENGL_V4_0', 'HW_CPU_X86_AVX512BW', 'HW_GPU_API_DIRECT3D_V8_0', 'HW_NIC_VMDQ', 'HW_GPU_RESOLUTION_W1440H900', 'HW_GPU_API_OPENGL_V3_0', 'HW_NIC_SRIOV_QOS_TX', 'HW_NIC_OFFLOAD_SCS', 'HW_CPU_X86_AVX512CD', 'HW_GPU_API_OPENGL_V2_0', 'HW_CPU_X86_ABM', 'HW_CPU_AARCH64_SHA1', 'HW_GPU_API_OPENGL_V4_1', 'HW_GPU_RESOLUTION_W800H600', 'HW_CPU_X86_CLMUL', 'MISC_SHARES_VIA_AGGREGATE', 'HW_GPU_API_OPENCL_V2_1', 'HW_CPU_AARCH64_CRC32', 'HW_GPU_RESOLUTION_W2560H1600', 'HW_CPU_AARCH64_SHA3', 'HW_CPU_X86_AVX512F', 'HW_GPU_API_VULKAN', 'HW_GPU_API_OPENGL_V4_3', 'HW_GPU_RESOLUTION_W640H480', 'HW_NIC_PROGRAMMABLE_PIPELINE', 'HW_GPU_RESOLUTION_W1280H768', 'HW_NIC_OFFLOAD_SWITCHDEV', 'HW_CPU_X86_F16C', 'HW_CPU_X86_SSE2', 'HW_NIC_ACCEL_RSA', 'HW_GPU_API_CUDA_V5_2', 'HW_GPU_API_DIRECT3D_V11_0', 'HW_GPU_API_CUDA_V6_0', 'HW_GPU_MAX_DISPLAY_HEADS_1', 'HW_CPU_X86_TBM'}"
2018-07-25 03:16:46.431146 | ubuntu-xenial | b'2018-07-25 03:16:33,359 INFO [nova.service] Starting conductor node (version 18.0.0)'
2018-07-25 03:16:46.431313 | ubuntu-xenial | b'2018-07-25 03:16:33,375 INFO [nova.service] Starting scheduler node (version 18.0.0)'
2018-07-25 03:16:46.431461 | ubuntu-xenial | b'2018-07-25 03:16:33,395 INFO [nova.service] Starting compute node (version 18.0.0)'
2018-07-25 03:16:46.431777 | ubuntu-xenial | b'2018-07-25 03:16:33,418 WARNING [nova.compute.manager] No compute node record found for host compute. If this is the first time this service is starting on this host, then you can ignore this warning.'
2018-07-25 03:16:46.432052 | ubuntu-xenial | b'2018-07-25 03:16:33,419 WARNING [nova.compute.monitors] Excluding nova.compute.monitors.cpu monitor virt_driver. Not in the list of enabled monitors (CONF.compute_monitors).'
2018-07-25 03:16:46.432239 | ubuntu-xenial | b'2018-07-25 03:16:33,424 WARNING [nova.compute.resource_tracker] No compute node record for compute:compute'
2018-07-25 03:16:46.432494 | ubuntu-xenial | b'2018-07-25 03:16:33,428 INFO [nova.compute.resource_tracker] Compute node record created for compute:compute with uuid: ca8ac9a6-aea5-428c-87cf-a75fc747e966'
2018-07-25 03:16:46.432814 | ubuntu-xenial | b'2018-07-25 03:16:33,449 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers?in_tree=ca8ac9a6-aea5-428c-87cf-a75fc747e966" status: 200 len: 26 microversion: 1.14'
2018-07-25 03:16:46.433066 | ubuntu-xenial | b'2018-07-25 03:16:33,456 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 200 len: 830 microversion: 1.20'
2018-07-25 03:16:46.433428 | ubuntu-xenial | b'2018-07-25 03:16:33,457 INFO [nova.scheduler.client.report] [req-8dc3699e-cff1-4683-b5d3-23ff88893518] Created resource provider record via placement API for resource provider with UUID ca8ac9a6-aea5-428c-87cf-a75fc747e966 and name compute.'
2018-07-25 03:16:46.433738 | ubuntu-xenial | b'2018-07-25 03:16:33,465 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/inventories" status: 200 len: 54 microversion: 1.0'
2018-07-25 03:16:46.434046 | ubuntu-xenial | b'2018-07-25 03:16:33,475 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers?in_tree=ca8ac9a6-aea5-428c-87cf-a75fc747e966" status: 200 len: 856 microversion: 1.14'
2018-07-25 03:16:46.434356 | ubuntu-xenial | b'2018-07-25 03:16:33,483 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/inventories" status: 200 len: 54 microversion: 1.0'
2018-07-25 03:16:46.434666 | ubuntu-xenial | b'2018-07-25 03:16:33,491 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/aggregates" status: 200 len: 53 microversion: 1.19'
2018-07-25 03:16:46.434981 | ubuntu-xenial | b'2018-07-25 03:16:33,500 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/traits" status: 200 len: 49 microversion: 1.6'
2018-07-25 03:16:46.435301 | ubuntu-xenial | b'2018-07-25 03:16:33,508 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/inventories" status: 200 len: 54 microversion: 1.0'
2018-07-25 03:16:46.435615 | ubuntu-xenial | b'2018-07-25 03:16:33,520 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/inventories" status: 200 len: 414 microversion: 1.0'
2018-07-25 03:16:46.435933 | ubuntu-xenial | b'2018-07-25 03:16:33,548 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/allocations" status: 200 len: 54 microversion: 1.0'
2018-07-25 03:16:46.436242 | ubuntu-xenial | b'2018-07-25 03:16:33,549 INFO [nova.compute.resource_tracker] Final resource view: name=compute phys_ram=8192MB used_ram=512MB phys_disk=100000GB used_disk=0GB total_vcpus=1000 used_vcpus=0 pci_stats=[]'
2018-07-25 03:16:46.436550 | ubuntu-xenial | b'2018-07-25 03:16:33,565 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers?in_tree=ca8ac9a6-aea5-428c-87cf-a75fc747e966" status: 200 len: 856 microversion: 1.14'
2018-07-25 03:16:46.436875 | ubuntu-xenial | b'2018-07-25 03:16:33,574 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/inventories" status: 200 len: 414 microversion: 1.0'
2018-07-25 03:16:46.437189 | ubuntu-xenial | b'2018-07-25 03:16:33,581 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/aggregates" status: 200 len: 53 microversion: 1.19'
2018-07-25 03:16:46.437493 | ubuntu-xenial | b'2018-07-25 03:16:33,589 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/traits" status: 200 len: 49 microversion: 1.6'
2018-07-25 03:16:46.437805 | ubuntu-xenial | b'2018-07-25 03:16:33,597 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/inventories" status: 200 len: 414 microversion: 1.0'
2018-07-25 03:16:46.438113 | ubuntu-xenial | b'2018-07-25 03:16:33,606 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers?in_tree=ca8ac9a6-aea5-428c-87cf-a75fc747e966" status: 200 len: 856 microversion: 1.14'
2018-07-25 03:16:46.438424 | ubuntu-xenial | b'2018-07-25 03:16:33,614 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/inventories" status: 200 len: 414 microversion: 1.0'
2018-07-25 03:16:46.438734 | ubuntu-xenial | b'2018-07-25 03:16:33,621 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/aggregates" status: 200 len: 53 microversion: 1.19'
2018-07-25 03:16:46.439038 | ubuntu-xenial | b'2018-07-25 03:16:33,629 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/traits" status: 200 len: 49 microversion: 1.6'
2018-07-25 03:16:46.439354 | ubuntu-xenial | b'2018-07-25 03:16:33,637 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/inventories" status: 200 len: 414 microversion: 1.0'
2018-07-25 03:16:46.439497 | ubuntu-xenial | b'2018-07-25 03:16:33,644 INFO [nova.service] Starting compute node (version 18.0.0)'
2018-07-25 03:16:46.439820 | ubuntu-xenial | b'2018-07-25 03:16:33,663 WARNING [nova.compute.manager] No compute node record found for host host2. If this is the first time this service is starting on this host, then you can ignore this warning.'
2018-07-25 03:16:46.440083 | ubuntu-xenial | b'2018-07-25 03:16:33,663 WARNING [nova.compute.monitors] Excluding nova.compute.monitors.cpu monitor virt_driver. Not in the list of enabled monitors (CONF.compute_monitors).'
2018-07-25 03:16:46.440256 | ubuntu-xenial | b'2018-07-25 03:16:33,667 WARNING [nova.compute.resource_tracker] No compute node record for host2:host2'
2018-07-25 03:16:46.440490 | ubuntu-xenial | b'2018-07-25 03:16:33,669 INFO [nova.compute.resource_tracker] Compute node record created for host2:host2 with uuid: ce292de2-7246-4887-a977-0fac6035abd3'
2018-07-25 03:16:46.440799 | ubuntu-xenial | b'2018-07-25 03:16:33,687 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers?in_tree=ce292de2-7246-4887-a977-0fac6035abd3" status: 200 len: 26 microversion: 1.14'
2018-07-25 03:16:46.441043 | ubuntu-xenial | b'2018-07-25 03:16:33,693 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 200 len: 828 microversion: 1.20'
2018-07-25 03:16:46.441390 | ubuntu-xenial | b'2018-07-25 03:16:33,694 INFO [nova.scheduler.client.report] [req-aeb70f5b-ad61-4dea-a04e-ba21055db31e] Created resource provider record via placement API for resource provider with UUID ce292de2-7246-4887-a977-0fac6035abd3 and name host2.'
2018-07-25 03:16:46.441691 | ubuntu-xenial | b'2018-07-25 03:16:33,701 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/inventories" status: 200 len: 54 microversion: 1.0'
2018-07-25 03:16:46.441988 | ubuntu-xenial | b'2018-07-25 03:16:33,711 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers?in_tree=ce292de2-7246-4887-a977-0fac6035abd3" status: 200 len: 854 microversion: 1.14'
2018-07-25 03:16:46.442288 | ubuntu-xenial | b'2018-07-25 03:16:33,718 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/inventories" status: 200 len: 54 microversion: 1.0'
2018-07-25 03:16:46.442588 | ubuntu-xenial | b'2018-07-25 03:16:33,725 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/aggregates" status: 200 len: 53 microversion: 1.19'
2018-07-25 03:16:46.442881 | ubuntu-xenial | b'2018-07-25 03:16:33,733 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/traits" status: 200 len: 49 microversion: 1.6'
2018-07-25 03:16:46.443180 | ubuntu-xenial | b'2018-07-25 03:16:33,741 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/inventories" status: 200 len: 54 microversion: 1.0'
2018-07-25 03:16:46.443482 | ubuntu-xenial | b'2018-07-25 03:16:33,751 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/inventories" status: 200 len: 414 microversion: 1.0'
2018-07-25 03:16:46.443788 | ubuntu-xenial | b'2018-07-25 03:16:33,775 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/allocations" status: 200 len: 54 microversion: 1.0'
2018-07-25 03:16:46.444086 | ubuntu-xenial | b'2018-07-25 03:16:33,776 INFO [nova.compute.resource_tracker] Final resource view: name=host2 phys_ram=8192MB used_ram=512MB phys_disk=100000GB used_disk=0GB total_vcpus=1000 used_vcpus=0 pci_stats=[]'
2018-07-25 03:16:46.444384 | ubuntu-xenial | b'2018-07-25 03:16:33,790 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers?in_tree=ce292de2-7246-4887-a977-0fac6035abd3" status: 200 len: 854 microversion: 1.14'
2018-07-25 03:16:46.444687 | ubuntu-xenial | b'2018-07-25 03:16:33,798 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/inventories" status: 200 len: 414 microversion: 1.0'
2018-07-25 03:16:46.445006 | ubuntu-xenial | b'2018-07-25 03:16:33,805 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/aggregates" status: 200 len: 53 microversion: 1.19'
2018-07-25 03:16:46.445305 | ubuntu-xenial | b'2018-07-25 03:16:33,815 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/traits" status: 200 len: 49 microversion: 1.6'
2018-07-25 03:16:46.445614 | ubuntu-xenial | b'2018-07-25 03:16:33,823 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/inventories" status: 200 len: 414 microversion: 1.0'
2018-07-25 03:16:46.445914 | ubuntu-xenial | b'2018-07-25 03:16:33,832 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers?in_tree=ce292de2-7246-4887-a977-0fac6035abd3" status: 200 len: 854 microversion: 1.14'
2018-07-25 03:16:46.446216 | ubuntu-xenial | b'2018-07-25 03:16:33,841 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/inventories" status: 200 len: 414 microversion: 1.0'
2018-07-25 03:16:46.446516 | ubuntu-xenial | b'2018-07-25 03:16:33,848 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/aggregates" status: 200 len: 53 microversion: 1.19'
2018-07-25 03:16:46.446810 | ubuntu-xenial | b'2018-07-25 03:16:33,856 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/traits" status: 200 len: 49 microversion: 1.6'
2018-07-25 03:16:46.447112 | ubuntu-xenial | b'2018-07-25 03:16:33,865 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/inventories" status: 200 len: 414 microversion: 1.0'
2018-07-25 03:16:46.447319 | ubuntu-xenial | b'2018-07-25 03:16:33,869 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1" status: 204 len: 0 microversion: - time: 0.000340'
2018-07-25 03:16:46.447599 | ubuntu-xenial | b'2018-07-25 03:16:33,918 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/os-server-groups" status: 200 len: 149 microversion: 2.1 time: 0.046089'
2018-07-25 03:16:46.447905 | ubuntu-xenial | b'2018-07-25 03:16:33,935 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/flavors/detail" status: 200 len: 2747 microversion: 2.1 time: 0.013285'
2018-07-25 03:16:46.448176 | ubuntu-xenial | b'2018-07-25 03:16:34,087 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/servers" status: 202 len: 480 microversion: 2.1 time: 0.149513'
2018-07-25 03:16:46.448384 | ubuntu-xenial | b'2018-07-25 03:16:34,091 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1" status: 204 len: 0 microversion: - time: 0.000268'
2018-07-25 03:16:46.448701 | ubuntu-xenial | b'2018-07-25 03:16:34,138 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/a4ea99d1-9c31-41ab-9ce6-51cc749c0e43" status: 200 len: 1459 microversion: 2.1 time: 0.044532'
2018-07-25 03:16:46.449046 | ubuntu-xenial | b'2018-07-25 03:16:34,205 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocation_candidates?limit=1000&resources=DISK_GB%3A20%2CMEMORY_MB%3A2048%2CVCPU%3A1" status: 200 len: 701 microversion: 1.25'
2018-07-25 03:16:46.449326 | ubuntu-xenial | b'2018-07-25 03:16:34,239 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocations/a4ea99d1-9c31-41ab-9ce6-51cc749c0e43" status: 200 len: 19 microversion: 1.0'
2018-07-25 03:16:46.449603 | ubuntu-xenial | b'2018-07-25 03:16:34,267 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "PUT /placement/allocations/a4ea99d1-9c31-41ab-9ce6-51cc749c0e43" status: 204 len: 0 microversion: 1.25'
2018-07-25 03:16:46.449800 | ubuntu-xenial | b'2018-07-25 03:16:34,420 INFO [nova.compute.claims] Attempting claim on node compute: memory 2048 MB, disk 20 GB, vcpus 1 CPU'
2018-07-25 03:16:46.449949 | ubuntu-xenial | b'2018-07-25 03:16:34,420 INFO [nova.compute.claims] Total memory: 8192 MB, used: 512.00 MB'
2018-07-25 03:16:46.450115 | ubuntu-xenial | b'2018-07-25 03:16:34,420 INFO [nova.compute.claims] memory limit not specified, defaulting to unlimited'
2018-07-25 03:16:46.450260 | ubuntu-xenial | b'2018-07-25 03:16:34,420 INFO [nova.compute.claims] Total disk: 100000 GB, used: 0.00 GB'
2018-07-25 03:16:46.450423 | ubuntu-xenial | b'2018-07-25 03:16:34,420 INFO [nova.compute.claims] disk limit not specified, defaulting to unlimited'
2018-07-25 03:16:46.450578 | ubuntu-xenial | b'2018-07-25 03:16:34,421 INFO [nova.compute.claims] Total vcpu: 1000 VCPU, used: 0.00 VCPU'
2018-07-25 03:16:46.450743 | ubuntu-xenial | b'2018-07-25 03:16:34,421 INFO [nova.compute.claims] vcpu limit not specified, defaulting to unlimited'
2018-07-25 03:16:46.450884 | ubuntu-xenial | b'2018-07-25 03:16:34,421 INFO [nova.compute.claims] Claim successful on node compute'
2018-07-25 03:16:46.451181 | ubuntu-xenial | b'2018-07-25 03:16:34,491 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers?in_tree=ca8ac9a6-aea5-428c-87cf-a75fc747e966" status: 200 len: 856 microversion: 1.14'
2018-07-25 03:16:46.451482 | ubuntu-xenial | b'2018-07-25 03:16:34,500 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/inventories" status: 200 len: 414 microversion: 1.0'
2018-07-25 03:16:46.451802 | ubuntu-xenial | b'2018-07-25 03:16:34,508 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/aggregates" status: 200 len: 53 microversion: 1.19'
2018-07-25 03:16:46.452117 | ubuntu-xenial | b'2018-07-25 03:16:34,517 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/traits" status: 200 len: 49 microversion: 1.6'
2018-07-25 03:16:46.452409 | ubuntu-xenial | b'2018-07-25 03:16:34,525 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/inventories" status: 200 len: 414 microversion: 1.0'
2018-07-25 03:16:46.452695 | ubuntu-xenial | b'2018-07-25 03:16:34,534 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers?in_tree=ca8ac9a6-aea5-428c-87cf-a75fc747e966" status: 200 len: 856 microversion: 1.14'
2018-07-25 03:16:46.452998 | ubuntu-xenial | b'2018-07-25 03:16:34,542 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/inventories" status: 200 len: 414 microversion: 1.0'
2018-07-25 03:16:46.453292 | ubuntu-xenial | b'2018-07-25 03:16:34,549 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/aggregates" status: 200 len: 53 microversion: 1.19'
2018-07-25 03:16:46.453576 | ubuntu-xenial | b'2018-07-25 03:16:34,557 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/traits" status: 200 len: 49 microversion: 1.6'
2018-07-25 03:16:46.453867 | ubuntu-xenial | b'2018-07-25 03:16:34,565 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ca8ac9a6-aea5-428c-87cf-a75fc747e966/inventories" status: 200 len: 414 microversion: 1.0'
2018-07-25 03:16:46.454136 | ubuntu-xenial | b'2018-07-25 03:16:34,630 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocations/a4ea99d1-9c31-41ab-9ce6-51cc749c0e43" status: 200 len: 231 microversion: 1.28'
2018-07-25 03:16:46.454306 | ubuntu-xenial | b'2018-07-25 03:16:34,678 INFO [nova.compute.manager] Took 0.00 seconds to spawn the instance on the hypervisor.'
2018-07-25 03:16:46.454467 | ubuntu-xenial | b'2018-07-25 03:16:34,763 INFO [nova.compute.manager] Took 0.35 seconds to build instance.'
2018-07-25 03:16:46.454765 | ubuntu-xenial | b'2018-07-25 03:16:34,782 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/a4ea99d1-9c31-41ab-9ce6-51cc749c0e43" status: 200 len: 1561 microversion: 2.1 time: 0.111480'
2018-07-25 03:16:46.455029 | ubuntu-xenial | b'2018-07-25 03:16:34,801 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/flavors/detail" status: 200 len: 2747 microversion: 2.1 time: 0.015703'
2018-07-25 03:16:46.455231 | ubuntu-xenial | b"2018-07-25 03:16:34,807 INFO [nova.scheduler.host_manager] Received an update from an unknown host 'compute'. Re-created its InstanceList."
2018-07-25 03:16:46.455494 | ubuntu-xenial | b'2018-07-25 03:16:34,988 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/servers" status: 202 len: 480 microversion: 2.1 time: 0.183775'
2018-07-25 03:16:46.455828 | ubuntu-xenial | b'2018-07-25 03:16:35,010 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/18cdaa10-2ded-4f4a-85ba-d2747534dd5f" status: 200 len: 1459 microversion: 2.1 time: 0.019221'
2018-07-25 03:16:46.456146 | ubuntu-xenial | b'2018-07-25 03:16:35,130 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocation_candidates?limit=1000&resources=DISK_GB%3A20%2CMEMORY_MB%3A2048%2CVCPU%3A1" status: 200 len: 705 microversion: 1.25'
2018-07-25 03:16:46.456422 | ubuntu-xenial | b'2018-07-25 03:16:35,169 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocations/18cdaa10-2ded-4f4a-85ba-d2747534dd5f" status: 200 len: 19 microversion: 1.0'
2018-07-25 03:16:46.456679 | ubuntu-xenial | b'2018-07-25 03:16:35,189 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "PUT /placement/allocations/18cdaa10-2ded-4f4a-85ba-d2747534dd5f" status: 204 len: 0 microversion: 1.25'
2018-07-25 03:16:46.456872 | ubuntu-xenial | b'2018-07-25 03:16:35,339 INFO [nova.compute.claims] Attempting claim on node host2: memory 2048 MB, disk 20 GB, vcpus 1 CPU'
2018-07-25 03:16:46.457015 | ubuntu-xenial | b'2018-07-25 03:16:35,339 INFO [nova.compute.claims] Total memory: 8192 MB, used: 512.00 MB'
2018-07-25 03:16:46.457171 | ubuntu-xenial | b'2018-07-25 03:16:35,339 INFO [nova.compute.claims] memory limit not specified, defaulting to unlimited'
2018-07-25 03:16:46.457308 | ubuntu-xenial | b'2018-07-25 03:16:35,339 INFO [nova.compute.claims] Total disk: 100000 GB, used: 0.00 GB'
2018-07-25 03:16:46.457461 | ubuntu-xenial | b'2018-07-25 03:16:35,339 INFO [nova.compute.claims] disk limit not specified, defaulting to unlimited'
2018-07-25 03:16:46.457612 | ubuntu-xenial | b'2018-07-25 03:16:35,339 INFO [nova.compute.claims] Total vcpu: 1000 VCPU, used: 0.00 VCPU'
2018-07-25 03:16:46.457769 | ubuntu-xenial | b'2018-07-25 03:16:35,340 INFO [nova.compute.claims] vcpu limit not specified, defaulting to unlimited'
2018-07-25 03:16:46.457902 | ubuntu-xenial | b'2018-07-25 03:16:35,340 INFO [nova.compute.claims] Claim successful on node host2'
2018-07-25 03:16:46.458190 | ubuntu-xenial | b'2018-07-25 03:16:35,406 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers?in_tree=ce292de2-7246-4887-a977-0fac6035abd3" status: 200 len: 854 microversion: 1.14'
2018-07-25 03:16:46.458482 | ubuntu-xenial | b'2018-07-25 03:16:35,414 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/inventories" status: 200 len: 414 microversion: 1.0'
2018-07-25 03:16:46.458771 | ubuntu-xenial | b'2018-07-25 03:16:35,421 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/aggregates" status: 200 len: 53 microversion: 1.19'
2018-07-25 03:16:46.459055 | ubuntu-xenial | b'2018-07-25 03:16:35,429 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/traits" status: 200 len: 49 microversion: 1.6'
2018-07-25 03:16:46.459346 | ubuntu-xenial | b'2018-07-25 03:16:35,437 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/inventories" status: 200 len: 414 microversion: 1.0'
2018-07-25 03:16:46.459634 | ubuntu-xenial | b'2018-07-25 03:16:35,447 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers?in_tree=ce292de2-7246-4887-a977-0fac6035abd3" status: 200 len: 854 microversion: 1.14'
2018-07-25 03:16:46.459931 | ubuntu-xenial | b'2018-07-25 03:16:35,455 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/inventories" status: 200 len: 414 microversion: 1.0'
2018-07-25 03:16:46.460223 | ubuntu-xenial | b'2018-07-25 03:16:35,462 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/aggregates" status: 200 len: 53 microversion: 1.19'
2018-07-25 03:16:46.460508 | ubuntu-xenial | b'2018-07-25 03:16:35,470 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/traits" status: 200 len: 49 microversion: 1.6'
2018-07-25 03:16:46.460817 | ubuntu-xenial | b'2018-07-25 03:16:35,478 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce292de2-7246-4887-a977-0fac6035abd3/inventories" status: 200 len: 414 microversion: 1.0'
2018-07-25 03:16:46.461090 | ubuntu-xenial | b'2018-07-25 03:16:35,583 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocations/18cdaa10-2ded-4f4a-85ba-d2747534dd5f" status: 200 len: 231 microversion: 1.28'
2018-07-25 03:16:46.461396 | ubuntu-xenial | b'2018-07-25 03:16:35,631 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/18cdaa10-2ded-4f4a-85ba-d2747534dd5f" status: 200 len: 1552 microversion: 2.1 time: 0.097564'
2018-07-25 03:16:46.461573 | ubuntu-xenial | b'2018-07-25 03:16:35,635 INFO [nova.compute.manager] Took 0.00 seconds to spawn the instance on the hypervisor.'
2018-07-25 03:16:46.461716 | ubuntu-xenial | b'2018-07-25 03:16:35,686 INFO [nova.compute.manager] Took 0.35 seconds to build instance.'
2018-07-25 03:16:46.461921 | ubuntu-xenial | b"2018-07-25 03:16:35,698 INFO [nova.scheduler.host_manager] Received an update from an unknown host 'host2'. Re-created its InstanceList."
2018-07-25 03:16:46.462226 | ubuntu-xenial | b'2018-07-25 03:16:36,183 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/18cdaa10-2ded-4f4a-85ba-d2747534dd5f" status: 200 len: 1557 microversion: 2.1 time: 0.047864'
2018-07-25 03:16:46.462415 | ubuntu-xenial | b'2018-07-25 03:16:46,243 ERROR [nova.compute.api] Instance compute service state on host2 expected to be down, but it was up.'
2018-07-25 03:16:46.462598 | ubuntu-xenial | b'2018-07-25 03:16:46,243 INFO [nova.api.openstack.wsgi] HTTP exception thrown: Compute service of host2 is still in use.'
2018-07-25 03:16:46.462911 | ubuntu-xenial | b'2018-07-25 03:16:46,244 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/servers/18cdaa10-2ded-4f4a-85ba-d2747534dd5f/action" status: 400 len: 85 microversion: 2.1 time: 0.047029'
2018-07-25 03:16:46.462942 | ubuntu-xenial | b''

http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22Instance%20compute%20service%20state%20on%20host2%20expected%20to%20be%20down%2C%20but%20it%20was%20up.%5C%22%20AND%20tags%3A%5C%22console%5C%22&from=7d

37 hits in 7 days, check and gate, all failures. Looks like it might have started around July 24.

Zhenyu Zheng (zhengzhenyu)
Changed in nova:
assignee: nobody → Zhenyu Zheng (zhengzhenyu)
Revision history for this message
Zhenyu Zheng (zhengzhenyu) wrote :

After some check and test, the only reason I can think of is the sleep time is not good, as
sleep time and service_down_time is the same, maybe sometime when we post evacuate action
the service record did not got updated.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nova (master)

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

Changed in nova:
status: New → In Progress
Revision history for this message
Matt Riedemann (mriedem) wrote :

I was also thinking we could just force the service down before evacuate rather than stop the service; we have other evacuate tests that don't stop the service, they just force it down.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on nova (master)

Change abandoned by Stephen Finucane (<email address hidden>) on branch: master
Review: https://review.opendev.org/585978
Reason: Looks like we need another approach here. Going to abandon this as a result

Revision history for this message
Matt Riedemann (mriedem) wrote :

We don't seem to be hitting this in the gate anymore so I'm not sure if it's just rare now or if it's resolved some other way:

http://status.openstack.org/elastic-recheck/#1783565

I'm marking invalid for now though. We can re-open if necessary.

Changed in nova:
assignee: Zhenyu Zheng (zhengzhenyu) → nobody
status: In Progress → Invalid
Revision history for this message
Matt Riedemann (mriedem) wrote :

gibi has a fix here: https://review.opendev.org/692252

Changed in nova:
assignee: nobody → Balazs Gibizer (balazs-gibizer)
status: Invalid → In Progress
importance: Undecided → Low
OpenStack Infra (hudson-openstack)
Changed in nova:
assignee: Balazs Gibizer (balazs-gibizer) → melanie witt (melwitt)
Revision history for this message
Matt Riedemann (mriedem) wrote :

Oops, it was Mel's patch, gibi was +2 on it. My mistake.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nova (master)

Reviewed: https://review.opendev.org/692252
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=1c93ca82b8fb8e39787020decfe335d45f8732e7
Submitter: Zuul
Branch: master

commit 1c93ca82b8fb8e39787020decfe335d45f8732e7
Author: melanie witt <email address hidden>
Date: Thu Oct 31 01:57:41 2019 +0000

    Replace time.sleep(10) with service forced_down in tests

    The server group functional tests are doing time.sleep(10) in order
    to make sure a stopped compute service is considered "down" by the nova
    compute API.

    Instead of sleeping, we can set the service as "forced_down" to get the
    desired "down" compute service status and avoid unnecessary delays in
    these tests.

    Unnecessary service start() calls are also removed in this change. They
    appear at the end of tests and services are started during each test
    setUp() and killed during each test tearDown() via the ServiceFixture.

    Closes-Bug: #1783565

    Change-Id: I74f64b68e4b33ee0f8c45fdc5f570c7e12e05d3b

Changed in nova:
status: In Progress → Fix Released
Revision history for this message
Matt Riedemann (mriedem) wrote :

This might be another example of this in rocky:

https://dfb9d24e1b355e0fedb1-6e6e48394d17c4614241bca417c59e86.ssl.cf2.rackcdn.com/690721/4/gate/nova-tox-functional-py35/08c527d/testr_results.html.gz

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nova (stable/train)

Fix proposed to branch: stable/train
Review: https://review.opendev.org/696088

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nova (stable/train)

Reviewed: https://review.opendev.org/696088
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=a5daa0ddb3129ddd1bea4e85570c047fc2912b1a
Submitter: Zuul
Branch: stable/train

commit a5daa0ddb3129ddd1bea4e85570c047fc2912b1a
Author: melanie witt <email address hidden>
Date: Thu Oct 31 01:57:41 2019 +0000

    Replace time.sleep(10) with service forced_down in tests

    The server group functional tests are doing time.sleep(10) in order
    to make sure a stopped compute service is considered "down" by the nova
    compute API.

    Instead of sleeping, we can set the service as "forced_down" to get the
    desired "down" compute service status and avoid unnecessary delays in
    these tests.

    Unnecessary service start() calls are also removed in this change. They
    appear at the end of tests and services are started during each test
    setUp() and killed during each test tearDown() via the ServiceFixture.

    Closes-Bug: #1783565

    Change-Id: I74f64b68e4b33ee0f8c45fdc5f570c7e12e05d3b
    (cherry picked from commit 1c93ca82b8fb8e39787020decfe335d45f8732e7)

tags: added: in-stable-train
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nova (stable/stein)

Fix proposed to branch: stable/stein
Review: https://review.opendev.org/696175

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nova (stable/stein)

Reviewed: https://review.opendev.org/696175
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=92eb45ba5eb413400e1789f09d3739ee8c0b77de
Submitter: Zuul
Branch: stable/stein

commit 92eb45ba5eb413400e1789f09d3739ee8c0b77de
Author: melanie witt <email address hidden>
Date: Thu Oct 31 01:57:41 2019 +0000

    Replace time.sleep(10) with service forced_down in tests

    The server group functional tests are doing time.sleep(10) in order
    to make sure a stopped compute service is considered "down" by the nova
    compute API.

    Instead of sleeping, we can set the service as "forced_down" to get the
    desired "down" compute service status and avoid unnecessary delays in
    these tests.

    Unnecessary service start() calls are also removed in this change. They
    appear at the end of tests and services are started during each test
    setUp() and killed during each test tearDown() via the ServiceFixture.

    Closes-Bug: #1783565

    Change-Id: I74f64b68e4b33ee0f8c45fdc5f570c7e12e05d3b
    (cherry picked from commit 1c93ca82b8fb8e39787020decfe335d45f8732e7)
    (cherry picked from commit a5daa0ddb3129ddd1bea4e85570c047fc2912b1a)

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nova (stable/rocky)

Fix proposed to branch: stable/rocky
Review: https://review.opendev.org/696217

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nova (stable/rocky)

Reviewed: https://review.opendev.org/696217
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=ffce5be5cae59969ec5ecf7e2b36ae4ec87c29d1
Submitter: Zuul
Branch: stable/rocky

commit ffce5be5cae59969ec5ecf7e2b36ae4ec87c29d1
Author: melanie witt <email address hidden>
Date: Thu Oct 31 01:57:41 2019 +0000

    Replace time.sleep(10) with service forced_down in tests

    The server group functional tests are doing time.sleep(10) in order
    to make sure a stopped compute service is considered "down" by the nova
    compute API.

    Instead of sleeping, we can set the service as "forced_down" to get the
    desired "down" compute service status and avoid unnecessary delays in
    these tests.

    Unnecessary service start() calls are also removed in this change. They
    appear at the end of tests and services are started during each test
    setUp() and killed during each test tearDown() via the ServiceFixture.

    Closes-Bug: #1783565

    NOTE(melwitt): The differences from the cherry picked change are:

      * Addition of 'from nova import utils' because change
        Ie07b419732e0832a9b9d16565f6c9d00ba85d654 is not in Rocky

      * Addition of the put_service_force_down method for the API client
        because change If0693eab2ed31b5fbfe6cbafa5d67b69c2ed8442 is not
        in Rocky

    Change-Id: I74f64b68e4b33ee0f8c45fdc5f570c7e12e05d3b
    (cherry picked from commit 1c93ca82b8fb8e39787020decfe335d45f8732e7)
    (cherry picked from commit a5daa0ddb3129ddd1bea4e85570c047fc2912b1a)
    (cherry picked from commit 92eb45ba5eb413400e1789f09d3739ee8c0b77de)

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/nova 20.1.0

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

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/nova 19.1.0

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

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/nova 18.3.0

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

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

Duplicates of this bug

Subscribing...

Other bug subscribers

Remote bug watches

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