actions / actions/actions-runner-controller
bug(metrics): Large negative values are reported when time.IsZero() in code.
Nobody has claimed this yet.
- Dominant language
- Go
- Stars
- 6.5k
- Forks
- 1.5k
- Avg merge
- 2d 2h
- Merged PRs (30d)
- 27
Description
Checks
- I've already read https://github.com/actions/actions-runner-controller/blob/master/TROUBLESHOOTING.md and I'm sure my issue is not covered in the troubleshooting guide.
- I'm not using a custom entrypoint in my runner image
Controller Version
0.27.4
Helm Chart Version
No response
CertManager Version
No response
Deployment Method
Helm
cert-manager installation
Unneeded for this bug.
Checks
- This isn't a question or user support case (For Q&A and community support, go to Discussions. It might also be a good idea to contract with any of contributors and maintainers if your business is so critical and therefore you need priority support
- I've read releasenotes before submitting this issue and I'm sure it's not due to any recently-introduced backward-incompatible changes
- My actions-runner-controller version (v0.x.y) does support the feature
- I've already upgraded ARC (including the CRDs, see charts/actions-runner-controller/docs/UPGRADING.md for details) to the latest and it didn't fix the issue
- I've migrated to the workflow job webhook event (if you using webhook driven scaling)
Resource Definitions
Unneeded for this bug.
To Reproduce
Gather a large number of metrics and inspect the /metrics endpoint for large negative values.
Describe the bug
We see large negative values in our bucket timings. Code bug in additional context
Describe the expected behavior
The "run duration" of a job should never be a large negative value
Whole Controller Logs
.
Whole Runner Pod Logs
.
Additional Context
I'm looking at the function here: https://github.com/actions/actions-runner-controller/blob/e0a7e142e0fcd446c58e7875d4d44a7eea6e72f2/pkg/actionsmetrics/event_reader.go#L226
The code ends in this
return &ParseResult{
ExitCode: exitCode,
QueueTime: startedTime.Sub(queuedTime),
RunTime: completedTime.Sub(startedTime),
}, nil
I believe that sometimes, startedTime or completedTime, are never parsed and are still the zero value. When they are the zero value, the returned value is 0-<now> which is very large and reports as a large negative number in the /metrics endpoint.
Proposed fix
Rather than this
return &ParseResult{
ExitCode: exitCode,
QueueTime: startedTime.Sub(queuedTime),
RunTime: completedTime.Sub(startedTime),
}, nil
Do this
var ret ParseResult
if !startedTime.IsZero() && !queuedTime.IsZero() {
ret.QueueTime = startedTime.Sub(queuedTime)
}
And the same for RunTime.
Then on the caller side, if the metric QueueTime.IsZero() is true, don't report the zero value to /metrics historgram
Contributor guide
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Research direction
Start in pkg/actionsmetrics/event_reader.go around the referenced parsing function and trace how QueueTime and RunTime reach the /metrics endpoint. Reproduce the zero-time case, ensure missing timestamps do not produce large negative durations or histogram observations, and verify the relevant metrics behavior with tests.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- go
- Domain
- observability-sre
- Issue type
- Bug
- Difficulty
- 3/5
- Estimated time
- 1-2 days
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 35/100