argoproj / argoproj/argo-workflows
Metric duration gauge keeps incrementing for 'Pending' status, until the workflow is deleted
- Dominant language
- Go
- Stars
- 17k
- Forks
- 3.7k
- Avg merge
- 1d 20h
- Merged PRs (30d)
- 138
Description
## Summary
We added Prometheus _realtime_ gauges to templates with value of `{{duration}}`, and labeled with `{{status}}`. We were surprised to see that the value of `Pending` step duration keeps increasing even after the step has transitioned into Running and Succeeded/Failed states, and beyond workflow completion. The only way to stop this metric from being emitted is to delete the workflow.
Also, the `{{duration}}` for the `Running` state seems to not be emitted at all.
We would expect the `Pending` series to flatten once the step exits the Pending state, and for the `Running` series to be present.
A *separate* enhancement request might be to stop emitting realtime metrics for completed workflows, to both reduce the number of scraped series, and help report on the current state via `instant` queries, rather than having to calculate `delta()` on gauges to determine whether the value is still changing.
Argo Workflows v3.2.3
## Diagnostics
The workflow is a slightly modified version of the metrics [example](https://github.com/argoproj/argo-workflows/blob/master/examples/custom-metrics.yaml):
```yaml
apiVersion: argoproj.io/v1alpha1
kind: Workflow
metadata:
creationTimestamp: "2021-12-02T23:12:31Z"
generateName: metrics-
generation: 5
labels:
workflows.argoproj.io/archive-strategy: always
workflows.argoproj.io/completed: "true"
workflows.argoproj.io/phase: Failed
workflows.argoproj.io/workflow-archiving-status: Archived
managedFields:
- apiVersion: argoproj.io/v1alpha1
fieldsType: FieldsV1
fieldsV1:
f:metadata:
f:generateName: {}
manager: argo
operation: Update
time: "2021-12-02T23:12:31Z"
- apiVersion: argoproj.io/v1alpha1
fieldsType: FieldsV1
fieldsV1:
f:metadata:
f:labels:
.: {}
f:workflows.argoproj.io/archive-strategy: {}
f:workflows.argoproj.io/completed: {}
f:workflows.argoproj.io/phase: {}
f:workflows.argoproj.io/workflow-archiving-status: {}
f:spec: {}
f:status: {}
manager: workflow-controller
operation: Update
time: "2021-12-02T23:13:52Z"
name: metrics-lcvgb
namespace: sandbox
resourceVersion: "317267688"
uid: a2525a26-69b0-486b-9756-475f07c56b8d
spec:
entrypoint: main
securityContext: {}
serviceAccountName: argo-workflows
templates:
- inputs: {}
metadata: {}
name: main
outputs: {}
steps:
- - arguments: {}
name: random-int
template: random-int
- - arguments: {}
name: flakey
template: flakey
- container:
args:
- RAND_INT=$((1 + RANDOM % 10)); echo $RAND_INT; echo $RAND_INT > /tmp/rand_int.txt;
sleep 60
command:
- sh
- -c
image: alpine:latest
name: ""
resources: {}
inputs: {}
metadata: {}
metrics:
prometheus:
- counter:
value: "1"
help: Count of step execution by result
labels:
- key: step_template
value: random-int
- key: workflow_namespace
value: '{{workflow.namespace}}'
- key: workflow_name
value: '{{workflow.name}}'
- key: status
value: '{{status}}'
name: step_result_count
- gauge:
realtime: true
value: '{{duration}}'
help: Duration of template execution
labels:
- key: step_template
value: random-int
- key: workflow_namespace
value: '{{workflow.namespace}}'
- key: workflow_name
value: '{{workflow.name}}'
- key: status
value: '{{status}}'
name: step_duration_gauge
name: random-int
outputs:
parameters:
- globalName: rand-int-value
name: rand-int-value
valueFrom:
path: /tmp/rand_int.txt
- container:
args:
- import random; import sys; exit_code = random.choice([0, 1, 1]); sys.exit(exit_code)
command:
- python
- -c
image: python:alpine3.6
name: ""
resources: {}
inputs: {}
metadata: {}
metrics:
prometheus:
- counter:
value: "1"
help: Count of step execution by result
labels:
- key: step_template
value: flakey
- key: workflow_namespace
value: '{{workflow.namespace}}'
- key: workflow_name
value: '{{workflow.name}}'
- key: status
value: '{{status}}'
name: step_result_count
- gauge:
realtime: true
value: '{{duration}}'
help: Duration of template execution
labels:
- key: step_template
value: flakey
- key: workflow_namespace
value: '{{workflow.namespace}}'
- key: workflow_name
value: '{{workflow.name}}'
- key: status
value: '{{status}}'
name: step_duration_gauge
name: flakey
outputs: {}
ttlStrategy:
secondsAfterCompletion: 84600
status:
conditions:
- status: "False"
type: PodRunning
- status: "True"
type: Completed
finishedAt: "2021-12-02T23:13:52Z"
message: child 'metrics-lcvgb-1593082173' failed
nodes:
metrics-lcvgb:
children:
- metrics-lcvgb-3470239446
displayName: metrics-lcvgb
finishedAt: "2021-12-02T23:13:52Z"
id: metrics-lcvgb
message: child 'metrics-lcvgb-1593082173' failed
name: metrics-lcvgb
phase: Failed
progress: 2/2
resourcesDuration:
cpu: 122
memory: 184
startedAt: "2021-12-02T23:12:31Z"
templateName: main
templateScope: local/metrics-lcvgb
type: Retry
metrics-lcvgb-567759933:
boundaryID: metrics-lcvgb-3470239446
children:
- metrics-lcvgb-1593082173
displayName: '[1]'
finishedAt: "2021-12-02T23:13:52Z"
id: metrics-lcvgb-567759933
message: child 'metrics-lcvgb-1593082173' failed
name: metrics-lcvgb(0)[1]
phase: Failed
progress: 1/1
resourcesDuration:
cpu: 1
memory: 2
startedAt: "2021-12-02T23:13:42Z"
templateScope: local/metrics-lcvgb
type: StepGroup
metrics-lcvgb-1414972696:
boundaryID: metrics-lcvgb-3470239446
children:
- metrics-lcvgb-567759933
displayName: random-int(0)
finishedAt: "2021-12-02T23:13:32Z"
hostNodeName: ip-192-168-37-144.us-east-2.compute.internal
id: metrics-lcvgb-1414972696
name: metrics-lcvgb(0)[0].random-int(0)
outputs:
exitCode: "0"
parameters:
- globalName: rand-int-value
name: rand-int-value
value: "10"
valueFrom:
path: /tmp/rand_int.txt
phase: Succeeded
progress: 1/1
resourcesDuration:
cpu: 121
memory: 182
startedAt: "2021-12-02T23:12:31Z"
templateName: random-int
templateScope: local/metrics-lcvgb
type: Pod
metrics-lcvgb-1593082173:
boundaryID: metrics-lcvgb-3470239446
children:
- metrics-lcvgb-3459789644
displayName: flakey
finishedAt: "2021-12-02T23:13:52Z"
id: metrics-lcvgb-1593082173
message: Error (exit code 1)
name: metrics-lcvgb(0)[1].flakey
outputs:
exitCode: "1"
phase: Failed
progress: 1/1
resourcesDuration:
cpu: 1
memory: 2
startedAt: "2021-12-02T23:13:42Z"
templateName: flakey
templateScope: local/metrics-lcvgb
type: Retry
metrics-lcvgb-3459789644:
boundaryID: metrics-lcvgb-3470239446
displayName: flakey(0)
finishedAt: "2021-12-02T23:13:44Z"
hostNodeName: ip-192-168-37-144.us-east-2.compute.internal
id: metrics-lcvgb-3459789644
message: Error (exit code 1)
name: metrics-lcvgb(0)[1].flakey(0)
outputs:
exitCode: "1"
phase: Failed
progress: 1/1
resourcesDuration:
cpu: 1
memory: 2
startedAt: "2021-12-02T23:13:42Z"
templateName: flakey
templateScope: local/metrics-lcvgb
type: Pod
metrics-lcvgb-3470239446:
children:
- metrics-lcvgb-3721996232
displayName: metrics-lcvgb(0)
finishedAt: "2021-12-02T23:13:52Z"
id: metrics-lcvgb-3470239446
message: child 'metrics-lcvgb-1593082173' failed
name: metrics-lcvgb(0)
outboundNodes:
- metrics-lcvgb-3459789644
phase: Failed
progress: 2/2
resourcesDuration:
cpu: 122
memory: 184
startedAt: "2021-12-02T23:12:31Z"
templateName: main
templateScope: local/metrics-lcvgb
type: Steps
metrics-lcvgb-3595365697:
boundaryID: metrics-lcvgb-3470239446
children:
- metrics-lcvgb-1414972696
displayName: random-int
finishedAt: "2021-12-02T23:13:42Z"
id: metrics-lcvgb-3595365697
name: metrics-lcvgb(0)[0].random-int
outputs:
exitCode: "0"
parameters:
- globalName: rand-int-value
name: rand-int-value
value: "10"
valueFrom:
path: /tmp/rand_int.txt
phase: Succeeded
progress: 2/2
resourcesDuration:
cpu: 122
memory: 184
startedAt: "2021-12-02T23:12:31Z"
templateName: random-int
templateScope: local/metrics-lcvgb
type: Retry
metrics-lcvgb-3721996232:
boundaryID: metrics-lcvgb-3470239446
children:
- metrics-lcvgb-3595365697
displayName: '[0]'
finishedAt: "2021-12-02T23:13:42Z"
id: metrics-lcvgb-3721996232
name: metrics-lcvgb(0)[0]
phase: Succeeded
progress: 2/2
resourcesDuration:
cpu: 122
memory: 184
startedAt: "2021-12-02T23:12:31Z"
templateScope: local/metrics-lcvgb
type: StepGroup
outputs:
parameters:
- name: rand-int-value
value: "10"
phase: Failed
progress: 2/2
resourcesDuration:
cpu: 122
memory: 184
startedAt: "2021-12-02T23:12:31Z"
```
As a result of this workflow we can see that:
1. `status="Succeeded"` and `status="Failed"` series only start being emitted once the steps enter their respective state, and remain at that value.
2. `status="Pending"` steps series continue increasing the value of the gauge, even though the steps have long left the `Pending` state. The expected behaviour is that once step is running, the `Pending` series' value should flatten.
3. we are not seeing a value for the `Running` series at all.
Once the workflows are deleted, these metrics stop being emitted, as expected.


---
**Message from the maintainers**:
Impacted by this bug? Give it a 👍. We prioritise the issues with the most 👍.
Contributor guide
Assessment
This issue has not been assessed yet.