fix: Mark taskResult completed if wait container terminated not gracefully. Fixes #13373 #13491

jswxstw · 2024-08-21T06:09:01Z

Fixes #13373

Motivation

#12103 (comment)

Modifications

Mark its taskResult as completed if pod has been terminated not gracefully.

Verification

This issue only occurs when wait container is terminated not gracefully, it is hard to reproduce it.

submit a workflow with a long running pod.

apiVersion: argoproj.io/v1alpha1
kind: Workflow
metadata:
  generateName: sleep-example-
spec:
  entrypoint: main
  templates:
  - name: main
    steps:
    - - name: sleep
        template: sleep

  - name: sleep
    container:
      image: alpine:latest
      command: [sh, -c, sleep 3600]

kill -9 wait/main container

ctr task kill --signal 9 8c66238d4723b9237c4e71d3fd16710f5f985d2ce8f7218ff987e143b3e8140b # wait container
ctr task kill --signal 9 5da93afce108bc59f746e8c8df791ae6c808deaedaa87abc8f6ea5f4697da2df # main container

Pod Error and wait container does not write LabelKeyReportOutputsCompleted to true

# sleep-example-tdnk7-sleep-1943014577   0/2     Error     0            9m21s
# k logs -f sleep-example-tdnk7-sleep-1943014577 -c wait
time="2024-08-21T03:55:14.519Z" level=info msg="Starting Workflow Executor" version=untagged
time="2024-08-21T03:55:14.522Z" level=info msg="Using executor retry strategy" Duration=1s Factor=1.6 Jitter=0.5 Steps=5
time="2024-08-21T03:55:14.522Z" level=info msg="Executor initialized" deadline="2024-08-21 04:00:13 +0000 UTC" includeScriptOutput=false namespace=argo podName=sleep-example-tdnk7-sleep-1943014577 templateName=sleep version="&Version{Version:untagged,BuildDate:2024-08-15T12:58:34Z,GitCommit:c143e3e78c1b6d585d64a2d9363bf0c9c64caf6c,GitTag:untagged,GitTreeState:clean,GoVersion:go1.22.6,Compiler:gc,Platform:linux/amd64,}"
time="2024-08-21T03:55:14.529Z" level=debug msg="Create workflowtaskresults 201"
time="2024-08-21T03:55:14.530Z" level=info msg="Starting deadline monitor"
time="2024-08-21T03:55:21.534Z" level=debug msg="Create workflowtaskresults 409"
time="2024-08-21T03:55:21.538Z" level=debug msg="Patch workflowtaskresults 200"
time="2024-08-21T03:55:28.535Z" level=debug msg="Create workflowtaskresults 409"
time="2024-08-21T03:55:28.538Z" level=debug msg="Patch workflowtaskresults 200"
time="2024-08-21T03:55:35.535Z" level=debug msg="Create workflowtaskresults 409"
time="2024-08-21T03:55:35.538Z" level=debug msg="Patch workflowtaskresults 200"
time="2024-08-21T03:55:42.535Z" level=debug msg="Create workflowtaskresults 409"
time="2024-08-21T03:55:42.538Z" level=debug msg="Patch workflowtaskresults 200"
time="2024-08-21T03:55:49.536Z" level=debug msg="Create workflowtaskresults 409"
time="2024-08-21T03:55:49.540Z" level=debug msg="Patch workflowtaskresults 200"
time="2024-08-21T03:55:56.534Z" level=debug msg="Create workflowtaskresults 409"
time="2024-08-21T03:55:56.538Z" level=debug msg="Patch workflowtaskresults 200"
time="2024-08-21T03:56:03.534Z" level=debug msg="Create workflowtaskresults 409"
time="2024-08-21T03:56:03.537Z" level=debug msg="Patch workflowtaskresults 200"
time="2024-08-21T03:56:10.535Z" level=debug msg="Create workflowtaskresults 409"
time="2024-08-21T03:56:10.538Z" level=debug msg="Patch workflowtaskresults 200"
time="2024-08-21T03:56:17.535Z" level=debug msg="Create workflowtaskresults 409"
time="2024-08-21T03:56:17.538Z" level=debug msg="Patch workflowtaskresults 200"

Workflow Failed as expected.

