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

kedro-telemetry: Improve performance by switching to after_command_run #4014

Merged
merged 22 commits into from
Aug 1, 2024
Merged
Show file tree
Hide file tree
Changes from 13 commits
Commits
Show all changes
22 commits
Select commit Hold shift + click to select a range
1e67775
Tentative fix for the hook issue
lrcouto Jul 16, 2024
9fca028
Merge branch 'main' into telemetry-improve-cli-performance
lrcouto Jul 17, 2024
29b627f
Merge branch 'main' into telemetry-improve-cli-performance
lrcouto Jul 17, 2024
8e9e5d4
Merge branch 'main' into telemetry-improve-cli-performance
lrcouto Jul 18, 2024
22977d5
Add variable to track if hook was called already
lrcouto Jul 18, 2024
3142ef8
Merge branch 'main' into telemetry-improve-cli-performance
lrcouto Jul 19, 2024
6ee73b8
Properly set exit code when there is an exception
lrcouto Jul 19, 2024
a97a012
Merge branch 'main' into telemetry-improve-cli-performance
lrcouto Jul 24, 2024
45013cf
Add test coverage for exception on after_command_hook
lrcouto Jul 25, 2024
bbab82c
Merge branch 'telemetry-improve-cli-performance' of github.com:kedro-…
lrcouto Jul 25, 2024
66136bd
Add test for the finally block
lrcouto Jul 25, 2024
f5fe4cc
Merge branch 'main' into telemetry-improve-cli-performance
lrcouto Jul 26, 2024
67dd0ff
Merge branch 'main' into telemetry-improve-cli-performance
lrcouto Jul 29, 2024
184c35d
Merge branch 'main' into telemetry-improve-cli-performance
lrcouto Jul 31, 2024
7b592fe
Remove redundant logger configuration on cli.py
lrcouto Jul 31, 2024
c5c22eb
Add minimal required logger config to sned messages to stderr
lrcouto Jul 31, 2024
155a30d
Call sys.exit only once
lrcouto Jul 31, 2024
de64ef7
Lint
lrcouto Jul 31, 2024
f6f657b
Remove comment
lrcouto Aug 1, 2024
b66c0fd
Move exit into exception block
lrcouto Aug 1, 2024
43054c5
Change test
lrcouto Aug 1, 2024
a31f0d4
Merge branch 'main' into telemetry-improve-cli-performance
lrcouto Aug 1, 2024
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
27 changes: 27 additions & 0 deletions kedro/framework/cli/cli.py
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@
from __future__ import annotations

