Skip to content

fix: update queue duration calculation#752

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

Draft
yanksyoon wants to merge 4 commits into
base:main
Choose a base branch
from
+114 −10
Draft

fix: update queue duration calculation #752

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
061fa2d
fix: update queue duration calculation
yanksyoon Mar 16, 2026
23fd33c
Merge branch 'main' into fix/queue-duration
yanksyoon Mar 16, 2026
f3751e0
Merge branch 'main' into fix/queue-duration
yanksyoon Mar 18, 2026
b3e6d0b
fix: handle optional queued_at and started_at fields in JobInfo
yanksyoon Mar 18, 2026
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
14 changes: 13 additions & 1 deletion github-runner-manager/src/github_runner_manager/github_client.py
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -464,7 +464,18 @@ def _to_job_info(job: dict) -> JobInfo:
# datetime strings should be in ISO 8601 format, but they can also use Z instead of +00:00,
# which is not supported by datetime.fromisoformat
created_at = datetime.fromisoformat(job["created_at"].replace("Z", "+00:00"))
started_at = datetime.fromisoformat(job["started_at"].replace("Z", "+00:00"))
queued_at_raw = job.get("queued_at")
queued_at = (
datetime.fromisoformat(queued_at_raw.replace("Z", "+00:00"))
if queued_at_raw
else None
)
Comment on lines +467 to +472

@yhaliawyhaliawSep 2, 2026

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.

The GitHub Actions Jobs REST API ("Get a job for a workflow run") doesn't return a queued_at field at all — its response schema only has created_at/started_at/completed_at. That means job.get("queued_at") here always evaluates to None in production.

As a result, queued_or_created_at = job_info.queued_at or job_info.created_at in metrics/github.py:53 will always fall back to created_at, so the queue-duration value is unchanged from before this PR. The PR's stated goal — measuring queue duration from the true queue-entry timestamp — isn't actually achieved; only the missing-started_at handling is a real behavioral change. This is easy to miss because every unit test injects a synthetic queued_at key into the mocked response, so the suite can't detect the divergence from the real API shape.

Either drop the queued_at plumbing and scope this PR to the missing-started_at fix, or call out explicitly in the PR description that GitHub doesn't currently expose this field and the plumbing is forward-looking for a future data source (e.g. a workflow_job webhook payload, if that's the intent).

🤖 AI-assisted

