Cloud Native Computing Foundation KubeCon + CloudNativeCon North America 2019 (San Diego), 22 Nov 2019

Previous Meeting Next Meeting

⏯

youtube image

►

From YouTube: Walk-through: Debugging an RBAC Problem in Istio (But Without the Swearing) - Matt Turner

Description

Join us for Kubernetes Forums Seoul, Sydney, Bengaluru and Delhi - learn more at kubecon.io

Don't miss KubeCon + CloudNativeCon 2020 events in Amsterdam March 30 - April 2, Shanghai July 28-30 and Boston November 17-20! Learn more at kubecon.io. The conference features presentations from developers and end users of Kubernetes, Prometheus, Envoy, and all of the other CNCF-hosted projects

Walk-through: Debugging an RBAC Problem in Istio (But Without the Swearing) - Matt Turner, Native Wave

A few months ago, I lost a whole day to debugging a problem with RBAC in Istio. I swore a lot, but I also learned a lot. I learned new tools, new interfaces, and the rabbit hole took me past most major parts of Istio. Today I'll recreate that debugging session live, to show you the mental models and techniques I used to methodically follow this issue through a complex distributed system. We'll learn about systems debugging techniques in general, and operating Istio in particular.

https://sched.co/UaeJ

A

It's cool and we want to make things even better. I'm gonna add a little bit of security. The net ops team have said this is great, but every service can talk to every service and that shouldn't be necessary. So I just want you to turn on the our back system. Do a bit of do a few ACLs, a bit of service to service security. So this is where the demos and.

B

I have to work out on my like.

A

So we're gonna go turn on our back I.

A

Have another tea mug session attached on this screen, so I think this is gonna work, okay, so I'm gonna turn our back on no magic. Here right, we apply a config that says like there are no like tricks in this demo, honestly, so we're turning the our back system. um My script was designed for a steel 1.4. It's using a new command that waits for the propagation of resources across the mesh, because the the our back system is a little bit eventually consistent, you'll see if I start hitting f5.

A

That things are gonna, stop there we go so we good we've got a 403 on on the CSS right and the our backs on so the only arrow we saw on the on the terminal.

A

Oh, you can't say I'm highlighting things on this and it's not coming through, but the Evalia character is just at one point: it's just a sto CTL command that relies on a 1.4 sto mesh to watch for this propagation and to sort of let you block on it, but I'm running a 1.3 mesh, because there were some other issues, but don't worry about that. There are no tricks, so everything's blocked great cuz. We turn our back on sensible security stance is to block everything by default.

A

So that's exactly what it's done so now I'm going to go and add my rules to allow the are back again. This is just the standard booking for a demo that I'm using here so we're adding three service roles and three service roles bindings to allow the communication that we want from service a service to open things back up and make the application work again.

A

And it takes a while and kinda February members are booking for works. We've got the product. Page micro service gives you this overall view, but it calls details to get the top or the left panel and it calls reviews to get the bottom of the right panel and we can see product page, but we can't see details and reviews. It's just erroring out rights. Product pages is Gotham code. That says well, if you can't reach that service show a default value in this case, like I'm.

A

Sorry I can't get you that information we're trying to gracefully degrade, but we're running an integrated State. So what's going on, why can't we get there? And this is this- is analogous to the problem that I had.

A

I've got another meme.

A

Yeah somebody somebody posted that in slag, like after about three hours of my swearing I was like I'm going on lunch and I came back to find that so we're in the bad place it ain't working, I was gonna run this like a sort of on-call session. I was gonna, pretend we had this 30-minute SLO to get things back up and have like a countdown timer in a red light and a klaxon, but you can't take that in hand-luggage, so just like I'm gonna keep looking at my watch in my gym.

A

We're under imagine we're under ranch pressure. I also said I kind of talked about debugging principles. More generally, as I say, the time is a bit tight but I know not. Everybody has a software engineering background or you know, people who have assistants background. Maybe aren't used to distributed systems like this, and if you know this isn't typical software anyway, so I'm gonna, try and like a few things about debugging number. One is like this.