# argo get sleep-example-tdnk7
Name:                sleep-example-tdnk7
Namespace:           argo
ServiceAccount:      unset (will run with the default ServiceAccount)
Status:              Failed
Message:             child 'sleep-example-tdnk7-1943014577' failed
Conditions:
 PodRunning          False
 Completed           True
Created:             Wed Aug 21 11:55:13 +0800 (14 minutes ago)
Started:             Wed Aug 21 11:55:13 +0800 (14 minutes ago)
Finished:            Wed Aug 21 11:56:37 +0800 (13 minutes ago)
Duration:            1 minute 24 seconds
Progress:            0/1
ResourcesDuration:   13s*(1 cpu),2m0s*(100Mi memory)

STEP                    TEMPLATE  PODNAME                               DURATION  MESSAGE
 ✖ sleep-example-tdnk7  main                                                      child 'sleep-example-tdnk7-1943014577' failed
 └───✖ sleep            sleep     sleep-example-tdnk7-sleep-1943014577  1m        Error (exit code 137)

controller log:

time="2024-08-21T11:56:37.580Z" level=info msg="Processing workflow" Phase=Running ResourceVersion=2696088 namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.581Z" level=info msg="Task-result reconciliation" namespace=argo numObjs=1 workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.581Z" level=debug msg="task result:\n&WorkflowTaskResult{ObjectMeta:{sleep-example-tdnk7-1943014577  argo  64e126a5-83fe-4fc8-8c4d-9e416f3e8de4 2696021 1 2024-08-21 11:55:14 +0800 CST <nil> <nil> map[workflows.argoproj.io/report-outputs-completed:false workflows.argoproj.io/workflow:sleep-example-tdnk7] map[] [{argoproj.io/v1alpha1 Workflow sleep-example-tdnk7 28e951a9-8353-4d92-9cab-2853e00b7134 <nil> <nil>}] [] [{argoexec Update argoproj.io/v1alpha1 2024-08-21 11:55:14 +0800 CST FieldsV1 {\"f:metadata\":{\"f:labels\":{\".\":{},\"f:workflows.argoproj.io/report-outputs-completed\":{},\"f:workflows.argoproj.io/workflow\":{}},\"f:ownerReferences\":{\".\":{},\"k:{\\\"uid\\\":\\\"28e951a9-8353-4d92-9cab-2853e00b7134\\\"}\":{}}}} }]},NodeResult:NodeResult{Phase:,Message:,Outputs:nil,Progress:,},}" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.581Z" level=debug msg="task result name:\nsleep-example-tdnk7-1943014577" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.581Z" level=debug msg="Marking task result incomplete sleep-example-tdnk7-1943014577" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.581Z" level=info msg="task-result changed" namespace=argo nodeID=sleep-example-tdnk7-1943014577 workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.581Z" level=debug msg="Skipping artifact GC" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.581Z" level=info msg="Pod failed: Error (exit code 137)" displayName=sleep namespace=argo pod=sleep-example-tdnk7-sleep-1943014577 templateName=sleep workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.581Z" level=info msg="node changed" namespace=argo new.message="Error (exit code 137)" new.phase=Failed new.progress=0/1 nodeID=sleep-example-tdnk7-1943014577 old.message= old.phase=Running old.progress=0/1 workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.581Z" level=debug msg="TaskResult of the node not yet completed" namespace=argo nodeID=sleep-example-tdnk7-1943014577 workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.581Z" level=debug msg="Node failed or error, mark its taskResult as completed" namespace=argo nodeID=sleep-example-tdnk7-1943014577 workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.581Z" level=debug msg="Evaluating node sleep-example-tdnk7: template: *v1alpha1.WorkflowStep (main), boundaryID: " namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.581Z" level=debug msg="Resolving the template" base="*v1alpha1.Workflow (namespace=argo,name=sleep-example-tdnk7)" tmpl="*v1alpha1.WorkflowStep (main)"
time="2024-08-21T11:56:37.581Z" level=debug msg="Getting the template" base="*v1alpha1.Workflow (namespace=argo,name=sleep-example-tdnk7)" tmpl="*v1alpha1.WorkflowStep (main)"
time="2024-08-21T11:56:37.581Z" level=debug msg="Getting the template by name: main" base="*v1alpha1.Workflow (namespace=argo,name=sleep-example-tdnk7)" tmpl="*v1alpha1.WorkflowStep (main)"
time="2024-08-21T11:56:37.582Z" level=debug msg="Executing node sleep-example-tdnk7 of Steps is Running" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.582Z" level=debug msg="Evaluating node sleep-example-tdnk7[0].sleep: template: *v1alpha1.WorkflowStep (sleep), boundaryID: sleep-example-tdnk7" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.582Z" level=debug msg="Resolving the template" base="*v1alpha1.Workflow (namespace=argo,name=sleep-example-tdnk7)" tmpl="*v1alpha1.WorkflowStep (sleep)"
time="2024-08-21T11:56:37.582Z" level=debug msg="Getting the template" base="*v1alpha1.Workflow (namespace=argo,name=sleep-example-tdnk7)" tmpl="*v1alpha1.WorkflowStep (sleep)"
time="2024-08-21T11:56:37.582Z" level=debug msg="Getting the template by name: sleep" base="*v1alpha1.Workflow (namespace=argo,name=sleep-example-tdnk7)" tmpl="*v1alpha1.WorkflowStep (sleep)"
time="2024-08-21T11:56:37.582Z" level=debug msg="Node sleep-example-tdnk7[0].sleep already completed" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.582Z" level=info msg="Step group node sleep-example-tdnk7-2176115732 deemed failed: child 'sleep-example-tdnk7-1943014577' failed" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.582Z" level=info msg="node sleep-example-tdnk7-2176115732 phase Running -> Failed" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.582Z" level=info msg="node sleep-example-tdnk7-2176115732 message: child 'sleep-example-tdnk7-1943014577' failed" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.582Z" level=info msg="node sleep-example-tdnk7-2176115732 finished: 2024-08-21 03:56:37.582246691 +0000 UTC" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.582Z" level=info msg="step group sleep-example-tdnk7-2176115732 was unsuccessful: child 'sleep-example-tdnk7-1943014577' failed" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.582Z" level=debug msg="Resolving the template" base="*v1alpha1.Workflow (namespace=argo,name=sleep-example-tdnk7)" tmpl="*v1alpha1.NodeStatus (sleep)"
time="2024-08-21T11:56:37.582Z" level=debug msg="Getting the template" base="*v1alpha1.Workflow (namespace=argo,name=sleep-example-tdnk7)" tmpl="*v1alpha1.NodeStatus (sleep)"
time="2024-08-21T11:56:37.582Z" level=debug msg="Getting the template by name: sleep" base="*v1alpha1.Workflow (namespace=argo,name=sleep-example-tdnk7)" tmpl="*v1alpha1.NodeStatus (sleep)"
time="2024-08-21T11:56:37.582Z" level=info msg="Outbound nodes of sleep-example-tdnk7-1943014577 is [sleep-example-tdnk7-1943014577]" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.582Z" level=info msg="Outbound nodes of sleep-example-tdnk7 is [sleep-example-tdnk7-1943014577]" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.582Z" level=info msg="node sleep-example-tdnk7 phase Running -> Failed" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.582Z" level=info msg="node sleep-example-tdnk7 message: child 'sleep-example-tdnk7-1943014577' failed" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.582Z" level=info msg="node sleep-example-tdnk7 finished: 2024-08-21 03:56:37.582346369 +0000 UTC" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.582Z" level=debug msg="Checking daemoned children of sleep-example-tdnk7" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.582Z" level=info msg="TaskSet Reconciliation" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.582Z" level=info msg=reconcileAgentPod namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.582Z" level=debug msg="Task results completion status: map[sleep-example-tdnk7-1943014577:true]" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.582Z" level=info msg="Updated phase Running -> Failed" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.582Z" level=info msg="Updated message  -> child 'sleep-example-tdnk7-1943014577' failed" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.582Z" level=info msg="Marking workflow completed" namespace=argo workflow=sleep-example-tdnk7
time="2024-08-21T11:56:37.582Z" level=debug msg="Event(v1.ObjectReference{Kind:\"Workflow\", Namespace:\"argo\", Name:\"sleep-example-tdnk7\", UID:\"28e951a9-8353-4d92-9cab-2853e00b7134\", APIVersion:\"argoproj.io/v1alpha1\", ResourceVersion:\"2696088\", FieldPath:\"\"}): type: 'Warning' reason: 'WorkflowFailed' child 'sleep-example-tdnk7-1943014577' failed"
time="2024-08-21T11:56:37.582Z" level=debug msg="Log changes patch: {\"metadata\":{\"labels\":{\"workflows.argoproj.io/completed\":\"true\",\"workflows.argoproj.io/phase\":\"Failed\"}},\"status\":{\"conditions\":[{\"status\":\"False\",\"type\":\"PodRunning\"},{\"status\":\"True\",\"type\":\"Completed\"}],\"finishedAt\":\"2024-08-21T03:56:37Z\",\"message\":\"child 'sleep-example-tdnk7-1943014577' failed\",\"nodes\":{\"sleep-example-tdnk7\":{\"finishedAt\":\"2024-08-21T03:56:37Z\",\"message\":\"child 'sleep-example-tdnk7-1943014577' failed\",\"outboundNodes\":[\"sleep-example-tdnk7-1943014577\"],\"phase\":\"Failed\"},\"sleep-example-tdnk7-1943014577\":{\"finishedAt\":\"2024-08-21T03:56:34Z\",\"message\":\"Error (exit code 137)\",\"phase\":\"Failed\",\"resourcesDuration\":{\"cpu\":13,\"memory\":120}},\"sleep-example-tdnk7-2176115732\":{\"finishedAt\":\"2024-08-21T03:56:37Z\",\"message\":\"child 'sleep-example-tdnk7-1943014577' failed\",\"phase\":\"Failed\"}},\"phase\":\"Failed\",\"taskResultsCompletionStatus\":{\"sleep-example-tdnk7-1943014577\":true}}}"
time="2024-08-21T11:56:37.582Z" level=info msg="Workflow to be dehydrated" Workflow Size=2233
time="2024-08-21T11:56:37.586Z" level=debug msg="Create events 201"
time="2024-08-21T11:56:37.588Z" level=debug msg="Update workflows 200"
time="2024-08-21T11:56:37.589Z" level=info msg="Workflow update successful" namespace=argo phase=Failed resourceVersion=2696092 workflow=sleep-example-tdnk7

