Dan, is this fixed by our recent changes?
No, this isn't fixed. More precisely, there is a chain of errors here, none of which are fixed: 1. Something (non-networking-related) causes the build/deploy to fail. 2. Something in kubelet gets confused when this happens and calls the network teardown function twice while cleaning up the failed pod 3. The second time the network teardown function gets called, it prints a confusing error message because the pod is in an unexpected state (since it has already had its networking torn down). (Well, the last part is a little bit fixed; it will now print "Could not find IP address for container" rather than "field nw_dst missing value". That may be the "recent changes" you were thinking of.) I'm assuming we'd close this bug after figuring out and fixing #2.
Note that this bug is just a symptom of an earlier failure... it's typically not networking related. As Dan said, something causes the pod deploy to fail, and that needs to be checked on each system. The times we've troubleshot, the causes have been varied and often due to misconfiguration. At the moment, #2 in Dan's list is annoying, but not really problematic. We have a card open to work on that: https://trello.com/c/9L7VBvSv/242-3-fix-teardownpod-to-work-better-after-errors-techdebt In light of all that, i'm dropping the severity of this bug. For the associated cases, people should troubleshoot for errors that ar ecausing pod setup to fail. OVS just happened to be the most obvious symptom of the earlier failure.
Am I intended to figure out what is causing the kubelet to call teardown twice, or solve the problem on the card (ensure cleanup when the pod is dead)?
Maru: Neither. Sorry. I want to work out what the root cause of the reported problem is. At that point we may clone this bug and send the root cause to the right place, then just leave the cleanup problem as a lower priority bug on the networking team.
Passing off to the Kubernetes component. This is not a networking problem, it's just that the loudest errors happened to come because the networking code was either called twice, or was called after partial setup. We have made some changes to the errors we spit out and have a card open to go further: https://trello.com/c/9L7VBvSv/242-3-fix-teardownpod-to-work-better-after-errors-techdebt I looked at the sosreport from a linked case and nothing was obviously wrong. So if someone with a better eye for container startup errors can look, that would be great.
Paul, according to Ben, something causes the pod startup to fail, resulting in networking error messages down the line. Last time I looked, I don't believe any of the logs attached to the support cases were from atomic-openshift-node. Please take a look, and if we're missing the node logs, set needinfo. Thanks.
In 3.3 this happens everytime a pod terminates in an HA cluster. The message is changed (see comment #2) to "Could not find IP address for container"
See also https://github.com/kubernetes/kubernetes/pull/29217 for some more detail; pod network operations are not exclusive in the docker and rocket k8s runtimes. Specifically in the teardown case, there are two places that pods can be killed on the node. First is kubelet.go::killPod(), which is called from the pod sync goroutine. kilPod() is also called from podKiller() on a separate goroutine. These can race with each other and could lead to calling pod teardown in close succession. Mike, assuming that's the case, could you grab a new set of node logs that show the problem, ideally with loglevel 5? I'd like to see if this race is indeed the case.
Created attachment 1191756 [details] Node logs at loglevel=5
Node log attached. Error occurred at 20:16:00 - lots of messages pop in the log shortly after. Corresponding event: 2016-08-17T20:16:00-04:00 2016-08-17T20:16:00-04:00 1 nodejs-example-5-deploy Pod Warning FailedSync {kubelet ip-172-31-57-158.us-west-2.compute.internal} Error syncing pod, skipping: failed to "TeardownNetwork" for "nodejs-example-5-deploy_svt" with TeardownNetworkError: "Failed to teardown network for pod \"eddfa32a-64d8-11e6-963c-02a86e5559df\" using network plugins \"redhat/openshift-ovs-multitenant\": Error running network teardown script: Could not find IP address for container a3c971a3e3082a661c5a3b9bd816f20fca241c3b62d9e4383f1686d847ab670c"
I looked at Mike's log from comment 11. The pod nodejs-example-5-deploy_svt completed successfully (phase=succeeded). So it looks like this is just TeardownNetwork getting called twice when it should only be called once.
One of the teardowns is coming from the podKiller, which exists to remove pods whose associated pod workers aren't working properly. This comes first. The second teardown appears to come from the pod worker itself. It looks like there's an issue where the podKiller is being too aggressive. I'll continue to dig into this.
Actually both teardowns are coming from the podKiller. The first comes from 'SyncLoop (REMOVE, "api"): "nodejs-example-5-deploy_svt(eddfa32a-64d8-11e6-963c-02a86e55 59df)"', and the second (the one that fails) comes from 'kubelet.go:2609] SyncLoop (housekeeping)'. The housekeeping invocation is a periodic function that gets its list of running pods from the kubelet's runtimeCache. So this is probably just a race (the runtimeCache is a bit out of date). I haven't confirmed this yet, but that's my current theory.
Actually I was incorrect. The first teardown comes from SyncLoop REMOVE. I'm not yet sure where the 2nd teardown comes from. There is a 3rd attempt to delete the pod (SyncLoop housekeeping), but that short-circuits because it can't find the pod (it's gone by this time).
The SDN teardown code needs to not return an error if it's called multiple times for the same pod. There's no guarantee that the kubelet will only call the network teardown function a single time.
Is this fixed post-CNI?
(In reply to Ben Bennett from comment #20) > Is this fixed post-CNI? Not quite, but it's symptoms will be different.
PR https://github.com/openshift/origin/pull/11808 is open to resolve this.
to resolve it from Networking's POV. There will still be the problem that kubelet is trying to tear down the same pod multiple times for some reason
(In reply to Dan Winship from comment #24) > to resolve it from Networking's POV. There will still be the problem that > kubelet is trying to tear down the same pod multiple times for some reason And that is acceptable based on how the kubelet is designed.
*** Bug 1392255 has been marked as a duplicate of this bug. ***
do you have workaround for comment #2 and comment #8 ? The pod is failing with the same error message in comments. Thanks
This bug is not about any specific cause of pod failure, it's just about the internal errors that happen when cleaning up after a pod has failed, for whatever reason. If you're seeing a reproducible pod deployment failure, file a new bug about that.
This has been merged into ocp and is in OCP v3.4.0.35 or newer.
Tested on OCP v3.4.0.37 When trying to delete the deployer pod which is during the deployment process, it will call the teardown only once. And no teardown script error appears in node log. # journalctl -lf -u atomic-openshift-node.service | grep "teardown" Dec 19 17:41:19 ose-node1.bmeng.local atomic-openshift-node[91652]: + action=teardown Dec 19 17:41:19 ose-node1.bmeng.local atomic-openshift-node[91652]: I1219 17:41:19.901143 91652 pod_linux.go:505] teardown called on already-destroyed pod default/router2-1-deploy; only cleaning up IPAM
*** Bug 1333393 has been marked as a duplicate of this bug. ***
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHBA-2017:0066