A

This phrase that was told to me by an old manager that I really liked which is in order to debug something you've, got to be able to be observe it and you've got to be able to control it so that observability right is the ability to sort of work out the internal state of the system only by looking at it from the outside right.

A

So what we know at the moment is we're putting traffic in and we're getting an error out, so we notice we can observe that we know something about it, but that's not enough to work out what's going on in this box, so we can actually go fix it. So what we're gonna do is we're gonna get some more outputs from this. Basically, we're gonna turn logging up right. It's not rocket science, but if you think of it in more abstract sense like I need to see into this system to work out what's going wrong.

A

Product page is telling me it's had to degrade what on earth. So the first thing I know you didn't do is this is probably an Arabic problem right. It's probably responding to a 403 but hey, maybe the details and review just crashed or something like maybe a sequence and who knows first of all, I want to check that this really is like a 403 an hour back problem. So let's just go. Look at the traffic.

A

So I can and run this command. It's a bit of complicated helm wrangling, but it basically rewrites the master config map that this teo uses to look at everything. So it config my flashes do and we're turning on access logs in envoy we're riding some config that gets propagated through a complicated series of mechanisms to the Envoy like ours and tells them to just start dumping the access logs, because they they don't normally write at a thousand QPS. That's gonna be super noisy, so it's turned off by default.

A

So we turn that on and we sort of, let it think about it for a bit and then we can go get the logs. So these are the logs for the I want to focus on its details. So product page calls details and reviews I'm going to we're just going to look at details that top service for the for the whole thing, because it's it's not giving product page what it wants so we'll just dive into details.

A

So we've got a bunch of noise in here again, no tricks like there's nothing really sitting there, but if I start generating some traffic there we go. There's an access log. A lot of these systems are, you know they they log on a background thread. They get off the hot path they these butter, things on a background thread they batch them.

A

A lot of these systems is going to be very high performance and very latency aware, which means that actually getting the logs out involved often involves me just pressing f5 a lot of waiting right to fill a buffer or something. But as you can see, you can kind of read this if you've ever seen, nginx access log there's there's a 403 in there. So this is this. Is the envoy side carboy details, saying yep I saw your request, but no you asked a bid. It go away, debugging tool number one.

A

You can turn on envoy access logs and you can just read the logs of the sidecar container in that pod and you can get them. That's a bit hard to read. I think this is some like text format. It's not a structured log, it doesn't have any field annotations. I do actually have a picture.

A

Somebody on the internet helpfully put this together. I mean he's pretty fairly helpful right I mean oh girl. I'd, the production values are fairly high, so so we can see the I didn't draw it like. I got joy that well, but the response code should be at 200. It's a 4, a 3 right. We've got a problem.

A

First tool on God.

A

There is little tool, it's called on guard and it's basically an envoy access log parser, so you cut the command squad off. The top. I can probably go find it.

A

Yeah so keep CTR logs the details, polled the history of proxies sidecar and then pipe to pipe to this on guard thing, so on God basically passes it and dumps out Jason and then I'm piping, that into Jake Jake you to get some nice to get some nice pretty printing. Obviously because it's JQ you can you can query this thing, you can extract certain fields. You can take aggregates blah blah blah anything. You can do now.

A

You've got this structure Jason and we've got a schema for it because we know all the fields that are in an envoy access log, so they're again same same information, but with more colors status code for a3.

A

So, okay, what next.

A

I'm gonna do the same thing, but I'm going to do it more gratuitously. Cause I want to show you another another cool tool. That's so cool told is called casein it.

A

So this it's not quite the same thing that was an access log. Let's really dig into own voice. Saying 403 I mean there's a slight possibility that details has started to respond with a 403 itself and on voice just forwarding it right. I mean it's unlikely, but it could be a thing and there's a bunch of other reasons you might wanna do you might want to actually look inside the whole property? So remember, a pod is a order.

A

