Public bug reported:

Logs:
https://ae5a8daa4540c7da75ef-0b252c7b71d313ec10c19ced03a4a34b.ssl.cf1.rackcdn.com/927182/1/check/neutron-
tempest-plugin-openvswitch-
iptables_hybrid-2023-2/1047b7f/testr_results.html

Test traceback:

```
Traceback (most recent call last):
  File "/opt/stack/tempest/tempest/lib/common/utils/test_utils.py", line 87, in 
call_and_ignore_notfound_exc
    return func(*args, **kwargs)
  File "/opt/stack/tempest/tempest/common/waiters.py", line 136, in 
wait_for_server_termination
    raise lib_exc.DeleteErrorException(details, server_id=server_id)
tempest.lib.exceptions.DeleteErrorException: Resource %(resource_id)s failed to 
delete and is in ERROR status
Details: Server f9acc6d9-132d-4ed8-875a-48fedb5b81b9 failed to delete and is in 
ERROR status. Fault: {'code': 500, 'created': '2024-09-05T13:56:54Z', 
'message': 'MessagingTimeout'}.
```

In n-cpu logs,
https://ae5a8daa4540c7da75ef-0b252c7b71d313ec10c19ced03a4a34b.ssl.cf1.rackcdn.com/927182/1/check/neutron-
tempest-plugin-openvswitch-
iptables_hybrid-2023-2/1047b7f/controller/logs/screen-n-cpu.txt:

```
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [None req-99b4aa7a-c470-4313-807c-d22d46b0ae38 
tempest-MulticastTestIPv4-1796741707 
tempest-MulticastTestIPv4-1796741707-project-member] [instance: 
f9acc6d9-132d-4ed8-875a-48fedb5b81b9] Setting instance vm_state to ERROR: 
oslo_messaging.exceptions.MessagingTimeout: Timed out waiting for a reply to 
message ID 1bb84ce3208146ae828a98299bf658ea
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9] Traceback 
(most recent call last):
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/_drivers/amqpdriver.py",
 line 441, in get
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
return self._queues[msg_id].get(block=True, timeout=timeout)
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/eventlet/queue.py", line 
322, in get
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
return waiter.wait()
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/eventlet/queue.py", line 
141, in wait
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
return get_hub().switch()
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/eventlet/hubs/hub.py", line 
313, in switch
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
return self.greenlet.switch()
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9] 
_queue.Empty
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9] 
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9] During 
handling of the above exception, another exception occurred:
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9] 
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9] Traceback 
(most recent call last):
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/nova/nova/compute/manager.py", line 3315, in do_terminate_instance
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
self._delete_instance(context, instance, bdms)
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/nova/nova/compute/manager.py", line 3279, in _delete_instance
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
self._complete_deletion(context, instance)
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/nova/nova/compute/manager.py", line 926, in _complete_deletion
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
self._update_resource_tracker(context, instance)
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/nova/nova/compute/manager.py", line 693, in _update_resource_tracker
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
self.rt.update_usage(context, instance, instance.node)
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py",
 line 414, in inner
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
return f(*args, **kwargs)
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/nova/nova/compute/resource_tracker.py", line 702, in update_usage
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
self._update(context.elevated(), self.compute_nodes[nodename])
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/nova/nova/compute/resource_tracker.py", line 1400, in _update
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     with 
excutils.save_and_reraise_exception(logger=LOG):
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", 
line 227, in __exit__
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
self.force_reraise()
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", 
line 200, in force_reraise
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     raise 
self.value
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/nova/nova/compute/resource_tracker.py", line 1395, in _update
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
compute_node.save()
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_versionedobjects/base.py",
 line 209, in wrapper
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
updates, result = self.indirection_api.object_action(
Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/nova/nova/conductor/rpcapi.py", line 247, in object_action
Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
return cctxt.call(context, 'object_action', objinst=objinst,
Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/rpc/client.py",
 line 190, in call
Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
result = self.transport._send(
Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/transport.py",
 line 123, in _send
Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
return self._driver.send(target, ctxt, message,
Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/_drivers/amqpdriver.py",
 line 689, in send
Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
return self._send(target, ctxt, message, wait_for_reply, timeout,
Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/_drivers/amqpdriver.py",
 line 678, in _send
Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
result = self._waiter.wait(msg_id, timeout,
Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/_drivers/amqpdriver.py",
 line 567, in wait
Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
message = self.waiters.get(msg_id, timeout=timeout)
Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/_drivers/amqpdriver.py",
 line 443, in get
Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     raise 
oslo_messaging.MessagingTimeout(
Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9] 
oslo_messaging.exceptions.MessagingTimeout: Timed out waiting for a reply to 
message ID 1bb84ce3208146ae828a98299bf658ea
Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]
```

