Bug 1840872

Summary: [4.2.z] Node should not delete pods until all container status is available
Product: OpenShift Container Platform Reporter: OpenShift BugZilla Robot <openshift-bugzilla-robot>
Component: NodeAssignee: Ryan Phillips <rphillips>
Status: CLOSED WONTFIX QA Contact: Sunil Choudhary <schoudha>
Severity: high Docs Contact:
Priority: urgent    
Version: 4.3.zCC: aos-bugs, ccoleman, jokerman, maszulik, minmli, schoudha, sdodson, skuznets, vrutkovs, wking, zyu
Target Milestone: ---   
Target Release: 4.2.z   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2020-07-08 15:46:07 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On: 1821341    
Bug Blocks:    

Comment 5 MinLi 2020-06-22 10:49:51 UTC
It's no fixed with version : 4.2.0-0.nightly-2020-06-21-204910

$ /home/sunilc/go/src/github.com/openshift/origin/_output/local/bin/linux/amd64/openshift-tests run-test "[k8s.io] [sig-node] Pods Extended [k8s.io] Pod Container Status should never report success for a pending container [Skipped:ibmcloud] [Suite:openshift/conformance/parallel] [Suite:k8s]"
I0622 15:35:47.104615   47121 test_context.go:423] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready
Jun 22 15:35:47.140: INFO: Waiting up to 30m0s for all (but 100) nodes to be schedulable
Jun 22 15:35:47.416: INFO: Waiting up to 10m0s for all pods (need at least 0) in namespace 'kube-system' to be running and ready
Jun 22 15:35:48.346: INFO: 0 / 0 pods in namespace 'kube-system' are running and ready (0 seconds elapsed)
Jun 22 15:35:48.346: INFO: expected 0 pod replicas in namespace 'kube-system', 0 are Running and Ready.
Jun 22 15:35:48.346: INFO: Waiting up to 5m0s for all daemonsets in namespace 'kube-system' to start
Jun 22 15:35:48.653: INFO: e2e test version: v1.18.3
Jun 22 15:35:48.949: INFO: kube-apiserver version: v1.14.6+ae5fcd2
Jun 22 15:35:49.255: INFO: Cluster IP family: ipv4
[BeforeEach] [Top Level]
  /home/sunilc/go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/util/framework.go:1413
[BeforeEach] [Top Level]
  /home/sunilc/go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/util/framework.go:1413
[BeforeEach] [Top Level]
  /home/sunilc/go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/util/test.go:58
[BeforeEach] [k8s.io] [sig-node] Pods Extended
  /home/sunilc/go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:178
STEP: Creating a kubernetes client
STEP: Building a namespace api object, basename pods
Jun 22 15:35:50.179: INFO: About to run a Kube e2e test, ensuring namespace is privileged
Jun 22 15:35:53.000: INFO: No PodSecurityPolicies found; assuming PodSecurityPolicy is disabled.
STEP: Waiting for a default service account to be provisioned in namespace
[BeforeEach] [k8s.io] Pod Container Status
  /home/sunilc/go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/test/e2e/node/pods.go:212
[It] should never report success for a pending container [Skipped:ibmcloud] [Suite:openshift/conformance/parallel] [Suite:k8s]
  /home/sunilc/go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/test/e2e/node/pods.go:216
