Skip to content

Garbage collection happens on thread switch, freeing in-use reference on 3.13 #1032

Description

@gboutry

Hello,

After a deeper dive on #1030, I'm now certain a garbage collection happens after a context switch in Nova.
Therefore, I am opening a separate issue as this is a very different error from #1030.

Cross-posting from: https://bugs.launchpad.net/nova/+bug/2103413

After more investigation, I'm now certain the core of the issue is the Garbage Collector freeing up object much before their last use.

Quickly setup a reproducer VM: https://pastebin.ubuntu.com/p/gzMwyCZSct/
ppa:gboutry/plucky-proposed-openstack is a ppa containing the RC1 packaging for most openstack projects, but the nova package is carrying the following patch to help track object finalization: https://pastebin.ubuntu.com/p/cj7tb3kmGV/

I have also reverse applied this patch out of bound to have the greenthread identity (the same error happens with and without this patch):
openstack/nova@cd980cd

The carried patch for finalization tracing is tracing: https://opendev.org/openstack/nova/src/commit/98226b60f3fe7b20e8d7f208c12f8d0086cd83d0/nova/network/neutron.py#L1216

This object gets it's attributes freed up very early in the method runtime. I can't pin point a precise LOC where this happens, as it changes all the time. (meaning it's not a subsequent call that frees up the internal objects).

Note that the admin_client object itself does NOT get freed, only its inner objects.

2025-04-02 08:02:48.500 26057 INFO nova.network.neutron [-] /usr/lib/python3.13/weakref.py:590 - finalizer base_client
2025-04-02 08:02:48.500 26057 INFO nova.network.neutron [-] base_client - Monotonic delta, 0.158562s
2025-04-02 08:02:48.500 26057 INFO nova.network.neutron [-] base_client - end of finalizer
2025-04-02 08:02:48.500 26057 INFO nova.network.neutron [-] httpclient - finalizer called: <Thread(Thread-1 (poll), started daemon 123734175578944)>
2025-04-02 08:02:48.500 26057 INFO nova.network.neutron [-] httpclient - finalizer called: {123734291935488: <_MainThread(MainThread, started 123734291935488)>, 123734175578944: <Thread(Thread-1 (poll), started daemon 123734175578944)>, 123734174920256: <Thread(Rabbit-heartbeat, started daemon 123734174920256)>, 123734127568576: <Thread(Thread-2 (_native_thread), started daemon 123734127568576)>, 123734048372416: <Thread(tpool_thread_0, started daemon 123734048372416)>, 123734039979712: <Thread(tpool_thread_1, started daemon 123734039979712)>, 123734031587008: <Thread(tpool_thread_2, started daemon 123734031587008)>, 123734023194304: <Thread(tpool_thread_3, started daemon 123734023194304)>, 123734014801600: <Thread(tpool_thread_4, started daemon 123734014801600)>, 123734006408896: <Thread(tpool_thread_5, started daemon 123734006408896)>, 123733998016192: <Thread(tpool_thread_6, started daemon 123733998016192)>, 123733444392640: <Thread(tpool_thread_7, started daemon 123733444392640)>, 123733435999936: <Thread(tpool_thread_8, started daemon 123733435999936)>, 123733427607232: <Thread(tpool_thread_9, started daemon 123733427607232)>, 123733419214528: <Thread(tpool_thread_10, started daemon 123733419214528)>, 123733410821824: <Thread(tpool_thread_11, started daemon 123733410821824)>, 123733402429120: <Thread(tpool_thread_12, started daemon 123733402429120)>, 123733394036416: <Thread(tpool_thread_13, started daemon 123733394036416)>, 123732907521728: <Thread(tpool_thread_14, started daemon 123732907521728)>, 123732899129024: <Thread(tpool_thread_15, started daemon 123732899129024)>, 123732890736320: <Thread(tpool_thread_16, started daemon 123732890736320)>, 123732882343616: <Thread(tpool_thread_17, started daemon 123732882343616)>, 123732873950912: <Thread(tpool_thread_18, started daemon 123732873950912)>, 123732865558208: <Thread(tpool_thread_19, started daemon 123732865558208)>, 123734129856768: <Thread(Thread-3 (_runner), started daemon 123734129856768)>}
2025-04-02 08:02:48.500 26057 INFO nova.network.neutron [-] /usr/lib/python3.13/weakref.py:590 - finalizer httpclient
2025-04-02 08:02:48.500 26057 INFO nova.network.neutron [-] httpclient - Monotonic delta, 0.171590s
2025-04-02 08:02:48.500 26057 INFO nova.network.neutron [-] httpclient - end of finalizer

PS: admin_client is the object where this happens the most, but not at all the runs, some of the other failures, it's neutron_client (https://opendev.org/openstack/nova/src/commit/98226b60f3fe7b20e8d7f208c12f8d0086cd83d0/nova/network/neutron.py#L1212) that gets its internal object freed.

using gc.disable() makes the issue disappear (yay! disable gc!) or actually holding a hard ref to admin_client.base_client.httpclient makes the method pass most of the time...

Metadata

Metadata

Assignees

No one assigned

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions