Flag of Ukraine
SymfonyCasts stands united with the people of Ukraine
TRACK

Dev Tools >

COURSE

Blackfire.io: Revealing Performance Secrets with Profiling

Creating an Automatic Probe Early in 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.
Previous Chapter

Next Chapter
Edit on GitHub

Once we determine that we want to create a probe dynamically in our code, we really want to do that as early as possible so that Blackfire can "instrument" as much of our code as possible.

Generating the Event Subscriber

In Symfony, we can do that with an event subscriber... which we will generate to be super lazy. First, in .env, make sure that you're back in the dev environment:

29 lines .env
... lines 1 - 16
APP_ENV=dev
... lines 18 - 29

Then, find your terminal and run:

php bin/console make:subscriber

Call it BlackfireAutoProfileSubscriber... and we want to listen to RequestEvent: Go check out the code src/EventSubscriber/BlackfireAutoProfileSubscriber.php:

22 lines src/EventSubscriber/BlackfireAutoProfileSubscriber.php
... lines 1 - 2
namespace App\EventSubscriber;
use Symfony\Component\EventDispatcher\EventSubscriberInterface;
use Symfony\Component\HttpKernel\Event\RequestEvent;
class BlackfireAutoProfileSubscriber implements EventSubscriberInterface
{
public function onRequestEvent(RequestEvent $event)
{
// ...
}
public static function getSubscribedEvents()
{
return [
RequestEvent::class => 'onRequestEvent',
];
}
}

So, when this RequestEvent happens - which Symfony dispatches super early when handling a request, we want to create & enable the probe. Copy all of the $shouldProfile code, remove it from the controller and paste it here:

30 lines src/EventSubscriber/BlackfireAutoProfileSubscriber.php
... lines 1 - 4
use Blackfire\Client;
... lines 6 - 8
class BlackfireAutoProfileSubscriber implements EventSubscriberInterface
{
public function onRequestEvent(RequestEvent $event)
{
... lines 13 - 16
if ($shouldProfile) {
$blackfire = new Client();
$probe = $blackfire->createProbe();
}
}
... lines 22 - 28
}

Creating the Prove in the Subscriber

Now add $request = $event->getRequest(). To make this only profile the GitHub organization AJAX call - whose URL is /api/github-organization - set $shouldProfile equal to $request->getPathInfo() === '/api/github-organization':

30 lines src/EventSubscriber/BlackfireAutoProfileSubscriber.php
... lines 1 - 8
class BlackfireAutoProfileSubscriber implements EventSubscriberInterface
{
public function onRequestEvent(RequestEvent $event)
{
// replace with some conditional logic
$request = $event->getRequest();
$shouldProfile = $request->getPathInfo() === '/api/github-organization';
if ($shouldProfile) {
$blackfire = new Client();
$probe = $blackfire->createProbe();
}
}
... lines 22 - 28
}

In a real app, I would add more code to make sure $shouldProfile is only true on the very specific requests we want to profile.

Now I'll re-type the t on Client and select the correct Client class so that PhpStorm adds that use statement to the top of the class for me:

30 lines src/EventSubscriber/BlackfireAutoProfileSubscriber.php
... lines 1 - 4
use Blackfire\Client;
... lines 6 - 8
class BlackfireAutoProfileSubscriber implements EventSubscriberInterface
{
public function onRequestEvent(RequestEvent $event)
{
... lines 13 - 16
if ($shouldProfile) {
$blackfire = new Client();
... line 19
}
}
... lines 22 - 28
}

Thanks PhpStorm!

But before we try this, I want to code for one edge case: if not $event->isMasterRequest(), then return:

50 lines src/EventSubscriber/BlackfireAutoProfileSubscriber.php
... lines 1 - 10
class BlackfireAutoProfileSubscriber implements EventSubscriberInterface
{
... lines 13 - 17
public function onRequestEvent(RequestEvent $event)
{
if (!$event->isMasterRequest()) {
return;
}
... lines 23 - 31
}
... lines 33 - 48
}

It might not be important in your app, but Symfony has a "sub-request" system... and the short explanation is that we don't want to profile those: they are not real requests... and would make a big mess of things.

Ok, let's try this! I'll close a tab... then refresh the homepage... which causes the AJAX request to be made. You can see it's slow. Now reload the list of profiles on Blackfire... there it is! Open it up.

And... oh wow, oh weird! 281 microseconds. Give this a name: [Recording] Auto from subscriber: http://bit.ly/sf-bf-broken-auto-profile

