Analyzing Results & Removing Async

[00:00:00]
>> So let's see, did we actually improve the performance? So our integration tests are now working. I'm a positive, a lot of you did not follow along with that code. I hope you followed along with the idea, which is to measure, identify, come up with a better solution.

[00:00:13]
Don't just try to fix that one function. If we would have just thought about how to make timer better, guarantee you we would not have come up with a, or take her better. We would not have come up with a solution. You really do wanna think larger and outside of the box and identify what is the issue.

[00:00:27]
And memory plus CPU is a great way to know where the issue was, all right? So we have that let's start this server up. And what I'm gonna do is do the exact same thing we have been doing, which is I'm gonna go second optimization 500. And I'm gonna drop the inspect, okay?

[00:00:42]
We don't even wanna see the inspect. We'll look at, we'll look at the performance here in a moment to see if we did it, but I just wanna see do what do we have here? So I'm gonna run this one, and I'm gonna now run cargo. Everyone's favorite language, Rust, with 500.

[00:00:58]
And so we're gonna let this thing run for a moment. It's at temp shout out 500. So let's see if we got anything going here. I'm gonna put this in and use our little identifying program to do this, that's first optimization. I was about to say that, looks like we've already done this before.

[00:01:15]
Second optimization, okay, hey, this is starting to look a lot better, and this isn't even compounded with our first optimization. This is just the second optimization. So let this one run for a while. Our ratio is already looking significantly better locally, or really the percentage. So let it run.

[00:01:38]
We're gonna try to get about a thousand games played. This is great. This is actually great. This is really what you wanna see because honestly, when you're doing performance work, and you see just like movement by 5% or 3%. I mean often I'm just like am I lying to myself?

[00:01:54]
Am I kidding myself? I don't know why this is better, but it doesn't feel like it's better because it doesn't It doesn't feel real yet. I wanna see something that jumps in a real intangible way, all right? So I'm just gonna kill that. Notice that we actually went down, okay?

[00:02:08]
All right, 18% of the time. Now, if you remember when we started off this, we originally started off at 31.6. Our first optimization only brought it down to 30.9. And we're not even sure if that's real. And so this one was a real one, I would say we have dramatically changed the landscape.

[00:02:25]
And I'm sure when we profile it, we'll see that it's dramatically changed. So again, we're gonna do the boring part. We're gonna go to 1000. We're gonna relaunch this thing. We're gonna do it again over here and relaunch that one. And we're gonna let it go for a little while longer.

[00:02:42]
We're gonna let this thing run, and then we'll do a little bit of a recap. And then the third optimization is a very fun one. It's very fun. It's very exciting. Very easy, very exciting. Much wow. And for those that are joining on frontendmasters.com or Twitch, yes, there is a live audience here.

[00:03:05]
Not very many, they're very quiet right now. My typing might've been too fast. Too furious, use Vim by the way. It's a good time. It's a good time. All right, so we're almost there. Look at this. I mean, the ratio somehow is even better at this point than it was when we did 500.

[00:03:25]
So what's that all about? Nobody knows, maybe we just didn't let the 500 one run long enough. It's going down in value, but look at that. This is really good right? I'm happy about this. Did I know this was gonna happen? Maybe. Maybe I did know it was gonna happen, all right?

[00:03:40]
Let's do one more. I know this is the boring part, but I just really wanna make sure we have a good history of what happened because it's just so important to have that history of what happened. You don't wanna lose this because you've got to see it. Putting things in temp, by the way, it's a really great way to lose it on accident when you restart your system and all of your data goes away.

[00:04:02]
So, I don't recommend storing things in temp, but sometimes it's nice.
>> Can I just say you're going so fast and furious that you could call yourself Vin Diesel?
>> I could call myself Vin Diesel, but I'd be infringing on Luke Smith, so I will not infringe upon him, but Is that a thing that already exists?

[00:04:20]
>> Yea, someone already has Vin Diesel. That was a good, I'm gonna give you many points for knowing this, okay? I'm gonna give you many points for at least coming up with it, all right? So we're about done. Look at this, okay? So we'll do a quick recap.

