Intermittent "InvalidTaskResultReference" when running tasks with big results

[skaegi]

We've been seeing an increasing number of teams reporting InvalidTaskResultReference problems in pipelines that might otherwise run successfully. We are seeing this infrequently (1 in 40) but we've now seen it a number of different unrelated pipelines. Something like this...

---

---

The "results" in question are generally large-ish -- 2K+ (correction here thanks @pritidesai) and are present when we look ;)

We suspect that what's happening is that there is a race somewhere. Perhaps a race between the "next" task running and the current TaskRun being updated with the Result. That's just a guess, but does this seem possible/likely?

I'll try to create a good test-case but this sort of race condition is not easy to get to happen on demand although it clearly is occurring with some regularity.

[pritidesai]

I think its very likely possible and surprised to see this happening intermittently.

The taskRun status is updated once all containers in the pod have terminated (pod succeeded or failed).

pipeline/pkg/pod/status.go

Lines 109 to 115 in 6cb0f4c

	complete := areStepsComplete(pod) || pod.Status.Phase == corev1.PodSucceeded || pod.Status.Phase == corev1.PodFailed
	if complete {
	updateCompletedTaskRunStatus(logger, trs, pod)
	} else {
	updateIncompleteTaskRunStatus(trs, pod)
	}

updateCompletedTaskRunStatus includes updating the condition and competition time.

But there is more updates done after updating the status to completed.

In the end, the taskRun status is updated with the results:

pipeline/pkg/pod/status.go

Line 138 in 6cb0f4c

trs.TaskRunResults = removeDuplicateResults(trs.TaskRunResults)

So if its possible for the pipelineRun controller to pick up the completed status before the task results are populated, its also possible to run into this issue.

[lbernick]

/priority important-soon

[pritidesai]

@lbernick thanks for adding the priority 👍 Let me know if you want to take a stab at it else I am happy to try fixing it 🙏

/assign

[chitrangpatel]

/assign

[vdemeester]

@skaegi @pritidesai if you manage to reproduce, can you look at the container's termination message. We do have some similar failures that happens because in the case it fails, the termination message content (json) is cut in the middle (and thus invalid).

[vdemeester]

/assign
I think I know why this is happening, I'll create an additional issue around this, but in a gist, it's because of the termination message behavior in k8s with multiple containers.

The total size of termination messages of all containers in a pod cannot exceed 12 KB. If the total size exceeds 12 KB, the state manager of Kubernetes sets a limit on the termination message sizes. For example, if a pod contains four InitContainers and eight application containers, the state manager limits the termination message of each container to 1 KB. This indicates that only the first 1 KB of the termination message of each container is intercepted.

[vdemeester]

@skaegi @pritidesai @chitrangpatel see #4808

[vdemeester]

@skaegi #4826 has a "regression" test that reproduce this constantly between 0.32 and 0.35 😉

[dibyom]

Closing in favor of #4808 which tracks larger results in general