yonirab · 2024-08-22T09:40:39Z

@jswxstw Does this PR also address the scenario of a workflow with a step that gets OOMKilled and then retries and succeeds?
Does it make sure the workflow status is correctly reflected as Succeeded in such a case?

jswxstw · 2024-08-22T11:12:15Z

@jswxstw Does this PR also address the scenario of a workflow with a step that gets OOMKilled and then retries and succeeds? Does it make sure the workflow status is correctly reflected as Succeeded in such a case?

@yonirab Can you provide your problem scenario(detail status of workflow and pod, logs of workflow-controller) in issue #13373?
Based on my testing, if the main container is OOMKilled, it doesn't cause any issues, and I couldn't create a scenario where the wait container is OOMKilled.
I guess the wait container in your OOMKilled pod should be terminated with non-zero exitcode, and there might be a line like this in the controller logs:

time="2024-07-22T08:07:05.077Z" level=debug msg="taskresults of workflow are incomplete or still have daemon nodes, so can't mark workflow completed" fromPhase=Running namespace=argo-simu-simulation-platform toPhase=Error workflow=simulation-platform-new-scenario-183614-1557733-prod-fqjrw

workflow/controller/operator.go

…inated not gracefully. Fixes argoproj#13373 Signed-off-by: oninowang <[email protected]>

