WEBVTT 1 00:00:21.060 --> 00:00:22.080 Hey, Matt. 2 00:00:22.080 --> 00:00:32.620 So last time we were talking about performance and amazingly, you and I have remembered just about enough of what we were talking about before to be able continue on that subject. 3 00:00:32.620 --> 00:00:33.340 Mm hmm. Yep. 4 00:00:33.340 --> 00:00:43.690 So the story so far, as we were recapping during the intro, we have a relatively trivial piece of code and we were interested in making it go as fast as possible. 5 00:00:43.690 --> 00:00:44.560 okay 6 00:00:44.560 --> 00:00:55.110 mostly by looking at the things outside of the code itself that could be taking time, IO and shipping things magically through kernel space or ah avoiding kernel space and that good stuff. 7 00:00:55.110 --> 00:00:55.360 Mm-hmm. 8 00:00:55.360 --> 00:01:07.180 So then you said, well, what happens if it wasn't a trivial piece of code? What if it was like a lot of work? How do you make that go fast? And I think that's where we were we were going to continue. 9 00:01:07.180 --> 00:01:08.280 Right. 10 00:01:08.280 --> 00:01:11.000 So, I mean, how do you want to start this? 11 00:01:11.000 --> 00:01:11.380 Yeah. 12 00:01:11.380 --> 00:01:17.180 Well, so yeah, like the previous example, it was dominated by IO, right? Like ... 13 00:01:17.180 --> 00:01:22.700 Or you know a very simple map lookup and just RAM. And we talked about L1, L2, L3 and that kind of stuff. 14 00:01:22.700 --> 00:01:32.220 right. Yeah, not quite adding two numbers together. You do maybe have to go out to RAM and and and pull some data down, but you know I think ah Redis cache was sort of like the rough idea. 15 00:01:32.220 --> 00:01:35.320 The mental model we had, exactly, yeah. 16 00:01:35.320 --> 00:01:41.060 Yeah. And you know maybe alternating with robot servo control but that's i think we went off on a tangent there yeah 17 00:01:41.060 --> 00:01:44.760 That's right, we wouldn't have we both, yeah, unsurprisingly. 18 00:01:44.760 --> 00:02:07.060 So now imagine the the program that i wish to make go fast instead of being dominated by i o let's say is dominated by the program itself And I think this could be interesting in two dimensions One is you might have something where um what you're actually looking for is throughput, right? 19 00:02:07.060 --> 00:02:18.560 You're just trying to process a lot of data, or maybe you're not trying to process that much data, but the computation on that data is very expensive. And so you're trying to do that as quickly as you possibly can. 20 00:02:18.560 --> 00:02:31.920 And then there's also the dimension of just latency, where it's like, okay, IO is maybe not the dominant factor here, but the round trip time of this still matters. 21 00:02:31.920 --> 00:02:40.470 And so you have trade-offs that you now need to make. Whereas before we were just kind of optimizing for, you know, let's stay in the L1 cache and let's make sure that we you know never miss it. 22 00:02:40.470 --> 00:02:40.820 Right, right. 23 00:02:40.820 --> 00:02:48.860 It's like, well, we can't, this problem is too complicated for that. So now we maybe have some interesting trade-offs between IO and performance inside the CPU. 24 00:02:48.860 --> 00:02:51.980 To sort of concretize, concretize, something that, like that a word? 25 00:02:51.980 --> 00:02:53.360 That's a word now. 26 00:02:53.360 --> 00:03:01.140 It is a word now. um Something like a video game is a great example of there's a ton of stuff going on in every frame, but you want it so that when you hit the fire button, 27 00:03:01.140 --> 00:03:08.200 You aren't waiting 120 milliseconds before you actually finally see the fire, you know, the shot go off. 28 00:03:08.200 --> 00:03:08.200 Yeah, yeah. 29 00:03:08.200 --> 00:03:19.340 And, you know, there's a number of things that are sort of kernel bypass-ey in the way, but most of it is just down to computation. And can you get something done in say 60th of a second or a hundredth of a second in modern things. 30 00:03:19.340 --> 00:03:23.040 And then for a throughput based thing, we're talking maybe credit card processing? 31 00:03:23.040 --> 00:03:23.300 Right. 32 00:03:23.300 --> 00:03:30.360 I don't know that's still IO-ey feeling. i don't know. I'm trying to think of an example that might be, um, that that we could talk about that's, uh, 33 00:03:30.360 --> 00:03:44.720 I mean, you know there's all kinds of problems with like text manipulation. Like, you've got lots and lots of text you're trying to ah summarize it, extract some you know signal from it, you know, run some NLP process on it. 34 00:03:44.720 --> 00:03:44.780 Yeah. 35 00:03:44.780 --> 00:03:45.800 That's one. 36 00:03:45.800 --> 00:03:52.420 Right, right. And you've got tons of data to go through and you just want to get through it quickly. But, you know, the end of any one piece of text is not particularly important. 37 00:03:52.420 --> 00:03:52.660 Yeah. 38 00:03:52.660 --> 00:03:53.210 Yeah, I mean, that works. 39 00:03:53.210 --> 00:03:53.660 Right. 40 00:03:53.660 --> 00:04:09.960 Well, so I think probably something we didn't even talk about last time or I don't remember talking about last time is the single most important thing about any kind of performance, which is measuring it and making sure you know what you're doing 41 00:04:09.960 --> 00:04:09.960 Ah, uh-huh. 42 00:04:09.960 --> 00:04:28.990 Before you make any changes, because unlike almost any other aspect of software engineering, there are so many hidden variables and so many weird things going on inside computers or exogenous or in in your own code, which is more complicated than perhaps you remember it is 43 00:04:28.990 --> 00:04:29.020 Yes. Right. 44 00:04:29.020 --> 00:04:37.090 or there are surprising aspects of it that the only way is to establish some kind of base truth, like, 45 00:04:37.090 --> 00:04:37.780 Mm-hmm. Mm-hmm. 46 00:04:37.780 --> 00:04:54.180 I have a representative amount of work and I have a harness that can run it and I can get reproducible results that are hopefully intersubjective so I can share it with my team and they can run it and they can also see that or that kind of thing first before you even start making the first change or even trying to understand the problem. 47 00:04:54.180 --> 00:04:54.240 Yeah. 48 00:04:54.240 --> 00:04:56.080 You just need to have a baseline. 49 00:04:56.080 --> 00:04:57.440 Right. Right. 50 00:04:57.440 --> 00:05:01.210 So measure, measure, measure, you know, is the, is the, the key there. 51 00:05:01.210 --> 00:05:01.320 Mm-hmm. 52 00:05:01.320 --> 00:05:27.350 And then, Profiling is the next sort of aspect of it. like How do you know where you're spending time in your program? and that can be a surprising journey as you discover that actually it's not the computation. It's not the big O(N^2) thing that you've got. it it's It's the fact that unbeknownst to you, the particular function you're calling has to do a locale lookup every single time to parse a string and you didn't realize that it was just checking. 53 00:05:27.350 --> 00:05:27.580 Right. 54 00:05:27.580 --> 00:05:31.580 I wonder if the user has switched into German locale they're expecting us to use periods instead of commas whatever. 55 00:05:31.580 --> 00:05:38.670 Right. It treats this identifier as a domain name and does a DNS lookup every time you call this function. Right? Yeah, exactly. 56 00:05:38.670 --> 00:05:38.950 Right. You know, yeah, yeah, exactly. 57 00:05:38.950 --> 00:05:39.000 Yeah. 58 00:05:39.000 --> 00:05:46.240 Understanding the complex code that you have written and that you're interacting with and the surprising effects it has are key. 59 00:05:46.240 --> 00:05:47.040 Yeah. 60 00:05:47.040 --> 00:05:52.660 So I realized we didn't really touch on that last time, but that would be like the first and most important thing is: measure everything. 61 00:05:52.660 --> 00:05:52.760 Mm-hmm. 62 00:05:52.760 --> 00:06:07.720 And then you kind of hit the the sort of list of, you know, do I need to do this? Can I do this before? And then ah you know can I avoid it? those Those kinds of things. I can't even remember. that that so Who was it? Somebody we spoke to once had a list of like, 63 00:06:07.720 --> 00:06:12.260 the sort of like rules of optimization and sort Zeroth rule is, do I even need to do this at all? 64 00:06:12.260 --> 00:06:14.310 Man, that's always That's a good rule for anything, honestly. 65 00:06:14.310 --> 00:06:18.240 um But anyway, I'm getting ahead of myself. I'm getting, it yeah, that's true. 66 00:06:18.240 --> 00:06:23.180 um Okay, so let me, let me throw to kind of kick this conversation off, let me throw a scenario at you. 67 00:06:23.180 --> 00:06:23.760 That's true. 68 00:06:23.760 --> 00:06:32.440 Because everything you're saying here makes a ton of sense, right? And so like, okay, yeah, measure: measure at least twice, cut once, right? Like I'm going to measure this thing. 69 00:06:32.440 --> 00:06:54.820 I'm going to make sure that it is slow. slow I'm going to maybe have a profile that tells me that that it is the slow part in the context of the system. It's not that it has some you know slowness to it that I don't like. It's like, no, the reason that you know the bullet isn't traveling out of the gun fast enough is because this line of code or this method or this thing is slow. 70 00:06:54.820 --> 00:07:19.880 So let's say that I'm like, all right, well, obviously what I want to do here is I want to measure it and then i want to change it. And then I want to measure it again and I want to make sure it got better, right? What do I do when I set up my little thing to measure it and I run it and I get one result and then I run it again after having made no changes and I get a totally different result? 71 00:07:19.880 --> 00:07:23.180 Errr... I mean, despair!? 72 00:07:23.180 --> 00:07:24.740 [laughing] 73 00:07:24.740 --> 00:07:38.790 but be aware that that's very common, right? You know, it's... Benchmarking anything is incredibly difficult. And with all the variables that we've talked about, the noise on your machine is perhaps and a source of of that. 74 00:07:38.790 --> 00:07:38.820 Mm-hmm. Mm-hmm. Mm-hmm. 75 00:07:38.820 --> 00:07:50.900 you know Making sure that there isn't an exogenous input that actually you're you're depending on, like you say, a DNS lookup that sometimes is is in the cache, sometimes isn't in the cache, those kinds of things. And then if you're on a shared machine, 76 00:07:50.900 --> 00:08:12.260 Obviously, I guess it depends, right? right there are some Some aspects of performance are so large, like if you're measuring the throughput of a system and you're running it for like 20 minutes and then it's you're getting results out of that, then usually the noise levels are low enough that it doesn't matter as much. But if you're doing something that's like ah write a... 77 00:08:12.260 --> 00:08:28.050 you know, the collision detection for a video game. And you're like, okay, I have a test essentially, just like I would write a test to say, do these two things intersect, except that it's a little benchmark and I'm going to run the, "are these intersecting?" over and over again? 78 00:08:28.050 --> 00:08:28.140 Mm-hmm. Mm-hmm. 79 00:08:28.140 --> 00:08:39.800 And each time it takes, I know, 200 micros, something like that. And, and um and then I run it once and it says 200 micros and I changed nothing. I run it again and it says 10 micros. i'm like, what, hang on, this is, 80 00:08:39.800 --> 00:09:03.210 This is bonkers. Now you're in sort of like the noise of the machine area and you are looking at things like the warmth of the cache, whether or not other processes are running at the same time as you, whether you're you're being kicked off the CPU, whether or not, you know, you've got Slack open and in the background and someone's just posted an animating GIF and now 200% of your CPU is is actually animating a stupid ah cat. 81 00:09:03.210 --> 00:09:03.820 Yeah. 82 00:09:03.820 --> 00:09:16.860 um those are the things, um, that you immediately think about if you, if you can rule out some sort of internal, um, differences like the DNS related thing, or like maybe there's even a cache file on the disc and, and whatever. 83 00:09:16.860 --> 00:09:29.820 Um, and you know, there are frameworks for running benchmarks that try to do their best to isolate your process. They will warn you if you haven't like turned off other, um, certain aspects of your CPU. 84 00:09:29.820 --> 00:09:35.020 so So for example, the CPU can throttle its speed up and down for power saving reasons. 85 00:09:35.020 --> 00:09:45.210 And so that might be a reason, you know, like the first time you ran it it, it ran slowly and then it ran fast because actually the CPU woke up and was now faster, you know, the actual gigahertz clock frequency. 86 00:09:45.210 --> 00:09:45.430 Mm-hmm. 87 00:09:45.430 --> 00:09:45.880 Mm-hmm. Mm-hmm. 88 00:09:45.880 --> 00:10:11.720 So there's a ton of sources of noise at that level. And realistically, um when I've done this kind of stuff for the more micro-optimizey stuff, it's best to try and have a dedicated resource somewhere. So we've had like CI machines before now that have been things that we can reserve and or run continuous performance monitoring on critical pieces of code and then just keep a graph of it. But it is noisy. 89 00:10:11.720 --> 00:10:27.140 um There are tools you can run. So I have a friend who swears by using ah Valgrind, which many people know as being like a memory checker for compiled languages, but there are other modes that it has. 90 00:10:27.140 --> 00:10:41.100 And one the modes that it has is like to count the number of instructions executed. It kind of virtualizes the whole thing and it runs as a sort of an emulator of the the very CPU you're running it on, which is kind of how Valgrind itself works. 91 00:10:41.100 --> 00:10:47.080 but it gives you a deterministic "how many instructions did this code path take?", which is interesting. 92 00:10:47.080 --> 00:10:49.480 Interesting. Yeah. So you're not measuring it by time anymore, right? 93 00:10:49.480 --> 00:10:57.100 You're not measuring by time. And of course, that's not necessarily a perfect proxy because ultimately you want "how long did it take" is the you're trying to optimize. 94 00:10:57.100 --> 00:10:57.240 Yeah. 95 00:10:57.240 --> 00:11:10.220 But if you, for example, want to put something in CI where you could say, ah literally write a test that says, if this function takes more than 20 million CPU instructions, then we've probably done something dumb somewhere. 96 00:11:10.220 --> 00:11:15.410 Like either we've forgotten a command line switch or we someone added something huge to a function. 97 00:11:15.410 --> 00:11:15.640 Mm-hmm. 98 00:11:15.640 --> 00:11:27.900 So it's a very... gross um check, but it is one that you could consider doing. And similarly within that, there's a Cachegrind, which tries to estimate what a cache might look like. 99 00:11:27.900 --> 00:11:32.350 And in fact, actually only today, somebody posted, I'm going to just go over to my other screen here. 100 00:11:32.350 --> 00:11:32.500 Oh, interesting. 101 00:11:32.500 --> 00:11:48.840 Sorry for the sound changing. um Someone's just posted a tool called Cache Explorer, which tries to, um yeah, exactly. Tries to run a little bit of code and give you a visualization of what cache things have happened by simulating a cache. 102 00:11:48.840 --> 00:11:55.200 But again, we don't really know 100% what Intel's caches are doing and AMD's caches are doing, but we can make some you know guesses. 103 00:11:55.200 --> 00:11:56.120 Yeah. 104 00:11:56.120 --> 00:12:02.360 But those are the kinds of things that might be unstable between runs. 105 00:12:02.360 --> 00:12:17.580 Interesting. so So in that world you are, and I think there's a few different things here. So you're talking about like you could have a continuously running performance test, continuously running in the sense of it runs on every change, ah runs on every build. 106 00:12:17.580 --> 00:12:22.760 or Or once a night, and you know, two in the morning or something like that, where you can say like, hey, no one is working right now. 107 00:12:22.760 --> 00:12:22.840 Yeah, yeah, yeah, yeah. 108 00:12:22.840 --> 00:12:27.800 We've got all these resources that are dedicated and there's no other noise coming from it. 109 00:12:27.800 --> 00:12:41.300 Right. Yeah. And, you know, obviously you can, you can try running those sorts of tests on dedicated hardware. You can try running the tests by not measuring time at all. And just by counting instructions, which should be relatively stable, you know, even if the cat GIF is running. And, 110 00:12:41.300 --> 00:12:58.260 and is Is your usual MO to then reuse those types of tests for performance optimization? Are you running the same tool that you would run in your CI process when you're like, oh, I need to optimize this method? Or are you building things that are more bespoke? 111 00:12:58.260 --> 00:13:12.060 It depends, honestly. um There have been times when I've used the same tooling. you know Those microbenchmarks are a great source of... um things to look at, but it's really, really easy if you're not very careful. 112 00:13:12.060 --> 00:13:26.720 Again, it depends on which domain you're in and what's, you know, we're talking again from the kind of industries that we've been in where we have a very usually homogenous deployment environment where it's like, well, we have many computers that all look the same. 113 00:13:26.720 --> 00:13:26.940 okay 114 00:13:26.940 --> 00:13:35.040 So they have this CPU in them and we have the luxury of targeting that CPU or, you know, caring about this particular amount of RAM and number of CPUs and all that good stuff. 115 00:13:35.040 --> 00:13:35.700 Right. Right. 116 00:13:35.700 --> 00:13:50.900 But typically, developer workstations are not necessarily the same as the servers you're deploying to. And it's it can be easy to fool yourself by running microbenchmarks on your local developer hardware and then be very, very sad when it doesn't pan out when you run it in production. 117 00:13:50.900 --> 00:13:58.080 So you really do have to be careful about drawing too many conclusions from local stuff at the sort of scale that we're talking about with the you know hundreds of microseconds. ah 118 00:13:58.080 --> 00:13:58.080 Yeah, yeah. 119 00:13:58.080 --> 00:14:16.500 level. So it does it is antagonistic to doing like quick turnaround and sort of like TDD style. Hey, just make it go faster. You've really got to be able to run on representative data, which is hard because it's really, really easy to write a microbenchmark, which is representative on its face, but actually 120 00:14:16.500 --> 00:14:18.000 Mm-hmm. 121 00:14:18.000 --> 00:14:21.120 is is ah a little bit too best case scenario. um 122 00:14:21.120 --> 00:14:21.120 Yeah. Mm-hmm. 123 00:14:21.120 --> 00:14:36.810 For example, CPUs have caches we've just talked about, CPUs have branch predictors. And so if you have a very branchy bit of code that you're running 100 million times in a tight loop with the same input data to sort of get you how fast this is gonna be, 124 00:14:36.810 --> 00:14:37.260 yeah 125 00:14:37.260 --> 00:14:49.380 A: you're hitting the same cache lines over and over again. B: the branch predictor has learned 100% of all of the branches in your benchmark and the benchmarking code around it. And so it is a perfect representation of the best case. 126 00:14:49.380 --> 00:15:04.600 Now, that's an important thing to understand. Like the min, this is something I see people do all sorts of distributions of these profiles. And like the min is an important point. It says like if everything lines up, perfectly, then this is the theoretical best case that you can get. 127 00:15:04.600 --> 00:15:14.920 So the min gives you a piece of information, right? Then there's sort of like people talk about the mean, and I think that's a terrible representation of anything because there's so many tails in there usually. 128 00:15:14.920 --> 00:15:15.420 Yeah, yeah, right. 129 00:15:15.420 --> 00:15:31.360 but so But having an idea about what the distribution of your function looks like is important. And usually it's a horrible log normal thing that is not very amenable to understanding. But like looking at it and kind of getting a sense of like, are most of them less than 100 micros or is it is it you know just the average? Yeah. 130 00:15:31.360 --> 00:15:31.620 Yeah. 131 00:15:31.620 --> 00:15:40.580 I don't even know what, I'm not a statistician, but I do tend to look at plots and CDFs and things of that, of what's coming out of the function under test. 132 00:15:40.580 --> 00:15:40.780 Right. 133 00:15:40.780 --> 00:15:54.360 But yeah, what winding back round to the cache and the branch predictor, if you don't have representative data, then yeah, when you then deploy to production, then you discover that every time you call your function, 134 00:15:54.360 --> 00:15:56.880 it's the worst case because you haven't recently called it. 135 00:15:56.880 --> 00:15:57.120 right 136 00:15:57.120 --> 00:16:03.420 The branch predictor has lost, has forgotten about that. The cache is not warm. Then you're hitting the worst case of everything. 137 00:16:03.420 --> 00:16:04.080 Mm-hmm. 138 00:16:04.080 --> 00:16:05.120 And then that doesn't dovetail. 139 00:16:05.120 --> 00:16:05.260 Mm-hmm. 140 00:16:05.260 --> 00:16:22.540 you like, well, I made this improvement, but you don't you don't see it. So it's almost impossible to do a good micro benchmarks. They can only be sort of representative. They can help you along the way, but you always have to run on real hardware and you always have to run on like a real workload and measure something that you actually care about. 141 00:16:22.540 --> 00:16:49.380 You know, for us, In our world, it's usually you know like the end-to-end latency of a system that we care about. you know So you maybe you say, going back to our Redis example, let's say it was a bit more there was some bit more meat in inside what it was actually doing. And you're like, well, I've optimized the hell out of this part, the bit that does a tree look up for the cache key. And then there's some complicated stuff that goes on. And then we return it. And there's this you know all this networking code that we've talked about. Well, yeah. 142 00:16:49.380 --> 00:17:00.820 you could probably sit and write a really good hash map implementation and all the benchmarks that go with it and think that you've done a great job. And then really you still have to see it in context of in the... 143 00:17:00.820 --> 00:17:01.980 yeah 144 00:17:01.980 --> 00:17:19.510 the actual Redis server, has it made a difference? Or is it actually no? Well, this is great because it uses tons more RAM than before. And in my micro benchmark, that just works a treat because I've got all the cache to myself. But when I have to share the cache with the networking code that runs around it, then suddenly it's not good anymore. 145 00:17:19.510 --> 00:17:20.680 okay 146 00:17:20.680 --> 00:17:24.580 I realise, that's an incredibly long and rambly answer to your point, but... 147 00:17:24.580 --> 00:17:44.380 No, no, that's, I mean, that's, that's really good. And so, you know, I, ah can go back and forth and argue one versus the other about whether it's more important to have systems that are sort of, you know, we talk about systems that are designed to be tested, systems that are designed to be observable. 148 00:17:44.380 --> 00:17:45.300 yeah 149 00:17:45.300 --> 00:17:53.590 ah You know, you can maybe argue one dimension of observability as performance, I guess. And so you could say like, is this is this system designed to be profiled, right? 150 00:17:53.590 --> 00:17:53.880 I think so, yeah. 151 00:17:53.880 --> 00:18:08.420 Like, can you measure its performance under real world conditions with real world data? And the trick, of course, there is that you know the more you care about performance, the more you care about not slowing down your performance by measuring your performance. 152 00:18:08.420 --> 00:18:22.900 And so having something that's running in the most real world environment, which is to say the actual production environment that is measuring performance, you might be questioning, have i am I making my system slower by measuring how slow it is? 153 00:18:22.900 --> 00:18:28.040 So what are some tricks that you've used in the past to sort of break this? it know that it's an iron triangle, but ah the trade-off there. 154 00:18:28.040 --> 00:18:44.060 Oh, that no, that's interesting. yeah Yeah, because we haven't really talked about that. We've been talking about sort of end-to-end measurements, be it because I'm running a microbenchmark and calling a function, and then literally the microbenchmarking system is doing the, start the clock, call your function 100,000 times, stop the clock. 155 00:18:44.060 --> 00:18:44.420 Yeah. 156 00:18:44.420 --> 00:18:45.870 That's how long it takes. You know, that's the one thing. 157 00:18:45.870 --> 00:18:46.100 Yeah, yeah. 158 00:18:46.100 --> 00:19:00.700 Or in the case of, you know, our Redis thing, it's like, well, I have, um I start the clock, I send a request to Redis, I get the request back, I stop the clock. You know, that's how long the request takes. That's pretty obvious. But yeah, if you need anything more fine grained than that, then usually some kind of instrumentation 159 00:19:00.700 --> 00:19:01.460 Mm-hmm. Mm-hmm. Mm-hmm. 160 00:19:01.460 --> 00:19:25.140 is what you want to put into your software. But to your point, somewhere along the line, that instrumentation itself takes time. And so you kind of put a Heisenberg effect of like, hey, i so I know exactly how long my program takes and it's really, really long because it's measuring time all the, you know, to a first approximation is all it's doing is getting the current time at any point in in the program. 161 00:19:25.140 --> 00:19:25.480 yeah 162 00:19:25.480 --> 00:19:35.960 And so there are lots of tricks you can do. I mean, there are um there are definitely... relatively low overhead timers that you can use. 163 00:19:35.960 --> 00:19:51.100 If you're, again, if you're in the weeds of microseconds, then it's useful in a C++ context to write yourself a little RAII style class, which is something which starts a clock in its constructor and stops the clock in its destructor. 164 00:19:51.100 --> 00:19:51.320 Mm-hmm. Mm-hmm. 165 00:19:51.320 --> 00:20:16.400 And then it squirrels away the number somewhere so that you know how long something took. And maybe you can accumulate over time all of the calls that fall into this scope. And those timers can be measured using the CPU's own timestamp clock, which is a relatively low overhead measured in CPU cycles number that you can then later on turn back into a clock number. 166 00:20:16.400 --> 00:20:45.620 I mean, it's also nowadays, actually, the Linux kernel, if we're talking about Linux, is pretty fast at getting at the actual real time. But... But the TSC is a pretty decent, fast way of getting time. ah So that lets you accumulate blocks, and then you can at least sort of look for hotspots in that way. But then there are many tools that you can get that will give you more information, or you can write your own tools that sort of hierarchically arrange these. So you can end up with like flame graphs, which are these time divided blocks 167 00:20:45.620 --> 00:20:54.770 It's almost like stalagmites or stalactite-looking things, like you know flames, I suppose. That's what they look like, rather than if you use the red colors. And so you see hierarchically where time is being spent. 168 00:20:54.770 --> 00:20:54.800 Mm-hmm. Mm-hmm. 169 00:20:54.800 --> 00:21:08.020 and that's a useful thing to um to have. So you can say, hey, I spend all my time doing this thing, but um really in this function, it's because these three functions it calls are the things that take time, and you get that kind of view out of ah out of it. 170 00:21:08.020 --> 00:21:23.880 But there is a little bit of overhead there because you're measuring and on the entrance and exit from those those functions, and maybe you having to write that down somewhere in like a log file or in shared memory or something like that. So those are all valid ways of, of measuring, but they have different amounts of overhead. 171 00:21:23.880 --> 00:21:33.700 um There is, yeah, cool I was gonna say this one other sort of trick, which is that modern CPUs have some amount of accounting that you can do within the CPU itself. 172 00:21:33.700 --> 00:21:34.720 so look um Go ahead. 173 00:21:34.720 --> 00:21:55.420 And there are sort of two ways of viewing that. So a traditional profiler, which is, um, and by tradition, I mean like every profile I'd used until fairly, you know, until sometime at previous company, um every profile use is a trick where you, 174 00:21:55.420 --> 00:22:06.420 set a timer, like in the a CPU timer. And then after every, you know ah you know, a thousand times a second, you just say, where the hell is the CPU right now? 175 00:22:06.420 --> 00:22:07.790 What program counter do I have? 176 00:22:07.790 --> 00:22:07.840 Mm-hmm. Mm-hmm. 177 00:22:07.840 --> 00:22:38.320 And then you do a little bit of work to find out what the stack is. And then that gives you a sample that says, Hey, you spent this much time in here. And then you can sort of infer if you can run your task long enough. then you get this great answer of like, well, you spend 30% of your time in malloc and 30% time in free. And you're like, well, maybe I need to think about my memory allocation strategy. that's ah That's a great thing. and that's That's fantastic for throughput-based things where you have a continuous workload that you care about it all the time. You just want the whole thing to be faster So you can put that on. It's relatively low overhead. 178 00:22:38.320 --> 00:22:51.880 You know, a thousand times a second sounds amazing and, she's you know, like really, really often. But to a computer, that's like eternities between sample points. And so if you can run it long enough, you get great results. If you're worried about latency, though, 179 00:22:51.880 --> 00:23:01.030 that's not much use. You typically find that you're spending 99.99% of your time in the "wait for something to do" routine. 180 00:23:01.030 --> 00:23:01.480 Right, right. 181 00:23:01.480 --> 00:23:13.760 And then the samples never actually land in a in the code that you care about. So in the, yeah in the In the Redis case, for example, you would find that you've got to optimize your epoll routine. 182 00:23:13.760 --> 00:23:24.300 You're like, no, I haven't. The epoll is just waiting for a packet to arrive, and I only care about it when the packet comes in And it's like, well, that thousand a thousand times a second timer and never went off while you were actually doing anything useful. 183 00:23:24.300 --> 00:23:25.760 Right. Yeah, yeah, yeah. Yeah. 184 00:23:25.760 --> 00:23:30.990 um And that's where like the instrumentation I was just talking about coming to, because there you get to put the instrumentation where you care about it. 185 00:23:30.990 --> 00:23:31.260 yeah 186 00:23:31.260 --> 00:23:48.160 But modern CPUs have the ability to do, ah like, essentially record Oh, that's great. So we've got a car alarm going off somewhere in the background. I don't you can hear it. or I can, and I've got my noise-canceling headphones on. all right, well, sorry. Sorry, editor Matt, you've now got something to worry about. [Editor Matt says, seems fine to me!] 187 00:23:48.160 --> 00:24:41.520 um But yeah, so the modern CPUs, Intel ones, can do like a trace of execution. And so they can essentially... instrument themselves and every time a call happens or a return happens or a branch a conditional branch is either taken or not taken some amount of tiny information is recorded into a buffer and then you can ask it to write out that buffer and then you can post process that and sort of infer what happened and there are tooling so uh linux has perf that can record this information And then there's things like um MagicTrace, which is like ah a set of user scripts over the top of it and a nice website that lets you view it in like a timeline diagram. And that's an eye opener, honestly. At that point, you've kind of got the whole world open to you and every single nanosecond is accounted for you. And that's really quite something. 188 00:24:41.520 --> 00:24:48.060 So I forgot what you asked now. Again, you've just you see, this is what you just keep winding me up and watching me go. 189 00:24:48.060 --> 00:24:48.620 No, no, this is 190 00:24:48.620 --> 00:25:07.280 this is great. I mean, you yeah you answered my question exactly. so So let's say that you do all these things and you find the part of your code that you're now fairly convinced is the reason that it's slow, right? um And at the risk of having you just recount the compiler explorer origin story, now what? 191 00:25:07.280 --> 00:25:15.510 Well, so that's funny you should say that. Yeah, the Compiler Explorer origin story is almost a somewhat orthogonal, actually, you know in some ways. 192 00:25:15.510 --> 00:25:15.520 Okay. 193 00:25:15.520 --> 00:25:16.640 That was, yeah, a little bit, but... 194 00:25:16.640 --> 00:25:19.760 It's not, what are what is, what instructions is this code generating? 195 00:25:19.760 --> 00:25:32.460 and Well, it was, but it was that was more like arguing over whether the compiler was smart enough to make human readable code as good as like the awkward code that you used to write because compilers weren't smart enough, right? 196 00:25:32.460 --> 00:25:32.580 Right. 197 00:25:32.580 --> 00:25:37.470 and that's So we've i mean we're very much in the micro-optimizations when we're talking about code generation. 198 00:25:37.470 --> 00:25:38.040 Right, right. 199 00:25:38.040 --> 00:25:40.200 And honestly, that's the fun bit for me. 200 00:25:40.200 --> 00:25:40.200 Mm-hmm. 201 00:25:40.200 --> 00:25:44.680 But very often, it's like, the again, the things I can't remember. 202 00:25:44.680 --> 00:25:44.680 Yeah, it's just, you're just doing something dumb, right? Like it's not some, yeah. 203 00:25:44.680 --> 00:25:52.930 Don't be stupid on purpose is like the very first thing you should say. is like you know i'm ah 204 00:25:52.930 --> 00:25:53.480 Yeah. 205 00:25:53.480 --> 00:26:05.790 Like, am I looking this up in a map over and over and over again when I could just look it up once and remember it, right? Now, compilers are smart, but they're not necessarily smart enough to stop you from calling a whole function chain that is the look up something in the map. 206 00:26:05.790 --> 00:26:05.820 Mm-hmm. 207 00:26:05.820 --> 00:26:14.090 it's It may not, you know, the compiler hasn't got perfect knowledge. It can't tell that like no one has changed that map since the last time you looked in it. 208 00:26:14.090 --> 00:26:14.760 Mm-hmm. 209 00:26:14.760 --> 00:26:43.720 And so this is the kind of thing you see. But again, these are relatively small wins sometimes. um Algorithms are important, obviously. you know If you're doing something dumb, if you're searching through a massive array of things when you could use an acceleration structure, be it a hash map or something else, then that's important. But then at this granularity that we're sort of talking about, sometimes it is actually faster to go through a big array than it is to... 210 00:26:43.720 --> 00:26:48.590 ah like jump randomly around in memory that would be like hash map potentially. 211 00:26:48.590 --> 00:26:49.460 I really 212 00:26:49.460 --> 00:26:54.140 There's almost no case in which a linked list is the right answer. 213 00:26:54.140 --> 00:26:55.660 it's yeah 214 00:26:55.660 --> 00:27:01.140 I have one special case of where I think a linked list is the right answer. 215 00:27:01.140 --> 00:27:06.160 i really want to hear this. what When should one use linked list? 216 00:27:06.160 --> 00:27:21.810 So one should use a linked list when you need to keep an ordered list of things, not necessarily ordered as in like they, let's say insertion ordered list of things. 217 00:27:21.810 --> 00:27:22.000 Mm-hmm. 218 00:27:22.000 --> 00:27:29.410 So I've got an ah a sequence of objects and I can only ever add them to the back of that list, right? 219 00:27:29.410 --> 00:27:29.660 Mm-hmm. 220 00:27:29.660 --> 00:27:42.550 But I can arbitrarily remove them out from the middle of the list. And those, I'm given a unique identifier for that object by some external source that I have no control over. 221 00:27:42.550 --> 00:27:43.160 Mm-hmm. 222 00:27:43.160 --> 00:27:59.360 And it's associated forever with one of those objects. And I need to keep them in that sequence, right? But at any point, I could get a message saying, oh, number 79234 is gone. And I need to be able to find it and remove it from that ordered sequence. But I need to keep the sequence. 223 00:27:59.360 --> 00:28:09.800 So you've kind of, in the traditional sense, you might have a hash map to find that object. 224 00:28:09.800 --> 00:28:15.760 which is great. But if it's in the middle of a vector, like an array of memory, that that would be cool. 225 00:28:15.760 --> 00:28:16.200 Yeah. 226 00:28:16.200 --> 00:28:26.240 You deleting it is not only really painful because you have to shuffle everyone beyond it down one, but you now have to go into the map of where everyone else is. 227 00:28:26.240 --> 00:28:29.810 And kind of update them to be in the new location that they're in 228 00:28:29.810 --> 00:28:31.280 Mm-hmm. Mm-hmm. Yeah. 229 00:28:31.280 --> 00:28:33.150 So that's a pain. 230 00:28:33.150 --> 00:28:34.260 Yeah. 231 00:28:34.260 --> 00:28:47.920 Having a doubly linked list is disgusting, but... But given a pointer to just that object itself, all you have to do is like look at its next and prev and wire them up together and you're done. 232 00:28:47.920 --> 00:28:48.660 Yeah. And connect them together. Yeah. yeah 233 00:28:48.660 --> 00:29:00.920 And you're done. And so that's one of those examples where the worst case is for a single operation. 234 00:29:00.920 --> 00:29:08.020 So like if i if I say, ah so, I mean, I mean I'm alluding to this, this is me thinking about an order book. So in in our world of finance, the exchange 235 00:29:08.020 --> 00:29:11.650 Man, I was just going to say this sounds like the priority queue for an order. 236 00:29:11.650 --> 00:29:11.860 It's a price level. 237 00:29:11.860 --> 00:29:12.200 Yeah. Uh huh. 238 00:29:12.200 --> 00:29:15.340 It's a price level for, ah yeah, exactly. So so you're you're told about these things and that happens. 239 00:29:15.340 --> 00:29:15.340 Yep. 240 00:29:15.340 --> 00:29:25.370 So you could imagine you've got um thousands and thousands of orders on a single level, and it's important to keep them in that sequence so you know their relative priority. 241 00:29:25.370 --> 00:29:26.860 Mhm. Mhm. 242 00:29:26.860 --> 00:29:36.680 Whenever anyone trades, it's always the order at the front that trades away, which is kind of the worst case for if you did keep them in a vector, right? 243 00:29:36.680 --> 00:29:36.820 Mhm. 244 00:29:36.820 --> 00:29:36.960 Yeah. 245 00:29:36.960 --> 00:29:42.080 But you could always store them backwards. And then that's a good case, right? 246 00:29:42.080 --> 00:29:42.280 Yeah, yeah. 247 00:29:42.280 --> 00:29:43.970 Maybe that works, you know, that's sort of a weird. 248 00:29:43.970 --> 00:29:45.520 Treat a little more like a stack basically in weird way. 249 00:29:45.520 --> 00:29:47.920 And then you're kind of like the ones at the back. 250 00:29:47.920 --> 00:29:54.410 Yeah, exactly. Which is not, and and there also, there are things like ah deques, double-ended queues that have like this sort of capability of being like multiple slabs, 251 00:29:54.410 --> 00:29:54.860 Yeah, yeah. 252 00:29:54.860 --> 00:29:55.080 Yeah. 253 00:29:55.080 --> 00:29:55.300 Yeah. 254 00:29:55.300 --> 00:30:06.000 which you can chain a linked list effectively of slabs. You could chain a new link slab at the beginning or unchain it moreover. So those are all great and cool and everything. 255 00:30:06.000 --> 00:30:06.830 Mm-hmm. 256 00:30:06.830 --> 00:30:23.180 um And it's very, you know, much more cache efficient to have them laid out that way. But it does mean that the worst case is worse, right? You know, like whatever it is, it'd be at the front order or the back order, depending on which one you've optimized for, 257 00:30:23.180 --> 00:30:30.680 If you have to remove that one, then suddenly you're shuffling however many thousand other orders around potentially. So that's bad. 258 00:30:30.680 --> 00:30:31.340 yeah 259 00:30:31.340 --> 00:30:40.520 It's probably the case that the linked list based version is always worse, but it's consistently no... there isn't a bad case, right? 260 00:30:40.520 --> 00:30:44.560 Right, right. You get the same amount of worseness every time. 261 00:30:44.560 --> 00:30:45.180 And so that's an interesting trade-off. 262 00:30:45.180 --> 00:30:45.600 Yeah. 263 00:30:45.600 --> 00:30:56.660 it's ah It's an interesting choice. And you know I've seen a number of book implementations in my time. And there's just different tradeoffs. It's a really interesting data structure to try and optimize and ask the question, why would you do it this way? 264 00:30:56.660 --> 00:31:02.740 you know I've just started working in a new company and I've seen another way that it can be done, which I can't talk about, but is fascinating. 265 00:31:02.740 --> 00:31:02.840 Mm-hmm. 266 00:31:02.840 --> 00:31:03.040 All right. 267 00:31:03.040 --> 00:31:05.850 And I'm really, really excited by, but you know that's how it is. 268 00:31:05.850 --> 00:31:06.600 right Yeah. 269 00:31:06.600 --> 00:31:15.360 um So you know that's an interesting one. So anyway, the algorithm... the algorithm can be important. ah you know That's what I think what we got onto this. 270 00:31:15.360 --> 00:31:16.640 Mm-hmm. 271 00:31:16.640 --> 00:31:25.020 ah And then you know caching, not doing work you don't have to do. So I think, yeah, we've said that the questions you ask yourself are something like, do I actually need to do this at all for each thing? 272 00:31:25.020 --> 00:31:25.140 Mm-hmm. 273 00:31:25.140 --> 00:31:35.860 And oftentimes you're like you discover, actually, why are we logging this out? Let's just take just take the log line out right or put it behind a guard so it doesn't happen in production. It only turns on when we want that log or whatever. 274 00:31:35.860 --> 00:31:46.030 so It's an expensive piece of work. you know The classic example here is that you format a bunch of strings and then you pass them to debug log, which is not on in production, but you've already done all the work of formatting all the strings. 275 00:31:46.030 --> 00:31:46.180 Yeah, yeah, yeah. 276 00:31:46.180 --> 00:31:48.060 And you're like, well, hang on a second. 277 00:31:48.060 --> 00:31:49.220 Right, right. 278 00:31:49.220 --> 00:31:59.840 I don't need to do these. um Another thing is, do I need to do this now? So can I cache this ahead of time? 279 00:31:59.840 --> 00:32:12.540 Is it just ah you know something I could do at program startup? Can I make a reasonable guess as to the values that will happen in this particular thing? In which case, maybe I take some time at the startup and I pre-populate a lookup table with all the possible values. 280 00:32:12.540 --> 00:32:12.620 Yeah. 281 00:32:12.620 --> 00:32:25.320 And then I say, okay, well, it's just a lookup now at runtime. ah there are other tricks in that world where you can say, well, do I need a perfect answer to this now? Or can I defer updating something until later? 282 00:32:25.320 --> 00:32:40.880 Or can I have another thread post me back occasionally saying, hey, you know, this is the amount of whatever's that are available, you know can you be conservative and get away without on your hot path doing the really complicated stuff and then push other stuff to other threads. 283 00:32:40.880 --> 00:32:46.780 um yeah, I'm just, I'm trying to think of the, the sort of obvious things here and, you know, 284 00:32:46.780 --> 00:33:13.100 So how often i feel like there's this almost myth of, and I have to wonder if anyone has ever come up to you with questions like this, the myth of the expert programmer that has like the function that is taking all the time. And they're like, I'm going to rewrite this in assembly code and it will be super fast because I have written it in assembly code. 285 00:33:13.100 --> 00:33:18.720 Like; does that actually happen? And when and why would that actually happen? 286 00:33:18.720 --> 00:33:56.440 So yes, yes, but it's, it's a, it's something you have to do very advisedly. um I'm trying to think about how I can say this without breaking any confidences, but I'm aware of certain critical core loops in certain circumstances where compilers just aren't good at intuiting which variables are the important variables and no amount of tagging them can convince them otherwise. And so they forever spill onto or off of the stack for those things. 287 00:33:56.440 --> 00:34:09.340 and In one specific case, rewriting the core loop of something, you know, and by core loop, I mean, it's a chunky piece of code, know, page of assembly, at least. 288 00:34:09.340 --> 00:34:10.420 Mm-hmm. Mm-hmm. 289 00:34:10.420 --> 00:34:38.080 um Rewriting that was, writing that in assembly was a definite, definite win in terms of not spending half the time pushing and popping or reading and writing to memory, which has its own issues to do with aliasing and stuff. We've grazed at before in in some of the conversations we've had about the clever tricks that registry naming that can happen if you use registers. But as soon as you put into memory, a whole new system has to come in and it's a lot more complicated and slow. Anyway, so, so yes. 290 00:34:38.080 --> 00:34:50.520 And there are also some other examples where if there are specific instructions and sequences of instructions that do specific things that you need to do, then sometimes cracking out the assembly is worth it. 291 00:34:50.520 --> 00:35:04.940 Although less often now that most of the instructions are available as intrinsics that you can call or library functions that have the same meaning behind the scenes and have basically been invented to wrap the underlying hardware's capabilities. 292 00:35:04.940 --> 00:35:29.830 And then you can phrase things in maybe a slightly tortured way where you know you have to call underscore, underscore some weird thing to get some function and assign it to some weird type and then write your your instructions, not instructions, write your code out longhand where it's like __add bracket, __sub X comma Y, close brackets comma Z, that stuff rather than the more. 293 00:35:29.830 --> 00:35:30.480 Mm-hmm. Mm-hmm. 294 00:35:30.480 --> 00:35:52.660 But you know you can get it to generate the right code. So both... But at that point, you're really just using the C compiler to write the assembly code that you would like it to write. And that's still better than writing the assembly. So to answer your question, yes, but it really, really has to be worth it because you more than anything else, you're trading off the ability to change and understand your code down the line. 295 00:35:52.660 --> 00:36:10.530 It's so fragile. It is so very, very fragile once you've written it in assembly. And you have to be so sure it's right. So testing is important and you know keeping a C version of it around that you occasionally race with a new compiler against your other input optimization you know version and making sure they... 296 00:36:10.530 --> 00:36:10.780 Yeah. 297 00:36:10.780 --> 00:36:18.260 I was going to say, I feel like one of the things you give up by doing this is the ability to just upgrade your compiler and then all of a sudden it's faster, right? 298 00:36:18.260 --> 00:36:47.050 Right, exactly. So that's I think the times that I've known that has worked, and this is not anything I've done for what it's worth. I haven't written the substantial amount of assembly code since the nineties. um But you know where where it has been known to work is where folks have taken the time to carefully write some assembly for something that's really, really important and then keep a C version of it next to it and then have like continual races against the C code versus the assembly code on upgrades and also correctness checks against the two. 299 00:36:47.050 --> 00:36:47.120 Yeah. 300 00:36:47.120 --> 00:36:47.840 you know this is We run inputs... 301 00:36:47.840 --> 00:36:48.440 Yeah. Right. 302 00:36:48.440 --> 00:37:17.740 we run inputs on the C code and then we compare it against the output from the, the, the assembly code, that kind of stuff. But yeah, it's, it's tough, man. And I mean, another example of like, when you have to write assemblies, like if you're interacting with kernel magical stuff, you know, like that, but which, which for some of the more esoteric um profiling things, you might have to do an instruction here and there to get, but, but yeah, usually no, usually um the flex in my experience, 303 00:37:17.740 --> 00:37:18.020 Sure. 304 00:37:18.020 --> 00:37:18.300 Mm-hmm. 305 00:37:18.300 --> 00:37:55.200 the flexibility you get of leaving it in C or C++ and having the ability to quickly manipulate, move things around, change around, play with compiler flags and let essentially 40 years of other people's experiences that have been poured into the heuristics of a compiler at my code, they're usually better than most things I can come up with. And you know the times that I found I can substantially beat the compiler with assembly have been times where I have been unable to explain correctly to the compiler the unwritten constraints that I'm aware of that it is not. 306 00:37:55.200 --> 00:38:08.360 or vice versa. It is being more conservative. you know It doesn't know that writing through pointer X and then reading through pointer Y, those two things will never be the same address, but I do. And so if I write the code that way, of course I won't. 307 00:38:08.360 --> 00:38:16.840 I'll read one into a register and and keep it in the register the whole time. Whereas the compiler's like, well, every time you write to Y, I have to reread X again because for all I know, Y points at X, that kind of thing. 308 00:38:16.840 --> 00:38:17.580 Yeah. 309 00:38:17.580 --> 00:38:24.900 Gosh, that's a lot of things to talk about abstractly 40 minutes into a podcast. 310 00:38:24.900 --> 00:38:44.220 Well, i so I got i got one, i don't know if this is, I'm just gonna ask this question. So talking about perf and using using perf, a tool that I have also used for just answering generally the question of what is my code doing for lots of reasons, performance optimization being one is strace. 311 00:38:44.220 --> 00:38:45.140 go ahead. 312 00:38:45.140 --> 00:38:59.050 ah Like what system calls am I making? What are the arguments to those system calls? When are you using one versus the other? When are you using perf? When are you using strace? What problems are you trying to solve when you use those tools? 313 00:38:59.050 --> 00:39:09.860 Yeah, that's a really good point, actually. ah strace is like the go-to, isn't it? For like, if something's taking a long time, that I don't have the source code to, I'm going to strace that thing and see what the hell it's doing. 314 00:39:09.860 --> 00:39:09.890 Right. Yeah. 315 00:39:09.890 --> 00:39:09.960 And it's like... 316 00:39:09.960 --> 00:39:13.430 Going back to the, it's doing the DNS lookup or it's doing the weird file system call. 317 00:39:13.430 --> 00:39:13.460 Exactly. 318 00:39:13.460 --> 00:39:14.760 Right. Yeah. 319 00:39:14.760 --> 00:39:26.150 Exactly. And so if we're talking about very high performance things like we have been, then if you're doing it right, strace will show you nothing because you shouldn't be interacting with the operating system. 320 00:39:26.150 --> 00:39:26.980 Right. 321 00:39:26.980 --> 00:39:32.610 ah You know, if you're the instant you're calling fwrite to write to a file, you've already lost, right? 322 00:39:32.610 --> 00:39:32.800 Mm-hmm. 323 00:39:32.800 --> 00:39:34.810 That's not a high performance piece of code, right? 324 00:39:34.810 --> 00:39:35.080 Mm-hmm. 325 00:39:35.080 --> 00:39:55.720 And that's perfectly valid. I mean, obviously, there are loads of bits of... high throughput code that are going to call fwrite. And then you know you do want to look at a strace. So maybe that's your answer. If you're looking for latency, you won't see anything. But for throughput, it might be a really good indicator of like, am I spending a lot of time waiting for the file write to finish happening? 326 00:39:55.720 --> 00:40:14.340 ah So strace is very valuable for that kind of thing. and There are other tools as well. So there's various eBPF-based stuff that I haven't had much personal experience with. but So my knowledge goes back to System Tap, which is like another similar thing where you can hook into more parts than just system calls. You can say like, hey, tell... 327 00:40:14.340 --> 00:40:32.340 call this function effectively in like a funny little scripting language every time there's a page fault. And then I can aggregate page faults and they can be I can see what the heck's happening there and give me the stack. And then I can work out, hey, wait a second, we've just allocated a massive slab of memory and then we get all these page faults. What's going on? And you realize, oh, of course, 328 00:40:32.340 --> 00:40:38.940 Although I think I've allocated a big slab of memory, the operating system has just given me a big gaping empty hole of virtual address space. 329 00:40:38.940 --> 00:40:39.200 Mm-hmm. 330 00:40:39.200 --> 00:40:45.090 And then every time I read or write to it, it decides to now fault in the 4K page. And that takes a bit of time. 331 00:40:45.090 --> 00:40:45.400 Yeah. 332 00:40:45.400 --> 00:40:52.870 I'm like, no, no, no, no! I don't want to do this. It's a low latency thing. look At the program startup, I'd like you to do all of that, please. And then I don't have to pay for it later on. 333 00:40:52.870 --> 00:40:53.400 Yeah. 334 00:40:53.400 --> 00:41:05.820 those kinds of things. And those kinds of stuff you can, you can find from like a SystemTap or dtrace in other operating systems, or again, there's some something, something eBPF. So, so yeah, there are other tools available for sure. 335 00:41:05.820 --> 00:41:16.640 And I know that things like a SystemTap and eBPF based things can also um patch function calls, both in the kernel. And I think in your user code as well, you can put trace points. 336 00:41:16.640 --> 00:41:21.710 And so you can kind of add some dynamic things where you can say every time this function is called, I want to, I want to know about it. 337 00:41:21.710 --> 00:41:21.860 Nice. 338 00:41:21.860 --> 00:41:34.580 I mean, like, Funny, funny, ah true story. Like it's not the worst profiler in the world for throughput based things to just run it in GDB and hit control C and say backtrace, where are you now? Okay, continue. 339 00:41:34.580 --> 00:41:35.070 You're sampling. 340 00:41:35.070 --> 00:41:35.240 Control C. 341 00:41:35.240 --> 00:41:37.240 You're just acting as a sampler, right? 342 00:41:37.240 --> 00:41:38.760 Yeah. Exactly. it's But it's a great... 343 00:41:38.760 --> 00:41:39.140 Sometimes it works. 344 00:41:39.140 --> 00:41:55.930 Exactly. and And another... While we're just thinking about these things, another performance investigation technique is to just single step through your code. And if *you* get bored of stepping through stuff, then your CPU is taking too long. 345 00:41:55.930 --> 00:41:57.250 Sympathetic profiling. 346 00:41:57.250 --> 00:41:57.680 That's right. 347 00:41:57.680 --> 00:42:02.500 how How do I feel when this code runs? Do I feel fast? 348 00:42:02.500 --> 00:42:03.220 Does it feel good? 349 00:42:03.220 --> 00:42:03.480 Nah, it's just, yeah. 350 00:42:03.480 --> 00:42:24.600 I mean... But no, I mean, i joking aside... Like, especially with the levels layers and layers of indirection that things like ah C++ can give you. And if it hasn't inlined at everything and the compiler hasn't had heuristically determined that it's valuable to keep inlining until it nets out and says, oh well, actually, this is just, you know, return to. 351 00:42:24.600 --> 00:42:47.780 and Then sometimes you'll find yourself stepping into functions that step into functions that step into functions. You're like, what? where How far down is this going? And then eventually get to the return to and you're like, okay, i need to I need to do something about this, right? that This is not... This is not right. i know yeah And again, I say this and people are but in order to debug it, surely you had to do a debug build and debug builds have no... you know aren't fast. 352 00:42:47.780 --> 00:42:58.730 It's like, no, we have to separate the idea of optimization, you know the -O1 -O2 -O3 of like a C++ build from leaving the debug symbols around. 353 00:42:58.730 --> 00:42:59.140 Yeah, 354 00:42:59.140 --> 00:43:15.080 And knowing that you can still have a completely optimized binary that has at least somewhat useful debug information so that you although inlining has happened and code has been moved all over the shop. And so if you actually single step through it, you'll see your poor cursor inside your source code jumping all over the place. 355 00:43:15.080 --> 00:43:15.160 yeah yeah 356 00:43:15.160 --> 00:43:31.940 But it still gives you some idea about what happened and where time is being spent and what things are going on. Yeah, so, you know, for me, I all always have debug symbols around because it's like, why wouldn't I? Now, obviously, if we were shipping to external customers, that maybe we wouldn't send. 357 00:43:31.940 --> 00:43:39.440 Yeah, you're leaking that information or maybe your binaries are just a little bigger that way. And if you're sensitive about the space, but otherwise, why would you not? 358 00:43:39.440 --> 00:43:42.560 Yeah, and it does slow down some parts of the build. You know, it can slow down the build in into cases because it's a lot of debug stuff to go. 359 00:43:42.560 --> 00:43:42.560 Yeah. Yeah. Okay. 360 00:43:42.560 --> 00:43:44.940 on But there are clever linkers that can do tricks and things. 361 00:43:44.940 --> 00:43:45.610 Yeah. 362 00:43:45.610 --> 00:43:46.300 And yeah, so. 363 00:43:46.300 --> 00:43:46.760 Yeah. Okay. 364 00:43:46.760 --> 00:43:49.820 But yeah, that's why strace. What was the question again? 365 00:43:49.820 --> 00:43:56.750 No, I love that point of like, if you're in latency sensitive code and and strace gives you anything, well, there's your problem, right? 366 00:43:56.750 --> 00:43:57.080 Yeah. 367 00:43:57.080 --> 00:43:58.280 Like, like that's great. 368 00:43:58.280 --> 00:44:03.380 Yeah. Now, although of course, you know, with multiple threads, you have to be a bit careful because, you know, other threads could be doing system calls and that's, that's fine. 369 00:44:03.380 --> 00:44:03.940 Right. Right. 370 00:44:03.940 --> 00:44:05.070 We didn't really talk about threads as well. 371 00:44:05.070 --> 00:44:05.140 Yeah. Yeah. 372 00:44:05.140 --> 00:44:22.600 You know, there are all sorts of horrible thread sharing related issues that can come from that, you know, and the fact that waiting on a mutex or not waiting on a mutex is sometimes an operating system level thing and sometimes is a futex and sometimes it's sort of slightly outside of the kernel so that things can be, you know, so 373 00:44:22.600 --> 00:44:23.440 Mm hmm. 374 00:44:23.440 --> 00:44:28.780 It's complicated, man. I think that's the short version. There's a lot. It's a deep topic. 375 00:44:28.780 --> 00:44:31.980 Well, um we've gone 45 minutes on this so far. 376 00:44:31.980 --> 00:44:35.160 Yeah, I think there's a part three, isn't there? 377 00:44:35.160 --> 00:44:35.240 Maybe we do part three. i don't know. 378 00:44:35.240 --> 00:44:35.240 Maybe. 379 00:44:35.240 --> 00:44:39.400 i'm not going to commit to that yet, but that that could possibly be a thing in the future. 380 00:44:39.400 --> 00:44:43.980 Yeah, we could we could certainly consider that. well We'll see how this goes out. 381 00:44:43.980 --> 00:44:44.440 Yeah. 382 00:44:44.440 --> 00:44:44.900 Yeah. 383 00:44:44.900 --> 00:44:57.250 Well, we better stop because, yeah, I've got to edit this. And I'm lazy [Editor Matt certainly is...]. I don't want to have to do more than 45 minutes. Have you any idea how awful it is listening to yourself gabble and realizing all the mistakes you made while editing? 384 00:44:57.250 --> 00:45:00.660 Yeah. 385 00:45:00.660 --> 00:45:04.990 uh yeah you gotta listen in on repeat and trying to cut out this um that i said and it's just like the worst thing in the whole world 386 00:45:04.990 --> 00:45:05.220 you know There's only so much I can do in the edit to make myself sound intelligent. 387 00:45:05.220 --> 00:45:11.800 Yeah, I'm sure our listeners have noticed that recently I've stopped cutting most of the things out because life's too short. 388 00:45:11.800 --> 00:45:14.760 yeah nah it's better this way oh natural 389 00:45:14.760 --> 00:45:23.460 Yeah, this is Yeah, our listener is ah sat on the table next to us in a restaurant while we're having this kind of conversation anyway and just listening in. And that's fine by me. 390 00:45:23.460 --> 00:45:27.080 Yeah, that's the way to do it. All right, should we call it there? 391 00:45:27.080 --> 00:45:30.120 Let's call it there, my friend. So I will see you next time. 392 00:45:30.120 --> 00:45:33.120 Until next time.