Containers share in network namespace of this sort of one set of routes and iptables rules in there all the traffic flies around freely between all the different containers. So if only we could tap into that, it would like if this were a Linux machine in the 90s I'd shut into it and I'd run TCP dump right to find out. What's really going on turns out, you can do that. There's a tool called pay sniff, which is a cube, CTL plugin.

A

So things get a little bit interesting because you use crew, which is the cube CTL package manager, which is itself a cube, CTL plugin so install the QC TR plug-in court case NIT, which does a whole bunch of just come up on the wrong screen.

A

Basically, it shells into your sidecar, it runs TCP dump, it sets up a port for words and it the pcap output, a TCP dump into Wireshark on your local machine. So this is a live traffic capture of everything. That's going through that pod I can't see it so I'm gonna have to bring it.

B

Back and I'll point out things like.

A

Right, something is getting slashed at slash, Prometheus right, so fine thing scraping. The Prometheus endpoint is getting a 200, fantastic. All the traffic going through the pod I.

B

Can apply a filter.

B

Generate some more traffic and there we go I.

A

Won't dig into that. It's honestly it's too hard, but those are your four threes and you can dig it off see and get all the layer, two layer, three layer, seven information, your full Wireshark! You can write these very expressive filters. You can do all kinds of stuff. It's super cool. It's saw this slightly shinier version of what we did before, but it's awesome so I wanted to show you it.

A

A

Am gonna start swearing honestly right, um so it's all messed up we're getting for our trees. What the hell do I understand, need to find out. Why? So? What about the controllability side of this thing right? Can we go into the system and effect what it does, because we want to start running experiments like we kind of know. What's wrong, we want to start tweaking dials. We want to see if we can control it and get it closer to the right thing or if we can break it in a different way or whatever.

A

So it's a 403, we think its own, voicing it, not the app. It's a reasonable hypothesis to think that that was because we just turned our back on right and it's starting to deny a traffic. So what could we do to test that? Well, we can turn our back back off and see if it works. It sounds stupid, but that's basically what we're going to do. You can actually do a little bit better, there's a permissive, our back mode, so it's like a scene in expressive mode.

A

If anybody's seen that we can basically say to the our back system, I want you to still look at the traffic still ingest. All the rules still understand the rules, but not enforce them. So I want you to log what you would have done and why but don't actually enforce them. So that'll kind of kill two birds with one stone.

A

But I've I can spend missive with some logging again, there's there's a bunch of esoteric config for this. The book info sample even comes to, and this is why I'm using booking photo cuz I had to work all this out myself. The book info sample comes with a couple Yama's ones, one that puts our back into permissive mode and one that turns on all of the like permissive modal logging.

A

B

Turned it on, we can read it.

A

This is where you sit there and I press f5, because mixer like aggressively batches, so you can see it started to work again. Right, traffic's come through so pretty much 99.9 percent. That was an hour back issue traffic's going through again, but we're now in permissive mode. So if we can finally fill that buffer there we go and it will come through at once, because we're in a big batch I've added some highlight so these are mix along STIs are structured. These are these are Jason.

A

So at a warning level, we've got it says: well, any response code is 200, but the permissive response code, as in what I would have done is is denied. So this absolutely is an are back deny coming from the site car, but this is about that. That kind of controllability right I, can take the our bike. Iq I think it's the R max this time. I could turn it on. I can turn it off. I can put it into a into a verbose mode. Our back decisions are enforced at well.

A

Our back policy is enforceable sidecar, but the decision is ultimately made by by mixer currently for anybody who kind of knows the sto architecture. So it's the history of POD logs that we go and look at.

A

I turn just asked me if I won our grade, because you should never do live demos.

A

Right, so this is reminder because I always forgot to do this in the run-through. I need to turn the hour back back on, so I need to actually make it fail again if we can carry on debugging, but this is this is under the broader spectrum of only change one thing at a time right. This is the scientific method.

A

