Ensure that App logger emits DEBUG events if the CLI is invoked with --debug #238
Conversation
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
…gging is emitted.
Contributor Author
| Downstream compatibility (ucx) is currently failing because some tests that capture and check logs assume an underlying configuration where the loggers are all at |
github-merge-queue bot pushed a commit to databrickslabs/ucx that referenced this pull request May 16, 2025
## Changes This PR updates unit tests that verify logs to ensure they set up log-capturing to capture the level of the logs they're looking for. Previously this wasn't the case, and they relied on the underlying logging configuration have a level that would emit the record. ### Linked issues Relates databrickslabs/blueprint#238. ### Tests - updated unit tests
asnare requested review from a team, gueniai and sundarshankar89 and removed request for nfx 
| ✅ 40/40 passed, 2 skipped, 2m16s total Running from acceptance #288 |
Contributor Author
Fixed, as of databrickslabs/ucx#4032. |
sundarshankar89 added a commit that referenced this pull request May 16, 2025
* Consistent exception formatting in logs ([#237](#237)). The logger's exception formatting has been enhanced to provide a consistent and readable log format, adhering to standard Python norms. When an exception occurs, the log message now ensures a newline character separates the error message from the exception details, regardless of whether logs are colorized or not. This update applies to both exception text and stack information, which are now prepended with a newline character if necessary, resulting in a uniform format for all log types. This change resolves previous inconsistencies between colorized and non-colorized logs, aligning the logging functionality with standard Python practices for exception logging, and improving overall log readability. * Ensure that App logger emits `DEBUG` events if the CLI is invoked with `--debug` ([#238](#238)). The `get_logger` function has been enhanced to provide more flexibility and consistency with standard logging practices. It now accepts an optional `manager` parameter, allowing for customization of the logging manager, and returns a `logging.Logger` object. The logger level is automatically set to `DEBUG` when the application is running in debug mode, as detected by the `is_in_debug` function, and the level is set using the `logging.DEBUG` constant for consistency. This change simplifies the code and ensures that the logger emits `DEBUG` events when the application is run with the debug flag, which is verified through an updated test suite that covers various scenarios, including logger name setting, debug mode behavior, and logger propagation. * Ensure the names of logger levels are consistent ([#234](#234)). The logger has been updated to use consistent naming conventions for logging levels, aligning with the Python ecosystem's norms. Previously, colorized logs used compact names `WARN` and `FATAL` for warning and critical levels, while non-colorized logs used the conventional `WARNING` and `CRITICAL` names. To address this inconsistency, two new dictionaries have been introduced to store colorized level names and color codes, and the `format` method has been modified to utilize these dictionaries, ensuring consistent logging level names and colorized message text. As a result, logging level names have been updated to use the conventional `WARNING` and `CRITICAL` instead of `WARN` and "FATAL", and color codes for message text have been added for each logging level, promoting consistency and adherence to Python logging conventions. * Ensure the non-colorized logs also include timestamps with second-lev… ([#235](#235)). The log formatter has been updated to include second-granular timestamps in non-colorized logs, providing more precise logging information and ensuring consistency with colorized output. Previously, only minute-granular timestamps were logged, which was insufficient for logging purposes. The update changes the timestamp format from `%H:%M` to `%H:%M:%S` to include seconds, resulting in more detailed timestamp information. This change resolves the inconsistency between colorized and non-colorized logs, and is verified by updated tests that validate the formatter's behavior with and without colors, confirming that the formatter now correctly starts with a timestamp in both cases. * Fixed Blueprint Install ([#225](#225)). The `__version__` variable import statement has been updated to utilize a fully qualified module name, providing a more explicit and absolute reference to the module containing version information. This change ensures that the correct version is imported and used to set the user agent extra in relevant function calls, enhancing the reliability and accuracy of version tracking within the library. * Fixed argument interpolation in colorised logs ([#233](#233)). The colorised log formatter has been enhanced to correctly handle log entries containing `%`-style placeholders with arguments, a common pattern in third-party code, by retrieving the log message using `record.getMessage()` instead of directly accessing `record.msg`. This update resolves an issue with improper formatting of logging from third-party components and builds upon previous changes to address the underlying logging problem. Additionally, the corresponding test case has been updated to verify that the formatter correctly handles messages with arguments that require interpolation, both with and without colors enabled, and is no longer expected to fail, indicating that the issue with argument interpolation in the colorized log formatter has been resolved. * Fixed logger name abbreviation fails if the logger name contains `..` ([#236](#236)). The logger's format method has been enhanced to correctly abbreviate logger names containing multiple consecutive dots, which previously led to exceptions. The new logic splits the logger name into components, abbreviating all but the last two, and then reassembles them, ensuring correct abbreviation and formatting even when consecutive dots are present. This improvement also fixes the colorized logger output to handle logger names with consecutive dots without throwing an exception, and the corresponding test case has been updated to reflect this change, now directly testing the logging functionality by formatting the log record and stripping ANSI escape sequences, providing a more straightforward verification of the logging functionality.
Merged
sundarshankar89 added a commit that referenced this pull request May 16, 2025
* Consistent exception formatting in logs ([#237](#237)). The logger's exception formatting has been enhanced to provide a consistent and readable log format, adhering to standard Python norms. When an exception occurs, the log message now ensures a newline character separates the error message from the exception details, regardless of whether logs are colorized or not. This update applies to both exception text and stack information, which are now prepended with a newline character if necessary, resulting in a uniform format for all log types. This change resolves previous inconsistencies between colorized and non-colorized logs, aligning the logging functionality with standard Python practices for exception logging, and improving overall log readability. * Ensure that App logger emits `DEBUG` events if the CLI is invoked with `--debug` ([#238](#238)). The `get_logger` function has been enhanced to provide more flexibility and consistency with standard logging practices. It now accepts an optional `manager` parameter, allowing for customization of the logging manager, and returns a `logging.Logger` object. The logger level is automatically set to `DEBUG` when the application is running in debug mode, as detected by the `is_in_debug` function, and the level is set using the `logging.DEBUG` constant for consistency. This change simplifies the code and ensures that the logger emits `DEBUG` events when the application is run with the debug flag, which is verified through an updated test suite that covers various scenarios, including logger name setting, debug mode behavior, and logger propagation. * Ensure the names of logger levels are consistent ([#234](#234)). The logger has been updated to use consistent naming conventions for logging levels, aligning with the Python ecosystem's norms. Previously, colorized logs used compact names `WARN` and `FATAL` for warning and critical levels, while non-colorized logs used the conventional `WARNING` and `CRITICAL` names. To address this inconsistency, two new dictionaries have been introduced to store colorized level names and color codes, and the `format` method has been modified to utilize these dictionaries, ensuring consistent logging level names and colorized message text. As a result, logging level names have been updated to use the conventional `WARNING` and `CRITICAL` instead of `WARN` and "FATAL", and color codes for message text have been added for each logging level, promoting consistency and adherence to Python logging conventions. * Ensure the non-colorized logs also include timestamps with second-lev… ([#235](#235)). The log formatter has been updated to include second-granular timestamps in non-colorized logs, providing more precise logging information and ensuring consistency with colorized output. Previously, only minute-granular timestamps were logged, which was insufficient for logging purposes. The update changes the timestamp format from `%H:%M` to `%H:%M:%S` to include seconds, resulting in more detailed timestamp information. This change resolves the inconsistency between colorized and non-colorized logs, and is verified by updated tests that validate the formatter's behavior with and without colors, confirming that the formatter now correctly starts with a timestamp in both cases. * Fixed Blueprint Install ([#225](#225)). The `__version__` variable import statement has been updated to utilize a fully qualified module name, providing a more explicit and absolute reference to the module containing version information. This change ensures that the correct version is imported and used to set the user agent extra in relevant function calls, enhancing the reliability and accuracy of version tracking within the library. * Fixed argument interpolation in colorised logs ([#233](#233)). The colorised log formatter has been enhanced to correctly handle log entries containing `%`-style placeholders with arguments, a common pattern in third-party code, by retrieving the log message using `record.getMessage()` instead of directly accessing `record.msg`. This update resolves an issue with improper formatting of logging from third-party components and builds upon previous changes to address the underlying logging problem. Additionally, the corresponding test case has been updated to verify that the formatter correctly handles messages with arguments that require interpolation, both with and without colors enabled, and is no longer expected to fail, indicating that the issue with argument interpolation in the colorized log formatter has been resolved. * Fixed logger name abbreviation fails if the logger name contains `..` ([#236](#236)). The logger's format method has been enhanced to correctly abbreviate logger names containing multiple consecutive dots, which previously led to exceptions. The new logic splits the logger name into components, abbreviating all but the last two, and then reassembles them, ensuring correct abbreviation and formatting even when consecutive dots are present. This improvement also fixes the colorized logger output to handle logger names with consecutive dots without throwing an exception, and the corresponding test case has been updated to reflect this change, now directly testing the logging functionality by formatting the log record and stripping ANSI escape sequences, providing a more straightforward verification of the logging functionality.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
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.
This PR resolves an issue whereby
--debugbeing used when launching CLI applications did not result inDEBUGlogging, as described on #228.The issue is that although the
DEBUGlog-level is set on a parent logger, the "application" logger (a child) was being set toINFO, unless running within an IDE. This meant that most logs from within the application were suppressed.Prior to this PR the hierarchy typically looked like this when
--debugwas provided:WARNINGWARNINGdatabricksDEBUGDEBUGdatabricks.labs.appINFOINFOdatabricks.labs.app.module.aINFOdatabricks.labs.app.module.bINFOWith this PR it becomes this:
WARNINGWARNINGdatabricksDEBUGDEBUGdatabricks.labs.appDEBUGdatabricks.labs.app.module.aDEBUGdatabricks.labs.app.module.bDEBUGLinked Issues
Resolves: #228, databrickslabs/lakebridge#1494.
Tests
remorphucxSample remorph logs: