Manually Profile (Instrument) Part of your Code

Video not working?

It looks like your browser may not support the H264 codec. If you're using Linux, try a different browser or try installing the gstreamer0.10-ffmpeg gstreamer0.10-plugins-good packages.

Thanks! This saves us from needing to use Flash or encode videos in multiple formats. And that let's us get back to making more videos :). But as always, please feel free to message us.

Profiling a page looks like this.

Profiling: What happens Behind the Scenes

First, something tells the Blackfire PHP extension - the "Probe":

Hey! Start profiling!

Which basically means that it starts collecting tons of data. The process of collecting data is called instrumentation... because when a concept is too simple, sometimes we tech people like to invent confusing words. Instrumentation means that the PHP extension is collecting data.

The second step is that - eventually - something tells the PHP extension to stop "instrumentation" and to send the data. The collection of data is known as a "profile". The PHP extension sends the profile to the agent, which aggregates it, prune some stuff and ultimately sends it to the Blackfire server.

So: what is the "thing" that tells the PHP extension to activate? We know that the PHP extension doesn't profile every request... so what is it that says:

Hey PHP extension "probe" thing: start profiling!

The answer - so far - is: the browser extension: it sends special information that tells the probe to do its thing. Or, if you use the blackfire command line utility, which we did earlier to profile a command, then it is what tells the PHP extension to activate.

In either situation, the extension is activated before even the first line of code is executed. That means that every single line of PHP code is "instrumented": our final profile contains everything. This is called auto-instrumentation: instrumentation starts automatically.

This naturally leads to three interesting questions.

First, who is baby Yoda? I mean, is he... like, related to Yoda? Or just the same species?

The second question is: could we trigger, or create a Blackfire profile in a different way? Could we, for example, dynamically tell the PHP extension to create a profile from inside our code under some specific condition?

And third, regardless of who triggers the profile, could we "zoom in" and only collect profiling data for part of our code? Like, could we create a profile that only collects data about the code from our controller instead of the entire request?

Let's actually start with that last question: profiling a specific part of our code, instead of the whole thing. To be fully honest, I don't know if this part has a ton of practical use-cases, but it will give you an even better idea of how Blackfire works behind the scenes.

Installing the Blackfire SDK

To help with this crazy experiment, we're going to install Blackfire's PHP SDK. Find your terminal, dial up your modem to the Internet, and run:

composer require blackfire/php-sdk

This is a normal PHP library that helps interact directly with Blackfire from inside your code. You'll see how.

When it finishes, move over and open src/Controller/MainController.php:

... lines 1 - 16
class MainController extends AbstractController
{
/**
* @Route("/", name="app_homepage")
*/
public function homepage(BigFootSightingRepository $bigFootSightingRepository)
{
$sightings = $this->createSightingsPaginator(1, $bigFootSightingRepository);
return $this->render('main/homepage.html.twig', [
'sightings' => $sightings
]);
}
... lines 30 - 120
}

Ok: this is the controller for our homepage. Let's pretend that when we profile this page, we don't want to collect data about all of our code. Nope, we want to, sort of, "zoom in" and see only what's happening inside the controller.

Manually Instrumenting Code

We can do that by saying $probe = \BlackfireProbe::getMainInstance():

... lines 1 - 16
class MainController extends AbstractController
{
... lines 19 - 21
public function homepage(BigFootSightingRepository $bigFootSightingRepository)
{
$probe = \BlackfireProbe::getMainInstance();
... lines 25 - 34
}
... lines 36 - 126
}

Remember: the PHP extension is called the "probe"... that's important if you want this to make sense. Then call $probe->enable():

... lines 1 - 16
class MainController extends AbstractController
{
... lines 19 - 21
public function homepage(BigFootSightingRepository $bigFootSightingRepository)
{
$probe = \BlackfireProbe::getMainInstance();
$probe->enable();
... lines 26 - 34
}
... lines 36 - 38
*/
... lines 40 - 126
}

At the bottom, I'll set the rendered template to a $response variable, add $probe->disable() and finish with return $response:

... lines 1 - 16
class MainController extends AbstractController
{
... lines 19 - 21
public function homepage(BigFootSightingRepository $bigFootSightingRepository)
{
$probe = \BlackfireProbe::getMainInstance();
$probe->enable();
... lines 26 - 27
$response = $this->render('main/homepage.html.twig', [
'sightings' => $sightings
]);
$probe->disable();
return $response;
}
... lines 36 - 126
}

Okay, so... what the heck does this do? The first thing I want you to notice is that if I refresh the homepage a bunch of times... and then go to https://blackfire.io, I do not have any new profiles. Adding this code does not "trigger" a new profile to be created: it does not tell the PHP extension - the "probe" - that it should to do its work.

Instead, if a profile is currently being created, this tells the probe when to start collecting data. Hmm, this isn't going to quite make sense until we see it in action. Trigger a new profile on the homepage. I'll call this one: [Recording] Only instrument some code.

