Cloud Native Computing Foundation KubeCon + CloudNativeCon Europe 2021, 14 May 2021

Previous Meeting Next Meeting

⏯

youtube image

►

From YouTube: Ghosts in the Runtime: Who Ate My Capabilities & Other Mysteries- Laurent Bernaille & Eric Mountain,

Description

Don’t miss out! Join us at our upcoming event: KubeCon + CloudNativeCon North America 2021 in Los Angeles, CA from October 12-15. Learn more at https://kubecon.io The conference features presentations from developers and end users of Kubernetes, Prometheus, Envoy, and all of the other CNCF-hosted projects.

Ghosts in the Runtime: Who Ate My Capabilities and Other Mysteries - Laurent Bernaille & Eric Mountain, Datadog

In the last 3 years Datadog migrated most of its workloads to dozens of Kubernetes clusters, many of which consist of thousands of nodes each. At this scale, our engineers encounter strange and surprising bugs on a regular basis. Some of the most difficult bugs to investigate are those related to the kubelet and its interactions with the container runtime.

In this talk we will share some of our favorite investigations on this front, such as the container image that only worked when built on our laptops, rather than by our CI. You'll leave with a stronger understanding of the low level components that are responsible of a critical task: running your containers.

A

Hello, uh we're very happy to be there with you today. uh We'd rather be live with you, and hopefully we might be able to uh in los angeles right. uh So we are lujan eric and we're going to share stories about low-level problems uh we face from kubernetes.

A

We showed a few stories in the past about control, plane challenges, but today we're going to focus on what happens on nodes. So in case.

B

You don't know datadog.

A

uh We're a monitoring company, but today we're not going to talk about the product, we're going to talk about the infrastructure behind the products and uh it's pretty large uh we're running tens of thousands of hosts and dozens of clusters uh with up to four thousand nodes uh and it comes with uh multiple challenges, and this is what we're going to talk about today.

A

So we have a few stories, uh not completely related, but they they all happen locally on notes and we're going to to focus on that. So, let's start uh with this first story about disappearing containers.

A

So it started uh with this simple graph here when we migrated an application from a virtual machine to kubernetes, and we noticed that the cpu profile was very different, which was a bit worrying right.

A

So we looked at uh the pods running this application and we discovered that several of them were in great container error, actually about 10 of them, so they were not ready and not processing traffic. We found very easy solutions to address this by editing the bird or researching the cubelet, but it wasn't very satisfying.

A

So the first thing we did was try to understand what this error was. So we looked at the qubit logs and basically the qubit is getting an error for the runtime containing in our case, uh because it's trying it seems to be trying to create a container that already exists according to the runtime, and it's doing this a lot, as you can see here with 62 attempts right and it keeps retrying and getting the exact same results.

A

So, of course, we wonder well who is right? uh Who is wrong, so the cubit believes it needs to create a container what about continuity? So if we have container d, this container is actually running completely fine.

A

B

A

Was to try and reproduce a problem in a test environment and we had noticed that it seemed to be related with cubelet restarts. So we did a very simple script that we started the cubelet frequently and after only an hour as you can see, all the parts in the deployment were in the same era, so we were able to very easily reproduce it right.

A

So what is this error exactly? So we went to the cubelet code and we looked for it and we found that this error is is appearing in the runtime manager where uh in the syncpod function. So it seems that the cubelet wants to create this container and entails.

A

How is this function called, so this function is called in in sync bud after computing, both actions, which is basically uh the reconciliation that needs to happen between the pod spec and what's in the runtime, and in this case here it seems that the results of this computation is wrong. How could that be?

A

We looked at clogged, but we couldn't find much in logs, even when we increased the velocity level. So we did a very simple thing and we added print statements in in the code and it turned out.

A

It was very efficient because, as you can see at the bottom of the screen, um a container of the container 15, that is completely fine in the first output statement, is missing in the second one, but the container is still running, so it seemed that container statuses, which has the statuses of all the containers in a pod, is actually wrong.

A