import importlib
import logging
import sys
import traceback
from collections import defaultdict
Expand Down Expand Up @@ -38,6 +39,13 @@
v{version}
"""

logger = logging.getLogger(__name__)
logger.setLevel(logging.ERROR)
Copy link
Contributor

Choose a reason for hiding this comment

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

This will hide WARNING level logs as I understand, what's the reasoning behind this?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

My initial idea was that, since this would happen instead of the run stopping for an exception, it should appear only when an error occurs. But yeah it makes sense, we can lower it to a warning level.

handler = logging.StreamHandler(sys.stderr)
formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s")
Copy link
Contributor

Choose a reason for hiding this comment

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

Is this not formatted by kedro already? Why is this needed?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

When I added this I had issues with the hook not being called unless this formatting was explicitly on the file, it was not using kedro's. I'm doing some tests to see if I can make it just use kedro's instead.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Ok, I recalled why I did this. Since it was not using the config from kedro correctly, it was putting the error messages on stdout instead of stderr.

handler.setFormatter(formatter)
logger.addHandler(handler)


@click.group(context_settings=CONTEXT_SETTINGS, name="Kedro")
@click.version_option(version, "--version", "-V", help="Show version and exit")
Expand Down Expand Up @@ -154,6 +162,10 @@ def main(
self._cli_hook_manager.hook.before_command_run(
project_metadata=self._metadata, command_args=args
)

hook_called = False
exit_code = 0

try:
super().main(
args=args,
Expand All @@ -169,6 +181,8 @@ def main(
self._cli_hook_manager.hook.after_command_run(
project_metadata=self._metadata, command_args=args, exit_code=exc.code
)
hook_called = True

# When CLI is run outside of a project, project_groups are not registered
catch_exception = "click.exceptions.UsageError: No such command"
# click convert exception handles to error message
Expand Down Expand Up @@ -199,6 +213,19 @@ def main(
click.echo(message)
click.echo(hint)
sys.exit(exc.code)
except Exception as error:
logger.error(f"An error has occurred: {error}")
exit_code = 1
self._cli_hook_manager.hook.after_command_run(
project_metadata=self._metadata, command_args=args, exit_code=1
)
ankatiyar marked this conversation as resolved.
Show resolved Hide resolved
hook_called = True
finally:
if not hook_called:
Copy link
Member

Choose a reason for hiding this comment

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

Thank you for the PR, @lrcouto! Could you please explain how this is possible? It looks like hook_called will be set to True in the try block or, if it fails, in the except block, so this line will never be executed?

Copy link
Contributor

Choose a reason for hiding this comment

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

I guess that's in case of no exception

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Yes, this finally block is there to solve that issue where the hook was called twice when there was not an exception.

self._cli_hook_manager.hook.after_command_run(
project_metadata=self._metadata, command_args=args, exit_code=0
)
sys.exit(exit_code)
Copy link
Contributor

Choose a reason for hiding this comment

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

Is this sys.exit necessary? I think there is a high chance this will cause problem to use kedro CLI as sys.exit would terminate the program eagerly.

#4026 is trying to change click to standalone=False to make CLI

https://stackoverflow.com/questions/60780051/python-click-command-exit-flow

This issue document the previous investigation done by @antonymilne and explains more in depth.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I've used it here as a way to ensure that it exits with the appropriate error code, because it was exiting with a 0 even when an error happened. It's not necessary to exit at this point, as long as when it exits, it's with the correct code.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

What I did for now moving the sys.exit into the block that handles the exception in case something goes wrong. So if no errors happen, click will exit normally.


@property
def global_groups(self) -> Sequence[click.MultiCommand]:
Expand Down
34 changes: 34 additions & 0 deletions tests/framework/cli/test_cli.py
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@
from itertools import cycle
from os import rename
from pathlib import Path
from unittest.mock import MagicMock, patch

import click
from click.testing import CliRunner
Expand Down Expand Up @@ -432,6 +433,39 @@ def test_kedro_cli_with_project(self, mocker, fake_metadata):
assert "Global commands from Kedro" in result.output
assert "Project specific commands from Kedro" in result.output

@patch("sys.exit")
def test_main_hook_exception_handling(self, mock_sys_exit, fake_metadata):
kedro_cli = KedroCLI(fake_metadata.project_path)
kedro_cli._cli_hook_manager.hook.after_command_run = MagicMock()

with patch.object(
click.CommandCollection, "main", side_effect=Exception("Test Exception")
):
result = CliRunner().invoke(kedro_cli, [])

kedro_cli._cli_hook_manager.hook.after_command_run.assert_called_once_with(
project_metadata=kedro_cli._metadata, command_args=[], exit_code=1
)

mock_sys_exit.assert_called_once_with(1)
assert "An error has occurred: Test Exception" in result.output

@patch("sys.exit")
def test_main_hook_finally_block(self, mock_sys_exit, fake_metadata):
kedro_cli = KedroCLI(fake_metadata.project_path)
kedro_cli._cli_hook_manager.hook.after_command_run = MagicMock()

# No exception is raised, so it should go to the finally block and call the hook
with patch.object(click.CommandCollection, "main"):
result = CliRunner().invoke(kedro_cli, [])

kedro_cli._cli_hook_manager.hook.after_command_run.assert_called_once_with(
project_metadata=kedro_cli._metadata, command_args=[], exit_code=0
)

mock_sys_exit.assert_called_once_with(0)
assert "An error has occurred:" not in result.output


@mark.usefixtures("chdir_to_dummy_project")
class TestRunCommand:
Expand Down