Skip to content

Fix queue time calculation for builds and pipeline steps#406

Merged
nikita-tkachenko-datadog merged 2 commits into
masterfrom
nikita-tkachenko/queue-time-fixes
Apr 2, 2024
Merged

Fix queue time calculation for builds and pipeline steps#406
nikita-tkachenko-datadog merged 2 commits into
masterfrom
nikita-tkachenko/queue-time-fixes

Conversation

@nikita-tkachenko-datadog

@nikita-tkachenko-datadog nikita-tkachenko-datadog commented Mar 25, 2024

Copy link
Copy Markdown
Collaborator

Requirements for Contributing to this repository

  • Fill out the template below. Any pull request that does not include enough information to be reviewed in a timely manner may be closed at the maintainers' discretion.
  • The pull request must only fix one issue at the time.
  • The pull request must update the test suite to demonstrate the changed functionality.
  • After you create the pull request, all status checks must be pass before a maintainer reviews your contribution. For more details, please see CONTRIBUTING.

What does this PR do?

Fixes the logic that calculates queue time for pipelines and pipeline steps.

The following problems are fixed:

  • queue time calculated incorrectly for pipelines that first wait to start (for example, because of throttling settings) and then wait for their executor to become available. These waiting times should be summed (because the two waits happen sequentially), while the old implementations only used the biggest of the two values.
  • pipeline span and all of its children spans are shifted into the past, because propagated queue time is subtracted from both the start and the end timestamps (I think it used to be done this way because the plugin used DD Java Agent's API for creating spans. Pipeline span had to start before queue time, and modifying start time later was not possible)
  • queueing time of individual pipeline steps is counted twice: first as the queuing time, and second as part of the step itself (both durations can be seen in the pipeline trace)

Description of the Change

Alternate Designs

Possible Drawbacks

Verification Process

Additional Notes

Release Notes

Review checklist (to be filled by reviewers)

  • Feature or bug fix MUST have appropriate tests (unit, integration, etc...)
  • PR title must be written as a CHANGELOG entry (see why)
  • Files changes must correspond to the primary purpose of the PR as described in the title (small unrelated changes should have their own PR)
  • PR must have one changelog/ label attached. If applicable it should have the backward-incompatible label attached.
  • PR should not have do-not-merge/ label attached.
  • If Applicable, issue must have kind/ and severity/ labels attached at least.

@nikita-tkachenko-datadog nikita-tkachenko-datadog added the changelog/Fixed Fixed features results into a bug fix version bump label Mar 25, 2024
Base automatically changed from nikita-tkachenko/downstream-pipelines-support to master March 26, 2024 14:03
@nikita-tkachenko-datadog
nikita-tkachenko-datadog force-pushed the nikita-tkachenko/queue-time-fixes branch from 0f47c16 to d2537c8 Compare March 26, 2024 14:04
@nikita-tkachenko-datadog
nikita-tkachenko-datadog marked this pull request as ready for review March 26, 2024 15:56

@drodriguezhdez drodriguezhdez left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

Dropped some comments.

// At this point, the current node is traceable.
final TraceSpan.TraceSpanContext spanContext = new TraceSpan.TraceSpanContext(current.getTraceId(), current.getParentSpanId(), current.getSpanId());
final TraceSpan span = new TraceSpan(buildOperationName(current), fixedStartTimeNanos + current.getNanosInQueue(), spanContext);
final TraceSpan span = new TraceSpan(buildOperationName(current), startTimeNanos + current.getQueueTimeMillis(), spanContext);

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

Are we removing the queue time twice? We're doing the same in this part of the code and we're not doing it for webhooks protocol.

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

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

Good catch, fixed!

* This queue time goes AFTER timestamp that is reported by {@link Run#getStartTimeInMillis()}
* and is INCLUDED into the duration reported by {@link Run#getDuration()}.
*/
private long propagatedMillisInQueue;

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

@nikita-tkachenko-datadog nikita-tkachenko-datadog Apr 1, 2024

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

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

As BuildData represents the entire build, only the time spent waiting for the agent specified in the top-level agent {} section is propagated, which I think is the correct behaviour.
For individual stages the time spent waiting for their respective agents will be accounted for in the PipelineStepData instances

queueInfoAction.setQueueTimeMillis(waitingMs);
if (waitingMs != null) {
try (Metrics metrics = client.metrics()) {
metrics.gauge("jenkins.job.waiting", TimeUnit.MILLISECONDS.toSeconds(waitingMs), hostname, tags);

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

Not sure if this metric has the same meaning than CI Visibility Queue Time, but here we're not taking into account the "propagated" queue time (for Jenkins Declarative Pipelines using agent)

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

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

I'm not sure either, the documentation just says "Time spent waiting for job to run".
I'd leave it as is, at least for now, given that there haven't been any customer complaints

@drodriguezhdez drodriguezhdez left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

LGTM

@nikita-tkachenko-datadog
nikita-tkachenko-datadog merged commit 26f09a7 into master Apr 2, 2024
@nikita-tkachenko-datadog
nikita-tkachenko-datadog deleted the nikita-tkachenko/queue-time-fixes branch April 2, 2024 08:31
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

changelog/Fixed Fixed features results into a bug fix version bump

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants