Time to get our hands dirty! In this chapter, we are going to profile a real application and use Blackfire’s web interface to understand its behavior and find some code optimizations.
Note
This chapter and the next do not require any language-dependent installation. The example code and application is hosted on a demo server, so that you can walk through the next steps without taking care of it.
The project we are going to work on is an Open-Source PHP project, GitList:
GitList is an elegant and modern web interface for interacting with multiple git repositories.
According to the Git repository, GitList “allows you to browse repositories using your favorite browser, viewing files under different revisions, commit history, diffs. It also generates RSS feeds for each repository, allowing you to stay up-to-date with the latest changes anytime, anywhere. GitList was written in PHP, on top of the Silex microframework and powered by the Twig template engine.”
For the purpose of this tutorial, we have installed GitList on a demo server at https://gitlist.demo.blackfire.io/ and set up a repository for Twig there. Blackfire has also been installed and configured.
Our goal is to find bottlenecks in the GitList source code and, if we find any, propose changes to optimize its performance.
The first step in our quest is to gather data about the behavior of the
current codebase by using the Blackfire profiler. To do that, we will
generate profiles for GitList’s home page (/
) and each of the tabs on the
repository page: “Files” (/Twig
), “Commits” /Twig/commits
, “Stats”
(/Twig/stats
), and “Network” (/Twig/network
).
Before we do this, you will need to create an account on Blackfire.io if you don’t have one yet. It takes less than a minute if you already have a GitHub, Google or Platform.sh account.
Then, make sure to subscribe to the Premium or Enterprise Edition. Premium does enable to profile non-local HTTP applications, and also offers more profiling dimensions (such as SQL) and a lot more features you’ll want to use in this tutorial, like assertions.
To trigger some GitList profiles, first install the Blackfire browser extension: for Firefox or for Google Chrome.
We are now ready to start our first profiling session!
To profile the GitList homepage, go to https://gitlist.demo.blackfire.io/ and trigger a profile by clicking on the Blackfire Extension icon:
By clicking the profile button, you have asked Blackfire to begin profiling the page currently displayed in the browser. You should see a black toolbar at the top of the browser window with a nice progress bar:
Note
If anything does not work as described in this tutorial, do not hesitate to contact us.
As you can see, it takes way more time to profile the page than it took to display it initially. This is because Blackfire triggers several page reloads behind the scenes to get a larger sample size, aggregate the results, and present more accurate information. Relying on only a single profile is not ideal, as we discussed in the previous chapter.
At the end of the profiling process, the toolbar displays a summary of the profile:
This summary provides some basic information (your numbers may vary slightly, but should be similar), from left to right:
For now, we are only going to focus on main time and memory. We will discuss I/O and CPU in later chapters.
Hooray! You’ve just generated your first profile.
It took almost 27 ms for the server to generate the HTTP response. Is this good? Can we do better? When analyzing the performance of a project for the very first time, the slowest requests are the ones to optimize first. Now that we have our first profile, the baseline, let’s profile another page and see if its performance is different from the homepage.
Let’s profile the Twig project homepage, https://gitlist.demo.blackfire.io/Twig/. Load this page in your browser and use the browser extension to trigger a profile.
These numbers are quite different compared to the homepage. This page took more than 100ms to render (vs 14ms), and consumed around 2MB of memory (vs 1.5MB). It looks like this page can be optimized!
The Blackfire summary toolbar is a good way to find which pages need to be optimized first, but then we need to dive deeper to better understand what’s going on. Click on the “View Call Graph” button now. You should be redirected to the detailed profile on Blackfire.io.
Your profile should be similar to this one:
Now it’s time to learn how to use the Blackfire interface to detect performance issues.
The table on the left side of the screen displays a list of the main functions and methods that were executed. Clicking on a function name reveals the resources consumed by this function, like time, memory, network, …
By default, the most time-consuming function calls are listed first. These
functions are almost always where you want to look first. In our case,
stream_select()
comes first. It takes a significant amount of time to
execute: almost half of the total time for 80 calls. As stream_select()
is
a PHP built-in function, it cannot be optimized; but we can try to lower the
number of times it is called.
The next step is to understand which parts of userland code trigger these
calls. Click on the stream_select()
link to reveal this function’s
details, then click on the magnifying glass. The call graph will now be redrawn
and centered on this specific node:
The call graph displays the executed code as a visual diagram where each node corresponds to a function or method call. The edges of the graph show the execution flow.
Now that we are focused on the stream_select()
node, drag the graph up
with your mouse until you find the Gitter\Client::getVersion()
and
Gitter\Client::run()
nodes. These are the first calls defined in userland
PHP and the ones which we are most interested in:
The Gitter\Client::getVersion()
method is called 10 times and accounts
for 33% of the total execution time, that’s a lot. Its implementation reads
as follows:
1 2 3 4 5 6 7 8 9 10 11 12 | public function getVersion()
{
$process = new Process($this->getPath() . ' --version');
$process->run();
if (!$process->isSuccessful()) {
throw new \RuntimeException($process->getErrorOutput());
}
$version = substr($process->getOutput(), 12);
return trim($version);
}
|
Apparently, getVersion()
returns the version of the local git
CLI tool,
as getPath()
returns the path to the git
binary. We can safely assume
that this method will always return the same result for any given request (and
most of the time even across requests).
Caching the returned value locally avoids running 10 identical sub-processes:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 | public function getVersion()
{
static $version;
if (null !== $version) {
return trim($version);
}
$process = new Process($this->getPath() . ' --version');
$process->run();
if (!$process->isSuccessful()) {
throw new \RuntimeException($process->getErrorOutput());
}
$version = substr($process->getOutput(), 12);
return trim($version);
}
|
And that’s it. In less than 5 minutes, in a codebase we knew nothing about before, we’ve already found a performance bottleneck and written a patch.
Blackfire provided us the tools necessary to understand the code’s actual behavior and showed us front and center exactly where to look to improve its performance.
We call that the “Blackfire effect”, and lots of people are experiencing it on their projects:
Woot! Thanks to @blackfireio, @michaelthieulin and I optimized one of the backoffice pages of @dayuse_fr. The page was taking 18 seconds to load due to a misconfiguration of our @MongoDB indexes on a 15M documents collection. Now, the pages loads within 200 ms. pic.twitter.com/KmX4yYxTd6
— Hugo Hamon (@hhamon) July 3, 2018
Used @blackfireio seriously for the first time yesterday. Went from 1min 39s to 2.98s on some heavy data processing code... It transformed our workflow in amazing ways. Thanks!
— belisar (@belisar) March 24, 2018
I think I found a way to improve performance by 15% in @phpunit using @blackfireio. Our unit tests take 17 seconds normally and with the changes it shaves off a few seconds. When running a code coverage report with xdebug on it shaves off several minutes. I will submit a PR soon.
— Jonathan H. Wage (@jwage) February 13, 2018
Optimizing colinodell/json5 with @blackfireiohttps://t.co/nwFI5d9AHN #php #performance
— 👨💻 Colin O'Dell (@colinodell) January 14, 2018
With #Symfony 3.4/4.0, enabling param `container.dumper.inline_class_loader` can boost your dev env perf by 50% and your prod by +2%. For free as usual :) /cc @blackfireio pic.twitter.com/vvPoZlTZEb
— Nicolas Grekas (@nicolasgrekas) November 10, 2017
Reduced core page load by a further 30% today using @blackfireio timelines view. Killer feature in a killer tool
— Peter Ward (@petewardreiss) November 8, 2017
This is great, but we’re not done yet. The complete process of performance optimization includes checking the impact of your code changes. First by running the unit tests to confirm that nothing is broken. Then, always compare the data between the current version of the code and the patched version to validate that the fix actually solves the problem and doesn’t introduce regressions in other parts of the code.
Performance comparisons are a key feature of Blackfire; one that we will look at in depth in the next chapter.