So we wanted to understand where this container status was coming from and how it could be wrong. So here is an overview of the main component involved in this data path in the cubelets. So everything starts with a single iteration, which is the main sync loop in the cubelet.

A

This sync loop receives events on channels um and these events can be event from api server, such as a spec change event from the lifecycle advanced generator, which has which are events from the runtime and other types of events.

A

When there is a change to a pod, it's then going to call pod workers which are going to get the status from the pod cache and called the syncpod function, which is the function that was failing when it was calling the runtime before.

A

So it seemed that when the status is retrieved from the podcache, it's wrong, which triggered the problem down underground.

A

So what is the pod cache? The pod cache is a cache of all the pods in the cubelets and how is it maintained?

A

So the podcast is maintained by the pod lifecycle event, generator plague, which is the component responsible for observing, what's happening with the runtime, updating the cache and generating events that will then be received by sync to preparation, and it seemed that this cache gets corrupted somehow.

A

So here is what we know. uh The data in the podcast is wrong. The podcast is managed by the plague and there's nothing in the play. That seems to indicate situations where we can get corruption so what's happening, and at that point we we were wondering well, what is something else is modifying the content of the cache. In particular, the container status is filled, which is uh what's wrong here.

A

So we looked at um the code of the cubelet and after a lot of digging, we found this function, which is sorted, which is sorting the container statuses and what's important here, is that this function is actually sorting in place and modifying the slides. So we now have another call in the cube that is modifying the podcast.

A

It's not only the plague anymore, and so we looked at where this function is called, and here you have the sequence of functions involved and what is important here is syncpod and sql iteration, which are two functions we saw before, are actually ending up calling this uh this this sort operation.

A

So let's go back to the cubelets.

A

To get back to the function that can actually modify the pod cache so, as we've seen before, the player can modify the pod cache, but also the function generate api put status that can be called in two different cases: one when there is a product date and one when there is a plague event where the contender dives and the problem is the handlers for these events are running in separate core routines, so they can race and which can lead to uh cash. Corruption- and uh here is a summary right.

A

We can have a concurrency between either syncpod if there's bot update from the api server if a container dies on the plague or during a plague release if there was something happening on the runtime, so we had a theory and we wanted to validate it. So what we did is instead of sorting the slice in place, we made a copy of it and then did all the operation on the copy and look everything is running now, even if we restart the cubelet every few seconds.

A

So we created a pr upstream and we're pretty happy because we've found and fixed the the issue. I also wanted to to credit nayef for doing all the work on this investigation and uh diving very deep inside the cubelet.

A

So key takeaways from this is that the current internals are complex but they're accessible. If you spend the time since the internals are complex, we're not 100 sure that our fix is the best one and that the data path I described is the full one.

A

But what we know is the fix, definitely works and solved our problem and the pr has not been much upstream, but we hope it will soon or an equivalent pr fixing thinking the problem, we're a bit lucky on this one, because we cut the problem in staging which allowed us to depot the production completely completely fine, which was good news.

A

So in in in this first um story we had a story about the cubelets and and now eric is going to dive even deeper into something that's happening in the runtime itself.

B

Yeah thanks man, so this one is titled random failures which, as we'll see, is a double pun on the actual problem.

B

So the the problem we saw was that occasionally we had a database crash and it was preceded by a rather puzzling log, the pro the database couldn't open their view random and it was getting an operation not permitted error, and this is happening occasionally, I mean clearly the database works most of the time and then all of a sudden it can't open, debut random, so what's happening.

B

If we look inside the container, everything is fine. The file permissions on debut random are perfectly open to everyone to read everyone right, everyone. We don't really see why we should be having a problem. Opening devi ran, so we write a straightforward, very stupid, reproducer very blunt.

B

It just sits in a loop and keeps opening debug random and errors. If it fails to do so and very quickly, we see that we're able to reproduce the problem we get the operation not permitted message and what's more interesting, maybe is that this happens every 10 or so seconds. So it's extremely regular.

B

If we search a little bit more for logs that the cubelet might be emitting for for this for this pod, we realized that, in fact, every 10 seconds, the cpu manager component is emitting a reconcile state log message.

