Pod shall not transition from terminated phase: "Failed" -> "Succeeded"

[0xmichalis]

/go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/deployments/deployments.go:1299
2017-12-05 09:50:41.393147976 +0000 UTC: detected deployer pod transition from terminated phase: "Failed" -> "Succeeded"
Expected
    <bool>: true
to be false
/go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/deployments/util.go:727

https://openshift-gce-devel.appspot.com/build/origin-ci-test/pr-logs/pull/17589/test_pull_request_origin_extended_conformance_install/3497/

/sig master
/kind test-flake
/assign mfojtik tnozicka

xref https://bugzilla.redhat.com/show_bug.cgi?id=1534492

[tnozicka]

@sjenning it seems to already have #17514

I don't think your condition prevents failed->succeded

origin/vendor/k8s.io/kubernetes/pkg/kubelet/status/status_manager.go

Line 286 in 21271eb

if oldStatus.State.Terminated != nil && newStatus.State.Terminated == nil {

There few other flakes likely caused by kubelet not respecting pod state transition diagram:

• deploymentconfigs when run iteratively [Conformance] should only deploy the last deployment  #17581
• flake: jenkins-plugin test imagestream SCM DSL #17487

/assign @sjenning
/unassign @tnozicka @mfojtik
/priority P0

[tnozicka]

(previous issue #17011)

[tnozicka]

https://openshift-gce-devel.appspot.com/build/origin-ci-test/pr-logs/pull/17713/test_pull_request_origin_extended_conformance_install/3886/

@sjenning any progress on this?

[sjenning]

https://openshift-gce-devel.appspot.com/build/origin-ci-test/pr-logs/pull/17839/test_pull_request_origin_extended_conformance_install/4317/

[tnozicka]

https://openshift-gce-devel.appspot.com/build/origin-ci-test/pr-logs/pull/17827/test_pull_request_origin_extended_conformance_install/4519/

[mfojtik]

@sjenning any chance the pod team can investigate this? regardless of flakes, this might affect production deployments where the deployer pod can go from failed to success.

[tnozicka]

https://openshift-gce-devel.appspot.com/build/origin-ci-test/pr-logs/pull/17773/test_pull_request_origin_extended_conformance_install/5243/

[sjenning]

I'm looking into this now. Sorry for the delay.

[sjenning]

@tnozicka just wondering, have you seen this one lately? Doesn't look like we have hit this one for a while now. Did it disappear at the same time we bumped the disk size on the CI instances?

[tnozicka]

I haven't. @ironcladlou @mfojtik got any flakes looking like this? (Those are usually different tests as the detector is asynchronous and run for every deployment test.)

Any chance that this might be related #18233?

[tnozicka]

likely not caused by the informers issue I pointed you to as @deads2k just saw it and the watch cache is already fixed on master

https://openshift-gce-devel.appspot.com/build/origin-ci-test/pr-logs/pull/18387/test_pull_request_origin_extended_conformance_install/6640/

[sjenning]

@tnozicka still trying to get to the root cause on this kubernetes/kubernetes#58711 (comment)

[tnozicka]

https://openshift-gce-devel.appspot.com/build/origin-ci-test/pr-logs/pull/batch/test_pull_request_origin_extended_conformance_install/7087/

[sjenning]

Opened a PR upstream:
kubernetes/kubernetes#59767

[smarterclayton]

Did this make it into 3.9? If so, still happening (below). If not, we need to get it in before release.

https://openshift-gce-devel.appspot.com/build/origin-ci-test/pr-logs/pull/18739/test_pull_request_origin_extended_conformance_install/7966/

[sjenning]

It did go in about 2 weeks ago
#18585

Looking into it. If this is legitimately happening even with the check I added, I'm very confused.

[tnozicka]

I don't think the requested check in apiserver is present.

To check, if I do

curl -k -v -XPATCH -H "Authorization: Bearer ${TOKEN}" -H "Accept: application/json" -H "Content-Type: application/strategic-merge-patch+json" https://172.16.20.11:8443/api/v1/namespaces/test/pods/busyapp-76589968df-xnthx/status -d '{"status": {"phase": "Failed"}}'

it gets overwritten back to Running.

This is a serious bug and I feel we need that enforcement in the apiserver as well as the fix.

It feels like the whole kubelet status manager ignores optimistic concurrency with resourceVersion and just does GET before updating the status no matter what resourceVersion was used for computing that status - the precondition might have changed in that case.

origin/vendor/k8s.io/kubernetes/pkg/kubelet/status/status_manager.go

Lines 451 to 476 in 710998e

	pod, err := m.kubeClient.CoreV1().Pods(status.podNamespace).Get(status.podName, metav1.GetOptions{})
	if errors.IsNotFound(err) {
	glog.V(3).Infof("Pod %q (%s) does not exist on the server", status.podName, uid)
	// If the Pod is deleted the status will be cleared in
	// RemoveOrphanedStatuses, so we just ignore the update here.
	return
	}
	if err != nil {
	glog.Warningf("Failed to get status for pod %q: %v", format.PodDesc(status.podName, status.podNamespace, uid), err)
	return
	}
	translatedUID := m.podManager.TranslatePodUID(pod.UID)
	// Type convert original uid just for the purpose of comparison.
	if len(translatedUID) > 0 && translatedUID != kubetypes.ResolvedPodUID(uid) {
	glog.V(2).Infof("Pod %q was deleted and then recreated, skipping status update; old UID %q, new UID %q", format.Pod(pod), uid, translatedUID)
	m.deletePodStatus(uid)
	return
	}
	pod.Status = status.status
	// TODO: handle conflict as a retry, make that easier too.
	newPod, err := m.kubeClient.CoreV1().Pods(pod.Namespace).UpdateStatus(pod)
	if err != nil {
	glog.Warningf("Failed to update status for pod %q: %v", format.Pod(pod), err)
	return
	}

[sjenning]

switching back to this issue

[sjenning]

I swear, I'm losing it. I totally forgot that this PR got reopened and merged upstream kubernetes/kubernetes#54530. I'll pick it right now.