STEP: creating pods that should always exit 1 and terminating the pod after a random delay
Jun 22 15:36:01.029: INFO: Pod pod-submit-status-2-0 on node ip-10-0-157-229.us-east-2.compute.internal timings total=7.679538206s t=1.637s run=0s execute=0s
Jun 22 15:36:01.029: INFO: Pod pod-submit-status-0-0 on node ip-10-0-157-229.us-east-2.compute.internal timings total=7.679539029s t=1.503s run=0s execute=0s
Jun 22 15:36:06.354: INFO: Pod pod-submit-status-1-0 on node ip-10-0-140-182.us-east-2.compute.internal timings total=13.005016404s t=815ms run=0s execute=0s
Jun 22 15:36:06.354: INFO: Pod pod-submit-status-2-1 on node ip-10-0-140-182.us-east-2.compute.internal timings total=5.325436361s t=602ms run=0s execute=0s
Jun 22 15:36:11.064: INFO: Pod pod-submit-status-0-1 on node ip-10-0-157-229.us-east-2.compute.internal timings total=10.034904727s t=1.144s run=0s execute=0s
Jun 22 15:36:11.064: INFO: Pod pod-submit-status-1-1 on node ip-10-0-157-229.us-east-2.compute.internal timings total=4.709380728s t=583ms run=0s execute=0s
Jun 22 15:36:16.287: INFO: Pod pod-submit-status-2-2 on node ip-10-0-140-182.us-east-2.compute.internal timings total=9.932293748s t=996ms run=0s execute=0s
Jun 22 15:36:16.287: INFO: Pod pod-submit-status-0-2 on node ip-10-0-140-182.us-east-2.compute.internal timings total=5.222960159s t=122ms run=0s execute=0s
Jun 22 15:36:20.997: INFO: Pod pod-submit-status-0-3 on node ip-10-0-157-229.us-east-2.compute.internal timings total=4.710175068s t=1.201s run=0s execute=0s
Jun 22 15:36:21.003: INFO: Pod pod-submit-status-1-2 on node ip-10-0-157-229.us-east-2.compute.internal timings total=9.939028735s t=1.019s run=0s execute=0s
Jun 22 15:36:26.254: INFO: Pod pod-submit-status-0-4 on node ip-10-0-140-182.us-east-2.compute.internal timings total=5.256595599s t=823ms run=0s execute=0s
Jun 22 15:36:26.278: INFO: Pod pod-submit-status-2-3 on node ip-10-0-140-182.us-east-2.compute.internal timings total=9.991197787s t=212ms run=0s execute=0s
Jun 22 15:36:31.031: INFO: Pod pod-submit-status-1-3 on node ip-10-0-157-229.us-east-2.compute.internal timings total=10.028115965s t=36ms run=0s execute=0s
Jun 22 15:36:31.031: INFO: Pod pod-submit-status-2-4 on node ip-10-0-157-229.us-east-2.compute.internal timings total=4.752923345s t=116ms run=0s execute=0s
Jun 22 15:36:36.298: INFO: Pod pod-submit-status-1-4 on node ip-10-0-140-182.us-east-2.compute.internal timings total=5.2664341s t=211ms run=0s execute=0s
Jun 22 15:36:36.298: INFO: Pod pod-submit-status-0-5 on node ip-10-0-140-182.us-east-2.compute.internal timings total=10.04370295s t=1.068s run=0s execute=0s
Jun 22 15:36:40.971: INFO: Pod pod-submit-status-2-5 on node ip-10-0-157-229.us-east-2.compute.internal timings total=9.939552547s t=695ms run=0s execute=0s
Jun 22 15:36:46.294: INFO: Pod pod-submit-status-2-6 on node ip-10-0-140-182.us-east-2.compute.internal timings total=5.323006495s t=903ms run=0s execute=0s
Jun 22 15:36:46.294: INFO: Pod pod-submit-status-0-6 on node ip-10-0-140-182.us-east-2.compute.internal timings total=9.996236591s t=837ms run=0s execute=0s
Jun 22 15:38:06.372: FAIL: 45 errors:
pod pod-submit-status-2-0 on node ip-10-0-157-229.us-east-2.compute.internal container unexpected exit code 137: start=0001-01-01 00:00:00 +0000 UTC end=0001-01-01 00:00:00 +0000 UTC reason=ContainerStatusUnknown message=The container could not be located when the pod was terminated
pod pod-submit-status-0-0 on node ip-10-0-157-229.us-east-2.compute.internal container unexpected exit code 137: start=0001-01-01 00:00:00 +0000 UTC end=0001-01-01 00:00:00 +0000 UTC reason=ContainerStatusUnknown message=The container could not be located when the pod was terminated
pod pod-submit-status-1-0 on node ip-10-0-140-182.us-east-2.compute.internal container unexpected exit code 137: start=0001-01-01 00:00:00 +0000 UTC end=0001-01-01 00:00:00 +0000 UTC reason=ContainerStatusUnknown message=The container could not be located when the pod was terminated
pod pod-submit-status-2-1 on node ip-10-0-140-182.us-east-2.compute.internal container unexpected exit code 137: start=0001-01-01 00:00:00 +0000 UTC end=0001-01-01 00:00:00 +0000 UTC reason=ContainerStatusUnknown message=The container could not be located when the pod was terminated
pod pod-submit-status-0-1 on node ip-10-0-157-229.us-east-2.compute.internal container unexpected exit code 137: start=0001-01-01 00:00:00 +0000 UTC end=0001-01-01 00:00:00 +0000 UTC reason=ContainerStatusUnknown message=The container could not be located when the pod was terminated
pod pod-submit-status-1-1 on node ip-10-0-157-229.us-east-2.compute.internal container unexpected exit code 137: start=0001-01-01 00:00:00 +0000 UTC end=0001-01-01 00:00:00 +0000 UTC reason=ContainerStatusUnknown message=The container could not be located when the pod was terminated
pod pod-submit-status-2-2 on node ip-10-0-140-182.us-east-2.compute.internal container unexpected exit code 137: start=0001-01-01 00:00:00 +0000 UTC end=0001-01-01 00:00:00 +0000 UTC reason=ContainerStatusUnknown message=The container could not be located when the pod was terminated
pod pod-submit-status-0-2 on node ip-10-0-140-182.us-east-2.compute.internal container unexpected exit code 137: start=0001-01-01 00:00:00 +0000 UTC end=0001-01-01 00:00:00 +0000 UTC reason=ContainerStatusUnknown message=The container could not be located when the pod was terminated
pod pod-submit-status-0-14 on node ip-10-0-140-182.us-east-2.compute.internal container unexpected exit code 137: start=0001-01-01 00:00:00 +0000 UTC end=0001-01-01 00:00:00 +0000 UTC reason=ContainerStatusUnknown message=The container could not be located when the pod was terminated
 
