Write Faster PHP Code: Retracing Brent’s Steps

[00:02] instead of hours. Last month, Brent talked through his performance journey on the JetBrains PHP Annotated YouTube channel, and I wanted to go through his blog post with the help of TypeRacer to demonstrate a few key learnings

[00:17] about PHP and database optimizations. Moin, I am Benjamin, and in my work, I focus on PHP performance topics for the last 10 years, helping thousands of developers like you along the way. A few days ago, Brent announced his 100

[00:31] million rows challenge, a PHP performance optimization competition to find the fastest PHP code for a specific processing problem. challenge. So, if you're interested in winning PHP Storm and TypeRacer

[00:46] licenses, along with an elephant such as this, follow the link in the description to find the the challenge. And if you want to learn more about PHP performance topics, please subscribe to this channel or to our newsletter. Links are in the

[01:01] description. So, let's dive into Brent's blog post, Processing 11 million rows in minutes instead of hours. So, Brent has implemented the analytics for his blog himself, so he uses PHP code to store

[01:17] when somebody write views a page. He stores that to the database as a event. And then, he's implemented event sourcing to aggregate all this data and generate

[01:33] And what he realized is that with the data over the last five years, which are 11 million rows, which are 11 million rows, it takes extremely long to process this.

[01:48] every visit is stored in the database, and he wanted to optimize this code because it was just processing 30 events per second. And he said it takes around 50 hours to

[02:02] And he said it takes around 50 hours to process the data in total and update the the database aggregations, which is obviously way too long. obviously way too long. So, what did he do to perform this

[02:14] This is a very good first step, establishing a baseline. It means we need to find out what is the current performance and use a profiler to find out what is the

[02:30] slowest part of the current performance to find an idea about how to optimize So, I've set up myself his his blog. Let me open

[02:43] PHP Storm. So, this is a Tempest application, so the framework that Brent is working on. He has a concept of or this framework has a concept of seeders. And and I extended it to um

[02:59] And and I extended it to um also seed data into the events table. I inserted around 10,000, I think

[03:11] 4,000 rows. And the reason I've inserted just And the reason I've inserted just the low number is because I need the the low number is because I need the runs to to run a quickly and so I can go

[03:23] runs to to run a quickly and so I can go through a lot of different um variations of his optimizations without having to wait for hours to to complete them. So, I have demo data for 4,000

[03:42] the code and see what he did here. So, I only made a simple optimization to be able to run this command without interactions. So, the current command that he has required you to confirm which projectors should run and

[03:58] this made it a little bit more difficult because this waiting time appeared in the profiling results. So, what does his code do? He has the projectors here and the projectors take all the data from

[04:12] the events that are stored in the database and process them. database and process them. So, I'm already on a recent version and so let's go back to like the oldest commit

[04:27] from January to see like what Oh, stash. to see like what Oh, stash. What his original code is. So,

[04:39] his original code iterates over all the projectors. I think projectors and he updated it to have seven or eight which at the moment. So,

[04:51] iterating over the projectors then for every projector fetching the events from the database and then iterating over every event and replaying it on the projector. So, I ran a profile for this to see what

[05:08] So, I ran a profile for this to see what the aggregated problem with this is. So, in what you can do to run a profile, let's demonstrate again here. is we have the tight way CLI command.

[05:23] You I'll run tight way run, give it the sort of project to profile the data into and then I run the command here events replay. I focused on running just one single projector to to make it more obvious.

[05:39] So, when I run this because I stash this change, so we now see the

[05:52] the projector re-running this and it takes quite a lot of time for this old code to run um until this is completed.

[06:09] So, I also have this Okay, so that is completed now and we this ran for 60 seconds, so quite a long time. Let's look at the trace and tight ways.

[06:23] I sorted that um um we see the flame graph profiler. It shows um insert performance or SQL performance around 7 seconds of the 60 seconds

[06:38] and then we can go into the core graph profiler find out [snorts] um sort of where the performance problems are and we see a lot of time spent here in reflection code and um

[06:52] here. So, let's go back to the blog post to find out uh what Brent did. So, um Brent did a few optimizations

[07:05] without actually looking at performance first. So, I believe he he didn't look at performance, uh just made some um judgment calls. So, first he removed the sorting, which makes a lot of sense. Um why are you sorting um data's from

[07:20] the um the database uh which are aggregated anyways? The time is irrelevant um at that point. So, that saves a lot of time in querying. trace like the querying is not actually taking

