[TwigHooks] Profiler call graph drops every hook rendered after a non-empty sibling hook (e.g. `sections#right`)
Nobody has claimed this yet.
- Dominant language
- PHP
- Stars
- 45
- Forks
- 34
- PR merge metrics
- No merged PRs in 30d
Description
Description
In the Symfony profiler, the Twig Hooks → Call Graph panel leaves out hooks that were rendered. Once a hookable renders a hook that has at least one hookable, every later hook rendered by the same hookable is dropped from the graph, together with everything rendered inside it. The page itself renders correctly; only the profiler data is wrong.
The admin customer form shows it clearly. src/Sylius/Bundle/AdminBundle/templates/customer/form/sections.html.twig (Sylius/Sylius) renders three sibling hooks:
<div class="row">
{% hook 'sections' %}
</div>
<div class="row">
<div class="col-12 col-md-6">
{% hook 'sections#left' %}
</div>
<div class="col-12 col-md-6">
{% hook 'sections#right' %}
</div>
</div>
The call graph shows sylius_admin.customer.update.content.form.sections#left with its whole subtree, but sylius_admin.customer.update.content.form.sections#right is missing, along with extra_information and the gender, birthday, phone number and newsletter fields, all of which are on the page.
It is not caused by #
Section hooks just make it common, because #left / #right pairs are always rendered next to each other, and more than 40 AdminBundle and ShopBundle templates use them. Plain hook names are affected the same way. For example, src/Sylius/Bundle/AdminBundle/templates/payment_method/form/sections/gateway_configuration.html.twig (lines 10-11) renders:
{% hook 'gateway_configuration' %}
{% hook 'gateway_configuration' ~ '.' ~ gateway_type %}
By default, the first hook renders type and use_payum on both the create and update pages, so the gateway-specific hook, which is where plugins such as PayPal, Adyen and Mollie register their fields (e.g. sylius_admin.payment_method.update.content.form.sections.gateway_configuration.sylius_paypal), is left out of the call graph. That is exactly the hook a plugin developer opens the panel to find.
A later sibling hook only survives if every hook before it in the same hookable rendered nothing. That is why #left is shown in the customer form: the sections hook before it has its only hookable, general, disabled.
Why it happens
src/TwigHooks/src/Profiler/Profile.php tracks its position in the tree with two pointers. The current hook is handled like a stack: when a hook ends, it goes back to its parent (line 57). The current hookable is not. When a hookable ends, the pointer is cleared instead of going back to the hookable that is still rendering (line 80):
public function registerHookStart(array $hooksNames): void
{
$this->previousHookProfile = $this->currentHookProfile;
$hookProfile = new HookProfile($hooksNames, [], $this->previousHookProfile);
$this->currentHookProfile = $hookProfile;
$this->currentHookableProfile?->addChild($hookProfile); // line 43
}
public function registerHookableRenderEnd(int|float|null $duration): void
{
if (null !== $duration) {
$this->currentHookableProfile?->setDuration($duration);
}
$this->currentHookableProfile = null; // line 80
}
A new hook is linked into the tree only through addChild() on the current hookable (line 43). For the customer form:
- The
sectionstemplate starts, so the current hookable issections. {% hook 'sections' %}renders no hookables. The pointer is untouched, so the hook is attached. ✅{% hook 'sections#left' %}is attached. ✅ Itsgeneralandaccount_credentialshookables render, and when they end the pointer becomesnull.{% hook 'sections#right' %}starts while the pointer isnull, soaddChild()is never called. It still getssections#left's parent hook as its parent, soregisterHookEnd()does not add it torootProfileseither (lines 48-50). ❌
HtmlDumper only walks getRootProfiles() → getHookablesProfiles() → getChildren(), so an orphaned hook and everything recorded under it is never printed.
The same line causes two more problems:
- The counters don't match the tree.
numberOfHooksandnumberOfHookablesare incremented for every hook and hookable, including the dropped ones. The panel header reports more than the graph contains, with no hint that anything is missing. - Durations of container hookables are lost. When a hookable that rendered a non-empty hook ends, the pointer is already
null, sosetDuration()on line 77 does nothing and the dumper prints ⏲ 0 ms. This hits the templates that wrap other templates, such assections, which are usually the most expensive ones on the page.
How to reproduce
- Run Sylius 2.2 in the
devenvironment with the web profiler enabled. - In the admin, open Customers → (any customer) → Edit.
- Open the profiler for that request and go to Twig Hooks → Call Graph.
Expected: sections#right is listed under sections next to sections#left, with extra_information and its four fields under it.
Actual: the graph ends after sections#left. Abridged to the form subtree, with priorities and timings removed:
└ (Hook) sylius_admin.customer.update.content.form
└ (Template) sections (@SyliusAdmin/customer/form/sections.html.twig)
└ (Hook) sylius_admin.customer.update.content.form.sections
└ (Hook) sylius_admin.customer.update.content.form.sections#left
└ (Template) general (@SyliusAdmin/customer/form/sections/general.html.twig)
│ └ (Hook) sylius_admin.customer.update.content.form.sections.general
│ └ (Template) first_name (@SyliusAdmin/customer/form/sections/general/first_name.html.twig)
│ └ (Template) last_name (@SyliusAdmin/customer/form/sections/general/last_name.html.twig)
│ └ (Template) email (@SyliusAdmin/customer/form/sections/general/email.html.twig)
│ └ (Template) group (@SyliusAdmin/customer/form/sections/general/group.html.twig)
└ (Template) account_credentials (@SyliusAdmin/customer/form/sections/account_credentials.html.twig)
└ (Hook) sylius_admin.customer.update.content.form.sections.account_credentials
└ (Template) password (@SyliusAdmin/customer/form/sections/account_credentials/password.html.twig)
└ (Template) enabled (@SyliusAdmin/customer/form/sections/account_credentials/enabled.html.twig)
└ (Template) verified (@SyliusAdmin/customer/form/sections/account_credentials/verified.html.twig)
For this subtree alone, the counters include 7 hooks and 15 hookables, but the graph shows 5 and 10.
The bug does not depend on a browser or a database. Calling Profile in the order HookProfilerRenderer and HookableProfilerRenderer use gives the same result. The unit test below does exactly that and fails on the current code:
1) ProfileTest::testItAttachesSiblingHooksRenderedAfterANonEmptyHookToTheSameHookable
Failed asserting that two arrays are identical.
--- Expected
+++ Actual
@@ @@
Array &0 [
0 => 'form.sections#left',
- 1 => 'form.sections#right',
]
2) ProfileTest::testItSetsDurationOfHookableThatRendersNonEmptyHooks
Failed asserting that null is identical to 5.0.
Possible Solution
Keep a stack of the hookables being rendered, and go back to the previous one when a hookable ends, just as registerHookEnd() already does for hooks:
private ?HookableProfile $currentHookableProfile = null;
+ /** @var array<HookableProfile> */
+ private array $hookableProfilesStack = [];
+
@@ public function registerHookableRenderStart(AbstractHookable $hookable): void
$hookableProfile = new HookableProfile($this->currentHookProfile, $hookable->name, $hookable, []);
+ $this->hookableProfilesStack[] = $hookableProfile;
$this->currentHookableProfile = $hookableProfile;
$this->currentHookProfile->addHookableProfile($this->currentHookableProfile);
@@ public function registerHookableRenderEnd(int|float|null $duration): void
$this->currentHookableProfile?->setDuration($duration);
}
- $this->currentHookableProfile = null;
+ array_pop($this->hookableProfilesStack);
+ $this->currentHookableProfile = end($this->hookableProfilesStack) ?: null;
}
@@ public function reset(): void
$this->currentHookableProfile = null;
+ $this->hookableProfilesStack = [];
$this->numberOfHooks = 0;
There is no ProfileTest yet (tests/Unit/Profiler only has HookProfileTest and HookableProfilerTest), so the fix could come with one:
final class ProfileTest extends TestCase
{
public function testItAttachesSiblingHooksRenderedAfterANonEmptyHookToTheSameHookable(): void
{
$profile = $this->profileHookableRenderingTwoSiblingHooks();
$sections = $profile->getRootProfiles()[0]->getHookablesProfiles()[0];
self::assertSame(
['form.sections#left', 'form.sections#right'],
array_map(static fn (HookProfile $hookProfile): string => $hookProfile->getName(), $sections->getChildren()),
);
}
public function testItSetsDurationOfHookableThatRendersNonEmptyHooks(): void
{
$profile = $this->profileHookableRenderingTwoSiblingHooks();
$sections = $profile->getRootProfiles()[0]->getHookablesProfiles()[0];
self::assertSame(5.0, $sections->getDuration());
}
private function profileHookableRenderingTwoSiblingHooks(): Profile
{
$profile = new Profile();
$profile->registerHookStart(['form']);
$profile->registerHookableRenderStart(HookableTemplateMotherObject::withName('sections'));
$profile->registerHookStart(['form.sections#left']);
$profile->registerHookableRenderStart(HookableTemplateMotherObject::withName('general'));
$profile->registerHookableRenderEnd(1.0);
$profile->registerHookEnd(2.0);
$profile->registerHookStart(['form.sections#right']);
$profile->registerHookableRenderStart(HookableTemplateMotherObject::withName('extra_information'));
$profile->registerHookableRenderEnd(1.0);
$profile->registerHookEnd(2.0);
$profile->registerHookableRenderEnd(5.0);
$profile->registerHookEnd(6.0);
return $profile;
}
}
With the patch applied, both tests pass. The customer form subtree then contains all 7 hooks and 15 hookables, matching the counters, and sections gets its own duration:
└ (Hook) sylius_admin.customer.update.content.form.sections#right
└ (Template) extra_information (@SyliusAdmin/customer/form/sections/extra_information.html.twig)
└ (Hook) sylius_admin.customer.update.content.form.sections.extra_information
└ (Template) gender (@SyliusAdmin/customer/form/sections/extra_information/gender.html.twig)
└ (Template) birthday (@SyliusAdmin/customer/form/sections/extra_information/birthday.html.twig)
└ (Template) phone_number (@SyliusAdmin/customer/form/sections/extra_information/phone_number.html.twig)
└ (Template) subscribe_to_the_newsletter (@SyliusAdmin/customer/form/sections/extra_information/subscribe_to_the_newsletter.html.twig)
The stack is the smallest change. An alternative is to store the parent hookable on HookProfile and read it back when a hookable ends, but that also means changing the HookProfile constructor and every place that creates one.
I am happy to open a PR with the patch and the test.
Additional Context
- Affected code (Sylius/Stack):
src/TwigHooks/src/Profiler/Profile.php(line 43: hooks are attached only through the current hookable; line 80: the current hookable is cleared instead of restored)src/TwigHooks/src/Profiler/Dumper/HtmlDumper.php(lines 33, 54, 83: the graph is built only from root hooks → hookables → children, so orphaned hooks are never reached)src/TwigHooks/src/Hook/Renderer/Debug/HookProfilerRenderer.phpandsrc/TwigHooks/src/Hookable/Renderer/Debug/HookableProfilerRenderer.php(the decorators that callProfile; they work correctly)
- Hooks, hookables and root-level durations are recorded correctly. Only the tree links and the durations of hookables that render non-empty hooks are lost. The toolbar total is summed from root hooks, so it is unaffected.
- Examples in Sylius/Sylius where a hook goes missing:
src/Sylius/Bundle/AdminBundle/templates/customer/form/sections.html.twig(sections#right)src/Sylius/Bundle/AdminBundle/templates/payment_method/form/sections/gateway_configuration.html.twig(gateway_configuration.<gateway factory>)
- Components are affected the same way as templates, because the profiler decorator wraps the composite hookable renderer.
Contributor guide
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Research direction
Start with src/TwigHooks/src/Profiler/Profile.php and trace registerHookStart(), registerHookableRenderStart(), and registerHookableRenderEnd() in the order used by the profiler renderers. Add focused regression coverage under tests/Unit/Profiler, including sibling hooks and container-hookable duration, then run the profiler unit tests. Done means both hooks remain in the profile tree and the container duration is preserved.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- php
- Domain
- devtools
- Issue type
- Bug
- Difficulty
- 3/5
- Estimated time
- 1-2 days
- Activity status
- Active
- Clarity
- Clearly specified
- Newbie friendliness
- 84/100