…fully. Fixes argoproj#13373 (argoproj#13491) Signed-off-by: oninowang <[email protected]>

…fully. Fixes #13373 (#13491) Signed-off-by: oninowang <[email protected]>

jswxstw marked this pull request as draft August 21, 2024 06:53

This comment was marked as resolved.

Sign in to view

jswxstw marked this pull request as ready for review August 21, 2024 08:47

agilgur5 requested review from Joibel and isubasinghe August 21, 2024 13:44

agilgur5 changed the title ~~fix: Mark its taskResult as completed if pod has been terminated not gracefully. Fixes #13373~~ fix: Mark taskResult as completed if pod terminated not gracefully. Fixes #13373 Aug 21, 2024

agilgur5 changed the title ~~fix: Mark taskResult as completed if pod terminated not gracefully. Fixes #13373~~ fix: Mark taskResult completed if pod terminated not gracefully. Fixes #13373 Aug 21, 2024

agilgur5 added the area/controller Controller issues, panics label Aug 21, 2024

jswxstw mentioned this pull request Aug 21, 2024

v3.4.11: workflow stuck Running state, but only pod is Completed #12103

Open

3 tasks

Joibel requested changes Aug 22, 2024

View reviewed changes

workflow/controller/operator.go Outdated Show resolved Hide resolved