[07:36] um a lot of the time. So, this is an optimization just based on feeling and optimization just based on feeling and not on data. We would focus on the actually slow things first. So, he then says he's reversing the loop. So, this

[07:51] is just a snippet from his code. So, he first iterates over the projectors and then makes the query iterating over every event. I showed that before. And if we actually process multiple projectors, it would execute the query

[08:06] over and over again. So, that is inefficient. And to do this inside this loop here is actually much better.

[08:19] actually much better. So, we see a second trace here. And that is already much faster.

[08:33] Only takes 5 seconds. And we can see a lot of improvements we can already see

[08:46] that we now have sort of like a different performance problem. The problem really is here

[09:02] visit per day table. So, we see most of the time spent in the So, we see most of the time spent in the 5 seconds here of this request are spent inserting into the visits per day table.

[09:15] day table. So, we're probably seeing one query for every entry here. Because as you remember, I had 3,000 600

[09:27] Because as you remember, I had 3,000 600 around events and we see 3,500 inserts. So, this is probably insert into on duplicate key updating the values, and um this is also not wrapped into a transaction, and this is why Tideways

[09:44] also mentions wrapping multiple database writes into a transaction will considerably improve the performance. Because every write to the database needs to commit to the

[09:58] um disk to make sure the write is really um received. This is an uh one of the asset properties of uh databases, and um if you wrap them in a transaction, then only the commit

[10:13] operation actually has to guarantee that. So, this is a a big performance improvement that we can make. But, as you remember, um we saw like a lots of reflection code

[10:26] actually happening in the um code, and this is something that uh um code, and this is something that uh Brent uh also saw once he started um uh uh a profiler. So, here he ditches the

[10:40] Um That is something we I think also see in this one here. So, we don't have the ORM. That makes the performance much ORM. That makes the performance much better.

[10:56] he tries. So, is the serialization faster if he hand writes it? And instead of using PHP's unserialize into a class, he um hand writes the unserialization into the

[11:09] object. But, as he mentions, that is actually slower user relying on unserialize because that is very optimized, creating the classes, setting all the values. This code here

[11:22] has to do all this um in PHP code in the engine, and unserialize does this in a single C call, um so it's much faster.

[11:35] discovering a framework but uh bug running a profiler I saw something odd. So let's look at what we see here. We see a lot of reflection code here.

[11:47] code here. Um, in his um Xdebug output and this is something we see in this one here. So let's look at type in what was the class name we found here.

[12:09] Um, there's a lot of things happening um, inside his code with reflection. So he found a bug again. And once he fixed that, I have a profile

[12:23] for that with the um the performance change. Checked out the type reflector branch. We can see here the performance improved by uh 1.something seconds over this last

[12:36] example. And we can see by fixing this bug um the performance was improved considerably. So comparing So comparing this um against the

[12:51] So comparing this um against the 5-second trace that has just the um 5-second trace that has just the um uh or M ditched. So

[13:10] and switching this because this one should be the the type reflector construction was reduced by 60,000 calls and the time

[13:22] was reduced by 60,000 calls and the time spent here is uh massively reduced. So most of the time improvement here is by this uh bug that Brent found in the Tempest or Tempest framework.

[13:36] So, this is already a big improvement that he found. So, um this is the description of showing this. Performance improved. We see this this. Performance improved. We see this as well in our very small sample. Time

[13:50] as well in our very small sample. Time goes down from 5 seconds to 4 seconds. what he improves next is making the biggest difference. And this is something we saw in the first trace already.

[14:04] So, we saw insert performance uh taking a bunch of the time. Once we removed the ORM and fixed the type reflection code, the time uh is much faster. So, we have the 5

[14:18] is much faster. So, we have the 5 seconds one and then the 4 seconds one. this has the insert performance um being the biggest bottleneck now. So,

[14:32] writing all the statements into the database is the slowest part. So, let's see what he's doing next. So, another idea that someone on the Discord server mentioned was to buffer queries instead of sending one query

[14:44] um to the database server. So, that is fairly obvious. So, that is fairly obvious. Um however, if you wrap the code in Um however, if you wrap the code in an ORM and abstractions, it's not always

[14:57] easy to see the underlying code that is happening there and the inefficiencies. happening there and the inefficiencies. So, what did Brent do? So, he introduced some kind of buffer trade where he

[15:11] um stores the queries in a variable and then executes them So, um, this is also doing just one query here. So, it's

[15:25] appending all the queries to each other and just sending them into, uh, once to the database. So, this actually automatically makes them one transaction, um, without even calling begin, uh, and, uh,