B

And if we look at the details of that message, we see that it's actually includes a configuration for the cpu set. So I need to explain a little bit more. What the cpu set is in this situation. Our pod is in guaranteed qrs class, meaning that it has requests and limits which are all specified and all equal for all the resources it requires.

B

It also makes an integer request for cpus, so six in this example, and finally, we use a cubelet configuration where the cpu manager policy is static. Now the static cpu manager policy is there to allow requesting and setting aside a specific set of cpus for a container and doing so using the cpu set control group.

B

So now, if we look at the flow of configuration here so in the container runtime, so we have the cubelet which talks to container d over grpc so telling container d. What containers need to be launched? What uh configuration, what characteristics they need to have container indeed, container d in turn, uh fork ex container shims, which are per container and communicates them over time through grpc also and the container. The shim fork, execs run c to actually start containers and potentially update them again over time.

B

So, for instance, it will update the c group files of the containers.

B

So if we follow the smoking gun through that flow, we look at container d now and we see that container d also is every 10 seconds, reflecting an update to container resources, not a big surprise. At this point we follow further down and we trace the shim. We see that the shim every 10 seconds launches, run c and, in particular, launches run c, with an update instruction tracing the run c execution itself. We see something rather surprising.

B

On the other hand, we see that the um update to control group devices section is starting with a deny on all devices and then followed by individual allows for the rest of the devices for the ones that we actually should be allowed to access, and so we found a race in effect, there's a window where, for a certain amount of time, all devices are not allowed and progressively some will be re-allowed until finally, everything that should be allowed is allowed, but there's a definite window of opportunity here to attempt to open a device and to find that we're not allowed to do so because of the default denial.

B

So we found the issue and in fact what we're in luck, because the problem has actually been fixed upstream, and so we really only needed to upgrade run c here to resolve the issue and the way run c resolved. The problem is by emulating the changes that would be taken on update and checking them against what is in place and only reflecting the differences between the desired state and the current state.

B

So this was an interesting problem. We relearned how the flow of configuration from through the runtime from the cubelet down all the way down to the container, and we learned about uh c group device updates as well and possibly a little bit about the cpu set. um All this uh investigation goes to benjamin pino, who delved into this a little while back. Thank you very.

A

B

B

So key takeaways, it's really good to know the the container runtime flow and understand it and how the different components interact. It's also important to realize that here we had several parameters influencing the overall behavior.

B

For instance, we had pods with guaranteed qos integer cpu requests and a cpu manager configuration for static if any of those three parameters had been different, we would not have encountered this issue.

B

And so now I'll, uh let lauren dive into an even deeper investigation with the uh network uh layer of kubernetes.

A

We're we're not.

B

A

To talk about uh how well ips can become zombies, so this problem started with containers remaining in status container, creating for for a long time, and the error message was fun in our sense of fun, which is well very weird.

A

So here the queue is telling us that it can't create the butt sandbox, so it can create networking in the bud because it's failing to add an ip address, because this address is already in use, which is weird because it never happened before and suddenly it's starting to open so address already in use. Let's see if this address is banned on the host, it's not, can, I add it to an interface. I definitely can so nothing obvious there. So of course it could also be an ip address from a container.

A

So let's look at network name spaces and look at ip addresses in them. None of the network name spaces have disappeared address, so we've done the obvious, and now we need to take a step back to exactly understand what the components.

A

What components are involved in this? So let's look at our cni plugin on this cluster, so we use the livescenic plugin, which is uh basically allowing us to attach ip addresses from the underlying cloud provider aws directly to pods and not have an overlay. So it starts with an ipam plugin responsible for the aws api call, and then there is an ipvlan plugin that is creating the main pod interface and giving it an ip there's another interface that is only used for communication with the host and it doesn't really matter here.

A

What is interesting is what's happening with ipplan so now that we know that on this host we're using ipvlan, let's say we can create a new ipvland device with this opening ip and, as you can see, on the top of the slide, if we try, we actually can't and- and we get a very clear error message- saying- that this ip address is already already assigned sorry to an ipv land device.