Really you know you change where you have a hypothesis, you change one variable you go and see what it's, what it's kind of done, so I thought I only change one thing: when I turned our back on and everything stopped working, so it was a reasonable, reasonable hypothesis that it was our back that did it. We've now definitely only changed. One thinks I'm like right, I'm in debugging mode. Let's just turn our bike off and not touch anything else. Oh yeah that fixed it right. So what we will do.

B

Is just go and turn our back I'm.

A

Just gonna use that original script and just dump the are back on config over the top.

A

So it's our back. Let's look at how that subsystem works right. We need a mental model for this system and we just need to follow it through. Logically, so Howard is the our back system work while well from what I know of sto know. There's some rules, we apply the rules, pilot reads them pilot sort of interprets them and compiles them into own void.

A

Config pilot pushes that config to envoy the envoys receive it and ingest it and understand it, and then they enforce it something's going wrong at that stage, because I have given Envoy instructions to let this traffic through Envoy is not doing that. So one of these stages has gone wrong. That's what I should have joined a picture of it, but that's my my mental model of my pipeline left to right. So we can start at a left and we can just go check each one of these components.

A

B

A

So the first thing we can do there is a another magic sto debugging command to learn there. All of the control plan components are built friend like the same micro-services library. They all listen at supply. That makes a citadel I think and gali. They all have a web admin import. They all have this Hyneman port, where they expose away that main interface. See you can configure them obviously would come online are given syn config files, but they have. They have an online admin interface as well.

A

Sto CTL dashboard is a nice shortcut that basically sets up a port forward to that admin port right. So it's all kind of nice and easy to be operational. Remember you're, probably gonna be doing this at 3 a.m. right. So these are just tools there's no! This there's automation really rather than abstraction, but all this is doing is setting up a a port forward to the AB important. So we've got the pilot admin port. It's a fairly nice web interface, like it even updates in real time and.

B

There I can't see it, but there's a bunch of stuff we can do bunch of stuff. We can read and I think it's that one one of the things I can do is turn logging levels up in various places and I want our back.

B

So I could change that from info to debug. It's very web.

A

2.0 there isn't even a Save button, so that's that's done now. So I've now turned the are back logging off, because I know that I'm ingesting my are back and fig and it's trying to compile it and it's it's going wrong. So, let's, let's look at what it's thinking when it does that.

A

So what I'll do is just to kick the compiler I'll remove. Those are back. Rules are the ones that say, allow the traffic and I'll kind of weigh a bit then up at the back. Now that the logging is turned up.

A

And then we can dump the pilot logs and again I put a little bit of great magic in there. So you can see listener discovery service. So this is the thing that sets up the front end of envoy and tells it to listen he's indeed pushing some config to the side. Carboy details.

B

And that's not the problem. I don't mean just go that way.

A

I'm surprised, that's all the logs we've got.

B

That's: let's do it again.

B

Oh there we go. That is more like it.

A

Okay, we might not get exactly what we're looking for cause. It's a little bit. Oh no, there we go so the are back subsystem, says right: I'm gonna, go I'm compiling all your are back walls I'm going to go, build a policy! This is this is for details, so I'm going to check the the service role called ratings viewer. So that's the one that gives you permission to view ratings and details, and oh, yes, I've added something to the Envoy policy for that.

A

The Envoy, our back policy, because this ratings viewer sto policy had something to say about it. So we've definitely picked up the sto config that we want and we've added it to this other this Envoy, our back that we're building and then it looks at the one that lets you view product page and says: well, that's not relevant to this details.

A

Sidecar and then you know skips it, but eventually we build the HTTP listener and these are all multiplex so that we can't really see the though you know push the details on this page, but but that's how it's working. So we can reason about this kind of compilation. Process, for these are back rules, so that seems to be working.

A

So let's go further down that pipeline right, we've started with something seems to be working: let's follow it through and I'm, going to speed up a bit, but I think I'm doing that kind of okay. So.

A

Proxy status, STR, CTL, proxy status, very useful command, did pilot, managed to push and sync the config into all of these pots. It says yes, it did for therefore they're sidecar on details, which is the top of the list.

A