[15:40] commit. Um, because the database receives all of them as one state, not, yeah, not one statement, but as one query and executing all the statements together. So, um, he shows how he implements all

[15:54] this and how he improves the code and that he has, um, sort of this replay method still in place. And then calling persist to, um, uh, write all of them into the database.

[16:09] Let's look at this full code example in PHPStorm ourselves. So, let's look at the, uh, type race trace that implements this buffering to see what this, uh, brings as a performance benefit.

[16:23] And we can see here the trace we generated for that. generated for that. It takes 600 milliseconds only. So, we went from 4, um, seconds down to, um,

[16:35] 600 milliseconds. Let's look at a comparison. that we had before. Type, uh, with the type reflection

[16:49] improvements. And then we can see, um, what the difference is here. So, again, switching them. Before we had 4 seconds, after we had 600 milliseconds.

[17:03] And we can see that, um, most of the improvements was made in calling the database less. So, 3,000 calls less to the execute uh, function for the database makes up the performance improvements here. So,

[17:19] his batching of queries made a huge difference in performance.

[17:31] already having the performance much faster, he was wondering or saw on the Discord servers that he is not using database transactions. log, so, if you don't do database

[17:45] so, if you don't do database transactions, InnoDB calls the fsync command, so, storing the changes on disk after every commit due to asset, so, what I mentioned before, durability, not losing

[17:59] Without a transaction, every insert is an implicit commit, so, 20,000 inserts are 20,000 commits, are 20,000 fsync calls. With an explicit transaction, it's explicit, you can have 20,000 inserts in

[18:15] one transaction. So, this should improve performance even more, and he shows the changes that he made here. So, let me also check out this code and look at

[18:30] also check out this code and look at PHPStorm. is the code here. It's now using within transaction, and this means that when we call persist

[18:45] multiple times, this projector persist, then this will be wrapped in this database transaction. And the code here runs this in chunks of like 1,000 events processed at once.

[18:59] processed at once. So, we will have for every 1,000 events, we will have one database transaction for all the inserts. Because in my example, I only ran over a single projector, we still only see one big

[19:13] insert statement, so it doesn't make a big difference looking at it in the um profiler, but I want to show you.

[19:26] we saw this Tideways bottleneck explaining that wrapping into a database transaction makes sense here, impact 11% transaction makes sense here, impact 11% before we optimized the type um

[19:39] reflector API and ORM. In impact of not using a database transaction was even higher, 64% of the

[19:51] time. So, now if we look at the trace that does everything together, we see it only takes 500 milliseconds around. Um however, of this 500 milliseconds, a

[20:05] lot of time is auto loading and compiling because we run it on a CLI, the framework is bootstrapped. So, the actual code is only happening here of the command. So, the connect starts, it selects the

[20:17] stored events, it deletes the visits per day, and and this part of the code base is doing the the processing, and here we can see in Tideways that a transaction span is shown. The span represents a

[20:31] database transaction. The database transaction takes four [snorts] um milliseconds in total from begin to commit, and in it it includes the insert

[20:46] statement here, and because my data set is so small, uh we don't have real batching going on here, we only see this once. But, if you if Brent is using multiple projections and processing all his 11 million rows, then you will see

[21:02] thousands of inserts here being wrapped in into transactions, improving the in into transactions, improving the performance uh massively. experience um improving the analytics of his blog? We

[21:17] um see that with the profiler, we can find and see the performance problems. We saw both the insert statements taking a lot of time in the profiler, and also

[21:29] the type reflector bug in his framework that he uh eventually fixed. And based on this information, we could improve the code, or we could follow the changes that Brent made himself and see and explain the changes that were

[21:43] improvements. In general, the concept of database transactions is something that is underused uh in PHP applications from my experience. So, if you have a code that does a lot of inserts and updates, then

[22:00] maybe look into wrapping them into database transactions to get uh more performance out of them. This can have potential problems with database locking, so it's not a fix that um is without its um without downsides.

[22:15] So, you might run into more locking in the database, and it's something you need to try out to your example. If you like this kind of performance optimization, I would really uh suggest you look at to the um performance

[22:27] challenge that Brent set up. The link again is in the description. The three fastest solutions will get an elephant from Tighten, also uh a Tighten license, a PHP Storm license, and a PHP elephant PHP Storm elephant. So, take a look at

[22:42] interested, provide your own solution to it. See you in the next video on PHP performance. Bye.