-
Notifications
You must be signed in to change notification settings - Fork 54
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
instrument NADE commands using metric spans #1844
Conversation
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
file renamed from test_feature_metrics
since it was going to be too large with the spans, and also converted the tests to use the factories
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Generally the test directory mirrors the layout of the source directory so that tests are easy to locate. Breaking down the files like this because of some arbitrary size constraint makes things easier to manage, and makes it easier for us to review the changes because we can no longer see the diff. Please follow the convention instead.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
i don't follow this comment, did you mean to say it makes it harder if we split the test file?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
That's fair, I merged the new integ tests and also the old unit tests to test_metrics.py
in their respective folders, and also adjusted the codeowners file accordingly, let me know if this works for you!
[ | ||
( | ||
"app deploy", | ||
lambda: ProjectV11Factory( |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This is the best I could come up with to have parametrization with factories, if anyone has a better approach I'd be interested
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
what do we need parametrized tests at all? I don't think I can read this anymore. I think overall we make way, way too frequent use of parametrized tests in our codebase, but that's a different story.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
if the arguments to the factories are the same, you can parametrize just on the class and instantiate it in the test
@pytest.mark.parametrize("factory_class", [FooFactory, BarFactory])
def test_factory(factory_class):
obj = factory_class(arg=123)
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I ended up getting rid of all the parametrization and separating the tests out since the factories didn't have the same arguments, I think it's more clear and separated this way, let me know what you think
description + pre-review checklist aren't optional, please fill them in |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Generally the test directory mirrors the layout of the source directory so that tests are easy to locate. Breaking down the files like this because of some arbitrary size constraint makes things easier to manage, and makes it easier for us to review the changes because we can no longer see the diff. Please follow the convention instead.
@@ -88,7 +88,7 @@ def compile_artifacts(self): | |||
if not self._should_invoke_processors(): | |||
return | |||
|
|||
with cc.phase("Invoking artifact processors"): | |||
with cc.phase("Invoking artifact processors", span_name="compile_artifacts"): |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
there's no compilation happening. How about simply "artifact_processors"? We should probably also have individual processors as sub-spans.
@@ -213,6 +214,26 @@ def get_cli_context() -> _CliGlobalContextAccess: | |||
return _CliGlobalContextAccess(get_cli_context_manager()) | |||
|
|||
|
|||
def start_cli_metrics_span(span_name: str): |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I don't think "start" makes sense here, since this both starts and stops the span at the appropriate time. Let's workshop the name of this + the start_span
method it calls.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
+1, I feel @span would suffice
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Changed both the method name and the decorator name to just span
, let me know if this works for you
@@ -420,6 +421,7 @@ def get_objects_owned_by_application(self) -> List[ApplicationOwnedObject]: | |||
).fetchall() | |||
return [{"name": row[1], "type": row[2]} for row in results] | |||
|
|||
@start_cli_metrics_span("create_or_upgrade_app") |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
spans shouldn't be implementation-specific, but rather represent a logic step in the overall operation being performed.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Adjusted the names and locations of all the spans to better encapsulate this, let me know if they work for you!
@@ -915,6 +916,7 @@ def validate_setup_script( | |||
if validation_result["status"] == "FAIL": | |||
raise SetupScriptFailedValidation() | |||
|
|||
@start_cli_metrics_span("get_validation_result") |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
ditto, let's not name things according to the implementation. That can change over time.
src/snowflake/cli/api/console/abc.py
Outdated
@@ -68,6 +68,7 @@ def phase( | |||
self, | |||
enter_message: str, | |||
exit_message: Optional[str] = None, | |||
span_name: Optional[str] = None, |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
not sure if this is truly needed, since we can use multiple context managers on the same line. Thoughts?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I forgot about that feature, I adjusted these instances, thanks for the reminder
@@ -304,6 +308,7 @@ def validation_item_to_str(item: dict[str, str | int]): | |||
return s | |||
|
|||
|
|||
@start_cli_metrics_span("drop_generic_object") |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
same here
[ | ||
( | ||
"app deploy", | ||
lambda: ProjectV11Factory( |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
what do we need parametrized tests at all? I don't think I can read this anymore. I think overall we make way, way too frequent use of parametrized tests in our codebase, but that's a different story.
… un-parametrize tests, merge test files to keep with covention
My mistake, I usually do it at the same time as when I make the PR but I started it as a draft this time and forgot to do it when I set it as ready for review, should be populated now! |
def mock_time_monotonic(): | ||
with mock.patch("time.monotonic", side_effect=count()) as mocked_time_monotonic: | ||
yield mocked_time_monotonic | ||
def test_metrics_no_counters(): |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
All counter tests moved from test_metrics_counters.py
to consolidate the files and keep to the convention
|
||
@pytest.mark.integration | ||
@mock.patch("snowflake.connector.telemetry.TelemetryClient.try_add_log_to_batch") | ||
def test_feature_counters_v2_post_deploy_not_available_in_bundle( |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
counter tests moved from test_feature_metrics.py
to consolidate them in one file and keep to the convention, and converted to use factories
src/snowflake/cli/_plugins/nativeapp/entities/application_package.py
Outdated
Show resolved
Hide resolved
@@ -649,6 +650,7 @@ def resolve_without_follow(path: Path) -> Path: | |||
return Path(os.path.abspath(path)) | |||
|
|||
|
|||
@span("build_initial_bundle") |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
why not just bundle
?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
In my head bundle
is the higher level container that does both this step (populating the deploy root) and then applying all the processors on it, but if we're fine just having the first step be called bundle then that's good with me
@@ -355,6 +355,7 @@ def post_deploy_hooks(self) -> list[PostDeployHook] | None: | |||
model = self._entity_model | |||
return model.meta and model.meta.post_deploy | |||
|
|||
@span("deploy_app") |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Maybe we should consider some kind of standardized scheme for actions + entities, maybe something like action.app.deploy
?
src/snowflake/cli/_plugins/nativeapp/entities/application_package.py
Outdated
Show resolved
Hide resolved
@@ -544,6 +546,7 @@ def _bundle(self): | |||
compiler.compile_artifacts() | |||
return bundle_map | |||
|
|||
@span("deploy_app_package") |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
would rather do this on the action for consistency
@@ -68,7 +68,11 @@ def _format_message(self, message: str, output: Output) -> Text: | |||
return text | |||
|
|||
@contextmanager | |||
def phase(self, enter_message: str, exit_message: Optional[str] = None): | |||
def phase( |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
you're no longer touching this, I'd revert the file entirely
@@ -76,6 +76,7 @@ def _get_stage_paths_to_sync( | |||
return stage_paths | |||
|
|||
|
|||
@span("sync_remote_and_local_files") |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
this is one of the rare cases where I'd use the actual function name, since it's exactly the logical concept we're timing.
src/snowflake/cli/api/metrics.py
Outdated
spans_to_report, | ||
# start_time can be the same, so we want to sort by something more | ||
# deterministic, so we use a counter to see which spans are started first | ||
key=lambda span: span.creation_key, |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I still don't understand why we need this global counter. My reasoning is this: assume we have a stable sort. Then, given a list of spans, we can first sort by start time, then by end time. If two start times are the same, it's unlikely that they'll have the same end time. Even if they do, that means we have two spans that are identical, and the stable sort will keep them in the same order anyway. What am I missing?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The problem isn't that we don't have a stable sort (I believe python's builtins are stable), it's that we reorder (i.e. break the creation ordering of) the spans in the first sort pass where we take spans breadth first to ensure we conform to the limits in this code block
For example, given the following span tree where the creation order is [span1, span2, span3]:
├── span1
│ └── span2
└── span3
Then the first pass will reorder the spans to become breadth-first [span1, span3, span2] as the spans_to_report
, since we won't know which spans will be reported until we go through them
CMIIW but I believe this means we'll need some sort of persistent auxiliary structure to keep track of the spans in creation order, to re-sort after the first pass, unless we can say we trust the start/end_time
s being reported
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Discussed offline: requirement to have spans sorted by start_time during reporting was waived, the new requirement is to only do one sort, and keep the spans sorted by (depth, start_time, end_time), in that order for tiebreaking
src/snowflake/cli/api/metrics.py
Outdated
@@ -99,6 +100,9 @@ class for holding metrics span data and encapsulating related operations | |||
# denotes whether direct children were trimmed from telemetry payload | |||
TRIMMED_KEY: ClassVar[str] = "trimmed" | |||
|
|||
# counter for sorting by creation order | |||
_CREATION_COUNTER: ClassVar[count] = count() |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
global counters that never get reset are generally not a good idea
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Commented here
} | ||
|
||
|
||
def assert_spans_within_limits(spans: Dict) -> None: |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
move all helpers to the top, before any test cases. It's really hard to find them in between test cases.
for span in self._completed_spans | ||
if span.span_depth <= self.SPAN_DEPTH_LIMIT | ||
), | ||
key=lambda span: (span.span_depth, span.start_time, span.execution_time), |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
As discussed offline, only one sort, however the last tiebreaker is execution_time
here instead of end_time since they are logically equivalent and we only track execution time explicitly, not end time
""" | ||
Decorator to start a command metrics span that encompasses a whole function | ||
|
||
Must be used instead of directly calling @get_cli_context().metrics.start_span(span_name) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
it's span
now, not start_span
Pre-review checklist
Changes description
An example trace of
snow app run
looks like the following (truncated for brevity):