Repository: argoproj/argo (go)

Issue:
Pod gets stuck forever in pending state if it was deleted before initialisation
Checklist:

 * [x] I've included the version.
 * [x] I've included reproduction steps.
 * [x] I've included the workflow YAML.
 * [x] I've included the logs.

**What happened**:

In some cases kubernetes deletes pods before or right after it was initialized and argo misses that event - resulting in node stuck forever in "Pending" state. In our case it happens often under the load. According to our logs kube-scheduler deletes some pods shortly after they have been instantiated.

**What you expected to happen**:

Node changes phase to "Error" or "Failed".

**How to reproduce it (as minimally and precisely as possible)**:

1. submit this workflow:
    ```yaml
    apiVersion: argoproj.io/v1alpha1
    kind: Workflow
    metadata:
      generateName: hello-world-
    spec:
      entrypoint: whalesay
      templates:
        - name: whalesay
          container:
            image: nonexistent
            command: [cowsay]
            args: ["hello world"]
    ```
1. Manually delete the pod `hello-world-xxxxx`
1. Check that node is still in pending state

**Anything else we need to know?**:

Before this PR - https://github.com/argoproj/argo/pull/2385
this case was detected and pod's state changed to "Error"

**Environment**:
- Argo version:

```
argo: v2.7.1
  BuildDate: 2020-04-07T16:40:24Z
  GitCommit: 2a3f59c10ae260a460b6ad97a0cadd8667d4b488
  GitTreeState: clean
  GitTag: v2.7.1
  GoVersion: go1.13.4
  Compiler: gc
  Platform: darwin/amd64
```

- Kubernetes version :

```
clientVersion:
  buildDate: "2019-08-19T12:36:28Z"
  compiler: gc
  gitCommit: 2d3c76f9091b6bec110a5e63777c332469e0cba2
  gitTreeState: clean
  gitVersion: v1.15.3
  goVersion: go1.12.9
  major: "1"
  minor: "15"
  platform: darwin/amd64
serverVersion:
  buildDate: "2020-03-24T18:54:48Z"
  compiler: gc
  gitCommit: 71631703d37fb1b4b333abd427deae839aeb2032
  gitTreeState: clean
  gitVersion: v1.15.11-gke.3
  goVersion: go1.12.17b4
  major: "1"
  minor: 15+
  platform: linux/amd64
```

**Other debugging information (if applicable)**:
- workflow result:
```
➜  test-data git:(feature/td-45) argo get hello-world-76n8f
Name:                hello-world-76n8f
Namespace:           default
ServiceAccount:      default
Status:              Running
Created:             Thu Apr 16 15:06:04 +0300 (26 seconds ago)
Started:             Thu Apr 16 15:06:04 +0300 (26 seconds ago)
Duration:            26 seconds

STEP                  TEMPLATE  PODNAME            DURATION  MESSAGE
 ◷ hello-world-76n8f  whalesay  hello-world-76n8f  26s       ErrImagePull: rpc error: code = Unknown desc = Error response from daemon: pull access denied for nonexistent, repository does not exist or may require 'docker login': denied: requested access to the resource is denied
```

- executor logs:
```
kubectl logs <failedpodname> -c init
kubectl logs <failedpodname> -c wait
```
- workflow-controller logs:

