Python 3.11 regression: Garbage handler errors occur much more frequently

[LeonarddeR]

Steps to reproduce:

1. Open a new message in Thunderbird
2. Restart NVDA
3. Start typing in the message window.

Actual behavior:

Several errors like this in the log:

WARNING - garbageHandler.notifyObjectDeletion (10:28:12.961) - MainThread (1888):
Garbage collector has found one or more unreachable objects. See further warnings for specific objects.
Stack trace:
  File "nvda.pyw", line 399, in <module>
  File "core.pyc", line 813, in main
  File "wx\core.pyc", line 2262, in MainLoop
  File "wx\core.pyc", line 3427, in <lambda>
  File "gui\__init__.pyc", line 187, in showGui
  File "gui\__init__.pyc", line 625, in onActivate
  File "wx\core.pyc", line 3427, in <lambda>
  File "core.pyc", line 746, in processRequest
  File "core.pyc", line 761, in Notify
  File "IAccessibleHandler\__init__.pyc", line 1045, in pumpAll
  File "IAccessibleHandler\__init__.pyc", line 725, in processFocusWinEvent
  File "IAccessibleHandler\__init__.pyc", line 577, in winEventToNVDAEvent
  File "NVDAObjects\IAccessible\__init__.pyc", line 75, in getNVDAObjectFromEvent
  File "NVDAObjects\__init__.pyc", line 109, in __call__
  File "appModules\nvda.pyc", line 251, in chooseNVDAObjectOverlayClasses
  File "appModules\nvda.pyc", line 234, in isNvdaPythonConsoleUIInputCtrl
  File "<frozen importlib._bootstrap>", line 1176, in _find_and_load
  File "<frozen importlib._bootstrap>", line 1147, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 690, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 940, in exec_module
  File "<frozen importlib._bootstrap>", line 241, in _call_with_frames_removed
  File "pythonConsole.pyc", line 19, in <module>
  File "<frozen importlib._bootstrap>", line 1176, in _find_and_load
  File "<frozen importlib._bootstrap>", line 1147, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 690, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 940, in exec_module
  File "<frozen importlib._bootstrap>", line 241, in _call_with_frames_removed
  File "pydoc.pyc", line 70, in <module>
  File "<frozen importlib._bootstrap>", line 1176, in _find_and_load
  File "<frozen importlib._bootstrap>", line 1138, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 1078, in _find_spec
  File "<frozen importlib._bootstrap_external>", line 1504, in find_spec
  File "<frozen importlib._bootstrap_external>", line 1476, in _get_spec
  File "<frozen zipimport>", line 169, in find_spec
  File "<frozen importlib._bootstrap>", line 435, in spec_from_loader
  File "<frozen importlib._bootstrap_external>", line 798, in spec_from_file_location
  File "<frozen zipimport>", line 228, in get_filename
  File "<frozen zipimport>", line 762, in _get_module_code
  File "<frozen zipimport>", line 676, in _unmarshal_code
  File "garbageHandler.pyc", line 28, in __del__
  File "garbageHandler.pyc", line 67, in notifyObjectDeletion
WARNING - garbageHandler.notifyObjectDeletion (10:28:12.961) - MainThread (1888):
Deleting unreachable object <NVDAObjects.IAccessible.IA2TextTextInfo object at 0x0324D730>
WARNING - garbageHandler.notifyObjectDeletion (10:28:12.961) - MainThread (1888):
Deleting unreachable object <NVDAObjects.IAccessible.IA2TextTextInfo object at 0x08005B10>
ERROR - garbageHandler._collectionCallback (10:28:12.961) - MainThread (1888):
Found at least 2 unreachable objects in run

Expected behavior:

No errors

System configuration

NVDA installed/portable/running from source:

Installed

NVDA version:

alpha-29638,799554b2

Windows version:

Windows 11 23H2 release preview

Name and version of other software in use when reproducing the issue:

Thunderbird 115.3.1

Other questions

Does the issue still occur after restarting your computer?

Yes

Have you tried any other versions of NVDA? If so, please report their behaviors.

Yes, didn't occur on 3.7 versions of NVDA.

If NVDA add-ons are disabled, is your problem still occurring?

Yes

Does the issue still occur after you run the COM Registration Fixing Tool in NVDA's tools menu?

Yes

[LeonarddeR]

Another way to reproduce this is arrowing up and down in the teams chats list.
My assumption is that changes have been made in Python's garbage collection, making it more efficient and run more often, therefore we must reconsider our garbageHandler approach. CC @michaelDCurran and @seanbudd

[seanbudd]

We'd like to lower all these logs to debug warning level.
We also want to log from garbageHandler.notifyObjectDeletion only if "garbageHandler" is enabled in the advanced logging categories. The logging from garbageHandler._collectionCallback should remain at debug warning level.

[ruifontes]

Just a question:
If this is intended behaviour, why is logged as an error?

[seanbudd]

@ruifontes - this is not intended behaviour. It generally indicates a memory leak, which is a developer error and slows down your device.
However, it is possible now that these warnings are occurring before there's been enough time to cleanup the garbage memory.
We are planning to lower the log level to warning, as there is still an error occurring but it's likely only worth fixing if it's easy to reproduce, so an initial user log is less critical.

[Brian1Gaff]

Possibly the question was prompted by an issue with the preferences of Teseract on Windows 7, which generated garbage collection errors on the recent versions of nvda running in Windows 7, due to language lists differences. Brian

…

-- ***@***.*** Sent via blueyonder.(Virgin media) Please address personal E-mail to:- ***@***.***, putting 'Brian Gaff' in the display name field.

[CyrilleB79]

@LeonarddeR, are these Garbage handler errors still occurring in last alpha?

Regarding the ones in Chrome, they have been fixed with #15546.

[ruifontes]

I am using version alpha-29670,d0614df6
and during the first hour of use nothing in log about garbage deletion...

[LeonarddeR]

It looks like #15546 improved a lot indeed, though I'm not sure how.
I will be on my work pc next Monday to observe the behavior in Teams. When that's fixed, I will close this issue.

[Adriani90]

I cannot reproduce in Teams Microsoft Teams-Version 23258.704.2395.9691 with the last Alpha on Windows 11 22 H2.

[LeonarddeR]

In that case, lets close this as fixed.