I checked conductor and api logs but could find anything relevant there.
Rabbitmq logs seem fine too.

n-cond log has this but I don't think it's related and it seems to be
retried later anyway:

```
Sep 05 13:56:15.434438 np0038400601 nova-conductor[66392]: DEBUG oslo_db.api 
[-] DB error: (pymysql.err.OperationalError) (1205, 'Lock wait timeout 
exceeded; try restarting transaction')
Sep 05 13:56:15.434438 np0038400601 nova-conductor[66392]: [SQL: UPDATE 
services SET updated_at=%(updated_at)s, report_count=%(report_count)s, 
last_seen_up=%(last_seen_up)s WHERE services.id = %(services_id)s]
Sep 05 13:56:15.434438 np0038400601 nova-conductor[66392]: [parameters: 
{'updated_at': datetime.datetime(2024, 9, 5, 13, 55, 24, 730896), 
'report_count': 276, 'last_seen_up': datetime.datetime(2024, 9, 5, 13, 55, 24, 
730149), 'services_id': 1}]
Sep 05 13:56:15.434438 np0038400601 nova-conductor[66392]: (Background on this 
error at: https://sqlalche.me/e/14/e3q8) {{(pid=66392) _is_exception_expected 
/opt/stack/data/venv/lib/python3.10/site-packages/oslo_db/api.py:184}}
Sep 05 13:56:15.435657 np0038400601 nova-conductor[66392]: DEBUG oslo_db.api 
[-] Performing DB retry for function nova.db.main.api.service_update 
{{(pid=66392) wrapper 
/opt/stack/data/venv/lib/python3.10/site-packages/oslo_db/api.py:155}}
```

** Affects: nova
     Importance: Undecided
         Status: New

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

Title:
  Tempest test fails to delete an instance, MessagingTimeout in n-cpu
  log when processing "_complete_deletion"

Status in OpenStack Compute (nova):
  New

Bug description:
  Logs:
  
https://ae5a8daa4540c7da75ef-0b252c7b71d313ec10c19ced03a4a34b.ssl.cf1.rackcdn.com/927182/1/check/neutron-
  tempest-plugin-openvswitch-
  iptables_hybrid-2023-2/1047b7f/testr_results.html

  Test traceback:

  ```
  Traceback (most recent call last):
    File "/opt/stack/tempest/tempest/lib/common/utils/test_utils.py", line 87, 
in call_and_ignore_notfound_exc
      return func(*args, **kwargs)
    File "/opt/stack/tempest/tempest/common/waiters.py", line 136, in 
wait_for_server_termination
      raise lib_exc.DeleteErrorException(details, server_id=server_id)
  tempest.lib.exceptions.DeleteErrorException: Resource %(resource_id)s failed 
to delete and is in ERROR status
  Details: Server f9acc6d9-132d-4ed8-875a-48fedb5b81b9 failed to delete and is 
in ERROR status. Fault: {'code': 500, 'created': '2024-09-05T13:56:54Z', 
'message': 'MessagingTimeout'}.
  ```

  In n-cpu logs,
  
https://ae5a8daa4540c7da75ef-0b252c7b71d313ec10c19ced03a4a34b.ssl.cf1.rackcdn.com/927182/1/check/neutron-
  tempest-plugin-openvswitch-
  iptables_hybrid-2023-2/1047b7f/controller/logs/screen-n-cpu.txt:

  ```
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [None req-99b4aa7a-c470-4313-807c-d22d46b0ae38 
tempest-MulticastTestIPv4-1796741707 
tempest-MulticastTestIPv4-1796741707-project-member] [instance: 
f9acc6d9-132d-4ed8-875a-48fedb5b81b9] Setting instance vm_state to ERROR: 
oslo_messaging.exceptions.MessagingTimeout: Timed out waiting for a reply to 
message ID 1bb84ce3208146ae828a98299bf658ea
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9] Traceback 
(most recent call last):
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/_drivers/amqpdriver.py",
 line 441, in get
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
return self._queues[msg_id].get(block=True, timeout=timeout)
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/eventlet/queue.py", line 
322, in get
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
return waiter.wait()
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/eventlet/queue.py", line 
141, in wait
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
return get_hub().switch()
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/eventlet/hubs/hub.py", line 
313, in switch
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
return self.greenlet.switch()
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9] 
_queue.Empty
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9] 
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9] During 
handling of the above exception, another exception occurred:
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9] 
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9] Traceback 
(most recent call last):
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/nova/nova/compute/manager.py", line 3315, in do_terminate_instance
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
self._delete_instance(context, instance, bdms)
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/nova/nova/compute/manager.py", line 3279, in _delete_instance
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
self._complete_deletion(context, instance)
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/nova/nova/compute/manager.py", line 926, in _complete_deletion
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
self._update_resource_tracker(context, instance)
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/nova/nova/compute/manager.py", line 693, in _update_resource_tracker
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
self.rt.update_usage(context, instance, instance.node)
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_concurrency/lockutils.py",
 line 414, in inner
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
return f(*args, **kwargs)
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/nova/nova/compute/resource_tracker.py", line 702, in update_usage
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
self._update(context.elevated(), self.compute_nodes[nodename])
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/nova/nova/compute/resource_tracker.py", line 1400, in _update
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     with 
excutils.save_and_reraise_exception(logger=LOG):
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", 
line 227, in __exit__
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
self.force_reraise()
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", 
line 200, in force_reraise
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     raise 
self.value
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/nova/nova/compute/resource_tracker.py", line 1395, in _update
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
compute_node.save()
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_versionedobjects/base.py",
 line 209, in wrapper
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
updates, result = self.indirection_api.object_action(
  Sep 05 13:56:23.165930 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/nova/nova/conductor/rpcapi.py", line 247, in object_action
  Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
return cctxt.call(context, 'object_action', objinst=objinst,
  Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/rpc/client.py",
 line 190, in call
  Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
result = self.transport._send(
  Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/transport.py",
 line 123, in _send
  Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
return self._driver.send(target, ctxt, message,
  Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/_drivers/amqpdriver.py",
 line 689, in send
  Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
return self._send(target, ctxt, message, wait_for_reply, timeout,
  Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/_drivers/amqpdriver.py",
 line 678, in _send
  Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
result = self._waiter.wait(msg_id, timeout,
  Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/_drivers/amqpdriver.py",
 line 567, in wait
  Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     
message = self.waiters.get(msg_id, timeout=timeout)
  Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]   File 
"/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/_drivers/amqpdriver.py",
 line 443, in get
  Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]     raise 
oslo_messaging.MessagingTimeout(
  Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9] 
oslo_messaging.exceptions.MessagingTimeout: Timed out waiting for a reply to 
message ID 1bb84ce3208146ae828a98299bf658ea
  Sep 05 13:56:23.170702 np0038400601 nova-compute[66332]: ERROR 
nova.compute.manager [instance: f9acc6d9-132d-4ed8-875a-48fedb5b81b9]
  ```

  I checked conductor and api logs but could find anything relevant
  there. Rabbitmq logs seem fine too.

  n-cond log has this but I don't think it's related and it seems to be
  retried later anyway:

  ```
  Sep 05 13:56:15.434438 np0038400601 nova-conductor[66392]: DEBUG oslo_db.api 
[-] DB error: (pymysql.err.OperationalError) (1205, 'Lock wait timeout 
exceeded; try restarting transaction')
  Sep 05 13:56:15.434438 np0038400601 nova-conductor[66392]: [SQL: UPDATE 
services SET updated_at=%(updated_at)s, report_count=%(report_count)s, 
last_seen_up=%(last_seen_up)s WHERE services.id = %(services_id)s]
  Sep 05 13:56:15.434438 np0038400601 nova-conductor[66392]: [parameters: 
{'updated_at': datetime.datetime(2024, 9, 5, 13, 55, 24, 730896), 
'report_count': 276, 'last_seen_up': datetime.datetime(2024, 9, 5, 13, 55, 24, 
730149), 'services_id': 1}]
  Sep 05 13:56:15.434438 np0038400601 nova-conductor[66392]: (Background on 
this error at: https://sqlalche.me/e/14/e3q8) {{(pid=66392) 
_is_exception_expected 
/opt/stack/data/venv/lib/python3.10/site-packages/oslo_db/api.py:184}}
  Sep 05 13:56:15.435657 np0038400601 nova-conductor[66392]: DEBUG oslo_db.api 
[-] Performing DB retry for function nova.db.main.api.service_update 
{{(pid=66392) wrapper 
/opt/stack/data/venv/lib/python3.10/site-packages/oslo_db/api.py:155}}
  ```

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


-- 
Mailing list: https://launchpad.net/~yahoo-eng-team
Post to     : yahoo-eng-team@lists.launchpad.net
Unsubscribe : https://launchpad.net/~yahoo-eng-team
More help   : https://help.launchpad.net/ListHelp

Reply via email to