[00:04:35]
So that way anyone that's just joining us now can get a good recap, and we can kind of see what's happening, okay? So we started off the day with absolutely no optimizations when we ran 500 concurrent games at the exact same time. 31% of the time we were dropping frames.

[00:04:53]
When I say dropping frames, it's not quite accurate for the term drop. It's less than that, dropping frame usually involves when you exceed a V-sync or go beyond 16 milliseconds. But this one, anything that's above 17 milliseconds and below 15 is considered a drop in my case. And so we're at 31% of the time, we were dropping frames at 500.

[00:05:13]
At 1000, we were at 36 on my computer, and at 2000 games running, we were at 62% of the time We were just doing horrible. We made our first optimization. We barely changed the needle at 500. Sort of changed the needle at a thousand, maybe, maybe not. And at 2000, it does look like we did something.

[00:05:30]
We're down to 43%. The second optimization, just based off of the original game. We went from 31% to 18. What, 36% to 16? So you can see there's some variability when you're measuring, right? So you just got to be aware of that. And even at 2000, we went from 60 some to just 30 some.

[00:05:48]
So like there's something real going on here. I think we've made some good changes. And so let's look at what's happening, but with the inspect flag, don't forget to change your log path. I should just go. Always go testing for this and let's go. Let's just go. Instead of 1000 games, we're gonna go to 2000 games.

[00:06:05]
I feel like our server can handle this, should be pretty easy. And so if we look at our previous one, we had a bunch of time in garbage, 14.6% of the time in garbage, 9.2% of the time in Register Hook. We had a bunch of time destroy list on timeout, emit hook before promise hook, and, no, just a lot of these like little functions that are all taking up about a percent of time.

[00:06:27]
So let's record for 10 seconds. I'm gonna stop that. And before we look at the results, I'm just gonna jump over here and start a memory record just, so we can see that and see what it does. All right, so let's go back here. Idle is still at the top.

[00:06:51]
Update, we didn't merge over the changes. It's now taking up a larger portion of our program. Before it was like in the 14 to 15%, now it's taken up 24%. But I want you to notice something really big here. Garbage, 7%, it went from a big portion, and it went down a bunch.

[00:07:10]
Register hook destroy. We still are getting promises here. So that's a little strange. I thought we took out all of our promises. I thought we did the right thing. We still see a little bit more promise in knitting here. I'm starting to see some web sockets, right? Or buffer, okay?

[00:07:24]
So we're starting to see some new things starting to make some plays for the top, all right? So this is good to know, but we still have promises. So, what the heck's that? So let's look at our memory and let's see if that's actually true. Does our memory bear out that we still have promises?

[00:07:37]
If I look in here, I may have not let it run long enough. I don't think I let it run long enough. Come on.
>> Come on.
>> Okay, so there is actually one other place we do have promises. And I wanted to save this because this is just so incredibly disappointing.

[00:07:54]
If we go into my data writer, I just accidentally left some syncs on these functions. We had garbage collection running at 7% of the time. We had that other, that emit, what's it called, registered destroy hooks, 5%, 4.5% of the time it was running. A net, 3.2% of the time it was running.

[00:08:16]
And I literally just accidentally left some asyncs on there. And they're not even async, they don't even do anything. So if I just simply erase this and erase this, save, it's no longer async, nor did we ever use it to be async, and just simply rerun these results.

[00:08:33]
Again, emotional trauma is going on right now. I'll let it run for first second. I know, again, how crazy is that? Because we call out a couple of things to our data writer so we can aggregate a bunch of data. What the data writer does is it takes in a bunch of the data instead of just writing it all out to disk, it aggregates a bunch.

[00:08:52]
And then after some amount of time, it'll just write out one small piece of data that is the aggregated version instead of every single little event. And so when I read profile this. Let it run, let it run. Notice that that all went away. And also notice garbage collection.

[00:09:16]
It went from 7% to 2%. You know how many times you put something on your server for convenience to be a promise always, and a lot of time you're reading it synchronously. It can literally have an effect on your program. How wild is that? It's like we didn't even wonder, we're not even smart programming at this point.