Cluster discovery service, which is basically but the back, ends the things you might want to talk to listener discovery, which is for like thing on the front, end end point which is also backend stuff. Anyway, all of the different in all the different parts of the Envoy config service, the only one config space are all synchronized. So, okay, we built a policy that we assume is correct. We pushed it to the envoys.

A

What we do next well, let's look at envoy envoy, also has its own web interface. It's more web 1.0. To be honest, it's a bunch of links there just to get requests, but it is there and again there's this TOC TL dashboard command that will that will open it up for you. I won't show you around this because we're running a bit short on time.

A

If you ever want to know how complicated Envoy is press the config, Dom button and like count the liens honestly count the lines but because it's a bit dumb, unfortunately, to turn to turn the logging up, you have to do a post request and you can't do a post through this web interface, so we actually have to close it and then kill that poor forwards.

A

And actually just do a set up the port for with ourselves we have to. We have to based exactly and use curl. We have to hit that endpoint ourselves. We have to do a post, which we can't do with a browser very easily and the the output, the body that it respond. That returns in response to that post is the current state of all the debug or the tracing areas, including you can see it, though, if you can find it just below pool just above Redis. Our Mac is now on debug. Everything else is warning.

A

Which means again, I can read them with a nice sto. Ctl. Sorry keep CTR logs come on for that details like our you can see all the stuff. It was printing, a warning level before the access logs that we were talking around. But now, if I generate some more traffic, it should be really verbose about what it's doing with our back.

A

It's easy to read on my screen, so all that comes in request comes in you know, path is details, zero, the details of the zeros book, your standard, HTTP headers. So this is the set of metadata. That envoy has about this request and you can make policy decisions based on any of that right.

A

What we're looking at is there's the service, that's calling it so we're not blocking things based on user agent, we're not blocking things based on port, but blocking things based on who's. Trying to talk to you, because this is service to service ACLs right. We're saying that product page can actually make any request to me, but it's only product page. That's allowed to talk to me, so you can see the one of the the metadata includes all the HTTP headers.

A

It also includes a few pieces of dynamic metadata, a few things that aren't from the request that have been like injected by the environment. So he still has a bunch of plumbing to give it more information about the request. One of those things is it's Joe or them, as in authentication the the name. So we have this key issue or thing who's talking to me, but the value is empty and then it says enforce denied.

A

So that's a bit weird right. How do we know that it's product page talking to us this? This seems like the kind of information we should have to handle, because we know if we'd had time to open the service role binding. We know that we've said well its product page. That can talk to me. So there we go enforce denied and then the access log for three.

A

Get one last piece of debugging advice, guess and check right you have a mental model. All bottles are wrong. Some models are useful. Take a plausible hypothesis right that fits within that model, and this is a creative step.

A

This is why debugging is it's draining and you can't estimate how long it's going to take, but you take a you, take a creative step to a plausible hypothesis that makes sense in that model you design an experiment, that's going to check that and check only that, and ideally, your experiment wants to only change one thing about the system at a time right in standard scientific method, stuff. It gets super hard when your model is wrong right or when you have to run multiple experiments.

A

You have to change multiple things and you're, trying to infer one aren't so like it can get super super hard, but guessing and checking in general. Is it's a good idea? So we don't have this user account? We don't have this, like name for who's, trying to call me well where's that going to come from, if you think about how you bind a service role, you give it a. Certainly you give it a service account name, it's not the the name of the calling service or pod cuz. You can't really do that.

A

The only select strong identity you can trust is the service account token, because the product page pod has the product page service account token on the file system. So it's envoy can lift that off the file system, send it across the wire, and this thing is cryptographically signed. You know you can send that off to the kubernetes api server and say: hey. Does this job check out? Is this signed in the correct way? Can I trust the claims of identity that in it?

A

So we seem to be missing that I found a word this next, because if I say too much, I'll give it away and I want a big reveal cuz. We like a big, reveal.

A