A

B

A

To mention here is that the message is very clear, but it doesn't make it to the cubelet because of the netflix library used by the plugin, which only use um the error code right and not the error message. So we only have address news and we don't have the full detailed message which would have been helpful right.

A

So now we need to understand uh what else. Why are you seeing a plugin is using this ip.

A

If we look at the registry of ips used by the plugin, this ip is known, which means it has been used and assigned to a pod in the past, but it's been released, but somehow it's been released, but not completely right, because the ip address is still bound to the appeal and device.

A

So we looked at how ipvline handles deletion in this plugin and, as you can see here, there's code to delete the interface, but we never run it because we use chaining and in the case of chaining the deletion call is, is never done so we never delete the device. However, uh it works, usually because the runtime uh at the end of the deletion of a pod will actually delete the network namespace, which would which will take care of garbage collecting everything.

A

So what we know so far, the ipa has been a drain has been located to a pod. The pod was deleted and vip was marked free. The.

B

Equivalent interface was.

A

Not deleted when the runtime called network deletion, and so we can reuse the ip what's important about network namespace deletion is when you delete the namespace, uh the qnl will tell you okay, I can. I can delete it, but it won't actually delete the namespace until every single process.

A

Running it is is, is done running right, but what's important here is everything is fine from cni and from the runtime right, but the kernel hasn't finished, deleting the namespace.

A

Now that we have this piece of information, can we can we reproduce? So what we did is we took a part we exact into its network namespace from the commands and, as you can see here, we can see here that the um network namespace of this process is actually the one of the bug right.

A

If we delete this namespace everything works, the cni marks the ips released. However, we can't reuse it and add it to an end device, and what's interesting is if we enter the network namespace of the process we created, we can still see the iqlan interface, so we have a very good idea what's happening here.

A

So, um let's see if we can find the process holding this network namespace, so what we did here is we looked at all the processes and the network namespaces and we entered them and we looked for vip for our process. We were able to find it. However, we were not able to find it for the iphone that was already in use right, so that was we have an idea, but we can't actually trace the problem back to an actual process.

A

So we took a step back because we had a good idea what was happening, but we were not able to pinpoint exactly what was the concrete. We had a few additional data points. We knew that the problem started with a node and slowly propagated to others and that regularly the problem was completely disappearing and restarting again.

A

So what are we looking for we're looking at the process, we're looking for a process that is running on all nodes that is regularly either stopped, restarted or redeployed?

A

What kind of process is that? Maybe a demon set right, so we look at demon sets and we have a lot of very few demon sets, but there's one that has a lot of that. Does a lot of things and it's data log agents.

A

So we actually were able to trace back the fact that when the deadlock agent was redeployed, the error was fixed, so we reached out to the team and they told us well, we actually have a feature that is allowing us to instrument the contract and nuts inside network and space of containers, and so we looked into it with them and it turned out.

A

This new feature was using a long-lived connection on a netting circuit to get this information and, of course this was holding the network namespaces and to fix that we just had to use short-lived connections in terms of long-lived one. So the network namespace could be released by the kernel.

A

Key takeaways uh interaction between all these components are complex. It's also very difficult in the kernel to understand what's happening at the networking level, because a lot of information can't be found. So you need to to guess a lot and also I said that we were lucky because we code this in staging and also this error was made very visible by the cni issue.

A

But if we hadn't seen it in the sinai issue, we would have leaked network namespace with unknown consequences right and that's it for this network. Debugging problem I mean I love networking, but I think the story that eric is going to share next, uh which is even deeper because of the channels, is even more interesting.

B

Yeah thanks so who ate my capabilities. This is the the story that gave its title to to the presentation.

B

Okay, a word about uh lingus capabilities capabilities are a feature of the linux kernel that allow us to give privileges to certain processes that are not normally privileges that don't run as root, for instance.

B

