nvda
08075185 - logHandler: handle the case where messages from other loggers (E.g. comtypes) come through NVDA's logger with no codepath. (#14317)

Commit
3 years ago
logHandler: handle the case where messages from other loggers (E.g. comtypes) come through NVDA's logger with no codepath. (#14317) Partial fix for #14315 Summary of the issue: If an exception is raised inside a comtypes event handler and is not caught, Many many log messages are logged by NVDA at level error, with each line of the multiple nested tracebacks being individually logged via standard error. This is extremely noisy for the user, and the log output is very hard to read. Some background: To produce friendly module.class.function paths for NVDA's log messages, NVDA's logging code provides / generates a special 'codepath' attribute on its log erecords. However, as NVDA sets itself as the root logger, it also receives log messages from other libraries (E.g. comtypes). But these log messages don't come with the special 'codepath' record attribute, which is required by NVDA's log formatter. Thus, if one of these log messages is produced, an internal logging error occurs (KeyError: codepath), and this is pushed out via standard error as the log message could not be written to the log. However, NVDA's redirects standard error back to the logger, logging each line of output as its own log message. In this case then, What is logged is each separate line of the multiple nested tracebacks, including the actual exception in the comtypes UI Autpomation event handler, plus the logging error traceback itself, plus also a call stack for debugging. In totally on average about 22 or so separate log messages for one error. Description of user facing changes If an error occurs in a comtypes event handler method, only one error will be written to the log rather than more than 20. Description of development approach Add code to NVDA's log formatter.format method which checks if the record does not contain a codepath attribute, and if so, produces a simple one from standard log record attributes. e.g. name and funcName. After this change, raising Runtime error in the UI Automation handleAutomationEvent method produces just 1 much shorter and easier to read message.
Parents
Loading