Description
Symfony version(s) affected
6.2.5
Description
In environments using the debug mode, the Stopwatch/Profiler can be used to track the performance of the request.
Sometimes you want to reset the Stopwatch/Profiler e.g. on "heavy" routes to prevent OutOfMemoryExceptions caused by to much logs getting collected. This can be done by calling Profiler::reset().
However, doing this during a running request will cause an exception after the request was handled by the controller.
LogicException:
Event "__section__" is not started.
at C:\_Web\reproducer-stopwatch\vendor\symfony\stopwatch\Section.php:118
at Symfony\Component\Stopwatch\Section->stopEvent('__section__')
(C:\_Web\reproducer-stopwatch\vendor\symfony\stopwatch\Stopwatch.php:117)
at Symfony\Component\Stopwatch\Stopwatch->stop('__section__')
(C:\_Web\reproducer-stopwatch\vendor\symfony\stopwatch\Stopwatch.php:86)
at Symfony\Component\Stopwatch\Stopwatch->stopSection('bdfdfe')
(C:\_Web\reproducer-stopwatch\vendor\symfony\http-kernel\Debug\TraceableEventDispatcher.php:69)
at Symfony\Component\HttpKernel\Debug\TraceableEventDispatcher->afterDispatch('kernel.response', object(ResponseEvent))
(C:\_Web\reproducer-stopwatch\vendor\symfony\event-dispatcher\Debug\TraceableEventDispatcher.php:134)
at Symfony\Component\EventDispatcher\Debug\TraceableEventDispatcher->dispatch(object(ResponseEvent), 'kernel.response')
(C:\_Web\reproducer-stopwatch\vendor\symfony\http-kernel\HttpKernel.php:196)
at Symfony\Component\HttpKernel\HttpKernel->filterResponse(object(Response), object(Request), 1)
(C:\_Web\reproducer-stopwatch\vendor\symfony\http-kernel\HttpKernel.php:184)
at Symfony\Component\HttpKernel\HttpKernel->handleRaw(object(Request), 1)
(C:\_Web\reproducer-stopwatch\vendor\symfony\http-kernel\HttpKernel.php:74)
at Symfony\Component\HttpKernel\HttpKernel->handle(object(Request), 1, true)
(C:\_Web\reproducer-stopwatch\vendor\symfony\http-kernel\Kernel.php:184)
at Symfony\Component\HttpKernel\Kernel->handle(object(Request))
(C:\_Web\reproducer-stopwatch\vendor\symfony\runtime\Runner\Symfony\HttpKernelRunner.php:35)
at Symfony\Component\Runtime\Runner\Symfony\HttpKernelRunner->run()
(C:\_Web\reproducer-stopwatch\vendor\autoload_runtime.php:29)
at require_once('C:\\_Web\\reproducer-stopwatch\\vendor\\autoload_runtime.php')
(C:\_Web\reproducer-stopwatch\public\index.php:5)
What is happening?
After returning the response, the HttpKernel dispatches the KernelEvents::RESPONSE event.
The TraceableEventDispatcher gets the _stopwatch_token from the requests attributes (which is still present) and tries to stop the Stopwach Section.
Since the Section is not available anymore, an exception is thrown.
How to reproduce
-
Install Profiler
composer req profiler -
Make Profiler injectable in service.yaml
services:
Symfony\Component\HttpKernel\Profiler\Profiler: '@profiler'- Create Controller
#[AsController]
class DemoController
{
#[Route('/')]
public function demoAction(Profiler $profiler): Response
{
$profiler->reset();
return new Response('Welcome!');
}
}- Run Controller
I've created a small project to demonstrate the behaviour: https://github.com/stlrnz/reproducer-stopwatch
Possible Solution
Check if the Section is available before trying to stop it.
Additional Context
No response