Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

{Log} Adapt az_command_data_logger to Knack 0.8.0 #17324

Merged
merged 3 commits into from
Mar 26, 2021

Conversation

jiasli
Copy link
Member

@jiasli jiasli commented Mar 16, 2021

Adapt to microsoft/knack#228: [Log] CLILogging.configure returns as early as possible

Symptom

az feedback no longer works with knack dev branch:

> azdev test feedback

src\azure-cli\azure\cli\command_modules\feedback\tests\latest\test_feedback.py:130: in _helper_test_log_contents_correct
    self.assertEqual(command_log_files[1].get_command_status(), "SUCCESS")
E   AssertionError: '' != 'SUCCESS'
E   + SUCCESS

Cause

In pytest environment, pytest will configure the root logger to capture all logs.

Additional Context

  • az feedback relies on az_command_data_logger (which are written to ~/.azure/commands/).

  • az_command_data_logger is written by azure.cli.core.util.handle_exception.

  • During testing, azure.cli.core.util.handle_exception is mocked by azure.cli.testsdk.patches.patch_main_exception_handler so that the original Exception can be thrown and asserted.

  • However, azure.cli.testsdk.patches.patch_main_exception_handler doesn't write to az_command_data_logger.

  • In the oldest code ([wip] az feedback #8829), this is worked around by calling the leaked file handler after execute finishes.

  • As [Core] fix logging file fd leaking #13102 fixed the leaked file handler, the old code no longer worked. To work around it again, [Core] fix logging file fd leaking #13102 manually delayed the cleanup for file handler.

  • This PR refactors [Core] fix logging file fd leaking #13102 with a more elegant mock.patch on azure.cli.core.util.handle_exception again, so that no manual delay of file handler cleanup is necessary.

Comment on lines +205 to +206
with mock.patch('azure.cli.core.util.handle_exception', _handle_exception_with_log):
result = execute(cli_ctx, command, expect_failure=expect_failure).assert_with_checks(checks)
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The old code registers Logger as a Handler. It works simply because both Logger and Handler expose handle method by coincidence. It is never guaranteed to work as such and may break any time the internal logic of logging module changes.

@@ -69,89 +69,88 @@ def handle_exception(ex): # pylint: disable=too-many-locals, too-many-statement
# Print the traceback and exception message
logger.debug(traceback.format_exc())

with CommandLoggerContext(logger):
Copy link
Member Author

@jiasli jiasli Mar 16, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

CommandLoggerContext will be called again at:

def print_error(self):
from azure.cli.core.azlogging import CommandLoggerContext
from azure.cli.core.style import print_styled_text
with CommandLoggerContext(logger):

Calling it here is redundant.

Besides, no log is written here, so these lines shouldn't be surrounded by CommandLoggerContext.

Comment on lines +73 to +82
# print recommendations to action
if self.recommendations:
for recommendation in self.recommendations:
print(recommendation, file=sys.stderr)

if self.aladdin_recommendations:
print('\nTRY THIS:', file=sys.stderr)
for recommendation, description in self.aladdin_recommendations:
print_styled_text(recommendation, file=sys.stderr)
print_styled_text(description, file=sys.stderr)
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No log is written here. The scope of CommandLoggerContext should be as small as possible.

@yonzhan yonzhan added this to the S185 milestone Mar 16, 2021
@yonzhan
Copy link
Collaborator

yonzhan commented Mar 16, 2021

Log

@jiasli jiasli merged commit 3bff786 into Azure:dev Mar 26, 2021
@jiasli jiasli deleted the metadata-logger branch March 26, 2021 09:46
@jiasli jiasli changed the title {Log} Adapt az_command_data_logger to Knack 0.8.0 {Log} Adapt az_command_data_logger to Knack 0.8.0 Mar 26, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

5 participants