started_at_raw = job.get("started_at")
started_at = (
datetime.fromisoformat(started_at_raw.replace("Z", "+00:00"))
if started_at_raw
else None
)
# conclusion could be null or an empty dictionary per api schema, so we need to handle
# that though we would assume that it should always be present, as the job should be
# finished.
Expand All@@ -474,6 +485,7 @@ def _to_job_info(job: dict) -> JobInfo:
job_id = job["id"]
return JobInfo(
job_id=job_id,
queued_at=queued_at,
created_at=created_at,
started_at=started_at,
conclusion=conclusion,
Expand Down
7 changes: 6 additions & 1 deletion github-runner-manager/src/github_runner_manager/metrics/github.py
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -50,6 +50,11 @@ def job(
except (JobNotFoundError, PlatformApiError) as exc:
raise GithubMetricsError from exc

queue_duration = (job_info.started_at - job_info.created_at).total_seconds()
queued_or_created_at = job_info.queued_at or job_info.created_at
queue_duration = (
(job_info.started_at - queued_or_created_at).total_seconds()
if job_info.started_at
else None
)

return GithubJobMetrics(queue_duration=queue_duration, conclusion=job_info.conclusion)
16 changes: 12 additions & 4 deletions github-runner-manager/src/github_runner_manager/metrics/runner.py
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -550,7 +550,11 @@ def _issue_runner_start(
else float("inf")
)
RUNNER_IDLE_DURATION_SECONDS.labels(flavor).observe(idle_duration)
queue_duration = job_metrics.queue_duration if job_metrics else float("inf")
queue_duration = (
job_metrics.queue_duration
if job_metrics and job_metrics.queue_duration is not None
else float("inf")
)
RUNNER_QUEUE_DURATION_SECONDS.labels(flavor).observe(queue_duration)
return metric_events.RunnerStart

Expand DownExpand Up@@ -614,14 +618,18 @@ def _create_runner_start(
pre_job_metrics.timestamp - (runner_metrics.installation_end_timestamp or 0), 0
)

# GitHub API returns started_at < created_at in some rare cases.
if job_metrics and job_metrics.queue_duration < 0:
# GitHub API returns started_at < queued_at in some rare cases.
if job_metrics and job_metrics.queue_duration is not None and job_metrics.queue_duration < 0:
logger.warning(
"Queue duration for runner %s is negative: %f. Setting it to zero.",
runner_metrics.instance_id,
job_metrics.queue_duration,
)
queue_duration = max(job_metrics.queue_duration, 0) if job_metrics else None
queue_duration = (
max(job_metrics.queue_duration, 0)
if job_metrics and job_metrics.queue_duration is not None
else None
)
Comment on lines 553 to +632

@yhaliawyhaliawSep 2, 2026

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.

The new queue_duration is None branches in _issue_runner_start (falls back to float("inf")) and _create_runner_start (falls back to None, skipping the negative-clamp/warning) have no test coverage. A regression here — e.g. reverting to job_metrics.queue_duration if job_metrics else float("inf") — would raise a TypeError on None < 0 and wouldn't be caught by the existing suite, since every GithubJobMetrics(...) construction in tests/unit/metrics/test_runner.py currently passes a concrete queue_duration.

Could you add cases constructing GithubJobMetrics(queue_duration=None, ...), asserting the float("inf") observation for _issue_runner_start and RunnerStart.queue_duration is None for _create_runner_start?

🤖 AI-assisted


return metric_events.RunnerStart(
timestamp=pre_job_metrics.timestamp,
Expand Down
2 changes: 1 addition & 1 deletion github-runner-manager/src/github_runner_manager/metrics/type.py
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -19,5 +19,5 @@ class GithubJobMetrics(NamedTuple):
conclusion: The conclusion of the job.
"""

queue_duration: float
queue_duration: Optional[float]
conclusion: Optional[JobConclusion]
1 change: 1 addition & 0 deletions github-runner-manager/src/github_runner_manager/platform/github_provider.py
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -303,6 +303,7 @@ def get_job_info(
job_info,
)
return JobInfo(
queued_at=job_info.queued_at,
created_at=job_info.created_at,
started_at=job_info.started_at,
conclusion=job_info.conclusion,
Expand Down
4 changes: 3 additions & 1 deletion github-runner-manager/src/github_runner_manager/platform/platform_provider.py
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -243,12 +243,14 @@ class JobInfo:
"""Stats for a job on a platform.

Attributes:
queued_at: The time the job entered the queue.
created_at: The time the job was created.
started_at: The time the job was started.
conclusion: The end result of a job.
"""

queued_at: datetime | None
created_at: datetime
started_at: datetime
started_at: datetime | None
# A str until we realise a common pattern, use a simple str
conclusion: str | None
4 changes: 3 additions & 1 deletion github-runner-manager/src/github_runner_manager/types_/github.py
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -118,15 +118,17 @@ class JobInfo(BaseModel):

Attributes:
job_id: The ID of the job.
queued_at: The time the job entered the queue.
created_at: The time the job was created.
started_at: The time the job was started.
conclusion: The end result of a job.
status: The status of the job.
"""

job_id: int
queued_at: Optional[datetime]
created_at: datetime
started_at: datetime
started_at: Optional[datetime]
conclusion: Optional[JobConclusion]
status: JobStatus

Expand Down
34 changes: 34 additions & 0 deletions github-runner-manager/tests/unit/metrics/test_github.py
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -42,6 +42,7 @@ def test_job(pre_job_metrics: PreJobMetrics):
created_at = datetime(2021, 10, 1, 0, 0, 0, tzinfo=timezone.utc)
started_at = created_at + timedelta(seconds=3600)
github_client.get_job_info_by_runner_name.return_value = JobInfo(
queued_at=created_at,
created_at=created_at,
started_at=started_at,
conclusion=JobConclusion.SUCCESS,
Expand All@@ -63,6 +64,39 @@ def test_job(pre_job_metrics: PreJobMetrics):
assert job_metrics.conclusion == JobConclusion.SUCCESS


def test_job_missing_started_at(pre_job_metrics: PreJobMetrics):
"""
arrange: create a GithubClient mock with missing started_at.
act: Call job.
assert: queue_duration is None.
"""
prefix = "app-0"
github_client = MagicMock(spec=GithubClient)
runner = InstanceID.build(prefix=prefix)
created_at = datetime(2021, 10, 1, 0, 0, 0, tzinfo=timezone.utc)
github_client.get_job_info_by_runner_name.return_value = JobInfo(
queued_at=created_at,
created_at=created_at,
started_at=None,
conclusion=JobConclusion.SUCCESS,
status=JobStatus.QUEUED,
job_id=randint(1, 1000),
)

github_provider = GitHubRunnerPlatform(
prefix=prefix, path="canonical", github_client=github_client
)
job_metrics = github_metrics.job(
platform_provider=github_provider,
pre_job_metrics=pre_job_metrics,
runner=runner,
metadata=RunnerMetadata(),
)

assert job_metrics.queue_duration is None
assert job_metrics.conclusion == JobConclusion.SUCCESS


def test_job_job_not_found(pre_job_metrics: PreJobMetrics):
"""
arrange: create a GithubClient mock which raises a JobNotFound exception.
Expand Down
42 changes: 41 additions & 1 deletion github-runner-manager/tests/unit/test_github_client.py
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -38,7 +38,7 @@

JobStatsRawData = namedtuple(
"JobStatsRawData",
["created_at", "started_at", "runner_name", "conclusion", "id", "status"],
["created_at", "queued_at", "started_at", "runner_name", "conclusion", "id", "status"],
)


Expand DownExpand Up@@ -111,6 +111,7 @@ def job_stats_fixture() -> JobStatsRawData:
runner_name = secrets.token_hex(16)
return JobStatsRawData(
created_at="2021-10-01T00:00:00Z",
queued_at="2021-10-01T00:30:00Z",
started_at="2021-10-01T01:00:00Z",
conclusion="success",
status="completed",
Expand All@@ -134,6 +135,7 @@ def github_client_fixture(job_stats_raw: JobStatsRawData) -> GithubClient:
"jobs": [
{
"created_at": job_stats_raw.created_at,
"queued_at": job_stats_raw.queued_at,
"started_at": job_stats_raw.started_at,
"runner_name": job_stats_raw.runner_name,
"conclusion": job_stats_raw.conclusion,
Expand DownExpand Up@@ -171,6 +173,7 @@ def _mock_multiple_pages_for_job_response(
"jobs": [
{
"created_at": job_stats_raw.created_at,
"queued_at": job_stats_raw.queued_at,
"started_at": job_stats_raw.started_at,
"runner_name": runner_names[i * no_of_jobs_per_page + j],
"conclusion": job_stats_raw.conclusion,
Expand DownExpand Up@@ -202,6 +205,7 @@ def test_get_job_info_by_runner_name(github_client: GithubClient, job_stats_raw:
)
assert job_stats == JobInfo(
created_at=datetime(2021, 10, 1, 0, 0, 0, tzinfo=timezone.utc),
queued_at=datetime(2021, 10, 1, 0, 30, 0, tzinfo=timezone.utc),
started_at=datetime(2021, 10, 1, 1, 0, 0, tzinfo=timezone.utc),
conclusion=JobConclusion.SUCCESS,
status=JobStatus.COMPLETED,
Expand All@@ -224,6 +228,7 @@ def test_get_job_info_by_runner_name_no_conclusion(
"jobs": [
{
"created_at": job_stats_raw.created_at,
"queued_at": job_stats_raw.queued_at,
"started_at": job_stats_raw.started_at,
"runner_name": job_stats_raw.runner_name,
"conclusion": None,
Expand All@@ -241,6 +246,7 @@ def test_get_job_info_by_runner_name_no_conclusion(
)
assert job_stats == JobInfo(
created_at=datetime(2021, 10, 1, 0, 0, 0, tzinfo=timezone.utc),
queued_at=datetime(2021, 10, 1, 0, 30, 0, tzinfo=timezone.utc),
started_at=datetime(2021, 10, 1, 1, 0, 0, tzinfo=timezone.utc),
conclusion=None,
status=JobStatus.COMPLETED,
Expand All@@ -258,6 +264,7 @@ def test_get_job_info(github_client: GithubClient, job_stats_raw: JobStatsRawDat
{},
{
"created_at": job_stats_raw.created_at,
"queued_at": job_stats_raw.queued_at,
"started_at": job_stats_raw.started_at,
"runner_name": job_stats_raw.runner_name,
"conclusion": job_stats_raw.conclusion,
Expand All@@ -269,6 +276,7 @@ def test_get_job_info(github_client: GithubClient, job_stats_raw: JobStatsRawDat
job_stats = github_client.get_job_info(path=github_repo, job_id=job_stats_raw.id)
assert job_stats == JobInfo(
created_at=datetime(2021, 10, 1, 0, 0, 0, tzinfo=timezone.utc),
queued_at=datetime(2021, 10, 1, 0, 30, 0, tzinfo=timezone.utc),
started_at=datetime(2021, 10, 1, 1, 0, 0, tzinfo=timezone.utc),
conclusion=JobConclusion.SUCCESS,
status=JobStatus.COMPLETED,
Expand DownExpand Up@@ -297,6 +305,38 @@ def test_github_api_pagination_multiple_pages(
)
assert job_stats == JobInfo(
created_at=datetime(2021, 10, 1, 0, 0, 0, tzinfo=timezone.utc),
queued_at=datetime(2021, 10, 1, 0, 30, 0, tzinfo=timezone.utc),
started_at=datetime(2021, 10, 1, 1, 0, 0, tzinfo=timezone.utc),
conclusion=JobConclusion.SUCCESS,
status=JobStatus.COMPLETED,
job_id=job_stats_raw.id,
)


def test_get_job_info_without_queued_at(
github_client: GithubClient, job_stats_raw: JobStatsRawData
):
"""
arrange: A mocked Github Client with queued_at missing in the response.
act: Call get_job_info.
assert: The response is returned with queued_at set to None.
"""
github_client._requester.requestJsonAndCheck.return_value = (
{},
{
"created_at": job_stats_raw.created_at,
"started_at": job_stats_raw.started_at,
"runner_name": job_stats_raw.runner_name,
"conclusion": job_stats_raw.conclusion,
"status": job_stats_raw.status,
"id": job_stats_raw.id,
},
)
github_repo = GitHubRepo(owner=secrets.token_hex(16), repo=secrets.token_hex(16))
job_stats = github_client.get_job_info(path=github_repo, job_id=job_stats_raw.id)
assert job_stats == JobInfo(
created_at=datetime(2021, 10, 1, 0, 0, 0, tzinfo=timezone.utc),
queued_at=None,
started_at=datetime(2021, 10, 1, 1, 0, 0, tzinfo=timezone.utc),
conclusion=JobConclusion.SUCCESS,
status=JobStatus.COMPLETED,
Expand Down
Loading