This profile is... broken. That's 281 microseconds - so .281 milliseconds. And the entire profile is just the Probe::enable() call itself!

Probe Auto-Close Too Early

What happened!? Well... remember: the $probe object automatically calls close() on itself as soon as that variable is garbage collected... which happens at the end of the subscriber method. That means.... we profiled exactly one line of code.

The solution is to call $probe->close() manually... which - more importantly - will require us to store the Probe object in a way where PHP won't garbage collect it too early.

So here's the goal: call $probe->close() as late as possible during the request lifecycle. We can do this by listening to a different event: when TerminateEvent::class is dispatched - that's very late in Symfony - call the onTerminateEvent() method:

50 lines src/EventSubscriber/BlackfireAutoProfileSubscriber.php
... lines 1 - 8
use Symfony\Component\HttpKernel\Event\TerminateEvent;
class BlackfireAutoProfileSubscriber implements EventSubscriberInterface
{
... lines 13 - 40
public static function getSubscribedEvents()
{
return [
... lines 44 - 45
TerminateEvent::class => 'onTerminateEvent',
];
}
}

I'll hit an Alt+Enter shortcut to create that method... then add the argument TerminateEvent $event:

50 lines src/EventSubscriber/BlackfireAutoProfileSubscriber.php
... lines 1 - 10
class BlackfireAutoProfileSubscriber implements EventSubscriberInterface
{
... lines 13 - 33
public function onTerminateEvent(TerminateEvent $event)
{
... lines 36 - 38
}
... lines 40 - 48
}

To be able to call $probe->close(), we need to store the probe object on a property. Add private $probe with some documentation that says that this will either be a Probe instance from Blackfire or null:

50 lines src/EventSubscriber/BlackfireAutoProfileSubscriber.php
... lines 1 - 10
class BlackfireAutoProfileSubscriber implements EventSubscriberInterface
{
/**
* @var Probe|null
*/
private $probe;
... lines 17 - 48
}

Update the code below to be $this->probe = $blackfire->createProbe():

50 lines src/EventSubscriber/BlackfireAutoProfileSubscriber.php
... lines 1 - 10
class BlackfireAutoProfileSubscriber implements EventSubscriberInterface
{
/**
* @var Probe|null
*/
private $probe;
... line 17
public function onRequestEvent(RequestEvent $event)
{
... lines 20 - 27
if ($shouldProfile) {
... line 29
$this->probe = $blackfire->createProbe();
}
}
... lines 33 - 48
}

Finally, inside onTerminateEvent, if $this->probe - I should not have put that exclamation point, that's a mistake - then $this->probe->close():

50 lines src/EventSubscriber/BlackfireAutoProfileSubscriber.php
... lines 1 - 10
class BlackfireAutoProfileSubscriber implements EventSubscriberInterface
{
... lines 13 - 33
public function onTerminateEvent(TerminateEvent $event)
{
if ($this->probe) {
$this->probe->close();
}
}
... lines 40 - 48
}

If you assume that I did not include the exclamation point... then this makes sense! If we created the probe, then we will close it. Problem solved. And... really... the fact that we set the probe onto a property is the real magic: that will prevent PHP from garbage-collecting that object... which will prevent it from closing itself until we're ready.

Increasing the Event Priority

While we're here, let's make this a little bit cooler. Change onRequestEvent to be an array... and add 1000 as the second item:

50 lines src/EventSubscriber/BlackfireAutoProfileSubscriber.php
... lines 1 - 10
class BlackfireAutoProfileSubscriber implements EventSubscriberInterface
{
... lines 13 - 40
public static function getSubscribedEvents()
{
return [
// warning: adding a priority will run before routing & security
RequestEvent::class => ['onRequestEvent', 1000],
... line 46
];
}
}

This syntax is... weird. But the result is good: it says that we want to listen to this event with a priority of 1000. That will make our code run even earlier so that even more code will get profiled.

Configuration: Name your Profile

Oh, and there's one other cool thing we can do: we can configure the profile. Add $configuration = new Configuration() from Blackfire\Profile. Thanks to this, we can control a number of things about the profile... the best being ->setTitle(): Automatic GitHub org Profile. Pass this to createProbe():

53 lines src/EventSubscriber/BlackfireAutoProfileSubscriber.php
... lines 1 - 6
use Blackfire\Profile\Configuration;
... lines 8 - 11
class BlackfireAutoProfileSubscriber implements EventSubscriberInterface
{
... lines 14 - 18
public function onRequestEvent(RequestEvent $event)
{
... lines 21 - 28
if ($shouldProfile) {
$configuration = new Configuration();
$configuration->setTitle('Automatic GitHub org profile');
$blackfire = new Client();
$this->probe = $blackfire->createProbe($configuration);
}
}
... lines 36 - 51
}

That's it! Let's see how things whole thing works. Back at the browser, I'll close the old profile... and refresh the homepage. Once the AJAX call finishes... reload the Blackfire profile list. Ah! We were too fast - it's still processing. Try again and... there it is!

Open it up! http://bit.ly/sf-bf-auto-profile-subscriber

Much better. A few things might still look a bit odd... because we're still not profiling every single line of code. For example, Probe::enable() seems to wrap everything. But all the important data is there.

To avoid making a million of these profiles as we keep coding, I'll go back to the subscriber and avoid profiling entirely by setting $shouldProfile = false:

56 lines src/EventSubscriber/BlackfireAutoProfileSubscriber.php
... lines 1 - 11
class BlackfireAutoProfileSubscriber implements EventSubscriberInterface
{
... lines 14 - 18
public function onRequestEvent(RequestEvent $event)
{
... lines 21 - 28
// stop our testing code from profiling
$shouldProfile = false;
if ($shouldProfile) {
... lines 33 - 36
}
}
... lines 39 - 54
}

Next: you already write automated tests for your app to help prove that key features never have bugs. You... ah... do write tests right? Let's... say you do. Me too.

Anyways, have you ever thought about writing automated tests to prevent performance bugs? Yep, that's possible! We can use Blackfire inside our test suite to add performance assertions. It's pretty sweet... and now that we understand the SDK, it will feel great.

Leave a comment!

Most Useful Newest Oldest
0
Login or Register to join the conversation
Cat in space

"Houston: no signs of life"
Start the conversation!

This tutorial can be used to learn how to profile any app - including Symfony 5.
Symfony 4

What PHP libraries does this tutorial use?

// composer.json
{
    "require": {
        "php": "^7.1.3",
        "ext-ctype": "*",
        "ext-iconv": "*",
        "blackfire/php-sdk": "^1.20", // v1.20.0
        "composer/package-versions-deprecated": "^1.11", // 1.11.99
        "doctrine/annotations": "^1.0", // v1.8.0
        "doctrine/doctrine-bundle": "^1.6.10|^2.0", // 1.11.2
        "doctrine/doctrine-migrations-bundle": "^1.3|^2.0", // v2.0.0
        "doctrine/orm": "^2.5.11", // v2.6.4
        "phpdocumentor/reflection-docblock": "^3.0|^4.0", // 4.3.2
        "sensio/framework-extra-bundle": "^5.4", // v5.5.1
        "symfony/console": "4.3.*", // v4.3.10
        "symfony/dotenv": "4.3.*", // v4.3.10
        "symfony/flex": "^1.9", // v1.18.7
        "symfony/form": "4.3.*", // v4.3.10
        "symfony/framework-bundle": "4.3.*", // v4.3.9
        "symfony/http-client": "4.3.*", // v4.3.10
        "symfony/property-access": "4.3.*", // v4.3.10
        "symfony/property-info": "4.3.*", // v4.3.10
        "symfony/security-bundle": "4.3.*", // v4.3.10
        "symfony/serializer": "4.3.*", // v4.3.10
        "symfony/twig-bundle": "4.3.*", // v4.3.10
        "symfony/validator": "4.3.*", // v4.3.10
        "symfony/webpack-encore-bundle": "^1.6", // v1.7.2
        "symfony/yaml": "4.3.*", // v4.3.10
        "twig/extensions": "^1.5" // v1.5.4
    },
    "require-dev": {
        "doctrine/doctrine-fixtures-bundle": "^3.2", // 3.2.2
        "easycorp/easy-log-handler": "^1.0.7", // v1.0.9
        "fzaninotto/faker": "^1.8", // v1.8.0
        "symfony/browser-kit": "4.3.*", // v4.3.10
        "symfony/css-selector": "4.3.*", // v4.3.10
        "symfony/debug-bundle": "4.3.*", // v4.3.10
        "symfony/maker-bundle": "^1.13", // v1.14.3
        "symfony/monolog-bundle": "^3.0", // v3.5.0
        "symfony/phpunit-bridge": "^5.0", // v5.0.3
        "symfony/stopwatch": "4.3.*", // v4.3.10
        "symfony/var-dumper": "4.3.*", // v4.3.10
        "symfony/web-profiler-bundle": "4.3.*" // v4.3.10
    }
}
Edit on GitHub
Previous Chapter
Next Chapter
userVoice