Description of problem: We are noticing errors in pod start-ups or restarts. https://prow.ci.openshift.org/view/gs/origin-ci-test/logs/periodic-ci-openshift-release-master-ci-4.8-e2e-gcp/1382127394919288832 https://prow.ci.openshift.org/view/gs/origin-ci-test/logs/periodic-ci-openshift-release-master-ci-4.8-e2e-gcp/1382117425863987200 This is blocking our CI jobs. Version-Release number of selected component (if applicable): How reproducible: Steps to Reproduce: 1. 2. 3. Actual results: Expected results: Additional info:
This looks correct. The redhat-marketplace-km2ll pod starts at 00:40:46.195694 and then gets a delete at 00:40:58.668026 (12 seconds later), which results in a non-zero exit code from the application. Moving to OLM. ┌Apr 14 00:40:38.259590 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp hyperkube[1509]: I0414 00:40:38.259373 1509 kubelet.go:1946] "SyncLoop ADD" source="api" pods=[openshift-marketplace/redhat-marketplace-km2ll] │ │Apr 14 00:40:38.312732 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp hyperkube[1509]: I0414 00:40:38.310403 1509 reconciler.go:224] "operationExecutor.VerifyControllerAttachedVolume started for volume \"redhat-marketplace-token-9xw2v\" (UniqueName: \"kubernetes.io/secret/7b73f014-ec76-4dea-bf3a-97c176d10c10-redhat-marketplace-token-9xw2v\") pod \"redhat-marketplace-km2ll\" (UID: \"7b73f014-ec76-4dea-bf3a-97c176d10c10\") " │ │Apr 14 00:40:38.423533 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp hyperkube[1509]: I0414 00:40:38.421298 1509 reconciler.go:269] "operationExecutor.MountVolume started for volume \"redhat-marketplace-token-9xw2v\" (UniqueName: \"kubernetes.io/secret/7b73f014-ec76-4dea-bf3a-97c176d10c10-redhat-marketplace-token-9xw2v\") pod \"redhat-marketplace-km2ll\" (UID: \"7b73f014-ec76-4dea-bf3a-97c176d10c10\") " │ │Apr 14 00:40:38.446535 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp hyperkube[1509]: I0414 00:40:38.443967 1509 operation_generator.go:698] MountVolume.SetUp succeeded for volume "redhat-marketplace-token-9xw2v" (UniqueName: "kubernetes.io/secret/7b73f014-ec76-4dea-bf3a-97c176d10c10-redhat-marketplace-token-9xw2v") pod "redhat-marketplace-km2ll" (UID: "7b73f014-ec76-4dea-bf3a-97c176d10c10") │ │Apr 14 00:40:38.646635 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp hyperkube[1509]: I0414 00:40:38.646093 1509 kuberuntime_manager.go:460] "No sandbox for pod can be found. Need to start a new one" pod="openshift-marketplace/redhat-marketplace-km2ll" │ │Apr 14 00:40:38.648846 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp crio[1479]: time="2021-04-14 00:40:38.647005661Z" level=info msg="Running pod sandbox: openshift-marketplace/redhat-marketplace-km2ll/POD" id=1da5e68c-07eb-421c-b7ce-d00f56a27418 name=/runtime.v1alpha2.RuntimeService/RunPodSandbox │ │Apr 14 00:40:38.812807 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp crio[1479]: time="2021-04-14 00:40:38.812402378Z" level=info msg="Got pod network &{Name:redhat-marketplace-km2ll Namespace:openshift-marketplace ID:486a3d6d353bf7b730d14397a79003760b2172abd11157ec05796ba86cfdb0b1 NetNS:/var/run/netns/5b52a23f-be3d-47a4-89d0-4195012ae0c0 Networks:[] RuntimeConfig:map[multus-cni-network:{IP: MAC: PortMappings:[] Bandwidth:<nil> │ │Apr 14 00:40:40.545529 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp crio[1479]: 2021-04-14T00:40:40Z [verbose] Add: openshift-marketplace:redhat-marketplace-km2ll:7b73f014-ec76-4dea-bf3a-97c176d10c10:(openshift-sdn):eth0 {"cniVersion":"0.3.1","interfaces":[{"name":"eth0","sandbox":"/var/run/netns/5b52a23f-be3d-47a4-89d0-4195012ae0c0"}],"ips":[{"version":"4","interface":0,"address":"10.129.3.214/23"}],"routes":[{"dst":"0.0.0.0/0│ │Apr 14 00:40:40.545529 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp crio[1479]: I0414 00:40:40.480617 313200 event.go:278] Event(v1.ObjectReference{Kind:"Pod", Namespace:"openshift-marketplace", Name:"redhat-marketplace-km2ll", UID:"7b73f014-ec76-4dea-bf3a-97c176d10c10", APIVersion:"v1", ResourceVersion:"161351", FieldPath:""}): type: 'Normal' reason: 'AddedInterface' Add eth0 [10.129.3.214/23] │ │Apr 14 00:40:40.545834 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp crio[1479]: time="2021-04-14 00:40:40.545609144Z" level=info msg="Got pod network &{Name:redhat-marketplace-km2ll Namespace:openshift-marketplace ID:486a3d6d353bf7b730d14397a79003760b2172abd11157ec05796ba86cfdb0b1 NetNS:/var/run/netns/5b52a23f-be3d-47a4-89d0-4195012ae0c0 Networks:[] RuntimeConfig:map[multus-cni-network:{IP: MAC: PortMappings:[] Bandwidth:<nil> │ │Apr 14 00:40:40.549538 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp hyperkube[1509]: I0414 00:40:40.549085 1509 kubelet.go:1953] "SyncLoop UPDATE" source="api" pods=[openshift-marketplace/redhat-marketplace-km2ll] │ │Apr 14 00:40:42.292883 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp crio[1479]: time="2021-04-14 00:40:42.274658878Z" level=info msg="Ran pod sandbox 486a3d6d353bf7b730d14397a79003760b2172abd11157ec05796ba86cfdb0b1 with infra container: openshift-marketplace/redhat-marketplace-km2ll/POD" id=1da5e68c-07eb-421c-b7ce-d00f56a27418 name=/runtime.v1alpha2.RuntimeService/RunPodSandbox │ │Apr 14 00:40:43.141578 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp hyperkube[1509]: I0414 00:40:43.140492 1509 kubelet.go:1984] "SyncLoop (PLEG): event for pod" pod="openshift-marketplace/redhat-marketplace-km2ll" event=&{ID:7b73f014-ec76-4dea-bf3a-97c176d10c10 Type:ContainerStarted Data:486a3d6d353bf7b730d14397a79003760b2172abd11157ec05796ba86cfdb0b1} │ │Apr 14 00:40:43.921076 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp hyperkube[1509]: E0414 00:40:43.920847 1509 cadvisor_stats_provider.go:151] "Unable to fetch pod etc hosts stats" err="failed to get stats failed command 'du' ($ nice -n 19 du -x -s -B 1) on path /var/lib/kubelet/pods/7b73f014-ec76-4dea-bf3a-97c176d10c10/etc-hosts with error exit status 1" pod="openshift-marketplace/redhat-marketplace-km2ll" │ │Apr 14 00:40:44.999656 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp crio[1479]: time="2021-04-14 00:40:44.999177200Z" level=info msg="Creating container: openshift-marketplace/redhat-marketplace-km2ll/registry-server" id=72776954-d873-4ba1-b3b6-f2986e9cd757 name=/runtime.v1alpha2.RuntimeService/CreateContainer │ │Apr 14 00:40:46.026533 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp crio[1479]: time="2021-04-14 00:40:46.022709764Z" level=info msg="Created container d90aa7941cd37f0b80529f5ce01d897325fe02720efe0b6a16caa480175ce758: openshift-marketplace/redhat-marketplace-km2ll/registry-server" id=72776954-d873-4ba1-b3b6-f2986e9cd757 name=/runtime.v1alpha2.RuntimeService/CreateContainer │ │Apr 14 00:40:46.195694 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp crio[1479]: time="2021-04-14 00:40:46.193687698Z" level=info msg="Started container d90aa7941cd37f0b80529f5ce01d897325fe02720efe0b6a16caa480175ce758: openshift-marketplace/redhat-marketplace-km2ll/registry-server" id=1ca9d1db-e9af-49c8-9eaf-ace7404e59ec name=/runtime.v1alpha2.RuntimeService/StartContainer │ │Apr 14 00:40:46.468344 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp hyperkube[1509]: I0414 00:40:46.466833 1509 kubelet.go:1984] "SyncLoop (PLEG): event for pod" pod="openshift-marketplace/redhat-marketplace-km2ll" event=&{ID:7b73f014-ec76-4dea-bf3a-97c176d10c10 Type:ContainerStarted Data:d90aa7941cd37f0b80529f5ce01d897325fe02720efe0b6a16caa480175ce758} │ │Apr 14 00:40:46.468344 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp hyperkube[1509]: I0414 00:40:46.468268 1509 kubelet.go:2040] "SyncLoop (probe)" probe="readiness" status="" pod="openshift-marketplace/redhat-marketplace-km2ll" │ │Apr 14 00:40:58.460953 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp hyperkube[1509]: I0414 00:40:58.460837 1509 kubelet.go:2040] "SyncLoop (probe)" probe="readiness" status="ready" pod="openshift-marketplace/redhat-marketplace-km2ll" │ │Apr 14 00:40:58.668026 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp hyperkube[1509]: I0414 00:40:58.667923 1509 kubelet.go:1962] "SyncLoop DELETE" source="api" pods=[openshift-marketplace/redhat-marketplace-km2ll] │ │Apr 14 00:40:58.903750 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp hyperkube[1509]: I0414 00:40:58.903720 1509 kuberuntime_container.go:668] "Killing container with a grace period override" pod="openshift-marketplace/redhat-marketplace-km2ll" podUID=7b73f014-ec76-4dea-bf3a-97c176d10c10 containerName="registry-server" containerID="cri-o://d90aa7941cd37f0b80529f5ce01d897325fe02720efe0b6a16caa480175ce758" gracePeriod=2 │ │Apr 14 00:40:59.683012 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp crio[1479]: time="2021-04-14 00:40:59.682791867Z" level=info msg="Stopped container d90aa7941cd37f0b80529f5ce01d897325fe02720efe0b6a16caa480175ce758: openshift-marketplace/redhat-marketplace-km2ll/registry-server" id=81b61ca2-8d2b-46d1-b3d8-cb6a49f0578a name=/runtime.v1alpha2.RuntimeService/StopContainer │ │Apr 14 00:40:59.710544 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp crio[1479]: time="2021-04-14 00:40:59.709959065Z" level=info msg="Got pod network &{Name:redhat-marketplace-km2ll Namespace:openshift-marketplace ID:486a3d6d353bf7b730d14397a79003760b2172abd11157ec05796ba86cfdb0b1 NetNS:/var/run/netns/5b52a23f-be3d-47a4-89d0-4195012ae0c0 Networks:[{Name:multus-cni-network Ifname:eth0}] RuntimeConfig:map[multus-cni-network:{IP: │ │Apr 14 00:41:00.177334 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp hyperkube[1509]: I0414 00:41:00.176044 1509 kubelet.go:1984] "SyncLoop (PLEG): event for pod" pod="openshift-marketplace/redhat-marketplace-km2ll" event=&{ID:7b73f014-ec76-4dea-bf3a-97c176d10c10 Type:ContainerDied Data:d90aa7941cd37f0b80529f5ce01d897325fe02720efe0b6a16caa480175ce758} │ │Apr 14 00:41:00.325539 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp crio[1479]: 2021-04-14T00:40:59Z [verbose] Del: openshift-marketplace:redhat-marketplace-km2ll:7b73f014-ec76-4dea-bf3a-97c176d10c10:openshift-sdn:eth0 {"cniVersion":"0.3.1","name":"openshift-sdn","type":"openshift-sdn"} │ │Apr 14 00:41:00.392575 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp crio[1479]: time="2021-04-14 00:41:00.390624542Z" level=info msg="Removed container d90aa7941cd37f0b80529f5ce01d897325fe02720efe0b6a16caa480175ce758: openshift-marketplace/redhat-marketplace-km2ll/registry-server" id=ca3befa6-186b-422b-8935-052b33d49174 name=/runtime.v1alpha2.RuntimeService/RemoveContainer │ │Apr 14 00:41:01.199375 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp hyperkube[1509]: I0414 00:41:01.199172 1509 kubelet.go:1984] "SyncLoop (PLEG): event for pod" pod="openshift-marketplace/redhat-marketplace-km2ll" event=&{ID:7b73f014-ec76-4dea-bf3a-97c176d10c10 Type:ContainerDied Data:486a3d6d353bf7b730d14397a79003760b2172abd11157ec05796ba86cfdb0b1} │ │Apr 14 00:41:03.291128 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp hyperkube[1509]: I0414 00:41:03.290427 1509 kubelet.go:1962] "SyncLoop DELETE" source="api" pods=[openshift-marketplace/redhat-marketplace-km2ll] ┤ │Apr 14 00:41:03.438810 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp hyperkube[1509]: I0414 00:41:03.434947 1509 kubelet.go:1956] "SyncLoop REMOVE" source="api" pods=[openshift-marketplace/redhat-marketplace-km2ll] ┤ │Apr 14 00:41:03.438810 ci-op-knnzgsbt-f23e1-kft7g-worker-c-8chmp hyperkube[1509]: I0414 00:41:03.435061 1509 kubelet.go:2155] "Failed to delete pod" pod="openshift-marketplace/redhat-marketplace-km2ll" err="pod not found"
*** Bug 1949991 has been marked as a duplicate of this bug. ***
*** This bug has been marked as a duplicate of bug 1949991 ***