```
time="2020-04-16T12:02:20Z" level=info msg="config map" name=argo-workflow-controller-configmap
time="2020-04-16T12:02:20Z" level=info msg="Configuration:\nartifactRepository:\n  s3:\n    accessKeySecret:\n      key: access_key\n      name: argo-minio-credentials\n    bucket: argo-artifacts\n    endpoint: argo-minio:9000\n    insecure: true\n    secretKeySecret:\n      key: secret_key\n      name: argo-minio-credentials\ncontainerRuntimeExecutor: docker\nfeatureFlags: {}\nmetricsConfig:\n  disableLegacy: false\npersistence:\n  archive: true\n  connectionPool: null\n  postgresql:\n    database: argo\n    host: postgres\n    passwordSecret:\n      key: password\n      name: argo-postgres\n    port: \"5432\"\n    tableName: argo_workflows\n    userNameSecret:\n      key: username\n      name: argo-postgres\npodSpecLogStrategy: {}\ntelemetryConfig:\n  disableLegacy: false\n"
time="2020-04-16T12:02:20Z" level=info msg="Persistence configuration enabled"
time="2020-04-16T12:02:20Z" level=info msg="Creating DB session"
time="2020-04-16T12:02:20Z" level=info msg="Persistence Session created successfully"
time="2020-04-16T12:02:20Z" level=info msg="Migrating database schema" clusterName=default dbType=postgres
time="2020-04-16T12:02:20Z" level=info msg="Node status offloading is disabled"
time="2020-04-16T12:02:20Z" level=info msg="Workflow archiving is enabled"
time="2020-04-16T12:02:20Z" level=info msg="Starting CronWorkflow controller"
time="2020-04-16T12:02:20Z" level=info msg="Starting workflow TTL controller (resync 20m0s)"
time="2020-04-16T12:02:20Z" level=info msg="Starting Workflow Controller" version=vv2.7.1+2a3f59c.dirty
time="2020-04-16T12:02:20Z" level=info msg="Workers: workflow: 8, pod: 8"
time="2020-04-16T12:02:20Z" level=info msg="Performing periodic GC every 5m0s"
time="2020-04-16T12:02:20Z" level=info msg="Started workflow TTL worker"
time="2020-04-16T12:06:04Z" level=info msg="Processing workflow" namespace=default workflow=hello-world-76n8f
time="2020-04-16T12:06:04Z" level=info msg="Updated phase  -> Running" namespace=default workflow=hello-world-76n8f
time="2020-04-16T12:06:04Z" level=info msg="Pod node {hello-world-76n8f hello-world-76n8f hello-world-76n8f Pod whalesay nil    Pending   2020-04-16 12:06:04.9990897 +0000 UTC 0001-01-01 00:00:00 +0000 UTC   <nil> nil nil [] []} initialized Pending" namespace=default workflow=hello-world-76n8f
time="2020-04-16T12:06:05Z" level=info msg="Created pod: hello-world-76n8f (hello-world-76n8f)" namespace=default workflow=hello-world-76n8f
time="2020-04-16T12:06:05Z" level=info msg="Workflow update successful" namespace=default phase=Running resourceVersion=180991 workflow=hello-world-76n8f
time="2020-04-16T12:06:06Z" level=info msg="Processing workflow" namespace=default workflow=hello-world-76n8f
time="2020-04-16T12:06:06Z" level=info msg="Updating node &NodeStatus{ID:hello-world-76n8f,Name:hello-world-76n8f,DisplayName:hello-world-76n8f,Type:Pod,TemplateName:whalesay,TemplateRef:nil,Phase:Pending,BoundaryID:,Message:,StartedAt:2020-04-16 12:06:04 +0000 UTC,FinishedAt:0001-01-01 00:00:00 +0000 UTC,PodIP:,Daemoned:nil,Inputs:nil,Outputs:nil,Children:[],OutboundNodes:[],StoredTemplateID:,WorkflowTemplateName:,TemplateScope:,ResourcesDuration:ResourcesDuration{},} message: ContainerCreating"
time="2020-04-16T12:06:06Z" level=info msg="Workflow update successful" namespace=default phase=Running resourceVersion=180996 workflow=hello-world-76n8f
time="2020-04-16T12:06:07Z" level=info msg="Processing workflow" namespace=default workflow=hello-world-76n8f
time="2020-04-16T12:06:10Z" level=info msg="Processing workflow" namespace=default workflow=hello-world-76n8f
time="2020-04-16T12:06:10Z" level=info msg="Updating node &NodeStatus{ID:hello-world-76n8f,Name:hello-world-76n8f,DisplayName:hello-world-76n8f,Type:Pod,TemplateName:whalesay,TemplateRef:nil,Phase:Pending,BoundaryID:,Message:ContainerCreating,StartedAt:2020-04-16 12:06:04 +0000 UTC,FinishedAt:0001-01-01 00:00:00 +0000 UTC,PodIP:,Daemoned:nil,Inputs:nil,Outputs:nil,Children:[],OutboundNodes:[],StoredTemplateID:,WorkflowTemplateName:,TemplateScope:,ResourcesDuration:ResourcesDuration{},} message: ErrImagePull: rpc error: code = Unknown desc = Error response from daemon: pull access denied for nonexistent, repository does not exist or may require 'docker login': denied: requested access to the resource is denied"
time="2020-04-16T12:06:10Z" level=info msg="Workflow update successful" namespace=default phase=Running resourceVersion=181007 workflow=hello-world-76n8f
time="2020-04-16T12:06:11Z" level=info msg="Processing workflow" namespace=default workflow=hello-world-76n8f
time="2020-04-16T12:06:23Z" level=info msg="Processing workflow" namespace=default workflow=hello-world-76n8f
time="2020-04-16T12:06:23Z" level=info msg="Updating node &NodeStatus{ID:hello-world-76n8f,Name:hello-world-76n8f,DisplayName:hello-world-76n8f,Type:Pod,TemplateName:whalesay,TemplateRef:nil,Phase:Pending,BoundaryID:,Message:ErrImagePull: rpc error: code = Unknown desc = Error response from daemon: pull access denied for nonexistent, repository does not exist or may require 'docker login': denied: requested access to the resource is denied,StartedAt:2020-04-16 12:06:04 +0000 UTC,FinishedAt:0001-01-01 00:00:00 +0000 UTC,PodIP:,Daemoned:nil,Inputs:nil,Outputs:nil,Children:[],OutboundNodes:[],StoredTemplateID:,WorkflowTemplateName:,TemplateScope:,ResourcesDuration:ResourcesDuration{},} message: ImagePullBackOff: Back-off pulling image \"nonexistent\""
time="2020-04-16T12:06:23Z" level=info msg="Workflow update successful" namespace=default phase=Running resourceVersion=181030 workflow=hello-world-76n8f
time="2020-04-16T12:06:24Z" level=info msg="Processing workflow" namespace=default workflow=hello-world-76n8f
time="2020-04-16T12:06:26Z" level=info msg="Processing workflow" namespace=default workflow=hello-world-76n8f
time="2020-04-16T12:06:26Z" level=info msg="Processing workflow" namespace=default workflow=hello-world-76n8f
time="2020-04-16T12:06:26Z" level=info msg="Updating node &NodeStatus{ID:hello-world-76n8f,Name:hello-world-76n8f,DisplayName:hello-world-76n8f,Type:Pod,TemplateName:whalesay,TemplateRef:nil,Phase:Pending,BoundaryID:,Message:ImagePullBackOff: Back-off pulling image \"nonexistent\",StartedAt:2020-04-16 12:06:04 +0000 UTC,FinishedAt:0001-01-01 00:00:00 +0000 UTC,PodIP:,Daemoned:nil,Inputs:nil,Outputs:nil,Children:[],OutboundNodes:[],StoredTemplateID:,WorkflowTemplateName:,TemplateScope:,ResourcesDuration:ResourcesDuration{},} message: ErrImagePull: rpc error: code = Unknown desc = Error response from daemon: pull access denied for nonexistent, repository does not exist or may require 'docker login': denied: requested access to the resource is denied"
time="2020-04-16T12:06:26Z" level=info msg="Workflow update successful" namespace=default phase=Running resourceVersion=181041 workflow=hello-world-76n8f
time="2020-04-16T12:06:27Z" level=info msg="Processing workflow" namespace=default workflow=hello-world-76n8f
time="2020-04-16T12:06:28Z" level=info msg="Processing workflow" namespace=default workflow=hello-world-76n8f
```

