Jan 05 06:40:01 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:40:06 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:40:11 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:40:11 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:40:11 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: idle 5003 ms, sending inactivity probe {{(pid=818) run /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:117}}
Jan 05 06:40:11 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering IDLE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:40:11 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering ACTIVE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:40:11 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:40:11 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:40:12 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_unconfirmed_resizes {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:40:15 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_volume_usage {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:40:16 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:40:16 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Acquiring lock "593ce529-fc99-43bb-95b4-af04851aaa7b" by "nova.compute.manager.ComputeManager.reboot_instance.<locals>.do_reboot_instance" {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:404}}
Jan 05 06:40:16 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Lock "593ce529-fc99-43bb-95b4-af04851aaa7b" acquired by "nova.compute.manager.ComputeManager.reboot_instance.<locals>.do_reboot_instance" :: waited 0.001s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:409}}
Jan 05 06:40:16 ubuntu nova-compute[818]: INFO nova.compute.manager [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Rebooting instance
Jan 05 06:40:16 ubuntu nova-compute[818]: INFO nova.compute.manager [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Removing stale volume attachments of instance from Cinder
Jan 05 06:40:16 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Removing attachment 'e513a9c2-4b73-4dcc-8e0e-48def0687185' {{(pid=818) _delete_dangling_bdms /opt/stack/nova/nova/compute/manager.py:4247}}
Jan 05 06:40:18 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_rescued_instances {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:40:19 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Acquiring lock "refresh_cache-593ce529-fc99-43bb-95b4-af04851aaa7b" {{(pid=818) lock /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:312}}
Jan 05 06:40:19 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Acquired lock "refresh_cache-593ce529-fc99-43bb-95b4-af04851aaa7b" {{(pid=818) lock /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:315}}
Jan 05 06:40:19 ubuntu nova-compute[818]: DEBUG nova.network.neutron [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Building network info cache for instance {{(pid=818) _get_instance_nw_info /opt/stack/nova/nova/network/neutron.py:2009}}
Jan 05 06:40:19 ubuntu nova-compute[818]: DEBUG nova.network.neutron [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Updating instance_info_cache with network_info: [{"id": "6d4bffeb-c603-48f7-9de2-f977d58e5340", "address": "fa:16:3e:04:6d:dc", "network": {"id": "621767bb-46e7-4e6c-9683-b8653ff57922", "bridge": "br-int", "label": "private", "subnets": [{"cidr": "10.0.0.0/26", "dns": [], "gateway": {"address": "10.0.0.1", "type": "gateway", "version": 4, "meta": {}}, "ips": [{"address": "10.0.0.31", "type": "fixed", "version": 4, "meta": {}, "floating_ips": []}], "routes": [], "version": 4, "meta": {"dhcp_server": "10.0.0.1"}}, {"cidr": "fd::/64", "dns": [], "gateway": {"address": "fd::1", "type": "gateway", "version": 6, "meta": {}}, "ips": [{"address": "fd::f816:3eff:fe04:6ddc", "type": "fixed", "version": 6, "meta": {}, "floating_ips": []}], "routes": [], "version": 6, "meta": {"ipv6_address_mode": "slaac", "dhcp_server": "fd::1"}}], "meta": {"injected": false, "tenant_id": "0999c9c6e0c34e2792e91fd7e90e0525", "mtu": 1442, "physical_network": null, "tunneled": true}}, "type": "ovs", "details": {"port_filter": true, "connectivity": "l2", "bound_drivers": {"0": "ovn"}}, "devname": "tap6d4bffeb-c6", "ovs_interfaceid": "6d4bffeb-c603-48f7-9de2-f977d58e5340", "qbh_params": null, "qbg_params": null, "active": true, "vnic_type": "normal", "profile": {}, "preserve_on_delete": false, "delegate_create": true, "meta": {}}] {{(pid=818) update_instance_cache_with_nw_info /opt/stack/nova/nova/network/neutron.py:116}}
Jan 05 06:40:19 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Releasing lock "refresh_cache-593ce529-fc99-43bb-95b4-af04851aaa7b" {{(pid=818) lock /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:333}}
Jan 05 06:40:19 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Checking state {{(pid=818) _get_power_state /opt/stack/nova/nova/compute/manager.py:1782}}
Jan 05 06:40:21 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:40:23 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._check_instance_build_time {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:40:25 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._instance_usage_audit {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:40:26 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:40:26 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager.update_available_resource {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:40:26 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquiring lock "compute_resources" by "nova.compute.resource_tracker.ResourceTracker.clean_compute_node_cache" {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:404}}
Jan 05 06:40:26 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "compute_resources" acquired by "nova.compute.resource_tracker.ResourceTracker.clean_compute_node_cache" :: waited 0.001s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:409}}
Jan 05 06:40:26 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "compute_resources" "released" by "nova.compute.resource_tracker.ResourceTracker.clean_compute_node_cache" :: held 0.001s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:423}}
Jan 05 06:40:26 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Auditing locally available compute resources for ubuntu (node: ubuntu) {{(pid=818) update_available_resource /opt/stack/nova/nova/compute/resource_tracker.py:907}}
Jan 05 06:40:26 ubuntu nova-compute[818]: DEBUG nova.virt.libvirt.driver [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] skipping disk /dev/sdc (vda) as it is a volume {{(pid=818) _get_instance_disk_info_from_config /opt/stack/nova/nova/virt/libvirt/driver.py:11263}}
Jan 05 06:40:26 ubuntu nova-compute[818]: WARNING nova.virt.libvirt.driver [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] This host appears to have multiple sockets per NUMA node. The `socket` PCI NUMA affinity will not be supported.
Jan 05 06:40:26 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Hypervisor/Node resource view: name=ubuntu free_ram=3310MB free_disk=1.7365875244140625GB free_vcpus=3 pci_devices=[{"dev_id": "pci_0000_00_1f_2", "address": "0000:00:1f.2", "product_id": "2922", "vendor_id": "8086", "numa_node": null, "label": "label_8086_2922", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_3", "address": "0000:00:02.3", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_1b_0", "address": "0000:00:1b.0", "product_id": "293e", "vendor_id": "8086", "numa_node": null, "label": "label_8086_293e", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_04_00_0", "address": "0000:04:00.0", "product_id": "1042", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1042", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_01_0", "address": "0000:00:01.0", "product_id": "0100", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_0100", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_00_0", "address": "0000:00:00.0", "product_id": "29c0", "vendor_id": "8086", "numa_node": null, "label": "label_8086_29c0", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_0", "address": "0000:00:02.0", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_06_00_0", "address": "0000:06:00.0", "product_id": "1044", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1044", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_05_00_0", "address": "0000:05:00.0", "product_id": "1045", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1045", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_6", "address": "0000:00:02.6", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_03_00_0", "address": "0000:03:00.0", "product_id": "1043", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1043", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_02_00_0", "address": "0000:02:00.0", "product_id": "000d", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000d", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_1f_3", "address": "0000:00:1f.3", "product_id": "2930", "vendor_id": "8086", "numa_node": null, "label": "label_8086_2930", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_01_00_0", "address": "0000:01:00.0", "product_id": "1041", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1041", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_5", "address": "0000:00:02.5", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_1", "address": "0000:00:02.1", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_1f_0", "address": "0000:00:1f.0", "product_id": "2918", "vendor_id": "8086", "numa_node": null, "label": "label_8086_2918", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_2", "address": "0000:00:02.2", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_4", "address": "0000:00:02.4", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}] {{(pid=818) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:1106}}
Jan 05 06:40:26 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquiring lock "compute_resources" by "nova.compute.resource_tracker.ResourceTracker._update_available_resource" {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:404}}
Jan 05 06:40:26 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "compute_resources" acquired by "nova.compute.resource_tracker.ResourceTracker._update_available_resource" :: waited 0.000s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:409}}
Jan 05 06:40:26 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Instance 6f0d001d-e53d-44f9-8383-62a2ab2925e2 actively managed on this compute host and has allocations in placement: {'resources': {'MEMORY_MB': 512, 'VCPU': 1}}. {{(pid=818) _remove_deleted_instances_allocations /opt/stack/nova/nova/compute/resource_tracker.py:1707}}
Jan 05 06:40:26 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Instance 593ce529-fc99-43bb-95b4-af04851aaa7b actively managed on this compute host and has allocations in placement: {'resources': {'MEMORY_MB': 512, 'VCPU': 1}}. {{(pid=818) _remove_deleted_instances_allocations /opt/stack/nova/nova/compute/resource_tracker.py:1707}}
Jan 05 06:40:26 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Total usable vcpus: 4, total allocated vcpus: 2 {{(pid=818) _report_final_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:1129}}
Jan 05 06:40:26 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Final resource view: name=ubuntu phys_ram=7937MB used_ram=1536MB phys_disk=13GB used_disk=0GB total_vcpus=4 used_vcpus=2 pci_stats=[] {{(pid=818) _report_final_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:1138}}
Jan 05 06:40:26 ubuntu nova-compute[818]: DEBUG nova.compute.provider_tree [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Inventory has not changed in ProviderTree for provider: 6460a2b5-3d32-408b-92ef-54c8918273eb {{(pid=818) update_inventory /opt/stack/nova/nova/compute/provider_tree.py:180}}
Jan 05 06:40:26 ubuntu nova-compute[818]: DEBUG nova.scheduler.client.report [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Inventory has not changed for provider 6460a2b5-3d32-408b-92ef-54c8918273eb based on inventory data: {'VCPU': {'total': 4, 'reserved': 0, 'min_unit': 1, 'max_unit': 4, 'step_size': 1, 'allocation_ratio': 4.0}, 'MEMORY_MB': {'total': 7937, 'reserved': 512, 'min_unit': 1, 'max_unit': 7937, 'step_size': 1, 'allocation_ratio': 1.0}, 'DISK_GB': {'total': 13, 'reserved': 0, 'min_unit': 1, 'max_unit': 13, 'step_size': 1, 'allocation_ratio': 1.0}} {{(pid=818) set_inventory_for_provider /opt/stack/nova/nova/scheduler/client/report.py:940}}
Jan 05 06:40:26 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Compute_service record updated for ubuntu:ubuntu {{(pid=818) _update_available_resource /opt/stack/nova/nova/compute/resource_tracker.py:1067}}
Jan 05 06:40:26 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "compute_resources" "released" by "nova.compute.resource_tracker.ResourceTracker._update_available_resource" :: held 0.114s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:423}}
Jan 05 06:40:30 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._heal_instance_info_cache {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:40:30 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Starting heal instance info cache {{(pid=818) _heal_instance_info_cache /opt/stack/nova/nova/compute/manager.py:9933}}
Jan 05 06:40:30 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquiring lock "refresh_cache-593ce529-fc99-43bb-95b4-af04851aaa7b" {{(pid=818) lock /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:312}}
Jan 05 06:40:30 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquired lock "refresh_cache-593ce529-fc99-43bb-95b4-af04851aaa7b" {{(pid=818) lock /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:315}}
Jan 05 06:40:30 ubuntu nova-compute[818]: DEBUG nova.network.neutron [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Forcefully refreshing network info cache for instance {{(pid=818) _get_instance_nw_info /opt/stack/nova/nova/network/neutron.py:2003}}
Jan 05 06:40:31 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:40:31 ubuntu nova-compute[818]: DEBUG nova.network.neutron [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Updating instance_info_cache with network_info: [{"id": "6d4bffeb-c603-48f7-9de2-f977d58e5340", "address": "fa:16:3e:04:6d:dc", "network": {"id": "621767bb-46e7-4e6c-9683-b8653ff57922", "bridge": "br-int", "label": "private", "subnets": [{"cidr": "10.0.0.0/26", "dns": [], "gateway": {"address": "10.0.0.1", "type": "gateway", "version": 4, "meta": {}}, "ips": [{"address": "10.0.0.31", "type": "fixed", "version": 4, "meta": {}, "floating_ips": []}], "routes": [], "version": 4, "meta": {"dhcp_server": "10.0.0.1"}}, {"cidr": "fd::/64", "dns": [], "gateway": {"address": "fd::1", "type": "gateway", "version": 6, "meta": {}}, "ips": [{"address": "fd::f816:3eff:fe04:6ddc", "type": "fixed", "version": 6, "meta": {}, "floating_ips": []}], "routes": [], "version": 6, "meta": {"ipv6_address_mode": "slaac", "dhcp_server": "fd::1"}}], "meta": {"injected": false, "tenant_id": "0999c9c6e0c34e2792e91fd7e90e0525", "mtu": 1442, "physical_network": null, "tunneled": true}}, "type": "ovs", "details": {"port_filter": true, "connectivity": "l2", "bound_drivers": {"0": "ovn"}}, "devname": "tap6d4bffeb-c6", "ovs_interfaceid": "6d4bffeb-c603-48f7-9de2-f977d58e5340", "qbh_params": null, "qbg_params": null, "active": true, "vnic_type": "normal", "profile": {}, "preserve_on_delete": false, "delegate_create": true, "meta": {}}] {{(pid=818) update_instance_cache_with_nw_info /opt/stack/nova/nova/network/neutron.py:116}}
Jan 05 06:40:31 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Releasing lock "refresh_cache-593ce529-fc99-43bb-95b4-af04851aaa7b" {{(pid=818) lock /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:333}}
Jan 05 06:40:31 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Updated the network info_cache for instance {{(pid=818) _heal_instance_info_cache /opt/stack/nova/nova/compute/manager.py:10004}}
Jan 05 06:40:36 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:40:36 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:40:36 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: idle 5004 ms, sending inactivity probe {{(pid=818) run /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:117}}
Jan 05 06:40:36 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering IDLE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:40:36 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering ACTIVE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:40:36 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:40:41 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:40:46 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:40:47 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_rebooting_instances {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:40:51 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:40:51 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 0-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:40:51 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: idle 5003 ms, sending inactivity probe {{(pid=818) run /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:117}}
Jan 05 06:40:51 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering IDLE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:40:51 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering ACTIVE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:40:51 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:40:56 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:40:56 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._reclaim_queued_deletes {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:40:56 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] CONF.reclaim_instance_interval <= 0, skipping... {{(pid=818) _reclaim_queued_deletes /opt/stack/nova/nova/compute/manager.py:10552}}
Jan 05 06:41:01 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:41:06 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:41:06 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:41:11 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:41:13 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_unconfirmed_resizes {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:41:15 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_volume_usage {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:41:16 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:41:16 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:41:20 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_rescued_instances {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:41:21 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:41:23 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._check_instance_build_time {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:41:25 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._instance_usage_audit {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:41:26 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:41:26 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:41:26 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: idle 5004 ms, sending inactivity probe {{(pid=818) run /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:117}}
Jan 05 06:41:26 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering IDLE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:41:26 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering ACTIVE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:41:26 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:41:27 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager.update_available_resource {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:41:27 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquiring lock "compute_resources" by "nova.compute.resource_tracker.ResourceTracker.clean_compute_node_cache" {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:404}}
Jan 05 06:41:27 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "compute_resources" acquired by "nova.compute.resource_tracker.ResourceTracker.clean_compute_node_cache" :: waited 0.001s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:409}}
Jan 05 06:41:27 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "compute_resources" "released" by "nova.compute.resource_tracker.ResourceTracker.clean_compute_node_cache" :: held 0.001s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:423}}
Jan 05 06:41:27 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Auditing locally available compute resources for ubuntu (node: ubuntu) {{(pid=818) update_available_resource /opt/stack/nova/nova/compute/resource_tracker.py:907}}
Jan 05 06:41:27 ubuntu nova-compute[818]: DEBUG nova.virt.libvirt.driver [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] skipping disk /dev/sdc (vda) as it is a volume {{(pid=818) _get_instance_disk_info_from_config /opt/stack/nova/nova/virt/libvirt/driver.py:11263}}
Jan 05 06:41:27 ubuntu nova-compute[818]: WARNING nova.virt.libvirt.driver [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] This host appears to have multiple sockets per NUMA node. The `socket` PCI NUMA affinity will not be supported.
Jan 05 06:41:27 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Hypervisor/Node resource view: name=ubuntu free_ram=3308MB free_disk=1.7362556457519531GB free_vcpus=3 pci_devices=[{"dev_id": "pci_0000_00_1f_2", "address": "0000:00:1f.2", "product_id": "2922", "vendor_id": "8086", "numa_node": null, "label": "label_8086_2922", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_3", "address": "0000:00:02.3", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_1b_0", "address": "0000:00:1b.0", "product_id": "293e", "vendor_id": "8086", "numa_node": null, "label": "label_8086_293e", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_04_00_0", "address": "0000:04:00.0", "product_id": "1042", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1042", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_01_0", "address": "0000:00:01.0", "product_id": "0100", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_0100", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_00_0", "address": "0000:00:00.0", "product_id": "29c0", "vendor_id": "8086", "numa_node": null, "label": "label_8086_29c0", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_0", "address": "0000:00:02.0", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_06_00_0", "address": "0000:06:00.0", "product_id": "1044", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1044", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_05_00_0", "address": "0000:05:00.0", "product_id": "1045", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1045", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_6", "address": "0000:00:02.6", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_03_00_0", "address": "0000:03:00.0", "product_id": "1043", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1043", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_02_00_0", "address": "0000:02:00.0", "product_id": "000d", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000d", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_1f_3", "address": "0000:00:1f.3", "product_id": "2930", "vendor_id": "8086", "numa_node": null, "label": "label_8086_2930", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_01_00_0", "address": "0000:01:00.0", "product_id": "1041", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1041", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_5", "address": "0000:00:02.5", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_1", "address": "0000:00:02.1", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_1f_0", "address": "0000:00:1f.0", "product_id": "2918", "vendor_id": "8086", "numa_node": null, "label": "label_8086_2918", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_2", "address": "0000:00:02.2", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_4", "address": "0000:00:02.4", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}] {{(pid=818) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:1106}}
Jan 05 06:41:27 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquiring lock "compute_resources" by "nova.compute.resource_tracker.ResourceTracker._update_available_resource" {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:404}}
Jan 05 06:41:27 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "compute_resources" acquired by "nova.compute.resource_tracker.ResourceTracker._update_available_resource" :: waited 0.000s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:409}}
Jan 05 06:41:27 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Instance 6f0d001d-e53d-44f9-8383-62a2ab2925e2 actively managed on this compute host and has allocations in placement: {'resources': {'MEMORY_MB': 512, 'VCPU': 1}}. {{(pid=818) _remove_deleted_instances_allocations /opt/stack/nova/nova/compute/resource_tracker.py:1707}}
Jan 05 06:41:27 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Instance 593ce529-fc99-43bb-95b4-af04851aaa7b actively managed on this compute host and has allocations in placement: {'resources': {'MEMORY_MB': 512, 'VCPU': 1}}. {{(pid=818) _remove_deleted_instances_allocations /opt/stack/nova/nova/compute/resource_tracker.py:1707}}
Jan 05 06:41:27 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Total usable vcpus: 4, total allocated vcpus: 2 {{(pid=818) _report_final_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:1129}}
Jan 05 06:41:27 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Final resource view: name=ubuntu phys_ram=7937MB used_ram=1536MB phys_disk=13GB used_disk=0GB total_vcpus=4 used_vcpus=2 pci_stats=[] {{(pid=818) _report_final_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:1138}}
Jan 05 06:41:28 ubuntu nova-compute[818]: DEBUG nova.compute.provider_tree [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Inventory has not changed in ProviderTree for provider: 6460a2b5-3d32-408b-92ef-54c8918273eb {{(pid=818) update_inventory /opt/stack/nova/nova/compute/provider_tree.py:180}}
Jan 05 06:41:28 ubuntu nova-compute[818]: DEBUG nova.scheduler.client.report [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Inventory has not changed for provider 6460a2b5-3d32-408b-92ef-54c8918273eb based on inventory data: {'VCPU': {'total': 4, 'reserved': 0, 'min_unit': 1, 'max_unit': 4, 'step_size': 1, 'allocation_ratio': 4.0}, 'MEMORY_MB': {'total': 7937, 'reserved': 512, 'min_unit': 1, 'max_unit': 7937, 'step_size': 1, 'allocation_ratio': 1.0}, 'DISK_GB': {'total': 13, 'reserved': 0, 'min_unit': 1, 'max_unit': 13, 'step_size': 1, 'allocation_ratio': 1.0}} {{(pid=818) set_inventory_for_provider /opt/stack/nova/nova/scheduler/client/report.py:940}}
Jan 05 06:41:28 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Compute_service record updated for ubuntu:ubuntu {{(pid=818) _update_available_resource /opt/stack/nova/nova/compute/resource_tracker.py:1067}}
Jan 05 06:41:28 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "compute_resources" "released" by "nova.compute.resource_tracker.ResourceTracker._update_available_resource" :: held 0.180s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:423}}
Jan 05 06:41:31 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._heal_instance_info_cache {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:41:31 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Starting heal instance info cache {{(pid=818) _heal_instance_info_cache /opt/stack/nova/nova/compute/manager.py:9933}}
Jan 05 06:41:31 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Rebuilding the list of instances to heal {{(pid=818) _heal_instance_info_cache /opt/stack/nova/nova/compute/manager.py:9937}}
Jan 05 06:41:31 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquiring lock "refresh_cache-6f0d001d-e53d-44f9-8383-62a2ab2925e2" {{(pid=818) lock /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:312}}
Jan 05 06:41:31 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquired lock "refresh_cache-6f0d001d-e53d-44f9-8383-62a2ab2925e2" {{(pid=818) lock /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:315}}
Jan 05 06:41:31 ubuntu nova-compute[818]: DEBUG nova.network.neutron [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] [instance: 6f0d001d-e53d-44f9-8383-62a2ab2925e2] Forcefully refreshing network info cache for instance {{(pid=818) _get_instance_nw_info /opt/stack/nova/nova/network/neutron.py:2003}}
Jan 05 06:41:31 ubuntu nova-compute[818]: DEBUG nova.objects.instance [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lazy-loading 'info_cache' on Instance uuid 6f0d001d-e53d-44f9-8383-62a2ab2925e2 {{(pid=818) obj_load_attr /opt/stack/nova/nova/objects/instance.py:1141}}
Jan 05 06:41:31 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:41:31 ubuntu nova-compute[818]: DEBUG nova.network.neutron [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] [instance: 6f0d001d-e53d-44f9-8383-62a2ab2925e2] Updating instance_info_cache with network_info: [{"id": "38019df2-3871-428d-9b73-3019a6743c26", "address": "fa:16:3e:b7:c7:e5", "network": {"id": "621767bb-46e7-4e6c-9683-b8653ff57922", "bridge": "br-int", "label": "private", "subnets": [{"cidr": "10.0.0.0/26", "dns": [], "gateway": {"address": "10.0.0.1", "type": "gateway", "version": 4, "meta": {}}, "ips": [{"address": "10.0.0.19", "type": "fixed", "version": 4, "meta": {}, "floating_ips": []}], "routes": [], "version": 4, "meta": {"dhcp_server": "10.0.0.1"}}, {"cidr": "fd::/64", "dns": [], "gateway": {"address": "fd::1", "type": "gateway", "version": 6, "meta": {}}, "ips": [{"address": "fd::f816:3eff:feb7:c7e5", "type": "fixed", "version": 6, "meta": {}, "floating_ips": []}], "routes": [], "version": 6, "meta": {"ipv6_address_mode": "slaac", "dhcp_server": "fd::1"}}], "meta": {"injected": false, "tenant_id": "0999c9c6e0c34e2792e91fd7e90e0525", "mtu": 1442, "physical_network": null, "tunneled": true}}, "type": "ovs", "details": {"port_filter": true, "connectivity": "l2", "bound_drivers": {"0": "ovn"}}, "devname": "tap38019df2-38", "ovs_interfaceid": "38019df2-3871-428d-9b73-3019a6743c26", "qbh_params": null, "qbg_params": null, "active": false, "vnic_type": "normal", "profile": {}, "preserve_on_delete": false, "delegate_create": true, "meta": {}}] {{(pid=818) update_instance_cache_with_nw_info /opt/stack/nova/nova/network/neutron.py:116}}
Jan 05 06:41:31 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Releasing lock "refresh_cache-6f0d001d-e53d-44f9-8383-62a2ab2925e2" {{(pid=818) lock /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:333}}
Jan 05 06:41:31 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] [instance: 6f0d001d-e53d-44f9-8383-62a2ab2925e2] Updated the network info_cache for instance {{(pid=818) _heal_instance_info_cache /opt/stack/nova/nova/compute/manager.py:10004}}
Jan 05 06:41:31 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._cleanup_expired_console_auth_tokens {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:41:36 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:41:41 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:41:41 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:41:41 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: idle 5002 ms, sending inactivity probe {{(pid=818) run /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:117}}
Jan 05 06:41:41 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering IDLE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:41:41 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering ACTIVE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:41:41 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:41:46 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:41:47 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_rebooting_instances {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:41:51 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:41:55 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._sync_scheduler_instance_info {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:41:56 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:41:56 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._reclaim_queued_deletes {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:41:56 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] CONF.reclaim_instance_interval <= 0, skipping... {{(pid=818) _reclaim_queued_deletes /opt/stack/nova/nova/compute/manager.py:10552}}
Jan 05 06:42:01 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:42:06 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:42:06 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:42:06 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: idle 5004 ms, sending inactivity probe {{(pid=818) run /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:117}}
Jan 05 06:42:06 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering IDLE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:42:06 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering ACTIVE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:42:06 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:42:11 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:42:11 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._run_pending_deletes {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:42:11 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Cleaning up deleted instances {{(pid=818) _run_pending_deletes /opt/stack/nova/nova/compute/manager.py:11220}}
Jan 05 06:42:11 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] There are 0 instances to clean {{(pid=818) _run_pending_deletes /opt/stack/nova/nova/compute/manager.py:11229}}
Jan 05 06:42:14 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._sync_power_states {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:42:14 ubuntu nova-compute[818]: WARNING nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] While synchronizing instance power states, found 2 instances in the database and 1 instances on the hypervisor.
Jan 05 06:42:14 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Triggering sync for uuid 6f0d001d-e53d-44f9-8383-62a2ab2925e2 {{(pid=818) _sync_power_states /opt/stack/nova/nova/compute/manager.py:10343}}
Jan 05 06:42:14 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Triggering sync for uuid 593ce529-fc99-43bb-95b4-af04851aaa7b {{(pid=818) _sync_power_states /opt/stack/nova/nova/compute/manager.py:10343}}
Jan 05 06:42:14 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquiring lock "6f0d001d-e53d-44f9-8383-62a2ab2925e2" by "nova.compute.manager.ComputeManager._sync_power_states.<locals>._sync.<locals>.query_driver_power_state_and_sync" {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:404}}
Jan 05 06:42:14 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "6f0d001d-e53d-44f9-8383-62a2ab2925e2" acquired by "nova.compute.manager.ComputeManager._sync_power_states.<locals>._sync.<locals>.query_driver_power_state_and_sync" :: waited 0.000s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:409}}
Jan 05 06:42:14 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquiring lock "593ce529-fc99-43bb-95b4-af04851aaa7b" by "nova.compute.manager.ComputeManager._sync_power_states.<locals>._sync.<locals>.query_driver_power_state_and_sync" {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:404}}
Jan 05 06:42:14 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "6f0d001d-e53d-44f9-8383-62a2ab2925e2" "released" by "nova.compute.manager.ComputeManager._sync_power_states.<locals>._sync.<locals>.query_driver_power_state_and_sync" :: held 0.021s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:423}}
Jan 05 06:42:15 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_unconfirmed_resizes {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:42:16 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:42:17 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_volume_usage {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:42:20 ubuntu nova-compute[818]: WARNING nova.virt.libvirt.driver [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Failed to soft reboot instance. Trying hard reboot.
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG nova.compute.manager [req-18aa99d4-d30e-4875-9f5e-6c996f04233d req-cc141b9f-6c26-4b80-b728-dd8cef40cbfa service nova] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Received event network-vif-unplugged-6d4bffeb-c603-48f7-9de2-f977d58e5340 {{(pid=818) external_instance_event /opt/stack/nova/nova/compute/manager.py:11123}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [req-18aa99d4-d30e-4875-9f5e-6c996f04233d req-cc141b9f-6c26-4b80-b728-dd8cef40cbfa service nova] Acquiring lock "593ce529-fc99-43bb-95b4-af04851aaa7b-events" by "nova.compute.manager.InstanceEvents.pop_instance_event.<locals>._pop_event" {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:404}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [req-18aa99d4-d30e-4875-9f5e-6c996f04233d req-cc141b9f-6c26-4b80-b728-dd8cef40cbfa service nova] Lock "593ce529-fc99-43bb-95b4-af04851aaa7b-events" acquired by "nova.compute.manager.InstanceEvents.pop_instance_event.<locals>._pop_event" :: waited 0.000s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:409}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [req-18aa99d4-d30e-4875-9f5e-6c996f04233d req-cc141b9f-6c26-4b80-b728-dd8cef40cbfa service nova] Lock "593ce529-fc99-43bb-95b4-af04851aaa7b-events" "released" by "nova.compute.manager.InstanceEvents.pop_instance_event.<locals>._pop_event" :: held 0.000s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:423}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG nova.compute.manager [req-18aa99d4-d30e-4875-9f5e-6c996f04233d req-cc141b9f-6c26-4b80-b728-dd8cef40cbfa service nova] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] No waiting events found dispatching network-vif-unplugged-6d4bffeb-c603-48f7-9de2-f977d58e5340 {{(pid=818) pop_instance_event /opt/stack/nova/nova/compute/manager.py:320}}
Jan 05 06:42:20 ubuntu nova-compute[818]: WARNING nova.compute.manager [req-18aa99d4-d30e-4875-9f5e-6c996f04233d req-cc141b9f-6c26-4b80-b728-dd8cef40cbfa service nova] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Received unexpected event network-vif-unplugged-6d4bffeb-c603-48f7-9de2-f977d58e5340 for instance with vm_state active and task_state reboot_started.
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_rescued_instances {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:42:20 ubuntu nova-compute[818]: INFO nova.virt.libvirt.driver [-] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Instance destroyed successfully.
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG nova.objects.instance [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Lazy-loading 'resources' on Instance uuid 593ce529-fc99-43bb-95b4-af04851aaa7b {{(pid=818) obj_load_attr /opt/stack/nova/nova/objects/instance.py:1141}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG nova.virt.libvirt.vif [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] vif_type=ovs instance=Instance(access_ip_v4=None,access_ip_v6=None,architecture=None,auto_disk_config=False,availability_zone='nova',cell_name=None,cleaned=False,compute_id=1,config_drive='',created_at=2024-01-05T06:39:01Z,default_ephemeral_device=None,default_swap_device=None,deleted=False,deleted_at=None,device_metadata=<?>,disable_terminate=False,display_description='vm1',display_name='vm1',ec2_ids=<?>,ephemeral_gb=0,ephemeral_key_uuid=None,fault=<?>,flavor=Flavor(6),hidden=False,host='ubuntu',hostname='vm1',id=6,image_ref='',info_cache=InstanceInfoCache,instance_type_id=6,kernel_id='',key_data=None,key_name=None,keypairs=<?>,launch_index=0,launched_at=2024-01-05T06:39:12Z,launched_on='ubuntu',locked=False,locked_by=None,memory_mb=512,metadata={},migration_context=<?>,new_flavor=None,node='ubuntu',numa_topology=None,old_flavor=None,os_type=None,pci_devices=<?>,pci_requests=<?>,power_state=1,progress=0,project_id='579be1cd090145bcaca1938a594f13a3',ramdisk_id='',reservation_id='r-g5dd50i6',resources=None,root_device_name='/dev/vda',root_gb=1,security_groups=SecurityGroupList,services=<?>,shutdown_terminate=False,system_metadata={boot_roles='manager,reader,admin,member',image_base_image_ref='',image_container_format='bare',image_disk_format='qcow2',image_hw_cdrom_bus='ide',image_hw_disk_bus='virtio',image_hw_input_bus=None,image_hw_machine_type='pc',image_hw_pointer_model=None,image_hw_rng_model='virtio',image_hw_video_model='virtio',image_hw_vif_model='virtio',image_min_disk='1',image_min_ram='0',image_owner_specified.openstack.md5='',image_owner_specified.openstack.object='images/cirros-0.6.2-x86_64-disk',image_owner_specified.openstack.sha256='',owner_project_name='admin',owner_user_name='admin'},tags=<?>,task_state='reboot_started',terminated_at=None,trusted_certs=<?>,updated_at=2024-01-05T06:40:19Z,user_data=None,user_id='cf3d8447466a4bb3ae4f24e2c5a9b021',uuid=593ce529-fc99-43bb-95b4-af04851aaa7b,vcpu_model=<?>,vcpus=1,vm_mode=None,vm_state='active') vif={"id": "6d4bffeb-c603-48f7-9de2-f977d58e5340", "address": "fa:16:3e:04:6d:dc", "network": {"id": "621767bb-46e7-4e6c-9683-b8653ff57922", "bridge": "br-int", "label": "private", "subnets": [{"cidr": "10.0.0.0/26", "dns": [], "gateway": {"address": "10.0.0.1", "type": "gateway", "version": 4, "meta": {}}, "ips": [{"address": "10.0.0.31", "type": "fixed", "version": 4, "meta": {}, "floating_ips": []}], "routes": [], "version": 4, "meta": {"dhcp_server": "10.0.0.1"}}, {"cidr": "fd::/64", "dns": [], "gateway": {"address": "fd::1", "type": "gateway", "version": 6, "meta": {}}, "ips": [{"address": "fd::f816:3eff:fe04:6ddc", "type": "fixed", "version": 6, "meta": {}, "floating_ips": []}], "routes": [], "version": 6, "meta": {"ipv6_address_mode": "slaac", "dhcp_server": "fd::1"}}], "meta": {"injected": false, "tenant_id": "0999c9c6e0c34e2792e91fd7e90e0525", "mtu": 1442, "physical_network": null, "tunneled": true}}, "type": "ovs", "details": {"port_filter": true, "connectivity": "l2", "bound_drivers": {"0": "ovn"}}, "devname": "tap6d4bffeb-c6", "ovs_interfaceid": "6d4bffeb-c603-48f7-9de2-f977d58e5340", "qbh_params": null, "qbg_params": null, "active": true, "vnic_type": "normal", "profile": {}, "preserve_on_delete": false, "delegate_create": true, "meta": {}} {{(pid=818) unplug /opt/stack/nova/nova/virt/libvirt/vif.py:837}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG nova.network.os_vif_util [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Converting VIF {"id": "6d4bffeb-c603-48f7-9de2-f977d58e5340", "address": "fa:16:3e:04:6d:dc", "network": {"id": "621767bb-46e7-4e6c-9683-b8653ff57922", "bridge": "br-int", "label": "private", "subnets": [{"cidr": "10.0.0.0/26", "dns": [], "gateway": {"address": "10.0.0.1", "type": "gateway", "version": 4, "meta": {}}, "ips": [{"address": "10.0.0.31", "type": "fixed", "version": 4, "meta": {}, "floating_ips": []}], "routes": [], "version": 4, "meta": {"dhcp_server": "10.0.0.1"}}, {"cidr": "fd::/64", "dns": [], "gateway": {"address": "fd::1", "type": "gateway", "version": 6, "meta": {}}, "ips": [{"address": "fd::f816:3eff:fe04:6ddc", "type": "fixed", "version": 6, "meta": {}, "floating_ips": []}], "routes": [], "version": 6, "meta": {"ipv6_address_mode": "slaac", "dhcp_server": "fd::1"}}], "meta": {"injected": false, "tenant_id": "0999c9c6e0c34e2792e91fd7e90e0525", "mtu": 1442, "physical_network": null, "tunneled": true}}, "type": "ovs", "details": {"port_filter": true, "connectivity": "l2", "bound_drivers": {"0": "ovn"}}, "devname": "tap6d4bffeb-c6", "ovs_interfaceid": "6d4bffeb-c603-48f7-9de2-f977d58e5340", "qbh_params": null, "qbg_params": null, "active": true, "vnic_type": "normal", "profile": {}, "preserve_on_delete": false, "delegate_create": true, "meta": {}} {{(pid=818) nova_to_osvif_vif /opt/stack/nova/nova/network/os_vif_util.py:511}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG nova.network.os_vif_util [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Converted object VIFOpenVSwitch(active=True,address=fa:16:3e:04:6d:dc,bridge_name='br-int',has_traffic_filtering=True,id=6d4bffeb-c603-48f7-9de2-f977d58e5340,network=Network(621767bb-46e7-4e6c-9683-b8653ff57922),plugin='ovs',port_profile=VIFPortProfileOpenVSwitch,preserve_on_delete=False,vif_name='tap6d4bffeb-c6') {{(pid=818) nova_to_osvif_vif /opt/stack/nova/nova/network/os_vif_util.py:548}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG os_vif [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Unplugging vif VIFOpenVSwitch(active=True,address=fa:16:3e:04:6d:dc,bridge_name='br-int',has_traffic_filtering=True,id=6d4bffeb-c603-48f7-9de2-f977d58e5340,network=Network(621767bb-46e7-4e6c-9683-b8653ff57922),plugin='ovs',port_profile=VIFPortProfileOpenVSwitch,preserve_on_delete=False,vif_name='tap6d4bffeb-c6') {{(pid=818) unplug /opt/stack/data/venv/lib/python3.10/site-packages/os_vif/__init__.py:109}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 16 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.transaction [-] Running txn n=1 command(idx=0): DelPortCommand(_result=None, port=tap6d4bffeb-c6, bridge=br-int, if_exists=True) {{(pid=818) do_commit /opt/stack/data/venv/lib/python3.10/site-packages/ovsdbapp/backend/ovs_idl/transaction.py:89}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 16 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.transaction [-] Running txn n=1 command(idx=0): DbDestroyCommand(_result=None, table=QoS, record=71136716-e406-4f87-bfe1-3eb44b7336ea) {{(pid=818) do_commit /opt/stack/data/venv/lib/python3.10/site-packages/ovsdbapp/backend/ovs_idl/transaction.py:89}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 0-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:42:20 ubuntu nova-compute[818]: INFO os_vif [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Successfully unplugged vif VIFOpenVSwitch(active=True,address=fa:16:3e:04:6d:dc,bridge_name='br-int',has_traffic_filtering=True,id=6d4bffeb-c603-48f7-9de2-f977d58e5340,network=Network(621767bb-46e7-4e6c-9683-b8653ff57922),plugin='ovs',port_profile=VIFPortProfileOpenVSwitch,preserve_on_delete=False,vif_name='tap6d4bffeb-c6')
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG nova.virt.libvirt.volume.iscsi [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] calling os-brick to detach iSCSI Volume {{(pid=818) disconnect_volume /opt/stack/nova/nova/virt/libvirt/volume/iscsi.py:72}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG os_brick.initiator.connectors.iscsi [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] ==> disconnect_volume: call "{'args': (<os_brick.initiator.connectors.iscsi.ISCSIConnector object at 0x7fa964488e50>, {'target_discovered': False, 'target_portal': '192.168.122.172:3260', 'target_iqn': 'iqn.2010-10.org.openstack:volume-5bdc7501-409d-4494-bba5-eb9f9d3b4081', 'target_lun': 0, 'volume_id': '5bdc7501-409d-4494-bba5-eb9f9d3b4081', 'auth_method': 'CHAP', 'auth_username': '9VDqPzqx7MCg8w9VV4TH', 'auth_password': '***', 'encrypted': False, 'qos_specs': None, 'access_mode': 'rw', 'cacheable': False, 'device_path': '/dev/sdc'}, None), 'kwargs': True}}" {{(pid=818) trace_logging_wrapper /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/utils.py:176}}
Jan 05 06:42:20 ubuntu nova-compute[818]: WARNING os_brick.initiator.connectors.base [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Service needs to call os_brick.setup() before connecting volumes, if it doesn't it will break on the next release
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG os_brick.initiator.connectors.base [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Acquiring lock "connect_volume" by "os_brick.initiator.connectors.iscsi.ISCSIConnector.disconnect_volume" {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/base.py:68}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG os_brick.initiator.connectors.base [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Lock "connect_volume" acquired by "os_brick.initiator.connectors.iscsi.ISCSIConnector.disconnect_volume" :: waited 0.001s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/base.py:73}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] Running cmd (subprocess): iscsiadm -m discoverydb -o show -P 1 {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:384}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] CMD "iscsiadm -m discoverydb -o show -P 1" returned: 0 in 0.006s {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:422}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo.privsep.daemon [-] privsep: reply[07955320-0d8b-4cee-bc96-15c9a11c0816]: (4, ('SENDTARGETS:\nNo targets found.\niSNS:\nNo targets found.\nSTATIC:\nTarget: iqn.2010-10.org.openstack:volume-f426186f-2a76-49b6-92f5-e7d11e8c0a6c\n\tPortal: 192.168.122.172:3260,-1\n\t\tIface Name: default\nTarget: iqn.2010-10.org.openstack:volume-5bdc7501-409d-4494-bba5-eb9f9d3b4081\n\tPortal: 192.168.122.172:3260,-1\n\t\tIface Name: default\nTarget: iqn.2010-10.org.openstack:volume-5d651d4e-d17f-4794-8f78-2ce2c55f6695\n\tPortal: 192.168.122.172:3260,-1\n\t\tIface Name: default\nFIRMWARE:\nNo targets found.\n', '')) {{(pid=7142) _call_back /opt/stack/data/venv/lib/python3.10/site-packages/oslo_privsep/daemon.py:499}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG os_brick.initiator.connectors.iscsi [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] iscsiadm ['-m', 'discoverydb', '-o', 'show', '-P', 1]: stdout=SENDTARGETS:
Jan 05 06:42:20 ubuntu nova-compute[818]: No targets found.
Jan 05 06:42:20 ubuntu nova-compute[818]: iSNS:
Jan 05 06:42:20 ubuntu nova-compute[818]: No targets found.
Jan 05 06:42:20 ubuntu nova-compute[818]: STATIC:
Jan 05 06:42:20 ubuntu nova-compute[818]: Target: iqn.2010-10.org.openstack:volume-f426186f-2a76-49b6-92f5-e7d11e8c0a6c
Jan 05 06:42:20 ubuntu nova-compute[818]:         Portal: 192.168.122.172:3260,-1
Jan 05 06:42:20 ubuntu nova-compute[818]:                 Iface Name: default
Jan 05 06:42:20 ubuntu nova-compute[818]: Target: iqn.2010-10.org.openstack:volume-5bdc7501-409d-4494-bba5-eb9f9d3b4081
Jan 05 06:42:20 ubuntu nova-compute[818]:         Portal: 192.168.122.172:3260,-1
Jan 05 06:42:20 ubuntu nova-compute[818]:                 Iface Name: default
Jan 05 06:42:20 ubuntu nova-compute[818]: Target: iqn.2010-10.org.openstack:volume-5d651d4e-d17f-4794-8f78-2ce2c55f6695
Jan 05 06:42:20 ubuntu nova-compute[818]:         Portal: 192.168.122.172:3260,-1
Jan 05 06:42:20 ubuntu nova-compute[818]:                 Iface Name: default
Jan 05 06:42:20 ubuntu nova-compute[818]: FIRMWARE:
Jan 05 06:42:20 ubuntu nova-compute[818]: No targets found.
Jan 05 06:42:20 ubuntu nova-compute[818]:  stderr= {{(pid=818) _run_iscsiadm_bare /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1193}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG os_brick.initiator.connectors.iscsi [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Regex to get portals from discoverydb: ^SENDTARGETS:
Jan 05 06:42:20 ubuntu nova-compute[818]: .*?^DiscoveryAddress: 192.168.122.172,3260.*?
Jan 05 06:42:20 ubuntu nova-compute[818]: (.*?)^(?:DiscoveryAddress|iSNS):.* {{(pid=818) _get_discoverydb_portals /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:382}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG os_brick.initiator.connectors.iscsi [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Getting connected devices for (ips,iqns,luns)=[('192.168.122.172:3260', 'iqn.2010-10.org.openstack:volume-5bdc7501-409d-4494-bba5-eb9f9d3b4081', 0)] {{(pid=818) _get_connection_devices /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:830}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] Running cmd (subprocess): iscsiadm -m node {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:384}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] CMD "iscsiadm -m node" returned: 0 in 0.005s {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:422}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo.privsep.daemon [-] privsep: reply[3a1efa80-ac94-4398-b60b-c0616d7ebecd]: (4, ('192.168.122.172:3260,4294967295 iqn.2010-10.org.openstack:volume-5bdc7501-409d-4494-bba5-eb9f9d3b4081\n192.168.122.172:3260,4294967295 iqn.2010-10.org.openstack:volume-5d651d4e-d17f-4794-8f78-2ce2c55f6695\n192.168.122.172:3260,4294967295 iqn.2010-10.org.openstack:volume-f426186f-2a76-49b6-92f5-e7d11e8c0a6c\n', '')) {{(pid=7142) _call_back /opt/stack/data/venv/lib/python3.10/site-packages/oslo_privsep/daemon.py:499}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] Running cmd (subprocess): iscsiadm -m session {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:384}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] CMD "iscsiadm -m session" returned: 0 in 0.006s {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:422}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo.privsep.daemon [-] privsep: reply[c4eae12d-ae16-4f4c-9160-784bf76cfe26]: (4, ('tcp: [2] 192.168.122.172:3260,1 iqn.2010-10.org.openstack:volume-f426186f-2a76-49b6-92f5-e7d11e8c0a6c (non-flash)\ntcp: [3] 192.168.122.172:3260,1 iqn.2010-10.org.openstack:volume-5d651d4e-d17f-4794-8f78-2ce2c55f6695 (non-flash)\ntcp: [4] 192.168.122.172:3260,1 iqn.2010-10.org.openstack:volume-5bdc7501-409d-4494-bba5-eb9f9d3b4081 (non-flash)\n', '')) {{(pid=7142) _call_back /opt/stack/data/venv/lib/python3.10/site-packages/oslo_privsep/daemon.py:499}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG os_brick.initiator.connectors.iscsi [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] iscsiadm ('-m', 'session'): stdout=tcp: [2] 192.168.122.172:3260,1 iqn.2010-10.org.openstack:volume-f426186f-2a76-49b6-92f5-e7d11e8c0a6c (non-flash)
Jan 05 06:42:20 ubuntu nova-compute[818]: tcp: [3] 192.168.122.172:3260,1 iqn.2010-10.org.openstack:volume-5d651d4e-d17f-4794-8f78-2ce2c55f6695 (non-flash)
Jan 05 06:42:20 ubuntu nova-compute[818]: tcp: [4] 192.168.122.172:3260,1 iqn.2010-10.org.openstack:volume-5bdc7501-409d-4494-bba5-eb9f9d3b4081 (non-flash)
Jan 05 06:42:20 ubuntu nova-compute[818]:  stderr= {{(pid=818) _run_iscsiadm_bare /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1193}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG os_brick.initiator.connectors.iscsi [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] iscsi session list stdout=tcp: [2] 192.168.122.172:3260,1 iqn.2010-10.org.openstack:volume-f426186f-2a76-49b6-92f5-e7d11e8c0a6c (non-flash)
Jan 05 06:42:20 ubuntu nova-compute[818]: tcp: [3] 192.168.122.172:3260,1 iqn.2010-10.org.openstack:volume-5d651d4e-d17f-4794-8f78-2ce2c55f6695 (non-flash)
Jan 05 06:42:20 ubuntu nova-compute[818]: tcp: [4] 192.168.122.172:3260,1 iqn.2010-10.org.openstack:volume-5bdc7501-409d-4494-bba5-eb9f9d3b4081 (non-flash)
Jan 05 06:42:20 ubuntu nova-compute[818]:  stderr= {{(pid=818) _run_iscsi_session /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1182}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG os_brick.initiator.connectors.iscsi [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Resulting device map defaultdict(<function ISCSIConnector._get_connection_devices.<locals>.<lambda> at 0x7fa9646ebeb0>, {('192.168.122.172:3260', 'iqn.2010-10.org.openstack:volume-5bdc7501-409d-4494-bba5-eb9f9d3b4081'): ({'sdc'}, set())}) {{(pid=818) _get_connection_devices /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:863}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG os_brick.initiator.linuxscsi [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Removing single pathed devices sdc {{(pid=818) remove_connection /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/linuxscsi.py:374}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] Running cmd (subprocess): multipathd show status {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:384}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] CMD "multipathd show status" returned: 0 in 0.006s {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:422}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo.privsep.daemon [-] privsep: reply[65cbb989-f662-47c2-9610-8f08b36788b0]: (4, ('path checker states:\nup                  3\n\npaths: 0\nbusy: False\n', '')) {{(pid=7142) _call_back /opt/stack/data/venv/lib/python3.10/site-packages/oslo_privsep/daemon.py:499}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] Running cmd (subprocess): multipathd del path /dev/sdc {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:384}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] CMD "multipathd del path /dev/sdc" returned: 0 in 0.006s {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:422}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo.privsep.daemon [-] privsep: reply[cc7bc514-c16d-422b-81c1-1df0120f141d]: (4, ('ok\n', '')) {{(pid=7142) _call_back /opt/stack/data/venv/lib/python3.10/site-packages/oslo_privsep/daemon.py:499}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG os_brick.initiator.linuxscsi [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Flushing IO for device /dev/sdc {{(pid=818) flush_device_io /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/linuxscsi.py:434}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] Running cmd (subprocess): blockdev --flushbufs /dev/sdc {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:384}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] CMD "blockdev --flushbufs /dev/sdc" returned: 1 in 0.004s {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:422}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] 'blockdev --flushbufs /dev/sdc' failed. Retrying. {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:477}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] Running cmd (subprocess): blockdev --flushbufs /dev/sdc {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:384}}
Jan 05 06:42:20 ubuntu nova-compute[818]: DEBUG os_brick.privileged.rootwrap [-] Sleeping for 20 seconds {{(pid=7142) on_execute /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/privileged/rootwrap.py:106}}
Jan 05 06:42:22 ubuntu nova-compute[818]: DEBUG nova.compute.manager [req-da37c51e-9f19-4689-bcad-0e04f1021c3b req-0655f60d-2c6b-49ef-8ecd-ed4546519b7f service nova] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Received event network-vif-plugged-6d4bffeb-c603-48f7-9de2-f977d58e5340 {{(pid=818) external_instance_event /opt/stack/nova/nova/compute/manager.py:11123}}
Jan 05 06:42:22 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [req-da37c51e-9f19-4689-bcad-0e04f1021c3b req-0655f60d-2c6b-49ef-8ecd-ed4546519b7f service nova] Acquiring lock "593ce529-fc99-43bb-95b4-af04851aaa7b-events" by "nova.compute.manager.InstanceEvents.pop_instance_event.<locals>._pop_event" {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:404}}
Jan 05 06:42:22 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [req-da37c51e-9f19-4689-bcad-0e04f1021c3b req-0655f60d-2c6b-49ef-8ecd-ed4546519b7f service nova] Lock "593ce529-fc99-43bb-95b4-af04851aaa7b-events" acquired by "nova.compute.manager.InstanceEvents.pop_instance_event.<locals>._pop_event" :: waited 0.000s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:409}}
Jan 05 06:42:22 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [req-da37c51e-9f19-4689-bcad-0e04f1021c3b req-0655f60d-2c6b-49ef-8ecd-ed4546519b7f service nova] Lock "593ce529-fc99-43bb-95b4-af04851aaa7b-events" "released" by "nova.compute.manager.InstanceEvents.pop_instance_event.<locals>._pop_event" :: held 0.000s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:423}}
Jan 05 06:42:22 ubuntu nova-compute[818]: DEBUG nova.compute.manager [req-da37c51e-9f19-4689-bcad-0e04f1021c3b req-0655f60d-2c6b-49ef-8ecd-ed4546519b7f service nova] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] No waiting events found dispatching network-vif-plugged-6d4bffeb-c603-48f7-9de2-f977d58e5340 {{(pid=818) pop_instance_event /opt/stack/nova/nova/compute/manager.py:320}}
Jan 05 06:42:22 ubuntu nova-compute[818]: WARNING nova.compute.manager [req-da37c51e-9f19-4689-bcad-0e04f1021c3b req-0655f60d-2c6b-49ef-8ecd-ed4546519b7f service nova] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Received unexpected event network-vif-plugged-6d4bffeb-c603-48f7-9de2-f977d58e5340 for instance with vm_state active and task_state reboot_started.
Jan 05 06:42:24 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._check_instance_build_time {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:42:25 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:42:27 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._instance_usage_audit {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager.update_available_resource {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquiring lock "compute_resources" by "nova.compute.resource_tracker.ResourceTracker.clean_compute_node_cache" {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:404}}
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "compute_resources" acquired by "nova.compute.resource_tracker.ResourceTracker.clean_compute_node_cache" :: waited 0.001s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:409}}
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "compute_resources" "released" by "nova.compute.resource_tracker.ResourceTracker.clean_compute_node_cache" :: held 0.000s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:423}}
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Auditing locally available compute resources for ubuntu (node: ubuntu) {{(pid=818) update_available_resource /opt/stack/nova/nova/compute/resource_tracker.py:907}}
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG nova.virt.libvirt.driver [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] skipping disk /dev/sdc (vda) as it is a volume {{(pid=818) _get_instance_disk_info_from_config /opt/stack/nova/nova/virt/libvirt/driver.py:11263}}
Jan 05 06:42:29 ubuntu nova-compute[818]: WARNING nova.virt.libvirt.driver [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] This host appears to have multiple sockets per NUMA node. The `socket` PCI NUMA affinity will not be supported.
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Hypervisor/Node resource view: name=ubuntu free_ram=3512MB free_disk=1.7358856201171875GB free_vcpus=4 pci_devices=[{"dev_id": "pci_0000_00_1f_2", "address": "0000:00:1f.2", "product_id": "2922", "vendor_id": "8086", "numa_node": null, "label": "label_8086_2922", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_3", "address": "0000:00:02.3", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_1b_0", "address": "0000:00:1b.0", "product_id": "293e", "vendor_id": "8086", "numa_node": null, "label": "label_8086_293e", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_04_00_0", "address": "0000:04:00.0", "product_id": "1042", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1042", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_01_0", "address": "0000:00:01.0", "product_id": "0100", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_0100", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_00_0", "address": "0000:00:00.0", "product_id": "29c0", "vendor_id": "8086", "numa_node": null, "label": "label_8086_29c0", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_0", "address": "0000:00:02.0", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_06_00_0", "address": "0000:06:00.0", "product_id": "1044", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1044", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_05_00_0", "address": "0000:05:00.0", "product_id": "1045", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1045", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_6", "address": "0000:00:02.6", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_03_00_0", "address": "0000:03:00.0", "product_id": "1043", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1043", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_02_00_0", "address": "0000:02:00.0", "product_id": "000d", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000d", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_1f_3", "address": "0000:00:1f.3", "product_id": "2930", "vendor_id": "8086", "numa_node": null, "label": "label_8086_2930", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_01_00_0", "address": "0000:01:00.0", "product_id": "1041", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1041", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_5", "address": "0000:00:02.5", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_1", "address": "0000:00:02.1", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_1f_0", "address": "0000:00:1f.0", "product_id": "2918", "vendor_id": "8086", "numa_node": null, "label": "label_8086_2918", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_2", "address": "0000:00:02.2", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_4", "address": "0000:00:02.4", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}] {{(pid=818) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:1106}}
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquiring lock "compute_resources" by "nova.compute.resource_tracker.ResourceTracker._update_available_resource" {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:404}}
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "compute_resources" acquired by "nova.compute.resource_tracker.ResourceTracker._update_available_resource" :: waited 0.000s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:409}}
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Instance 6f0d001d-e53d-44f9-8383-62a2ab2925e2 actively managed on this compute host and has allocations in placement: {'resources': {'MEMORY_MB': 512, 'VCPU': 1}}. {{(pid=818) _remove_deleted_instances_allocations /opt/stack/nova/nova/compute/resource_tracker.py:1707}}
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Instance 593ce529-fc99-43bb-95b4-af04851aaa7b actively managed on this compute host and has allocations in placement: {'resources': {'MEMORY_MB': 512, 'VCPU': 1}}. {{(pid=818) _remove_deleted_instances_allocations /opt/stack/nova/nova/compute/resource_tracker.py:1707}}
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Total usable vcpus: 4, total allocated vcpus: 2 {{(pid=818) _report_final_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:1129}}
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Final resource view: name=ubuntu phys_ram=7937MB used_ram=1536MB phys_disk=13GB used_disk=0GB total_vcpus=4 used_vcpus=2 pci_stats=[] {{(pid=818) _report_final_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:1138}}
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG nova.scheduler.client.report [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Refreshing inventories for resource provider 6460a2b5-3d32-408b-92ef-54c8918273eb {{(pid=818) _refresh_associations /opt/stack/nova/nova/scheduler/client/report.py:804}}
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG nova.scheduler.client.report [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Updating ProviderTree inventory for provider 6460a2b5-3d32-408b-92ef-54c8918273eb from _refresh_and_get_inventory using data: {'VCPU': {'total': 4, 'reserved': 0, 'min_unit': 1, 'max_unit': 4, 'step_size': 1, 'allocation_ratio': 4.0}, 'MEMORY_MB': {'total': 7937, 'reserved': 512, 'min_unit': 1, 'max_unit': 7937, 'step_size': 1, 'allocation_ratio': 1.0}, 'DISK_GB': {'total': 13, 'reserved': 0, 'min_unit': 1, 'max_unit': 13, 'step_size': 1, 'allocation_ratio': 1.0}} {{(pid=818) _refresh_and_get_inventory /opt/stack/nova/nova/scheduler/client/report.py:768}}
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG nova.compute.provider_tree [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Updating inventory in ProviderTree for provider 6460a2b5-3d32-408b-92ef-54c8918273eb with inventory: {'VCPU': {'total': 4, 'reserved': 0, 'min_unit': 1, 'max_unit': 4, 'step_size': 1, 'allocation_ratio': 4.0}, 'MEMORY_MB': {'total': 7937, 'reserved': 512, 'min_unit': 1, 'max_unit': 7937, 'step_size': 1, 'allocation_ratio': 1.0}, 'DISK_GB': {'total': 13, 'reserved': 0, 'min_unit': 1, 'max_unit': 13, 'step_size': 1, 'allocation_ratio': 1.0}} {{(pid=818) update_inventory /opt/stack/nova/nova/compute/provider_tree.py:176}}
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG nova.scheduler.client.report [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Refreshing aggregate associations for resource provider 6460a2b5-3d32-408b-92ef-54c8918273eb, aggregates: None {{(pid=818) _refresh_associations /opt/stack/nova/nova/scheduler/client/report.py:813}}
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG nova.scheduler.client.report [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Refreshing trait associations for resource provider 6460a2b5-3d32-408b-92ef-54c8918273eb, traits: HW_CPU_X86_SSSE3,HW_CPU_X86_SSE41,COMPUTE_VIOMMU_MODEL_AUTO,HW_CPU_X86_SSE2,COMPUTE_STORAGE_BUS_SATA,COMPUTE_GRAPHICS_MODEL_VIRTIO,COMPUTE_SECURITY_UEFI_SECURE_BOOT,COMPUTE_IMAGE_TYPE_ISO,COMPUTE_IMAGE_TYPE_RAW,COMPUTE_TRUSTED_CERTS,COMPUTE_STORAGE_BUS_FDC,COMPUTE_SOCKET_PCI_NUMA_AFFINITY,HW_CPU_X86_SSE42,COMPUTE_NET_ATTACH_INTERFACE,COMPUTE_NET_VIF_MODEL_SPAPR_VLAN,COMPUTE_VIOMMU_MODEL_INTEL,COMPUTE_NET_VIRTIO_PACKED,COMPUTE_STORAGE_BUS_IDE,COMPUTE_NET_VIF_MODEL_E1000,COMPUTE_RESCUE_BFV,COMPUTE_IMAGE_TYPE_AMI,COMPUTE_VOLUME_ATTACH_WITH_TAG,COMPUTE_ACCELERATORS,COMPUTE_STORAGE_BUS_USB,COMPUTE_NET_VIF_MODEL_VIRTIO,COMPUTE_GRAPHICS_MODEL_VMVGA,COMPUTE_IMAGE_TYPE_AKI,COMPUTE_STORAGE_BUS_SCSI,COMPUTE_IMAGE_TYPE_QCOW2,COMPUTE_NET_VIF_MODEL_NE2K_PCI,COMPUTE_NET_VIF_MODEL_PCNET,COMPUTE_GRAPHICS_MODEL_CIRRUS,COMPUTE_NET_VIF_MODEL_VMXNET3,COMPUTE_NET_VIF_MODEL_E1000E,COMPUTE_NET_ATTACH_INTERFACE_WITH_TAG,COMPUTE_GRAPHICS_MODEL_QXL,COMPUTE_VOLUME_MULTI_ATTACH,COMPUTE_NODE,COMPUTE_DEVICE_TAGGING,HW_CPU_X86_MMX,COMPUTE_GRAPHICS_MODEL_VGA,COMPUTE_NET_VIF_MODEL_RTL8139,HW_CPU_X86_SSE,COMPUTE_STORAGE_BUS_VIRTIO,COMPUTE_GRAPHICS_MODEL_NONE,COMPUTE_VOLUME_EXTEND,COMPUTE_IMAGE_TYPE_ARI,COMPUTE_GRAPHICS_MODEL_BOCHS {{(pid=818) _refresh_associations /opt/stack/nova/nova/scheduler/client/report.py:825}}
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG nova.compute.provider_tree [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Inventory has not changed in ProviderTree for provider: 6460a2b5-3d32-408b-92ef-54c8918273eb {{(pid=818) update_inventory /opt/stack/nova/nova/compute/provider_tree.py:180}}
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG nova.scheduler.client.report [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Inventory has not changed for provider 6460a2b5-3d32-408b-92ef-54c8918273eb based on inventory data: {'VCPU': {'total': 4, 'reserved': 0, 'min_unit': 1, 'max_unit': 4, 'step_size': 1, 'allocation_ratio': 4.0}, 'MEMORY_MB': {'total': 7937, 'reserved': 512, 'min_unit': 1, 'max_unit': 7937, 'step_size': 1, 'allocation_ratio': 1.0}, 'DISK_GB': {'total': 13, 'reserved': 0, 'min_unit': 1, 'max_unit': 13, 'step_size': 1, 'allocation_ratio': 1.0}} {{(pid=818) set_inventory_for_provider /opt/stack/nova/nova/scheduler/client/report.py:940}}
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Compute_service record updated for ubuntu:ubuntu {{(pid=818) _update_available_resource /opt/stack/nova/nova/compute/resource_tracker.py:1067}}
Jan 05 06:42:29 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "compute_resources" "released" by "nova.compute.resource_tracker.ResourceTracker._update_available_resource" :: held 0.151s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:423}}
Jan 05 06:42:30 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:42:30 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._heal_instance_info_cache {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:42:30 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Starting heal instance info cache {{(pid=818) _heal_instance_info_cache /opt/stack/nova/nova/compute/manager.py:9933}}
Jan 05 06:42:31 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquiring lock "refresh_cache-593ce529-fc99-43bb-95b4-af04851aaa7b" {{(pid=818) lock /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:312}}
Jan 05 06:42:31 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquired lock "refresh_cache-593ce529-fc99-43bb-95b4-af04851aaa7b" {{(pid=818) lock /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:315}}
Jan 05 06:42:31 ubuntu nova-compute[818]: DEBUG nova.network.neutron [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Forcefully refreshing network info cache for instance {{(pid=818) _get_instance_nw_info /opt/stack/nova/nova/network/neutron.py:2003}}
Jan 05 06:42:31 ubuntu nova-compute[818]: DEBUG nova.network.neutron [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Updating instance_info_cache with network_info: [{"id": "6d4bffeb-c603-48f7-9de2-f977d58e5340", "address": "fa:16:3e:04:6d:dc", "network": {"id": "621767bb-46e7-4e6c-9683-b8653ff57922", "bridge": "br-int", "label": "private", "subnets": [{"cidr": "10.0.0.0/26", "dns": [], "gateway": {"address": "10.0.0.1", "type": "gateway", "version": 4, "meta": {}}, "ips": [{"address": "10.0.0.31", "type": "fixed", "version": 4, "meta": {}, "floating_ips": []}], "routes": [], "version": 4, "meta": {"dhcp_server": "10.0.0.1"}}, {"cidr": "fd::/64", "dns": [], "gateway": {"address": "fd::1", "type": "gateway", "version": 6, "meta": {}}, "ips": [{"address": "fd::f816:3eff:fe04:6ddc", "type": "fixed", "version": 6, "meta": {}, "floating_ips": []}], "routes": [], "version": 6, "meta": {"ipv6_address_mode": "slaac", "dhcp_server": "fd::1"}}], "meta": {"injected": false, "tenant_id": "0999c9c6e0c34e2792e91fd7e90e0525", "mtu": 1442, "physical_network": null, "tunneled": true}}, "type": "ovs", "details": {"port_filter": true, "connectivity": "l2", "bound_drivers": {"0": "ovn"}}, "devname": "tap6d4bffeb-c6", "ovs_interfaceid": "6d4bffeb-c603-48f7-9de2-f977d58e5340", "qbh_params": null, "qbg_params": null, "active": false, "vnic_type": "normal", "profile": {}, "preserve_on_delete": false, "delegate_create": true, "meta": {}}] {{(pid=818) update_instance_cache_with_nw_info /opt/stack/nova/nova/network/neutron.py:116}}
Jan 05 06:42:31 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Releasing lock "refresh_cache-593ce529-fc99-43bb-95b4-af04851aaa7b" {{(pid=818) lock /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:333}}
Jan 05 06:42:31 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Updated the network info_cache for instance {{(pid=818) _heal_instance_info_cache /opt/stack/nova/nova/compute/manager.py:10004}}
Jan 05 06:42:35 ubuntu nova-compute[818]: DEBUG nova.virt.driver [-] Emitting event <LifecycleEvent: 1704436940.7222445, 593ce529-fc99-43bb-95b4-af04851aaa7b => Stopped> {{(pid=818) emit_event /opt/stack/nova/nova/virt/driver.py:1659}}
Jan 05 06:42:35 ubuntu nova-compute[818]: INFO nova.compute.manager [-] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] VM Stopped (Lifecycle Event)
Jan 05 06:42:35 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:42:35 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-b072027e-6b68-46e6-8d70-aad8c7c55874 None None] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Checking state {{(pid=818) _get_power_state /opt/stack/nova/nova/compute/manager.py:1782}}
Jan 05 06:42:35 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-b072027e-6b68-46e6-8d70-aad8c7c55874 None None] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Synchronizing instance power state after lifecycle event "Stopped"; current vm_state: active, current task_state: reboot_started, current DB power_state: 1, VM power_state: 4 {{(pid=818) handle_lifecycle_event /opt/stack/nova/nova/compute/manager.py:1398}}
Jan 05 06:42:35 ubuntu nova-compute[818]: INFO nova.compute.manager [None req-b072027e-6b68-46e6-8d70-aad8c7c55874 None None] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] During sync_power_state the instance has a pending task (reboot_started). Skip.
Jan 05 06:42:40 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:42:40 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] CMD "blockdev --flushbufs /dev/sdc" returned: 1 in 20.023s {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:422}}
Jan 05 06:42:40 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] 'blockdev --flushbufs /dev/sdc' failed. Retrying. {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:477}}
Jan 05 06:42:40 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] Running cmd (subprocess): blockdev --flushbufs /dev/sdc {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:384}}
Jan 05 06:42:40 ubuntu nova-compute[818]: DEBUG os_brick.privileged.rootwrap [-] Sleeping for 40 seconds {{(pid=7142) on_execute /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/privileged/rootwrap.py:106}}
Jan 05 06:42:43 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._cleanup_incomplete_migrations {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:42:43 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Cleaning up deleted instances with incomplete migration  {{(pid=818) _cleanup_incomplete_migrations /opt/stack/nova/nova/compute/manager.py:11258}}
Jan 05 06:42:45 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:42:45 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 0-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:42:45 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: idle 5003 ms, sending inactivity probe {{(pid=818) run /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:117}}
Jan 05 06:42:45 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering IDLE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:42:45 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering ACTIVE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:42:45 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 0-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:42:47 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_rebooting_instances {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:42:50 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:42:55 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:42:57 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._reclaim_queued_deletes {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:42:57 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] CONF.reclaim_instance_interval <= 0, skipping... {{(pid=818) _reclaim_queued_deletes /opt/stack/nova/nova/compute/manager.py:10552}}
Jan 05 06:43:00 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:43:00 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 0-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:43:00 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: idle 5003 ms, sending inactivity probe {{(pid=818) run /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:117}}
Jan 05 06:43:00 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering IDLE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:43:00 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering ACTIVE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:43:00 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:43:05 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:43:10 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:43:15 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:43:17 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_unconfirmed_resizes {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:43:19 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_volume_usage {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:43:20 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:43:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] CMD "blockdev --flushbufs /dev/sdc" returned: 1 in 40.052s {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:422}}
Jan 05 06:43:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] 'blockdev --flushbufs /dev/sdc' failed. Not Retrying. {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:473}}
Jan 05 06:43:20 ubuntu nova-compute[818]: DEBUG oslo.privsep.daemon [-] privsep: Exception during request[1e63250e-d1b6-47ac-99eb-f64ac04be082]: Unexpected error while running command.
Jan 05 06:43:20 ubuntu nova-compute[818]: Command: blockdev --flushbufs /dev/sdc
Jan 05 06:43:20 ubuntu nova-compute[818]: Exit code: 1
Jan 05 06:43:20 ubuntu nova-compute[818]: Stdout: ''
Jan 05 06:43:20 ubuntu nova-compute[818]: Stderr: 'blockdev: cannot open /dev/sdc: No such device or address\n' {{(pid=7142) _process_cmd /opt/stack/data/venv/lib/python3.10/site-packages/oslo_privsep/daemon.py:477}}
Jan 05 06:43:20 ubuntu nova-compute[818]: Traceback (most recent call last):
Jan 05 06:43:20 ubuntu nova-compute[818]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_privsep/daemon.py", line 474, in _process_cmd
Jan 05 06:43:20 ubuntu nova-compute[818]:     ret = func(*f_args, **f_kwargs)
Jan 05 06:43:20 ubuntu nova-compute[818]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_privsep/priv_context.py", line 274, in _wrap
Jan 05 06:43:20 ubuntu nova-compute[818]:     return func(*args, **kwargs)
Jan 05 06:43:20 ubuntu nova-compute[818]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/privileged/rootwrap.py", line 197, in execute_root
Jan 05 06:43:20 ubuntu nova-compute[818]:     return custom_execute(*cmd, shell=False, run_as_root=False, **kwargs)
Jan 05 06:43:20 ubuntu nova-compute[818]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/privileged/rootwrap.py", line 145, in custom_execute
Jan 05 06:43:20 ubuntu nova-compute[818]:     return putils.execute(on_execute=on_execute,
Jan 05 06:43:20 ubuntu nova-compute[818]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py", line 438, in execute
Jan 05 06:43:20 ubuntu nova-compute[818]:     raise ProcessExecutionError(exit_code=_returncode,
Jan 05 06:43:20 ubuntu nova-compute[818]: oslo_concurrency.processutils.ProcessExecutionError: Unexpected error while running command.
Jan 05 06:43:20 ubuntu nova-compute[818]: Command: blockdev --flushbufs /dev/sdc
Jan 05 06:43:20 ubuntu nova-compute[818]: Exit code: 1
Jan 05 06:43:20 ubuntu nova-compute[818]: Stdout: ''
Jan 05 06:43:20 ubuntu nova-compute[818]: Stderr: 'blockdev: cannot open /dev/sdc: No such device or address\n'
Jan 05 06:43:20 ubuntu nova-compute[818]: DEBUG oslo.privsep.daemon [-] privsep: reply[1e63250e-d1b6-47ac-99eb-f64ac04be082]: (5, 'oslo_concurrency.processutils.ProcessExecutionError', ('', 'blockdev: cannot open /dev/sdc: No such device or address\n', 1, 'blockdev --flushbufs /dev/sdc', None)) {{(pid=7142) _call_back /opt/stack/data/venv/lib/python3.10/site-packages/oslo_privsep/daemon.py:499}}
Jan 05 06:43:20 ubuntu nova-compute[818]: WARNING os_brick.initiator.linuxscsi [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Failed to flush IO buffers prior to removing device: 1: oslo_concurrency.processutils.ProcessExecutionError: Unexpected error while running command.
Jan 05 06:43:20 ubuntu nova-compute[818]: WARNING os_brick.exception [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Flushing /dev/sdc failed: oslo_concurrency.processutils.ProcessExecutionError: Unexpected error while running command.
Jan 05 06:43:20 ubuntu nova-compute[818]: DEBUG os_brick.initiator.linuxscsi [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Remove SCSI device /dev/sdc with /sys/block/sdc/device/delete {{(pid=818) remove_scsi_device /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/linuxscsi.py:148}}
Jan 05 06:43:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] Running cmd (subprocess): tee -a /sys/block/sdc/device/delete {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:384}}
Jan 05 06:43:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] CMD "tee -a /sys/block/sdc/device/delete" returned: 0 in 0.055s {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:422}}
Jan 05 06:43:20 ubuntu nova-compute[818]: DEBUG oslo.privsep.daemon [-] privsep: reply[5241fa90-2617-460b-bd88-47f3b27e19a5]: (4, ('1', '')) {{(pid=7142) _call_back /opt/stack/data/venv/lib/python3.10/site-packages/oslo_privsep/daemon.py:499}}
Jan 05 06:43:20 ubuntu nova-compute[818]: DEBUG os_brick.initiator.linuxscsi [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Checking to see if SCSI volumes sdc have been removed. {{(pid=818) wait_for_volumes_removal /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/linuxscsi.py:156}}
Jan 05 06:43:20 ubuntu nova-compute[818]: DEBUG os_brick.initiator.linuxscsi [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] SCSI volumes sdc have been removed. {{(pid=818) wait_for_volumes_removal /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/linuxscsi.py:166}}
Jan 05 06:43:20 ubuntu nova-compute[818]: DEBUG os_brick.initiator.connectors.iscsi [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Disconnecting from: [('192.168.122.172:3260', 'iqn.2010-10.org.openstack:volume-5bdc7501-409d-4494-bba5-eb9f9d3b4081')] {{(pid=818) _disconnect_connection /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1171}}
Jan 05 06:43:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] Running cmd (subprocess): iscsiadm -m node -T iqn.2010-10.org.openstack:volume-5bdc7501-409d-4494-bba5-eb9f9d3b4081 -p 192.168.122.172:3260 --op update -n node.startup -v manual {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:384}}
Jan 05 06:43:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] CMD "iscsiadm -m node -T iqn.2010-10.org.openstack:volume-5bdc7501-409d-4494-bba5-eb9f9d3b4081 -p 192.168.122.172:3260 --op update -n node.startup -v manual" returned: 0 in 0.010s {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:422}}
Jan 05 06:43:20 ubuntu nova-compute[818]: DEBUG oslo.privsep.daemon [-] privsep: reply[c0dd2200-b909-41b8-ba0d-91935a5f6932]: (4, ('', '')) {{(pid=7142) _call_back /opt/stack/data/venv/lib/python3.10/site-packages/oslo_privsep/daemon.py:499}}
Jan 05 06:43:20 ubuntu nova-compute[818]: DEBUG os_brick.initiator.connectors.iscsi [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] iscsiadm ('--op', 'update', '-n', 'node.startup', '-v', 'manual'): stdout= stderr= {{(pid=818) _run_iscsiadm /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1037}}
Jan 05 06:43:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] Running cmd (subprocess): iscsiadm -m node -T iqn.2010-10.org.openstack:volume-5bdc7501-409d-4494-bba5-eb9f9d3b4081 -p 192.168.122.172:3260 --logout {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:384}}
Jan 05 06:43:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] CMD "iscsiadm -m node -T iqn.2010-10.org.openstack:volume-5bdc7501-409d-4494-bba5-eb9f9d3b4081 -p 192.168.122.172:3260 --logout" returned: 0 in 0.030s {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:422}}
Jan 05 06:43:20 ubuntu nova-compute[818]: DEBUG oslo.privsep.daemon [-] privsep: reply[775a8f4c-aa9d-4315-b303-09a7a9e7d959]: (4, ('Logging out of session [sid: 4, target: iqn.2010-10.org.openstack:volume-5bdc7501-409d-4494-bba5-eb9f9d3b4081, portal: 192.168.122.172,3260]\nLogout of [sid: 4, target: iqn.2010-10.org.openstack:volume-5bdc7501-409d-4494-bba5-eb9f9d3b4081, portal: 192.168.122.172,3260] successful.\n', '')) {{(pid=7142) _call_back /opt/stack/data/venv/lib/python3.10/site-packages/oslo_privsep/daemon.py:499}}
Jan 05 06:43:20 ubuntu nova-compute[818]: DEBUG os_brick.initiator.connectors.iscsi [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] iscsiadm ('--logout',): stdout=Logging out of session [sid: 4, target: iqn.2010-10.org.openstack:volume-5bdc7501-409d-4494-bba5-eb9f9d3b4081, portal: 192.168.122.172,3260]
Jan 05 06:43:20 ubuntu nova-compute[818]: Logout of [sid: 4, target: iqn.2010-10.org.openstack:volume-5bdc7501-409d-4494-bba5-eb9f9d3b4081, portal: 192.168.122.172,3260] successful.
Jan 05 06:43:20 ubuntu nova-compute[818]:  stderr= {{(pid=818) _run_iscsiadm /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1037}}
Jan 05 06:43:20 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] Running cmd (subprocess): iscsiadm -m node -T iqn.2010-10.org.openstack:volume-5bdc7501-409d-4494-bba5-eb9f9d3b4081 -p 192.168.122.172:3260 --op delete {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:384}}
Jan 05 06:43:21 ubuntu nova-compute[818]: DEBUG oslo_concurrency.processutils [-] CMD "iscsiadm -m node -T iqn.2010-10.org.openstack:volume-5bdc7501-409d-4494-bba5-eb9f9d3b4081 -p 192.168.122.172:3260 --op delete" returned: 0 in 0.010s {{(pid=7142) execute /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/processutils.py:422}}
Jan 05 06:43:21 ubuntu nova-compute[818]: DEBUG oslo.privsep.daemon [-] privsep: reply[54dc4501-6399-4076-aa06-d26863408272]: (4, ('', '')) {{(pid=7142) _call_back /opt/stack/data/venv/lib/python3.10/site-packages/oslo_privsep/daemon.py:499}}
Jan 05 06:43:21 ubuntu nova-compute[818]: DEBUG os_brick.initiator.connectors.iscsi [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] iscsiadm ('--op', 'delete'): stdout= stderr= {{(pid=818) _run_iscsiadm /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1037}}
Jan 05 06:43:21 ubuntu nova-compute[818]: WARNING os_brick.initiator.connectors.iscsi [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] There were errors removing {'sdc'}, leftovers may remain in the system
Jan 05 06:43:21 ubuntu nova-compute[818]: DEBUG os_brick.initiator.connectors.base [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Lock "connect_volume" "released" by "os_brick.initiator.connectors.iscsi.ISCSIConnector.disconnect_volume" :: held 60.257s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/base.py:87}}
Jan 05 06:43:21 ubuntu nova-compute[818]: DEBUG os_brick.initiator.connectors.iscsi [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] <== disconnect_volume: exception (60258ms)
Jan 05 06:43:21 ubuntu nova-compute[818]: Chained Exception #1
Jan 05 06:43:21 ubuntu nova-compute[818]:         Traceback (most recent call last):
Jan 05 06:43:21 ubuntu nova-compute[818]:           File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/linuxscsi.py", line 146, in remove_scsi_device
Jan 05 06:43:21 ubuntu nova-compute[818]:             self.flush_device_io(device)
Jan 05 06:43:21 ubuntu nova-compute[818]:           File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/linuxscsi.py", line 435, in flush_device_io
Jan 05 06:43:21 ubuntu nova-compute[818]:             self._execute('blockdev', '--flushbufs', device,
Jan 05 06:43:21 ubuntu nova-compute[818]:           File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/executor.py", line 55, in _execute
Jan 05 06:43:21 ubuntu nova-compute[818]:             result = self.__execute(*args, **kwargs)
Jan 05 06:43:21 ubuntu nova-compute[818]:           File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/privileged/rootwrap.py", line 172, in execute
Jan 05 06:43:21 ubuntu nova-compute[818]:             return execute_root(*cmd, **kwargs)
Jan 05 06:43:21 ubuntu nova-compute[818]:           File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_privsep/priv_context.py", line 271, in _wrap
Jan 05 06:43:21 ubuntu nova-compute[818]:             return self.channel.remote_call(name, args, kwargs,
Jan 05 06:43:21 ubuntu nova-compute[818]:           File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_privsep/daemon.py", line 215, in remote_call
Jan 05 06:43:21 ubuntu nova-compute[818]:             raise exc_type(*result[2])
Jan 05 06:43:21 ubuntu nova-compute[818]:         oslo_concurrency.processutils.ProcessExecutionError: Unexpected error while running command.
Jan 05 06:43:21 ubuntu nova-compute[818]:         Command: blockdev --flushbufs /dev/sdc
Jan 05 06:43:21 ubuntu nova-compute[818]:         Exit code: 1
Jan 05 06:43:21 ubuntu nova-compute[818]:         Stdout: ''
Jan 05 06:43:21 ubuntu nova-compute[818]:         Stderr: 'blockdev: cannot open /dev/sdc: No such device or address\n'
Jan 05 06:43:21 ubuntu nova-compute[818]:          {{(pid=818) trace_logging_wrapper /opt/stack/data/venv/lib/python3.10/site-packages/os_brick/utils.py:189}}
Jan 05 06:43:21 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Checking state {{(pid=818) _get_power_state /opt/stack/nova/nova/compute/manager.py:1782}}
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR nova.compute.manager [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Cannot reboot instance:
Jan 05 06:43:21 ubuntu nova-compute[818]: Chained Exception #1
Jan 05 06:43:21 ubuntu nova-compute[818]:         Traceback (most recent call last):
Jan 05 06:43:21 ubuntu nova-compute[818]:           File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/linuxscsi.py", line 146, in remove_scsi_device
Jan 05 06:43:21 ubuntu nova-compute[818]:             self.flush_device_io(device)
Jan 05 06:43:21 ubuntu nova-compute[818]:           File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/linuxscsi.py", line 435, in flush_device_io
Jan 05 06:43:21 ubuntu nova-compute[818]:             self._execute('blockdev', '--flushbufs', device,
Jan 05 06:43:21 ubuntu nova-compute[818]:           File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/executor.py", line 55, in _execute
Jan 05 06:43:21 ubuntu nova-compute[818]:             result = self.__execute(*args, **kwargs)
Jan 05 06:43:21 ubuntu nova-compute[818]:           File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/privileged/rootwrap.py", line 172, in execute
Jan 05 06:43:21 ubuntu nova-compute[818]:             return execute_root(*cmd, **kwargs)
Jan 05 06:43:21 ubuntu nova-compute[818]:           File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_privsep/priv_context.py", line 271, in _wrap
Jan 05 06:43:21 ubuntu nova-compute[818]:             return self.channel.remote_call(name, args, kwargs,
Jan 05 06:43:21 ubuntu nova-compute[818]:           File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_privsep/daemon.py", line 215, in remote_call
Jan 05 06:43:21 ubuntu nova-compute[818]:             raise exc_type(*result[2])
Jan 05 06:43:21 ubuntu nova-compute[818]:         oslo_concurrency.processutils.ProcessExecutionError: Unexpected error while running command.
Jan 05 06:43:21 ubuntu nova-compute[818]:         Command: blockdev --flushbufs /dev/sdc
Jan 05 06:43:21 ubuntu nova-compute[818]:         Exit code: 1
Jan 05 06:43:21 ubuntu nova-compute[818]:         Stdout: ''
Jan 05 06:43:21 ubuntu nova-compute[818]:         Stderr: 'blockdev: cannot open /dev/sdc: No such device or address\n'
Jan 05 06:43:21 ubuntu nova-compute[818]:         : os_brick.exception.ExceptionChainer: 
Jan 05 06:43:21 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Lock "593ce529-fc99-43bb-95b4-af04851aaa7b" "released" by "nova.compute.manager.ComputeManager.reboot_instance.<locals>.do_reboot_instance" :: held 184.421s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:423}}
Jan 05 06:43:21 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "593ce529-fc99-43bb-95b4-af04851aaa7b" acquired by "nova.compute.manager.ComputeManager._sync_power_states.<locals>._sync.<locals>.query_driver_power_state_and_sync" :: waited 66.543s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:409}}
Jan 05 06:43:21 ubuntu nova-compute[818]: INFO nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] During sync_power_state the instance has a pending task (reboot_started). Skip.
Jan 05 06:43:21 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "593ce529-fc99-43bb-95b4-af04851aaa7b" "released" by "nova.compute.manager.ComputeManager._sync_power_states.<locals>._sync.<locals>.query_driver_power_state_and_sync" :: held 0.001s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:423}}
Jan 05 06:43:21 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Acquiring lock "compute_resources" by "nova.compute.resource_tracker.ResourceTracker.update_usage" {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:404}}
Jan 05 06:43:21 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Lock "compute_resources" acquired by "nova.compute.resource_tracker.ResourceTracker.update_usage" :: waited 0.000s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:409}}
Jan 05 06:43:21 ubuntu nova-compute[818]: DEBUG nova.compute.provider_tree [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Inventory has not changed in ProviderTree for provider: 6460a2b5-3d32-408b-92ef-54c8918273eb {{(pid=818) update_inventory /opt/stack/nova/nova/compute/provider_tree.py:180}}
Jan 05 06:43:21 ubuntu nova-compute[818]: DEBUG nova.scheduler.client.report [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Inventory has not changed for provider 6460a2b5-3d32-408b-92ef-54c8918273eb based on inventory data: {'VCPU': {'total': 4, 'reserved': 0, 'min_unit': 1, 'max_unit': 4, 'step_size': 1, 'allocation_ratio': 4.0}, 'MEMORY_MB': {'total': 7937, 'reserved': 512, 'min_unit': 1, 'max_unit': 7937, 'step_size': 1, 'allocation_ratio': 1.0}, 'DISK_GB': {'total': 13, 'reserved': 0, 'min_unit': 1, 'max_unit': 13, 'step_size': 1, 'allocation_ratio': 1.0}} {{(pid=818) set_inventory_for_provider /opt/stack/nova/nova/scheduler/client/report.py:940}}
Jan 05 06:43:21 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Lock "compute_resources" "released" by "nova.compute.resource_tracker.ResourceTracker.update_usage" :: held 0.164s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:423}}
Jan 05 06:43:21 ubuntu nova-compute[818]: INFO nova.compute.manager [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Successfully reverted task state from reboot_started on failure for instance.
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server [None req-e1701144-dfe4-4735-bee7-07a4a3667c54 admin admin] Exception during message handling: os_brick.exception.ExceptionChainer:
Jan 05 06:43:21 ubuntu nova-compute[818]: Chained Exception #1
Jan 05 06:43:21 ubuntu nova-compute[818]:         Traceback (most recent call last):
Jan 05 06:43:21 ubuntu nova-compute[818]:           File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/linuxscsi.py", line 146, in remove_scsi_device
Jan 05 06:43:21 ubuntu nova-compute[818]:             self.flush_device_io(device)
Jan 05 06:43:21 ubuntu nova-compute[818]:           File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/linuxscsi.py", line 435, in flush_device_io
Jan 05 06:43:21 ubuntu nova-compute[818]:             self._execute('blockdev', '--flushbufs', device,
Jan 05 06:43:21 ubuntu nova-compute[818]:           File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/executor.py", line 55, in _execute
Jan 05 06:43:21 ubuntu nova-compute[818]:             result = self.__execute(*args, **kwargs)
Jan 05 06:43:21 ubuntu nova-compute[818]:           File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/privileged/rootwrap.py", line 172, in execute
Jan 05 06:43:21 ubuntu nova-compute[818]:             return execute_root(*cmd, **kwargs)
Jan 05 06:43:21 ubuntu nova-compute[818]:           File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_privsep/priv_context.py", line 271, in _wrap
Jan 05 06:43:21 ubuntu nova-compute[818]:             return self.channel.remote_call(name, args, kwargs,
Jan 05 06:43:21 ubuntu nova-compute[818]:           File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_privsep/daemon.py", line 215, in remote_call
Jan 05 06:43:21 ubuntu nova-compute[818]:             raise exc_type(*result[2])
Jan 05 06:43:21 ubuntu nova-compute[818]:         oslo_concurrency.processutils.ProcessExecutionError: Unexpected error while running command.
Jan 05 06:43:21 ubuntu nova-compute[818]:         Command: blockdev --flushbufs /dev/sdc
Jan 05 06:43:21 ubuntu nova-compute[818]:         Exit code: 1
Jan 05 06:43:21 ubuntu nova-compute[818]:         Stdout: ''
Jan 05 06:43:21 ubuntu nova-compute[818]:         Stderr: 'blockdev: cannot open /dev/sdc: No such device or address\n'
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server Traceback (most recent call last):
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/rpc/server.py", line 165, in _process_incoming
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     res = self.dispatcher.dispatch(message)
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/rpc/dispatcher.py", line 309, in dispatch
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     return self._do_dispatch(endpoint, method, ctxt, args)
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/rpc/dispatcher.py", line 229, in _do_dispatch
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     result = func(ctxt, **new_args)
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/nova/nova/exception_wrapper.py", line 65, in wrapped
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     with excutils.save_and_reraise_exception():
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 227, in __exit__
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     self.force_reraise()
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 200, in force_reraise
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     raise self.value
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/nova/nova/exception_wrapper.py", line 63, in wrapped
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     return f(self, context, *args, **kw)
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/nova/nova/compute/manager.py", line 166, in decorated_function
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     with excutils.save_and_reraise_exception():
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 227, in __exit__
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     self.force_reraise()
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 200, in force_reraise
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     raise self.value
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/nova/nova/compute/manager.py", line 157, in decorated_function
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     return function(self, context, *args, **kwargs)
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/nova/nova/compute/utils.py", line 1453, in decorated_function
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     return function(self, context, *args, **kwargs)
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/nova/nova/compute/manager.py", line 213, in decorated_function
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     with excutils.save_and_reraise_exception():
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 227, in __exit__
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     self.force_reraise()
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 200, in force_reraise
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     raise self.value
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/nova/nova/compute/manager.py", line 203, in decorated_function
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     return function(self, context, *args, **kwargs)
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/nova/nova/compute/manager.py", line 4266, in reboot_instance
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     do_reboot_instance(context, instance, block_device_info, reboot_type)
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py", line 414, in inner
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     return f(*args, **kwargs)
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/nova/nova/compute/manager.py", line 4264, in do_reboot_instance
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     self._reboot_instance(context, instance, block_device_info,
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/nova/nova/compute/manager.py", line 4339, in _reboot_instance
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     with excutils.save_and_reraise_exception() as ctxt:
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 227, in __exit__
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     self.force_reraise()
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 200, in force_reraise
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     raise self.value
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/nova/nova/compute/manager.py", line 4331, in _reboot_instance
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     self.driver.reboot(context, instance,
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 3912, in reboot
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     return self._hard_reboot(context, instance, network_info,
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 3982, in _hard_reboot
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     self.destroy(context, instance, network_info, destroy_disks=False,
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 1561, in destroy
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     self.cleanup(context, instance, network_info, block_device_info,
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 1631, in cleanup
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     return self._cleanup(
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 1686, in _cleanup
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     with excutils.save_and_reraise_exception() as ctxt:
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 227, in __exit__
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     self.force_reraise()
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 200, in force_reraise
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     raise self.value
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 1682, in _cleanup
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     self._disconnect_volume(
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 2013, in _disconnect_volume
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     vol_driver.disconnect_volume(
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/nova/nova/virt/libvirt/volume/iscsi.py", line 74, in disconnect_volume
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     self.connector.disconnect_volume(
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/utils.py", line 186, in trace_logging_wrapper
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     result = f(*args, **kwargs)
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/base.py", line 78, in inner
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     return f(*args, **kwargs)
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/utils.py", line 405, in change_encrypted
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     res = func(**call_args)
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py", line 891, in disconnect_volume
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     return self._cleanup_connection(connection_properties, force=force,
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server   File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py", line 969, in _cleanup_connection
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server     raise exc  # type: ignore
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server os_brick.exception.ExceptionChainer:
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server Chained Exception #1
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server         Traceback (most recent call last):
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server           File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/linuxscsi.py", line 146, in remove_scsi_device
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server             self.flush_device_io(device)
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server           File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/initiator/linuxscsi.py", line 435, in flush_device_io
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server             self._execute('blockdev', '--flushbufs', device,
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server           File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/executor.py", line 55, in _execute
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server             result = self.__execute(*args, **kwargs)
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server           File "/opt/stack/data/venv/lib/python3.10/site-packages/os_brick/privileged/rootwrap.py", line 172, in execute
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server             return execute_root(*cmd, **kwargs)
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server           File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_privsep/priv_context.py", line 271, in _wrap
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server             return self.channel.remote_call(name, args, kwargs,
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server           File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_privsep/daemon.py", line 215, in remote_call
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server             raise exc_type(*result[2])
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server         oslo_concurrency.processutils.ProcessExecutionError: Unexpected error while running command.
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server         Command: blockdev --flushbufs /dev/sdc
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server         Exit code: 1
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server         Stdout: ''
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server         Stderr: 'blockdev: cannot open /dev/sdc: No such device or address\n'
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server 
Jan 05 06:43:21 ubuntu nova-compute[818]: ERROR oslo_messaging.rpc.server 
Jan 05 06:43:21 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_rescued_instances {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:43:24 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._check_instance_build_time {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:43:25 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:43:29 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._instance_usage_audit {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:43:30 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager.update_available_resource {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:43:30 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquiring lock "compute_resources" by "nova.compute.resource_tracker.ResourceTracker.clean_compute_node_cache" {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:404}}
Jan 05 06:43:30 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "compute_resources" acquired by "nova.compute.resource_tracker.ResourceTracker.clean_compute_node_cache" :: waited 0.001s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:409}}
Jan 05 06:43:30 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "compute_resources" "released" by "nova.compute.resource_tracker.ResourceTracker.clean_compute_node_cache" :: held 0.001s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:423}}
Jan 05 06:43:30 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Auditing locally available compute resources for ubuntu (node: ubuntu) {{(pid=818) update_available_resource /opt/stack/nova/nova/compute/resource_tracker.py:907}}
Jan 05 06:43:30 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:43:30 ubuntu nova-compute[818]: DEBUG nova.virt.libvirt.driver [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] skipping disk /dev/sdc (vda) as it is a volume {{(pid=818) _get_instance_disk_info_from_config /opt/stack/nova/nova/virt/libvirt/driver.py:11263}}
Jan 05 06:43:30 ubuntu nova-compute[818]: WARNING nova.virt.libvirt.driver [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] This host appears to have multiple sockets per NUMA node. The `socket` PCI NUMA affinity will not be supported.
Jan 05 06:43:30 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Hypervisor/Node resource view: name=ubuntu free_ram=3497MB free_disk=1.735565185546875GB free_vcpus=4 pci_devices=[{"dev_id": "pci_0000_00_1f_2", "address": "0000:00:1f.2", "product_id": "2922", "vendor_id": "8086", "numa_node": null, "label": "label_8086_2922", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_3", "address": "0000:00:02.3", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_1b_0", "address": "0000:00:1b.0", "product_id": "293e", "vendor_id": "8086", "numa_node": null, "label": "label_8086_293e", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_04_00_0", "address": "0000:04:00.0", "product_id": "1042", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1042", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_01_0", "address": "0000:00:01.0", "product_id": "0100", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_0100", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_00_0", "address": "0000:00:00.0", "product_id": "29c0", "vendor_id": "8086", "numa_node": null, "label": "label_8086_29c0", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_0", "address": "0000:00:02.0", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_06_00_0", "address": "0000:06:00.0", "product_id": "1044", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1044", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_05_00_0", "address": "0000:05:00.0", "product_id": "1045", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1045", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_6", "address": "0000:00:02.6", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_03_00_0", "address": "0000:03:00.0", "product_id": "1043", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1043", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_02_00_0", "address": "0000:02:00.0", "product_id": "000d", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000d", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_1f_3", "address": "0000:00:1f.3", "product_id": "2930", "vendor_id": "8086", "numa_node": null, "label": "label_8086_2930", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_01_00_0", "address": "0000:01:00.0", "product_id": "1041", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1041", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_5", "address": "0000:00:02.5", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_1", "address": "0000:00:02.1", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_1f_0", "address": "0000:00:1f.0", "product_id": "2918", "vendor_id": "8086", "numa_node": null, "label": "label_8086_2918", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_2", "address": "0000:00:02.2", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_4", "address": "0000:00:02.4", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}] {{(pid=818) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:1106}}
Jan 05 06:43:30 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquiring lock "compute_resources" by "nova.compute.resource_tracker.ResourceTracker._update_available_resource" {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:404}}
Jan 05 06:43:30 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "compute_resources" acquired by "nova.compute.resource_tracker.ResourceTracker._update_available_resource" :: waited 0.000s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:409}}
Jan 05 06:43:30 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Instance 6f0d001d-e53d-44f9-8383-62a2ab2925e2 actively managed on this compute host and has allocations in placement: {'resources': {'MEMORY_MB': 512, 'VCPU': 1}}. {{(pid=818) _remove_deleted_instances_allocations /opt/stack/nova/nova/compute/resource_tracker.py:1707}}
Jan 05 06:43:30 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Instance 593ce529-fc99-43bb-95b4-af04851aaa7b actively managed on this compute host and has allocations in placement: {'resources': {'MEMORY_MB': 512, 'VCPU': 1}}. {{(pid=818) _remove_deleted_instances_allocations /opt/stack/nova/nova/compute/resource_tracker.py:1707}}
Jan 05 06:43:30 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Total usable vcpus: 4, total allocated vcpus: 2 {{(pid=818) _report_final_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:1129}}
Jan 05 06:43:30 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Final resource view: name=ubuntu phys_ram=7937MB used_ram=1536MB phys_disk=13GB used_disk=0GB total_vcpus=4 used_vcpus=2 pci_stats=[] {{(pid=818) _report_final_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:1138}}
Jan 05 06:43:30 ubuntu nova-compute[818]: DEBUG nova.compute.provider_tree [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Inventory has not changed in ProviderTree for provider: 6460a2b5-3d32-408b-92ef-54c8918273eb {{(pid=818) update_inventory /opt/stack/nova/nova/compute/provider_tree.py:180}}
Jan 05 06:43:31 ubuntu nova-compute[818]: DEBUG nova.scheduler.client.report [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Inventory has not changed for provider 6460a2b5-3d32-408b-92ef-54c8918273eb based on inventory data: {'VCPU': {'total': 4, 'reserved': 0, 'min_unit': 1, 'max_unit': 4, 'step_size': 1, 'allocation_ratio': 4.0}, 'MEMORY_MB': {'total': 7937, 'reserved': 512, 'min_unit': 1, 'max_unit': 7937, 'step_size': 1, 'allocation_ratio': 1.0}, 'DISK_GB': {'total': 13, 'reserved': 0, 'min_unit': 1, 'max_unit': 13, 'step_size': 1, 'allocation_ratio': 1.0}} {{(pid=818) set_inventory_for_provider /opt/stack/nova/nova/scheduler/client/report.py:940}}
Jan 05 06:43:31 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Compute_service record updated for ubuntu:ubuntu {{(pid=818) _update_available_resource /opt/stack/nova/nova/compute/resource_tracker.py:1067}}
Jan 05 06:43:31 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "compute_resources" "released" by "nova.compute.resource_tracker.ResourceTracker._update_available_resource" :: held 0.170s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:423}}
Jan 05 06:43:33 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._heal_instance_info_cache {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:43:33 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Starting heal instance info cache {{(pid=818) _heal_instance_info_cache /opt/stack/nova/nova/compute/manager.py:9933}}
Jan 05 06:43:33 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Rebuilding the list of instances to heal {{(pid=818) _heal_instance_info_cache /opt/stack/nova/nova/compute/manager.py:9937}}
Jan 05 06:43:33 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquiring lock "refresh_cache-6f0d001d-e53d-44f9-8383-62a2ab2925e2" {{(pid=818) lock /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:312}}
Jan 05 06:43:33 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquired lock "refresh_cache-6f0d001d-e53d-44f9-8383-62a2ab2925e2" {{(pid=818) lock /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:315}}
Jan 05 06:43:33 ubuntu nova-compute[818]: DEBUG nova.network.neutron [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] [instance: 6f0d001d-e53d-44f9-8383-62a2ab2925e2] Forcefully refreshing network info cache for instance {{(pid=818) _get_instance_nw_info /opt/stack/nova/nova/network/neutron.py:2003}}
Jan 05 06:43:33 ubuntu nova-compute[818]: DEBUG nova.objects.instance [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lazy-loading 'info_cache' on Instance uuid 6f0d001d-e53d-44f9-8383-62a2ab2925e2 {{(pid=818) obj_load_attr /opt/stack/nova/nova/objects/instance.py:1141}}
Jan 05 06:43:33 ubuntu nova-compute[818]: DEBUG nova.network.neutron [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] [instance: 6f0d001d-e53d-44f9-8383-62a2ab2925e2] Updating instance_info_cache with network_info: [{"id": "38019df2-3871-428d-9b73-3019a6743c26", "address": "fa:16:3e:b7:c7:e5", "network": {"id": "621767bb-46e7-4e6c-9683-b8653ff57922", "bridge": "br-int", "label": "private", "subnets": [{"cidr": "10.0.0.0/26", "dns": [], "gateway": {"address": "10.0.0.1", "type": "gateway", "version": 4, "meta": {}}, "ips": [{"address": "10.0.0.19", "type": "fixed", "version": 4, "meta": {}, "floating_ips": []}], "routes": [], "version": 4, "meta": {"dhcp_server": "10.0.0.1"}}, {"cidr": "fd::/64", "dns": [], "gateway": {"address": "fd::1", "type": "gateway", "version": 6, "meta": {}}, "ips": [{"address": "fd::f816:3eff:feb7:c7e5", "type": "fixed", "version": 6, "meta": {}, "floating_ips": []}], "routes": [], "version": 6, "meta": {"ipv6_address_mode": "slaac", "dhcp_server": "fd::1"}}], "meta": {"injected": false, "tenant_id": "0999c9c6e0c34e2792e91fd7e90e0525", "mtu": 1442, "physical_network": null, "tunneled": true}}, "type": "ovs", "details": {"port_filter": true, "connectivity": "l2", "bound_drivers": {"0": "ovn"}}, "devname": "tap38019df2-38", "ovs_interfaceid": "38019df2-3871-428d-9b73-3019a6743c26", "qbh_params": null, "qbg_params": null, "active": false, "vnic_type": "normal", "profile": {}, "preserve_on_delete": false, "delegate_create": true, "meta": {}}] {{(pid=818) update_instance_cache_with_nw_info /opt/stack/nova/nova/network/neutron.py:116}}
Jan 05 06:43:33 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Releasing lock "refresh_cache-6f0d001d-e53d-44f9-8383-62a2ab2925e2" {{(pid=818) lock /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:333}}
Jan 05 06:43:33 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] [instance: 6f0d001d-e53d-44f9-8383-62a2ab2925e2] Updated the network info_cache for instance {{(pid=818) _heal_instance_info_cache /opt/stack/nova/nova/compute/manager.py:10004}}
Jan 05 06:43:35 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:43:40 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:43:45 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:43:47 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_rebooting_instances {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:43:50 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:43:55 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._sync_scheduler_instance_info {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:43:55 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:43:55 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 0-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:43:55 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: idle 5002 ms, sending inactivity probe {{(pid=818) run /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:117}}
Jan 05 06:43:55 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering IDLE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:43:55 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering ACTIVE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:43:55 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:43:57 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._reclaim_queued_deletes {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:43:57 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] CONF.reclaim_instance_interval <= 0, skipping... {{(pid=818) _reclaim_queued_deletes /opt/stack/nova/nova/compute/manager.py:10552}}
Jan 05 06:44:00 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:44:05 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:44:10 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:44:15 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:44:17 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_unconfirmed_resizes {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:44:19 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_volume_usage {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:44:20 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:44:22 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_rescued_instances {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:44:25 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:44:26 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._check_instance_build_time {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:44:30 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager.update_available_resource {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:44:30 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquiring lock "compute_resources" by "nova.compute.resource_tracker.ResourceTracker.clean_compute_node_cache" {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:404}}
Jan 05 06:44:30 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "compute_resources" acquired by "nova.compute.resource_tracker.ResourceTracker.clean_compute_node_cache" :: waited 0.001s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:409}}
Jan 05 06:44:30 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "compute_resources" "released" by "nova.compute.resource_tracker.ResourceTracker.clean_compute_node_cache" :: held 0.000s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:423}}
Jan 05 06:44:30 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Auditing locally available compute resources for ubuntu (node: ubuntu) {{(pid=818) update_available_resource /opt/stack/nova/nova/compute/resource_tracker.py:907}}
Jan 05 06:44:30 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:44:30 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:44:30 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: idle 5002 ms, sending inactivity probe {{(pid=818) run /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:117}}
Jan 05 06:44:30 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering IDLE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:44:30 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering ACTIVE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:44:30 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:44:30 ubuntu nova-compute[818]: DEBUG nova.virt.libvirt.driver [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] skipping disk /dev/sdc (vda) as it is a volume {{(pid=818) _get_instance_disk_info_from_config /opt/stack/nova/nova/virt/libvirt/driver.py:11263}}
Jan 05 06:44:30 ubuntu nova-compute[818]: WARNING nova.virt.libvirt.driver [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] This host appears to have multiple sockets per NUMA node. The `socket` PCI NUMA affinity will not be supported.
Jan 05 06:44:30 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Hypervisor/Node resource view: name=ubuntu free_ram=3515MB free_disk=1.7352943420410156GB free_vcpus=4 pci_devices=[{"dev_id": "pci_0000_00_1f_2", "address": "0000:00:1f.2", "product_id": "2922", "vendor_id": "8086", "numa_node": null, "label": "label_8086_2922", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_3", "address": "0000:00:02.3", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_1b_0", "address": "0000:00:1b.0", "product_id": "293e", "vendor_id": "8086", "numa_node": null, "label": "label_8086_293e", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_04_00_0", "address": "0000:04:00.0", "product_id": "1042", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1042", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_01_0", "address": "0000:00:01.0", "product_id": "0100", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_0100", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_00_0", "address": "0000:00:00.0", "product_id": "29c0", "vendor_id": "8086", "numa_node": null, "label": "label_8086_29c0", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_0", "address": "0000:00:02.0", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_06_00_0", "address": "0000:06:00.0", "product_id": "1044", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1044", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_05_00_0", "address": "0000:05:00.0", "product_id": "1045", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1045", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_6", "address": "0000:00:02.6", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_03_00_0", "address": "0000:03:00.0", "product_id": "1043", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1043", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_02_00_0", "address": "0000:02:00.0", "product_id": "000d", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000d", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_1f_3", "address": "0000:00:1f.3", "product_id": "2930", "vendor_id": "8086", "numa_node": null, "label": "label_8086_2930", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_01_00_0", "address": "0000:01:00.0", "product_id": "1041", "vendor_id": "1af4", "numa_node": null, "label": "label_1af4_1041", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_5", "address": "0000:00:02.5", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_1", "address": "0000:00:02.1", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_1f_0", "address": "0000:00:1f.0", "product_id": "2918", "vendor_id": "8086", "numa_node": null, "label": "label_8086_2918", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_2", "address": "0000:00:02.2", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}, {"dev_id": "pci_0000_00_02_4", "address": "0000:00:02.4", "product_id": "000c", "vendor_id": "1b36", "numa_node": null, "label": "label_1b36_000c", "dev_type": "type-PCI"}] {{(pid=818) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:1106}}
Jan 05 06:44:30 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquiring lock "compute_resources" by "nova.compute.resource_tracker.ResourceTracker._update_available_resource" {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:404}}
Jan 05 06:44:30 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "compute_resources" acquired by "nova.compute.resource_tracker.ResourceTracker._update_available_resource" :: waited 0.000s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:409}}
Jan 05 06:44:30 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Instance 6f0d001d-e53d-44f9-8383-62a2ab2925e2 actively managed on this compute host and has allocations in placement: {'resources': {'MEMORY_MB': 512, 'VCPU': 1}}. {{(pid=818) _remove_deleted_instances_allocations /opt/stack/nova/nova/compute/resource_tracker.py:1707}}
Jan 05 06:44:30 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Instance 593ce529-fc99-43bb-95b4-af04851aaa7b actively managed on this compute host and has allocations in placement: {'resources': {'MEMORY_MB': 512, 'VCPU': 1}}. {{(pid=818) _remove_deleted_instances_allocations /opt/stack/nova/nova/compute/resource_tracker.py:1707}}
Jan 05 06:44:30 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Total usable vcpus: 4, total allocated vcpus: 2 {{(pid=818) _report_final_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:1129}}
Jan 05 06:44:30 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Final resource view: name=ubuntu phys_ram=7937MB used_ram=1536MB phys_disk=13GB used_disk=0GB total_vcpus=4 used_vcpus=2 pci_stats=[] {{(pid=818) _report_final_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:1138}}
Jan 05 06:44:31 ubuntu nova-compute[818]: DEBUG nova.compute.provider_tree [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Inventory has not changed in ProviderTree for provider: 6460a2b5-3d32-408b-92ef-54c8918273eb {{(pid=818) update_inventory /opt/stack/nova/nova/compute/provider_tree.py:180}}
Jan 05 06:44:31 ubuntu nova-compute[818]: DEBUG nova.scheduler.client.report [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Inventory has not changed for provider 6460a2b5-3d32-408b-92ef-54c8918273eb based on inventory data: {'VCPU': {'total': 4, 'reserved': 0, 'min_unit': 1, 'max_unit': 4, 'step_size': 1, 'allocation_ratio': 4.0}, 'MEMORY_MB': {'total': 7937, 'reserved': 512, 'min_unit': 1, 'max_unit': 7937, 'step_size': 1, 'allocation_ratio': 1.0}, 'DISK_GB': {'total': 13, 'reserved': 0, 'min_unit': 1, 'max_unit': 13, 'step_size': 1, 'allocation_ratio': 1.0}} {{(pid=818) set_inventory_for_provider /opt/stack/nova/nova/scheduler/client/report.py:940}}
Jan 05 06:44:31 ubuntu nova-compute[818]: DEBUG nova.compute.resource_tracker [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Compute_service record updated for ubuntu:ubuntu {{(pid=818) _update_available_resource /opt/stack/nova/nova/compute/resource_tracker.py:1067}}
Jan 05 06:44:31 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Lock "compute_resources" "released" by "nova.compute.resource_tracker.ResourceTracker._update_available_resource" :: held 0.136s {{(pid=818) inner /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:423}}
Jan 05 06:44:32 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._instance_usage_audit {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:44:32 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._heal_instance_info_cache {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:44:32 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Starting heal instance info cache {{(pid=818) _heal_instance_info_cache /opt/stack/nova/nova/compute/manager.py:9933}}
Jan 05 06:44:32 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquiring lock "refresh_cache-593ce529-fc99-43bb-95b4-af04851aaa7b" {{(pid=818) lock /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:312}}
Jan 05 06:44:32 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Acquired lock "refresh_cache-593ce529-fc99-43bb-95b4-af04851aaa7b" {{(pid=818) lock /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:315}}
Jan 05 06:44:32 ubuntu nova-compute[818]: DEBUG nova.network.neutron [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Forcefully refreshing network info cache for instance {{(pid=818) _get_instance_nw_info /opt/stack/nova/nova/network/neutron.py:2003}}
Jan 05 06:44:33 ubuntu nova-compute[818]: DEBUG nova.network.neutron [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Updating instance_info_cache with network_info: [{"id": "6d4bffeb-c603-48f7-9de2-f977d58e5340", "address": "fa:16:3e:04:6d:dc", "network": {"id": "621767bb-46e7-4e6c-9683-b8653ff57922", "bridge": "br-int", "label": "private", "subnets": [{"cidr": "10.0.0.0/26", "dns": [], "gateway": {"address": "10.0.0.1", "type": "gateway", "version": 4, "meta": {}}, "ips": [{"address": "10.0.0.31", "type": "fixed", "version": 4, "meta": {}, "floating_ips": []}], "routes": [], "version": 4, "meta": {"dhcp_server": "10.0.0.1"}}, {"cidr": "fd::/64", "dns": [], "gateway": {"address": "fd::1", "type": "gateway", "version": 6, "meta": {}}, "ips": [{"address": "fd::f816:3eff:fe04:6ddc", "type": "fixed", "version": 6, "meta": {}, "floating_ips": []}], "routes": [], "version": 6, "meta": {"ipv6_address_mode": "slaac", "dhcp_server": "fd::1"}}], "meta": {"injected": false, "tenant_id": "0999c9c6e0c34e2792e91fd7e90e0525", "mtu": 1442, "physical_network": null, "tunneled": true}}, "type": "ovs", "details": {"port_filter": true, "connectivity": "l2", "bound_drivers": {"0": "ovn"}}, "devname": "tap6d4bffeb-c6", "ovs_interfaceid": "6d4bffeb-c603-48f7-9de2-f977d58e5340", "qbh_params": null, "qbg_params": null, "active": false, "vnic_type": "normal", "profile": {}, "preserve_on_delete": false, "delegate_create": true, "meta": {}}] {{(pid=818) update_instance_cache_with_nw_info /opt/stack/nova/nova/network/neutron.py:116}}
Jan 05 06:44:33 ubuntu nova-compute[818]: DEBUG oslo_concurrency.lockutils [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Releasing lock "refresh_cache-593ce529-fc99-43bb-95b4-af04851aaa7b" {{(pid=818) lock /opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py:333}}
Jan 05 06:44:33 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] [instance: 593ce529-fc99-43bb-95b4-af04851aaa7b] Updated the network info_cache for instance {{(pid=818) _heal_instance_info_cache /opt/stack/nova/nova/compute/manager.py:10004}}
Jan 05 06:44:35 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:44:40 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:44:45 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:44:47 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_rebooting_instances {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:44:50 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:44:55 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4998-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:44:55 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 0-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:44:55 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: idle 5004 ms, sending inactivity probe {{(pid=818) run /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:117}}
Jan 05 06:44:55 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering IDLE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:44:55 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering ACTIVE {{(pid=818) _transition /opt/stack/data/venv/lib/python3.10/site-packages/ovs/reconnect.py:519}}
Jan 05 06:44:55 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:44:59 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._reclaim_queued_deletes {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:44:59 ubuntu nova-compute[818]: DEBUG nova.compute.manager [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] CONF.reclaim_instance_interval <= 0, skipping... {{(pid=818) _reclaim_queued_deletes /opt/stack/nova/nova/compute/manager.py:10552}}
Jan 05 06:45:00 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:45:05 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:45:10 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] 4999-ms timeout {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:248}}
Jan 05 06:45:15 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:45:18 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_unconfirmed_resizes {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}
Jan 05 06:45:20 ubuntu nova-compute[818]: DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 18 {{(pid=818) __log_wakeup /opt/stack/data/venv/lib/python3.10/site-packages/ovs/poller.py:263}}
Jan 05 06:45:21 ubuntu nova-compute[818]: DEBUG oslo_service.periodic_task [None req-630feb6d-9378-4cc3-9cbe-c6382b6adc19 None None] Running periodic task ComputeManager._poll_volume_usage {{(pid=818) run_periodic_tasks /opt/stack/data/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210}}