TaskRun taking too long to complete

[RafaeLeal]

Expected Behavior

TaskRuns to finish shortly after the last step finishes executing

Actual Behavior

There're times that TaskRuns can take several minutes to update.
In the most extreme scenario, I've found this TaskRun.
Let me summarize it here:

{ ...
 "status":{
      "conditions":[
         {
            "type":"Succeeded",
            "status":"True",
            "lastTransitionTime":"2023-03-07T18:24:53Z",
            "reason":"Succeeded",
            "message":"All Steps have completed executing"
         }
      ],
      "startTime":"2023-03-07T16:35:23Z",
      "completionTime":"2023-03-07T18:24:53Z",
      "steps":[
          {
            "terminated":{
               "exitCode":0,
               "reason":"Completed",
               "message": "..."
               "startedAt":"2023-03-07T16:35:49Z",
               "finishedAt":"2023-03-07T16:35:51Z",
               "containerID":"..."
            },
            "name":"checkout",
            "container":"step-checkout",
            "imageID": "..."
         },
         ...
         {
            "terminated":{
               "exitCode":0,
               "reason":"Completed",
               "message":"...",
               "startedAt":"2023-03-07T16:35:58Z",
               "finishedAt":"2023-03-07T16:35:58Z",
               "containerID":"docker://51cc488b8ec3bed2edd7d61e399ea22653634f797bf8dc4844d9fece0dd1df54"
            },
            "name":"notify-user",
            "container":"step-notify-user",
            "imageID":"..."
         }
      ]
}

Note that:

• The TaskRun succeeded at 2023-03-07T18:24:53Z
• From the status.startTime to status.completionTime it's 1h49m30s duration.
  (2023-03-07T16:35:23Z to 2023-03-07T18:24:53Z)
• From the first step status.steps[0].terminated.startedAt to the last step
  status.step[11].terminated.finishedAt it's 9s duration (2023-03-07T16:35:49Z to 2023-03-07T16:35:58Z)
• We have a very large Tekton cluster, running up to 600k TaskRuns every week.
  It might be related to load, but I couldn't confirm this with metrics.
• I've investigated the workqueue from the Tekton Controller, its depth is 1 (or zero)
  throughout this execution.
• Other metrics from the tekton-pipelines-controller also seems pretty stable,
  except by the reconcile error count. I've investigated, and the problem is that
  since we return this controller.NewRequeueAfter during the execution, we count that as errors, but it shouldn't be a problem.

Steps to Reproduce the Problem

I'm still not sure how to reproduce this problem, but it does happen every day
in our infrastructure, so I can try some fixes.

Additional Info

• Kubernetes version: 1.22.16-eks-ffeb93d

clientVersion:
  buildDate: "2022-10-12T10:47:25Z"
  compiler: gc
  gitCommit: 434bfd82814af038ad94d62ebe59b133fcb50506
  gitTreeState: clean
  gitVersion: v1.25.3
  goVersion: go1.19.2
  major: "1"
  minor: "25"
  platform: darwin/amd64
kustomizeVersion: v4.5.7
serverVersion:
  buildDate: "2022-11-29T18:41:42Z"
  compiler: gc
  gitCommit: 52e500d139bdef42fbc4540c357f0565c7867a81
  gitTreeState: clean
  gitVersion: v1.22.16-eks-ffeb93d
  goVersion: go1.16.15
  major: "1"
  minor: 22+
  platform: linux/amd64

• Tekton Pipeline version:

v0.35.1

[tekton-robot]

Issues go stale after 90d of inactivity.
Mark the issue as fresh with /remove-lifecycle stale with a justification.
Stale issues rot after an additional 30d of inactivity and eventually close.
If this issue is safe to close now please do so with /close with a justification.
If this issue should be exempted, mark the issue as frozen with /lifecycle frozen with a justification.

/lifecycle stale

Send feedback to tektoncd/plumbing.

[vdemeester]

/remove-lifecycle stale

[tekton-robot]

Issues go stale after 90d of inactivity.
Mark the issue as fresh with /remove-lifecycle stale with a justification.
Stale issues rot after an additional 30d of inactivity and eventually close.
If this issue is safe to close now please do so with /close with a justification.
If this issue should be exempted, mark the issue as frozen with /lifecycle frozen with a justification.

/lifecycle stale

Send feedback to tektoncd/plumbing.

[tekton-robot]

Stale issues rot after 30d of inactivity.
Mark the issue as fresh with /remove-lifecycle rotten with a justification.
Rotten issues close after an additional 30d of inactivity.
If this issue is safe to close now please do so with /close with a justification.
If this issue should be exempted, mark the issue as frozen with /lifecycle frozen with a justification.

/lifecycle rotten

Send feedback to tektoncd/plumbing.

[vdemeester]

The time to process a TaskRun (or other object) is dependent on a lot of things (such as the load of the api server, etcd, …) and higher number of tekton objects are a known factor in there. Every 10hs there is a global resync that goes through all objects, see #3676 or #8023 on this.

Given the version of this report, and the activity, I am going to close this.