Skip to content

Align workflow_task_schedule_to_start_latency #2669

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.

Sign up for GitHub

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

Merged
merged 3 commits into from
Oct 22, 2025
+4 −6
Merged

Align workflow_task_schedule_to_start_latency #2669

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
a7ab3c7
Align workflow_task_schedule_to_start_latency
Quinn-With-Two-Ns Sep 24, 2025
d8601e2
Fix format
Quinn-With-Two-Ns Sep 24, 2025
402f814
Fix AsyncActivityPollTask
Quinn-With-Two-Ns Sep 25, 2025
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
6 changes: 3 additions & 3 deletions temporal-sdk/src/main/java/io/temporal/internal/worker/AsyncActivityPollTask.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,6 @@
import static io.temporal.serviceclient.MetricsTag.METRICS_TAGS_CALL_OPTIONS_KEY;

import com.google.protobuf.DoubleValue;
import com.google.protobuf.Timestamp;
import com.uber.m3.tally.Scope;
import io.grpc.Context;
import io.temporal.api.common.v1.WorkerVersionCapabilities;
Expand Down Expand Up @@ -113,10 +112,11 @@ public CompletableFuture<ActivityTask> poll(SlotPermit permit) {
metricsScope.counter(MetricsType.ACTIVITY_POLL_NO_TASK_COUNTER).inc(1);
return null;
}
Timestamp startedTime = ProtobufTimeUtils.getCurrentProtoTime();
metricsScope
.timer(MetricsType.ACTIVITY_SCHEDULE_TO_START_LATENCY)
.record(ProtobufTimeUtils.toM3Duration(startedTime, r.getScheduledTime()));
.record(
ProtobufTimeUtils.toM3Duration(
r.getStartedTime(), r.getCurrentAttemptScheduledTime()));
return new ActivityTask(
r,
permit,
Expand Down
4 changes: 1 addition & 3 deletions temporal-sdk/src/main/java/io/temporal/internal/worker/AsyncWorkflowPollTask.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,6 @@

import static io.temporal.serviceclient.MetricsTag.METRICS_TAGS_CALL_OPTIONS_KEY;

import com.google.protobuf.Timestamp;
import com.uber.m3.tally.Scope;
import com.uber.m3.util.ImmutableMap;
import io.grpc.Context;
Expand Down Expand Up @@ -154,10 +153,9 @@ public CompletableFuture<WorkflowTask> poll(SlotPermit permit)
pollerMetricScope
.counter(MetricsType.WORKFLOW_TASK_QUEUE_POLL_SUCCEED_COUNTER)
.inc(1);
Timestamp startedTime = ProtobufTimeUtils.getCurrentProtoTime();
pollerMetricScope
.timer(MetricsType.WORKFLOW_TASK_SCHEDULE_TO_START_LATENCY)
.record(ProtobufTimeUtils.toM3Duration(startedTime, r.getScheduledTime()));
.record(ProtobufTimeUtils.toM3Duration(r.getStartedTime(), r.getScheduledTime()));
Comment on lines -160 to +158
Copy link
Member

Choose a reason for hiding this comment

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

Any idea of what the practical time difference could be for users that may be monitoring this metric? I guess we can just call it out in release notes

Copy link
Contributor Author

Choose a reason for hiding this comment

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

clock skew between the Server and Worker, maybe some unaccounted for network time. The main issue is the async poller was measuring it differently then everywhere else which is a bug.

Comment on lines -160 to +158
Copy link
Member

Choose a reason for hiding this comment

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

I see this same logic for activity, do we want to update that one to use the activity poll response start time too? I also saw this logic with Nexus, but no start time on its response (I also confirmed the activity and workflow started time fields on the response go as far back as Temporal, so we're safe for old server versions)

Copy link
Contributor Author

Choose a reason for hiding this comment

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

ah good catch, fixed

return new WorkflowTask(r, (reason) -> slotSupplier.releaseSlot(reason, permit));
})
.whenComplete(
Expand Down
Loading