Repository navigation
Add utask waiting time metric - #5545
brun0-matheus wants to merge 4 commits into
Conversation
Define the metric in `monitoring_metrics.py` and instrument the code to emmit it.
Improve unittests that used serialize_and_upload_uworker_input, now they actually test the behaviour and not how the code is written. Add some tests to check for preprocess_end_time being set and for the metric emmission.
| if self._previous_subtask_end_time_ns is not None: | ||
| wait_duration_secs = max( | ||
| 0, (self.start_time_ns - self._previous_subtask_end_time_ns) / 10**9) | ||
| monitoring_metrics.UTASK_SUBTASK_WAIT_DURATION_SECS.add( |
There was a problem hiding this comment.
What was the rationale for choosing UTASK_SUB_TASK_WAIT_DURATION as the name? I am not sure if the metric's purpose is easily understood from this name. I would go with something more explicit.
There was a problem hiding this comment.
This is the best name I thought of. If I choose to be more explicit the metric name will become giant, but I'm open to suggestions.
| uworker_input.preprocess_start_time, | ||
| previous_subtask_end_time=uworker_input.preprocess_end_time) |
There was a problem hiding this comment.
Since we have preprocess_start_time and preprocess_end_time, why create the new previous_subtask_end_time field? Is this because for other subtasks we do not have analogous fields?
There was a problem hiding this comment.
preprocess_start_time and preprocess_end_time are defined in the proto, and previous_subtask_end_time is a parameter of the method set_task_details, so it isn't a "new field".
|
|
||
| if self._previous_subtask_end_time_ns is not None: | ||
| wait_duration_secs = max( | ||
| 0, (self.start_time_ns - self._previous_subtask_end_time_ns) / 10**9) |
There was a problem hiding this comment.
Because other metrics are emitted there as well.
There was a problem hiding this comment.
Also, I see no problem in emitting on exit.
|
|
||
| if previous_subtask_end_time is not None: | ||
| end_time = previous_subtask_end_time.ToNanoseconds() | ||
| if end_time > 0: |
There was a problem hiding this comment.
Can it be less or equal zero?
There was a problem hiding this comment.
It can't be negative, but it can be zero if previous_subtask_end_time is not set. It's more of a safety precaution in case you parse an old protobuf that didn't have this field set.
| import time | ||
| import unittest | ||
| from unittest import mock | ||
| import zlib |
There was a problem hiding this comment.
nit: Jetski suggested adding tests for:
- The no-I/O path: tworker_preprocess_no_io sets the timestamp and uworker_main_no_io records it.
- Backward compatibility: an input without preprocess_end_time should record nothing.
Bug: b/573118558
Overview
Creates a new metric called
UTASK_SUBTASK_WAIT_DURATION_SECS, which keeps track of time spent between one subtask finishing and the next one starting. This PR only implements it for themainsubtask (so it tracks time betweenpreprocessandmain).Changes
UTASK_SUBTASK_WAIT_DURATION_SECSand instrument the code to emit it in themainsubtask.preprocess_end_timetouworker_msg.Inputprotobuf.serialize_and_upload_uworker_inputin two parts, moving all URLs generation/signing toprepare_uworker_io_urlsin order to precisely track the timepreprocessfinishes.serialize_and_upload_uworker_input: now they actually test the underlying behavior of the function instead of how its code is written.time_nsmethod tohelpers.MockTime.Tests
Add additional checks in
UworkerMainTestandTworkerPreprocessTestto check ifpreprocess_end_timeis set correctly and ifUTASK_SUBTASK_WAIT_DURATION_SECSis emitted.I deployed in the dev environment and it's working as intended. Evidence in the bug comments.