Click to view the call graph: https://bit.ly/sf-bf-partial-profile.

Fascinating. This contains less information than normal. It has a few things on top - main() and handleRaw()... but basically it jumps straight to the homepage() method.

How Disabling Auto-Instrumentation Works

What's happening here is that the only code that the probe "instrumented", the only code that it collected information on, is the code between the enable() and disable() calls:

... lines 1 - 16
class MainController extends AbstractController
{
... lines 19 - 21
public function homepage(BigFootSightingRepository $bigFootSightingRepository)
{
... line 24
$probe->enable();
$sightings = $this->createSightingsPaginator(1, $bigFootSightingRepository);
$response = $this->render('main/homepage.html.twig', [
'sightings' => $sightings
]);
$probe->disable();
... lines 33 - 34
}
... lines 36 - 126
}

This... completely confused me the first time I saw it. What really happens is this: as soon as we use the browser extension to tell the probe to do its job, the PHP extension starts instrumenting - so, collection data - immediately. Initially, it is collecting data about every line of PHP code.

But as soon as it sees $probe->enable(), it basically forgets about all the data collected so far. The $probe->enable() call says:

Hey! Start instrumenting here. If you've already collected some data before thanks to auto-instrumentation, get rid of it.

This effectively disables auto-instrumentation: we're now controlling which code is instrumented instead of it happening automatically. Once the code hits $probe->disable() instrumentation stops.

You can actually use $probe->enable() and $probe->disable() multiple times in your code if you want to profile different pieces: $probe->enable() only forgets data it's already collected the first time you call it.

Oh, and you can also optionally call $probe->close() - you'll see this in their documentation:

... lines 1 - 16
class MainController extends AbstractController
{
... lines 19 - 21
public function homepage(BigFootSightingRepository $bigFootSightingRepository)
{
... lines 24 - 31
$probe->disable();
$probe->close(); // optional - will auto-close at end of script
... lines 34 - 35
}
... lines 37 - 127
}

That tells the PHP extension that you're definitely done profiling and it can send the data to the agent. But, it's not strictly required, because it'll be sent automatically when the script ends anyways.

So... this feature is maybe useful... but it's definitely a nice intro into taking more control of the profiling process.

We haven't used the SDK Yet

And.. fun fact! We installed the blackfire/php-sdk library... but we haven't actually used it yet! This \BlackfireProbe class is not from the php-sdk library: it's from the Blackfire PHP extension. As long as you have the extension installed, that class will exist. We're interacting directly with the extension.

So... why did we install the SDK if we didn't need it? Because... it gave us auto-complete on that class. And you all know that I freakin' love auto-complete.

The SDK has a, sort of, "stub" version of this class. This is not the code that was actually executed when we called those methods... but having this at least shows us what methods and arguments exist.

Next, let's actually use the PHP SDK to do something a bit more interesting. I want to create a profile automatically in my code without needing to use the browser extension. This does have real-world use-cases.

Leave a comment!

  • 2020-05-27 Dennis de Best

    Thanks for the info!

  • 2020-05-27 weaverryan

    Hey Dennis de Best!

    You found a bug! Well, a few other people have found it also - https://github.com/symfony/... - but nice job! I have just commented on that bug to see if we can "push" a fix forward. For now, if you want to work around, as the comments say, you would need to manually use an older version of symfony/flex.

    Cheers!

  • 2020-05-25 Dennis de Best

    I made a basic Symfony 5.0.8 website starter that runs on the php:php:7.4.6-fpm-alpine (with some configuration) that works fine at the start but has the error as soon as composer requires the blackfire-sdk. Here is a link : https://github.com/Dennisde... there is more information in the README. Thanks for the quick reply

  • 2020-05-21 weaverryan

    Hey Dennis de Best!

    Hmm, very curious! You're totally right that Symfony 5 shouldn't matter. Hmm, if you have the code on GitHub handy, yes, I would love to have it :). We'll want to debug this - because it sounds very odd, could be a bug somewhere - and if you have a setup already handy, that would help.

    Thanks!

  • 2020-05-20 Dennis de Best

    Interesting, but I seem to have a problem when requiring the the blackfire-sdk. As it requires the composer/ca-bundle 1.2.7 I get the following error :
    "Attempted to call an undefined method named "getName" of class "Composer\CaBundle\CaBundle"

    I am running this on a php7.4.6 alpine docker container with composer 1.10.6 on it. (I can give you the link to the github file if you want). My project is based on Symfony 5.0.8 (even though, I guess, this shouldn't matter for blackfire).

    I have started looking for composer undefined method errors but have not yet found anything that has something to do with the CaBundle.

    Anyway this is not a priority for me for now and the cursus is great ! If anyone has had this issue and knows how to solve it I will be very grateful.