jswxstw force-pushed the fix-13373 branch 3 times, most recently from 97f93d2 to 606f994 Compare August 23, 2024 02:40

jswxstw requested a review from Joibel August 23, 2024 02:43

jswxstw changed the title ~~fix: Mark taskResult completed if pod terminated not gracefully. Fixes #13373~~ fix: Mark taskResult completed if wait container terminated not gracefully. Fixes #13373 Aug 23, 2024

agilgur5 added this to the v3.5.x patches milestone Aug 24, 2024

fix: Mark its taskResult as completed if wait container has been term…

5424273

…inated not gracefully. Fixes argoproj#13373 Signed-off-by: oninowang <[email protected]>

jswxstw force-pushed the fix-13373 branch from 606f994 to 5424273 Compare August 26, 2024 09:33

agilgur5 added the prioritized-review For members of the Sustainability Effort label Aug 26, 2024

Joibel approved these changes Aug 29, 2024

View reviewed changes

Joibel merged commit 3d41fb2 into argoproj:main Aug 29, 2024
28 checks passed

jswxstw mentioned this pull request Sep 2, 2024

fix: Mark task result as completed if pod has been deleted for a while. Fixes #13533 #13537

Merged

jswxstw mentioned this pull request Sep 13, 2024

v3.5.8: Stuck in Running when out of disk on a node during artifact packaging #13344

Closed

4 tasks

Joibel pushed a commit to pipekit/argo-workflows that referenced this pull request Sep 19, 2024

fix: Mark taskResult completed if wait container terminated not grace…

e105fa0

…fully. Fixes argoproj#13373 (argoproj#13491) Signed-off-by: oninowang <[email protected]>

jswxstw mentioned this pull request Sep 20, 2024

signaled container: wait error: unable to upgrade connection: container not found. node Succeeded but wf not progressing #13627

Open

4 tasks

Joibel mentioned this pull request Sep 20, 2024

Release v3.5 patch releases discussion #11997

Open

Joibel pushed a commit that referenced this pull request Sep 20, 2024

fix: Mark taskResult completed if wait container terminated not grace…

67253e8

…fully. Fixes #13373 (#13491) Signed-off-by: oninowang <[email protected]>

jswxstw mentioned this pull request Oct 8, 2024

v3.5.8: workflow shutdown with strategy: Terminate, but stuck in Running #13726

Closed

4 tasks

jswxstw mentioned this pull request Nov 1, 2024

REQUEST: Promotion to Reviewer for @jswxstw argoproj/argoproj#337

Closed

6 tasks

jswxstw mentioned this pull request Nov 26, 2024

Resource type steps that timeout due to activeDeadlineSeconds reached make the workflow remain stuck in Running forever #13937

Open

4 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

fix: Mark taskResult completed if wait container terminated not gracefully. Fixes #13373 #13491

fix: Mark taskResult completed if wait container terminated not gracefully. Fixes #13373 #13491

jswxstw commented Aug 21, 2024 •

edited by agilgur5

Loading

This comment was marked as resolved.

yonirab commented Aug 22, 2024

jswxstw commented Aug 22, 2024 •

edited

Loading

fix: Mark taskResult completed if wait container terminated not gracefully. Fixes #13373 #13491

fix: Mark taskResult completed if wait container terminated not gracefully. Fixes #13373 #13491

Conversation

jswxstw commented Aug 21, 2024 • edited by agilgur5 Loading

Motivation

Modifications

Verification

This comment was marked as resolved.

yonirab commented Aug 22, 2024

jswxstw commented Aug 22, 2024 • edited Loading

jswxstw commented Aug 21, 2024 •

edited by agilgur5

Loading

jswxstw commented Aug 22, 2024 •

edited

Loading