Full Stack Trace
github.com/openshift/origin/vendor/k8s.io/kubernetes/test/e2e/node.glob..func9.3.2()
        /home/sunilc/go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/test/e2e/node/pods.go:428 +0x3cd
github.com/openshift/origin/pkg/test/ginkgo.(*TestOptions).Run(0xc00225c000, 0xc00222f240, 0x1, 0x1, 0x0, 0x22f59a0)
        /home/sunilc/go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/pkg/test/ginkgo/cmd_runtest.go:59 +0x41f
main.newRunTestCommand.func1.1()
        /home/sunilc/go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/cmd/openshift-tests/openshift-tests.go:239 +0x4e
github.com/openshift/origin/test/extended/util.WithCleanup(0xc0022bfc48)
        /home/sunilc/go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/util/test.go:166 +0x5f
main.newRunTestCommand.func1(0xc001dc9400, 0xc00222f240, 0x1, 0x1, 0x0, 0x0)
        /home/sunilc/go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/cmd/openshift-tests/openshift-tests.go:239 +0x1be
github.com/openshift/origin/vendor/github.com/spf13/cobra.(*Command).execute(0xc001dc9400, 0xc00222f200, 0x1, 0x1, 0xc001dc9400, 0xc00222f200)
        /home/sunilc/go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/vendor/github.com/spf13/cobra/command.go:826 +0x453
github.com/openshift/origin/vendor/github.com/spf13/cobra.(*Command).ExecuteC(0xc001dc8c80, 0x0, 0x636ce40, 0x99ff300)
        /home/sunilc/go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/vendor/github.com/spf13/cobra/command.go:914 +0x2fb