But you know maybe it's something to do with the way to services talk to each other. What's on the wire? Well, let's check. Let's analyze, that config, mysterious ETL, experimental analyze, k-means go look in the cluster, you can point it at a bunch of gamal it'll check, whether it's consistent. This reads: everything out of the cluster, no validation error is found. Let's say, debugging gets really hard when your model, your tools, are wrong. This tool is wrong. It's told it's experimental I'm wrong.

A

It's not wrong! It's just not completely right! It's not lying anyway. It so.

A

So, let's look at the two sides: it's the product, page pod. It's calling the details service, so east, your CTL experimental describe the product page pod, while okay, it listens on port, 90, 80 and then out the back.

A

It's actually that doesn't really tell us anything useful at all, but the detailed service listens on ninety eighty HTTP, it's permissive insofar as it'll accept HTTP, RM, TLS and the clients will speak to it over HTTP and though, and it's found that our back policy there is an our back policy. That applies. That's that reviews viewer that we saw being compiled.

A

So, like hmm clients talk HTTP, so details is a server that will accept NLCS or HTTP, and its clients are talking HTTP, so M TLS is turned off in this cluster.

B

There's secretly fix things.

A

Find a mouse pointer said that wait. Timing works, look.

B

A

Turned ng alehsalaam because the way it gets that identity is it fix the service counter. I can hop off the file system and it uses it as the common name for the MTS certificate that it presents. That's the only thing you can really trust. You can't just look at the source IP, because that can be spoofed. There's no way to get the name, so you don't know which pods talking to you.

A

There are there's an EM TLS certificate on every side and the the identity of that the common name is the name of the pod, and that is verified by the sto agent. You know taking that service account token talking to the the sto control plane to Citadel and saying right. I have this: if you trust that this really is the identity of my pod, can you please meet me a TLS certificate? That's got that name in the CN and then those things are used for NLCS. So it not only gives you encryption on the wire.

A

It gives you a strong claim of identity on both sides, but it's tied all the way back to the workload and its identity, which is the kubernetes service account. So what we were doing was comparing, as we saw, comparing an empty string against product page because there's no MCLs, so there's no common name on the wire and that is I. Basically misconfigured listed I put it into a configuration state, that's inconsistent and therefore it was trying to enforce our back and it was just failing, safe and saying well, there'd, be these names didn't match denied.

A

So now it's working and we can go back and look at.

A

So it's your war, then suddenly a bunch of values in there right. It's not empty. We've got an author couple of source principles, authentication principle cluster, that local default namespace product page service account. Imagine Lee. It works. So now that was the problem.

A

Like why do it like why? Why are we allowed to get into this seemingly inconsistent state? Well, you can actually enforce policy based on end-user identity. You can enforce policy just based on other metadata, like the port or the user agent or something so it is okay to try to enforce are back with em TLS turned off, but if you want to look at if you actually want to do by far the most common case, which is service to service or then you're gonna need any less on to get that identity across the wire. Fine.

A

So and it's not the great Diskin fixed service ever, but they doing that it's just as flexible as it can be. It doesn't allow you to do those other things as I say: yo, it's doing, CTL analyze says well, there's nothing wrong with your config and besides service role and service role, binding are a little bit clunky to work with and they're going in 1.6 anyway, they've been replaced by by authorization policy, so that was it I just lost a day to it, but I went through that whole set of tools of turning lonely.

A

Like learning where all the logs are learning how to turn them up those two web interface, dashboards and all of the super cool traffic dumping stuff, so hopefully that was interesting.

B

A

More debugging tip is basically not panic. I just have a klaxon, but I mean seriously stress, doesn't help shortcuts, don't help you've got to be methodical. You've got to be scientific. Like you, don't speed yourself up by panicking. You don't speed your team up by shouting at them. You speed it up by reducing cognitive load like having those scripts that I used.

A

Those should be scripts that you have, or they should be in your wrong book, so you can copy/paste them and you can reduce typing time in error by just having that, like don't abstract things to oblivion and just automate them Keep Calm have ROM books, have practiced and use shiny tools, Thanks.