[00:09:34]
We just removed the word async and 4% went away another 5% went away, another 3% went away, it's rather wild what that is. And so let's jump back down here, and I'm gonna go like this. I'm gonna call the second optimization 2000, and I'm gonna call it -2, right?

[00:09:52]
And let's just do one measurement out at the 2000 to see what happens, see if we can even see a difference out here. We'll do 2000 run on our little system, and we'll go check, and we'll actually see do we actually see anything, right? Because you know, maybe we actually don't see anything, maybe that it's not practically seeable, right?

[00:10:11]
And so we're gonna let this thing run for a little bit. I don't know if promises can be replaced with generators and yields. I don't know if there's a big difference there. I have no idea. So I've never tried playing around with generators. They're neat. You get to add an asterisk to your function.

[00:10:37]
They're really cool for file tree walks. I just have never done one. So I honestly just simply have no idea.
>> Someone commented a stinky,
>> A stinky, it is a stinky, all right? So it looks like it might make a difference, probably not. But at the end of that it's pretty much the same value factor, even looks like a little bit more.

[00:10:57]
So in our time, it looks like this change was what I would refer to as a non-impactful change. But we are reducing the pressure on the garbage collection meaning that if another part of our programs say we added in some more analytics started producing more garbage, we now have room.

[00:11:12]
We can now make changes to our program that we have a room to make. And so this is a little bit of headroom. Very good thing to always have ready, and not to just simply let go so easily. So there we go. Yeah. So effectively-ish, the same, okay?

[00:11:29]
So we didn't really make an impact here on our program with that last change, but we have more headroom. So interesting thing to consider. Is that just because you put the async keyword, but don't even use the promise or anything. It doesn't mean it's free, right? Cause at the end of the day, V8 doesn't know you're not using that promise.

[00:11:50]
Like, I can't imagine their analysis is that deep that it's able to say, no one ever actually used this. Maybe they can at some point, maybe they will soon. I have no idea, but that seems like a hard problem to know, if your function will never actually be used in a promise.

[00:12:05]
There's a lot to that, but this is painful. It's painful to see that happens. So now let's try something. Our update function is now the most commanding item, 25% of the time. Let's try, I'm gonna go home, git status, git add, git commit, I opt 2, right? Awesome, and I'm gonna check out FSO, okay?

[00:12:26]
First optimization plus second optimization. I'm gonna go git merge first optimization awesome. We merged in fantastic, or didn't you rebase? It doesn't really matter at this point. So now we have them both in. So just for fun, let's go Also do one more run, but let's add in a, I'm gonna call this FSO 2000.

[00:12:48]
Let's see, does this actually make a difference with our new update function? Are we finally hitting a spot where it makes a big difference? Because last time, it made a difference, but it only really made it in the upper bounds, we really didn't see it in the lower bounds.

[00:13:04]
So I believe we're running again, fantastic. And so I'll do this thing, and we'll call this one FSO, first second optimization. Not gonna lie to you, it doesn't look like it's gonna do anything, which is too bad. Feels sad, right? Very sad. So even though we keep feeling like there's a there or there, it really hasn't yielded much, has it?

[00:13:37]
And so this is one of the problem about hotspot optimizations is not all hotspots are meaningful hotspots. You know, like this update function, we keep trying to, it clearly was a big spot. And again, it looks like it's made a small impact on our program from 30-ish percent down to 27 and a half.

[00:13:54]
Is that even real? Maybe this would be something we'd have to check out in production, something that we'd have to really measure over a course of a lot of requests in time, but maybe there's something there, okay? [SOUND] So sort of, we can say that this sort of did something, but maybe not.

[00:14:13]
The reason why I wanted to have this as a part of it, is that it's so important to realize that just because you make a performance change, and it looks like it makes a difference in a graph, it may not be as meaningful as possible. I really like making changes in which show up both on the performance side and on the memory side.

[00:14:29]
That's usually always a good indicator that that change will be bigger. Now, we still have some more room and some more things to do that actually have some pretty big changes and can make some pretty good, exciting things happen, and it may even make update into something that's important to change.