github.com/openshift/origin/vendor/github.com/spf13/cobra.(*Command).Execute(...)
        /home/sunilc/go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/vendor/github.com/spf13/cobra/command.go:864
main.main.func1(0xc001dc8c80, 0x0, 0x0)
        /home/sunilc/go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/cmd/openshift-tests/openshift-tests.go:61 +0x94
main.main()
        /home/sunilc/go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/cmd/openshift-tests/openshift-tests.go:62 +0x34d
[AfterEach] [k8s.io] [sig-node] Pods Extended
  /home/sunilc/go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:179
STEP: Collecting events from namespace "e2e-pods-8401".
STEP: Found 89 events.
Jun 22 15:38:07.499: INFO: At 2020-06-22 15:35:53 +0530 IST - event for pod-submit-status-0-0: {default-scheduler } Scheduled: Successfully assigned e2e-pods-8401/pod-submit-status-0-0 to ip-10-0-157-229.us-east-2.compute.internal
Jun 22 15:38:07.499: INFO: At 2020-06-22 15:35:53 +0530 IST - event for pod-submit-status-1-0: {default-scheduler } Scheduled: Successfully assigned e2e-pods-8401/pod-submit-status-1-0 to ip-10-0-140-182.us-east-2.compute.internal
Jun 22 15:38:07.499: INFO: At 2020-06-22 15:35:53 +0530 IST - event for pod-submit-status-2-0: {default-scheduler } Scheduled: Successfully assigned e2e-pods-8401/pod-submit-status-2-0 to ip-10-0-157-229.us-east-2.compute.internal
Jun 22 15:38:07.499: INFO: At 2020-06-22 15:36:01 +0530 IST - event for pod-submit-status-0-1: {default-scheduler } Scheduled: Successfully assigned e2e-pods-8401/pod-submit-status-0-1 to ip-10-0-157-229.us-east-2.compute.internal
Jun 22 15:38:07.499: INFO: At 2020-06-22 15:36:01 +0530 IST - event for pod-submit-status-2-1: {default-scheduler } Scheduled: Successfully assigned e2e-pods-8401/pod-submit-status-2-1 to ip-10-0-140-182.us-east-2.compute.internal
Jun 22 15:38:07.499: INFO: At 2020-06-22 15:36:03 +0530 IST - event for pod-submit-status-0-0: {kubelet ip-10-0-157-229.us-east-2.compute.internal} FailedCreatePodSandBox: Failed create pod sandbox: rpc error: code = Unknown desc = failed to create pod network sandbox k8s_pod-submit-status-0-0_e2e-pods-8401_f51adc95-b46f-11ea-8e72-0205b90661a2_0(b9be254b51b563e2c3276d25288ce2b99961fadb078bc26d9363fe42c9d51d94): Multus: Err adding pod to network "openshift-sdn": cannot set "openshift-sdn" ifname to "eth0": no netns: failed to Statfs "/proc/772284/ns/net": no such file or directory
Jun 22 15:38:07.499: INFO: At 2020-06-22 15:36:03 +0530 IST - event for pod-submit-status-1-0: {kubelet ip-10-0-140-182.us-east-2.compute.internal} FailedCreatePodSandBox: Failed create pod sandbox: rpc error: code = Unknown desc = failed to create pod network sandbox k8s_pod-submit-status-1-0_e2e-pods-8401_f51ad04f-b46f-11ea-8e72-0205b90661a2_0(a0e16643bcd7e20d1776553c2a2ead147963293afafe5213324a6d10e64ac391): Multus: Err adding pod to network "openshift-sdn": cannot set "openshift-sdn" ifname to "eth0": no netns: failed to Statfs "/proc/1074458/ns/net": no such file or directory
Jun 22 15:38:07.499: INFO: At 2020-06-22 15:36:03 +0530 IST - event for pod-submit-status-2-0: {kubelet ip-10-0-157-229.us-east-2.compute.internal} FailedCreatePodSandBox: Failed create pod sandbox: rpc error: code = Unknown desc = failed to create pod network sandbox k8s_pod-submit-status-2-0_e2e-pods-8401_f51a7b95-b46f-11ea-8e72-0205b90661a2_0(67da81f82a1d36c7f5474d66cdcc2b497074bfea06a35c0f7e05a554ca0410f8): Multus: Err adding pod to network "openshift-sdn": cannot set "openshift-sdn" ifname to "eth0": no netns: failed to Statfs "/proc/772263/ns/net": no such file or directory
Jun 22 15:38:07.499: INFO: At 2020-06-22 15:36:06 +0530 IST - event for pod-submit-status-1-1: {default-scheduler } Scheduled: Successfully assigned e2e-pods-8401/pod-submit-status-1-1 to ip-10-0-157-229.us-east-2.compute.internal
Jun 22 15:38:07.499: INFO: At 2020-06-22 15:36:06 +0530 IST - event for pod-submit-status-2-2: {default-scheduler } Scheduled: Successfully assigned e2e-pods-8401/pod-submit-status-2-2 to ip-10-0-140-182.us-east-2.compute.internal
Jun 22 15:38:07.502: INFO: At 2020-06-22 15:37:56 +0530 IST - event for pod-submit-status-0-14: {default-scheduler } Scheduled: Successfully assigned e2e-pods-8401/pod-submit-status-0-14 to ip-10-0-140-182.us-east-2.compute.internal
Jun 22 15:38:07.502: INFO: At 2020-06-22 15:38:01 +0530 IST - event for pod-submit-status-1-14: {kubelet ip-10-0-157-229.us-east-2.compute.internal} FailedCreatePodSandBox: Failed create pod sandbox: rpc error: code = Unknown desc = failed to create pod network sandbox k8s_pod-submit-status-1-14_e2e-pods-8401_3b364b40-b470-11ea-8e72-0205b90661a2_0(b0a4b20f1e9a2b885ad80cc60cc39ac099ffea7a78d60522c89095069650171d): Multus: Err adding pod to network "openshift-sdn": cannot set "openshift-sdn" ifname to "eth0": no netns: failed to Statfs "/proc/778625/ns/net": no such file or directory
Jun 22 15:38:07.783: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Jun 22 15:38:07.783: INFO:
Jun 22 15:38:08.314: INFO: skipping dumping cluster info - cluster too large
Jun 22 15:38:08.314: INFO: Waiting up to 7m0s for all (but 100) nodes to be ready
STEP: Destroying namespace "e2e-pods-8401" for this suite.
Jun 22 15:38:09.128: INFO: Running AfterSuite actions on all nodes
Jun 22 15:38:09.128: INFO: Running AfterSuite actions on node 1
fail [k8s.io/kubernetes/test/e2e/node/pods.go:428]: Jun 22 15:38:06.373: 45 errors:
pod pod-submit-status-2-0 on node ip-10-0-157-229.us-east-2.compute.internal container unexpected exit code 137: start=0001-01-01 00:00:00 +0000 UTC end=0001-01-01 00:00:00 +0000 UTC reason=ContainerStatusUnknown message=The container could not be located when the pod was terminated
pod pod-submit-status-0-0 on node ip-10-0-157-229.us-east-2.compute.internal container unexpected exit code 137: start=0001-01-01 00:00:00 +0000 UTC end=0001-01-01 00:00:00 +0000 UTC reason=ContainerStatusUnknown message=The container could not be located when the pod was terminated
pod pod-submit-status-1-0 on node ip-10-0-140-182.us-east-2.compute.internal container unexpected exit code 137: start=0001-01-01 00:00:00 +0000 UTC end=0001-01-01 00:00:00 +0000 UTC reason=ContainerStatusUnknown message=The container could not be located when the pod was terminated