**Logs**

```
argo get <workflowname>
kubectl logs <failedpodname> -c init
kubectl logs <failedpodname> -c wait
kubectl logs -n argo $(kubectl get pods -l app=workflow-controller -n argo -o name)
```

---
<!-- Issue Author: Don't delete this message to encourage other users to support your issue! -->
**Message from the maintainers**:

If you are impacted by this bug please add a 👍 reaction to this issue! We often sort issues this way to know what to prioritize.

Pull request:
fix: Error pending nodes w/o Pods unless resubmitPendingPods is set
Fixes #2711 

@vmanucharyan Can you please confirm if this fixes your issue?

Patch:
diff --git a/workflow/controller/operator.go b/workflow/controller/operator.go
index d3b5d736d..185f36925 100644
--- a/workflow/controller/operator.go
+++ b/workflow/controller/operator.go
@@ -223,7 +223,6 @@ func (woc *wfOperationCtx) operate() {
 		if err != nil {
 			woc.log.Errorf("%s error: %+v", woc.wf.ObjectMeta.Name, err)
 			woc.auditLogger.LogWorkflowEvent(woc.wf, argo.EventInfo{Type: apiv1.EventTypeWarning, Reason: argo.EventReasonWorkflowTimedOut}, "Workflow timed out")
-
 			// TODO: we need to re-add to the workqueue, but should happen in caller
 			return
 		}
@@ -797,11 +796,30 @@ func (woc *wfOperationCtx) podReconciliation() error {
 	// It is now impossible to infer pod status. The only thing we can do at this point is to mark
 	// the node with Error.
 	for nodeID, node := range woc.wf.Status.Nodes {
-		if node.Type != wfv1.NodeTypePod || node.Completed() || node.StartedAt.IsZero() || node.Pending() {
+		if node.Type != wfv1.NodeTypePod || node.Completed() || node.StartedAt.IsZero() {
 			// node is not a pod, it is already complete, or it can be re-run.
 			continue
 		}
 		if _, ok := seenPods[nodeID]; !ok {
+
+			// If the node is pending and the pod does not exist, it could be the case that we want to try to submit it
+			// again instead of marking it as an error. Check if that's the case.
+			if node.Pending() {
+				tmplCtx, err := woc.createTemplateContext(node.GetTemplateScope())
+				if err != nil {
+					return err
+				}
+				_, tmpl, _, err := tmplCtx.ResolveTemplate(&node)
+				if err != nil {
+					return err
+				}
+
+				if isResubmitAllowed(tmpl) {
+					// We want to resubmit. Continue and do not mark as error.
+					continue
+				}
+			}
+
 			node.Message = "pod deleted"
 			node.Phase = wfv1.NodeError
 			woc.wf.Status.Nodes[nodeID] = node


Test patch:
diff --git a/test/e2e/cli_test.go b/test/e2e/cli_test.go
index c9334cd48..ae87643bf 100644
--- a/test/e2e/cli_test.go
+++ b/test/e2e/cli_test.go
@@ -373,7 +373,7 @@ func (s *CLISuite) TestWorkflowDelete() {
 			Workflow("@smoke/basic.yaml").
 			When().
 			SubmitWorkflow().
-			WaitForWorkflow(30*time.Second).
+			WaitForWorkflow(1*time.Minute).
 			Given().
 			RunCli([]string{"delete", "--all", "-l", "argo-e2e"}, func(t *testing.T, output string, err error) {
 				if assert.NoError(t, err) {
@@ -394,7 +394,7 @@ func (s *CLISuite) TestWorkflowDelete() {
 				}
 			}).
 			When().
-			WaitForWorkflow(30*time.Second).
+			WaitForWorkflow(1*time.Minute).
 			Given().
 			RunCli([]string{"delete", "--completed", "-l", "argo-e2e"}, func(t *testing.T, output string, err error) {
 				if assert.NoError(t, err) {
@@ -407,7 +407,7 @@ func (s *CLISuite) TestWorkflowDelete() {
 			Workflow("@smoke/basic.yaml").
 			When().
 			SubmitWorkflow().
-			WaitForWorkflow(30*time.Second).
+			WaitForWorkflow(1*time.Minute).
 			Given().
 			RunCli([]string{"delete", "--older", "1d", "-l", "argo-e2e"}, func(t *testing.T, output string, err error) {
 				if assert.NoError(t, err) {
diff --git a/workflow/controller/operator_test.go b/workflow/controller/operator_test.go
index 2a8b7a8c9..b272baeac 100644
--- a/workflow/controller/operator_test.go
+++ b/workflow/controller/operator_test.go
@@ -17,6 +17,7 @@ import (
 	"github.com/argoproj/argo/persist/sqldb"
 	wfv1 "github.com/argoproj/argo/pkg/apis/workflow/v1alpha1"
 	"github.com/argoproj/argo/test"
+	"github.com/argoproj/argo/util/argo"
 	"github.com/argoproj/argo/workflow/common"
 	"github.com/argoproj/argo/workflow/util"
 )
@@ -2411,9 +2412,9 @@ func TestEventInvalidSpec(t *testing.T) {
 	assert.NoError(t, err)
 	assert.Equal(t, 2, len(events.Items))
 	runningEvent := events.Items[0]
-	assert.Equal(t, "WorkflowRunning", runningEvent.Reason)
+	assert.Equal(t, argo.EventReasonWorkflowRunning, runningEvent.Reason)
 	invalidSpecEvent := events.Items[1]
-	assert.Equal(t, "WorkflowFailed", invalidSpecEvent.Reason)
+	assert.Equal(t, argo.EventReasonWorkflowFailed, invalidSpecEvent.Reason)
 	assert.Equal(t, "invalid spec: template name '123' undefined", invalidSpecEvent.Message)
 }
 
@@ -2452,10 +2453,9 @@ func TestEventTimeout(t *testing.T) {
 	assert.NoError(t, err)
 	assert.Equal(t, 2, len(events.Items))
 	runningEvent := events.Items[0]
-	assert.Equal(t, "WorkflowRunning", runningEvent.Reason)
+	assert.Equal(t, argo.EventReasonWorkflowRunning, runningEvent.Reason)
 	timeoutEvent := events.Items[1]
-	assert.Equal(t, "WorkflowTimedOut", timeoutEvent.Reason)
-	assert.True(t, strings.HasPrefix(timeoutEvent.Message, "timeout-template error in entry template execution: Deadline exceeded"))
+	assert.Equal(t, argo.EventReasonWorkflowFailed, timeoutEvent.Reason)
 }
 
 var failLoadArtifactRepoCm = `
@@ -2494,9 +2494,9 @@ func TestEventFailArtifactRepoCm(t *testing.T) {
 	assert.NoError(t, err)
 	assert.Equal(t, 2, len(events.Items))
 	runningEvent := events.Items[0]
-	assert.Equal(t, "WorkflowRunning", runningEvent.Reason)
+	assert.Equal(t, argo.EventReasonWorkflowRunning, runningEvent.Reason)
 	failEvent := events.Items[1]
-	assert.Equal(t, "WorkflowFailed", failEvent.Reason)
+	assert.Equal(t, argo.EventReasonWorkflowFailed, failEvent.Reason)
 	assert.Equal(t, "Failed to load artifact repository configMap: configmaps \"artifact-repository\" not found", failEvent.Message)
 }