Enable logging for python dependencies, particularly comtypes#10393
Merged
Conversation
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
Collaborator
Author
|
This is not in alpha yet. |
|
Ok but something has upset my system in the last update then.
Brian
bglists@blueyonder.co.uk
Sent via blueyonder.
Please address personal E-mail to:-
briang1@blueyonder.co.uk, putting 'Brian Gaff'
in the display name field.
Newsgroup monitored: alt.comp.blind-users
-----
|
michaelDCurran
approved these changes
Oct 21, 2019
Collaborator
Author
|
This already proves to be helpful. When I open the Emoji panel in Windows 20:1 insider preview, i"m getting unhandled exceptions by our UIA event handler. I was already investing some resources in increasing UIA logging, so I fixed this in #10397 hopefully. |
Collaborator
Author
|
Here is an example traceback: In my opinion, we should catch these in NVDA |
JulienCochuyt
added a commit
to accessolutions/nvda
that referenced
this pull request
May 11, 2020
5 tasks
SaschaCowley
pushed a commit
that referenced
this pull request
May 13, 2025
Follow up for #10393 Summary of the issue: Since #10393, we log at level warning or higher for external Python dependencies. There is no way to enable logging at lower levels, such as debug. This can however be pretty helpful for external dependencies like comtypes to see what's going on under the hood. Description of user facing changes Have extra logging when a new debugging category, `externalPythonDependencies`, is enabled. Description of development approach The overall logging level is now determined from the level of the root logger, which is no longer limited to a minimum of WARNING. Instead, a filter is implemented on the handler that filters appropriately. Note that initially, it made sense to add this filter to the root logger, but filters don't propagate from the root logger to all loggers below. Testing strategy: Calling `comtypes.CoInitialize` with and without the new category enabled, logging at level debug. Ensured that behavior was as expected (i.e. comtypes logged when the category was enabled) Known issues with pull request: In #10393, I mentioned issues with re-entrancy when comtypes logs at level debug. I have not yet reproduced this. That said, the logging categories are documented in such a way that they should only be enabled on request. I don't think this needs extra documentation.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
4 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Link to issue number:
Related to #10247
Comtypes issue enthought/comtypes#192
Summary of the issue:
Some of our dependencies, particularly comtypes, have built in logging. However, logging data from these dependencies is ignored, as the NVDA logfile handler is set on the NVDA logger, not on the root logger of all loggers.
Description of how this pull request fixes the issue:
This pr registers our logHandler to the root logger. This means that python modules that use python's logging facility (not the NVDA specific one) are still able to log their information to the NVDA log.
The NVDA log level is also applied to the root logger, but only if it is warning or higher. This is because warnings or errors logged by dependencies like comtypes are certainly very interesting to know, though we want to avoid comtypes debug information leaking into our log when our log level is debug.
Testing performed:
Tested that comtypes.logger.error logs its data to the NVDA log and plays the NVDA error sound.
Known issues with pull request:
I initially started with a comtypes specific implementation that registered our log handler to the comtypes logger and was also able to log comtypes output at level debug. However, having comtypes log at the debug level is very verbose and, more importantly, can cause serious issues as some of its logging is re-entrant. Long story short, comtypes debug logging is not what we want.
Here is an example traceback generated when comtypes logging is set to debug. Strange enough, even though that traceback was sent to stderr, it didn't pop up in the log. I had to manually monkeypatch stderr to a text file in order for the traceback to be retrieved.
Change log entry: