Step 30: Discovering Symfony Internals

5.0 version

Discovering Symfony Internals

We have been using Symfony to develop a powerful application for quite a while now, but most of the code executed by the application comes from Symfony. A few hundred lines of code versus thousands of lines of code.

I like to understand how things work behind the scenes. And I have always been fascinated by tools that help me understand how things work. The first time I used a step by step debugger or the first time I discovered ptrace are magical memories.

Would you like to better understand how Symfony works? Time to dig into how Symfony makes your application tick. Instead of describing how Symfony handles an HTTP request from a theoretical perspective, which would be quite boring, we are going to use Blackfire to get some visual representations and use it to discover some more advanced topics.

Understanding Symfony Internals with Blackfire

You already know that all HTTP requests are served by a single entry point: the public/index.php file. But what happens next? How controllers are called?

Let’s profile the English homepage in production with Blackfire via the Blackfire browser extension:

$ symfony remote:open

Or directly via the command line:

$ blackfire curl `symfony env:urls --first`en/

Go to the “Timeline” view of the profile, you should see something similar to the following:

From the timeline, hover on the colored bars to have more information about each call; you will learn a lot about how Symfony works:

  • The main entry point is public/index.php;
  • The Kernel::handle() method handles the request;
  • It calls the HttpKernel that dispatches some events;
  • The first event is RequestEvent;
  • The ControllerResolver::getController() method is called to determine which controller should be called for the incoming URL;
  • The ControllerResolver::getArguments() method is called to determine which arguments to pass to the controller (the param converter is called);
  • The ConferenceController::index() method is called and most of our code is executed by this call;
  • The ConferenceRepository::findAll() method gets all conferences from the database (notice the connection to the database via PDO::__construct());
  • The Twig\Environment::render() method renders the template;
  • The ResponseEvent and the FinishRequestEvent are dispatched, but it looks like no listeners are actually registered as they seem to be really fast to execute.

The timeline is a great way to understand how some code works; which is very useful when you get a project developed by someone else.

Now, profile the same page from the local machine in the development environment:

$ blackfire curl `symfony var:export SYMFONY_PROJECT_DEFAULT_ROUTE_URL`en/

Open the profile. You should be redirected to the call graph view as the request was really quick and the timeline would be quite empty:

Do you understand what’s going on? The HTTP cache is enabled and as such, we are profiling the Symfony HTTP cache layer. As the page is in the cache, HttpCache\Store::restoreResponse() is getting the HTTP response from its cache and the controller is never called.

Disable the cache layer in public/index.php as we did in the previous step and try again. You can immediately see that the profile looks very different:

The main differences are the following:

  • The TerminateEvent, which was not visible in production, takes a large percentage of the execution time; looking closer, you can see that this is the event responsible for storing the Symfony profiler data gathered during the request;
  • Under the ConferenceController::index() call, notice the SubRequestHandler::handle() method that renders the ESI (that’s why we have two calls to Profiler::saveProfile(), one for the main request and one for the ESI).

Explore the timeline to learn more; switch to the call graph view to have a different representation of the same data.

As we have just discovered, the code executed in development and production is quite different. The development environment is slower as the Symfony profiler tries to gather many data to ease debugging problems. This is why you should always profile with the production environment, even locally.

Some interesting experiments: profile an error page, profile the / page (which is a redirect), or an API resource. Each profile will tell you a bit more about how Symfony works, which class/methods are called, what is expensive to run and what is cheap.

Using the Blackfire Debug Addon

By default, Blackfire removes all method calls that are not significant enough to avoid having big payloads and big graphs. When using Blackfire as a debugging tool, it is better to keep all calls. This is provided by the debug addon.

From the command line, use the --debug flag:

$ blackfire --debug curl `symfony var:export SYMFONY_PROJECT_DEFAULT_ROUTE_URL`en/
$ blackfire --debug curl `symfony env:urls --first`en/

In production, you would see for instance the loading of a file named .env.local.php:

Where does it come from? SymfonyCloud does some optimizations when deploying a Symfony application like optimizing the Composer autoloader (--optimize-autoloader --apcu-autoloader --classmap-authoritative). It also optimizes environment variables defined in the .env file (to avoid parsing the file for every request) by generating the .env.local.php file:

$ symfony run composer dump-env prod

Blackfire is a very powerful tool that helps understand how code is executed by PHP. Improving performance is just one way to use a profiler.

This work, including the code samples, is licensed under a Creative Commons BY-NC-SA 4.0 license.