So in the example that I'm showing here, we have the capture pro program that just displays the capabilities that it has and decodes them for us, which initially doesn't have any and to which I then assign a capability through the extended attributes of the file on disk, and then, when I run so here, the capnet bind service, which means I this process would be allowed to bind ports under 1024, which is privileged normally reserved for root, and um then once it has these capabilities on the file and extended attributes.

B

If I run the program, I see that I have this privilege now.

B

So we wanted to use this for the api server, the cube api server, which we run as a pod in certain circumstances, and so quite simply in our docker file. We set the capability on the file and then, when we run the prod, the strange thing is that it doesn't work. We are unable to bind port 443, we get a permission denied error, just as if we didn't have the privilege.

B

So if we look at the actual process characteristics, we see that indeed it does not have the privilege it doesn't have the capability, the permitted capabilities, the effective capabilities of the process are all zero there. All the bits are cleared, um even though we should have 400 uh where the the value of the cabinet main service uh a bit.

B

And yet, if we look at the capabilities on the file system, they're there it's what we built in the dockerfile. So again, what is happening.

B

If we think about the usual suspects, um there's the no new privileges flag, we check and that isn't set we're not using no set user id file systems. Our kernels are booted with file capabilities allowed, um and yet one interesting observation here is that, since the capabilities are all clear, it means, and yet the program it ran was was launched by the kernel. It does mean that the file capabilities literally don't apply according to the kernel and another thing we build the image on our laptops and, interestingly, it works.

B

So that prompts us to look at the layers of the image that we build, and here we realize that the extended attributes of the file are actually different.

B

In the laptop case, we see that the capabilities are encoded using a version 2 and in the comp by the the image built up by our continuous integration has a version three, and we also see that in the version three there's more information.

B

So what are these attributes exactly? In fact, now we realize that there's actually an extra option on the get cap command, which we didn't notice initially, which causes the extra information, the version, 3 capabilities, information to be displayed, and it's in fact a user id the root id. So what exactly is this root id? Well in our ci's docker configuration?

B

We actually run it with user name. Spaces.

B

Usernamespaces is a great feature uh very applicable in this particular context where we want to run untrusted code, and so what usernamespaces do is that they actually remap user, ids and group ids, and in this situation the kernel needs to ensure, from a security perspective, that, if a program run in one username space grants a certain set of capabilities to a file. You can't simply take that file and run it in another username space and acquire those same privileges. That would be an immediate security issue.

B

So what the kernel does is that it persists the root user id of the user namespace in the extended file attribute, so that it can ensure that if it's run in another username space, unless the user ids map match sorry, they will not be applied.

B

Now, as it happens, this is irrelevant for container image builds because clearly we want to build images in one place and run them anywhere else that we that we wish. So we really don't want a v3 capability here. We just want the v2 without the root id and- and in this case the fact that um docker mobi build actually persists this. um This information, this user id is, is an error, and so we developed a fix and the pr was merged upstream and we should have to fix in docker 21.

B

So key takeaways here well read the manuals. The capabilities manual page is really excellent, contains a lot of detail, a lot of explanations and allows you to reason about what is happening with respect to capabilities in great detail. Also read the get capman page.

B

This is the one that we missed initially, where we didn't see the dash n option, which would have been really useful and finally, reproducible build yes by all means, but to within bugs so there we have it and, just to conclude, then um kubernetes does an awful lot of heavy lifting for us um and all the associated uh software around it. The container runtimes the container network interfaces.

B

um However, the bigger your organization grows the more strange issues you are going to encounter, and these will challenge you to go deep in your understanding of the of kubernetes and the overall ecosystem, but it is extremely interesting to do so.

B

We have maybe a strange definition of fun, but we definitely like digging into these kinds of issues.

B

We think the debugging also teaches us an awful lot about the the platform and that overall, it allows us to give our users a better experience, because we're able to help them better, because we know the platform well and it's not easy. Definitely, but it is feasible in particular, because here we are dealing with open source and so we're able to dig through absolutely everything, but it is definitely worth it and we find it's very rewarding.

B

So thank you for listening watching and we hope to see you one day in person again. Thank you very much.