kupshop/bundles/KupShop/MetricsBundle/EventSubscriber/RequestMetricsSubscriber.php

<?php

namespace KupShop\MetricsBundle\EventSubscriber;

use Doctrine\DBAL\Connection;
use Doctrine\DBAL\Logging\DebugStack;
use KupShop\KupShopBundle\Util\RequestUtil;
use KupShop\MetricsBundle\PrometheusRegistryAccessor;
use KupShop\MetricsBundle\PrometheusWrapper;
use KupShop\MetricsBundle\Util\SQLTimeLogger;
use KupShop\ResponseCacheBundle\Controller\FragmentController;
use Prometheus\CollectorRegistry;
use Symfony\Component\EventDispatcher\EventSubscriberInterface;
use Symfony\Component\HttpKernel\Event\ControllerEvent;
use Symfony\Component\HttpKernel\Event\RequestEvent;
use Symfony\Component\HttpKernel\Event\TerminateEvent;
use Symfony\Component\HttpKernel\KernelEvents;
use Symfony\Contracts\Service\Attribute\Required;

class RequestMetricsSubscriber implements EventSubscriberInterface
{
    public static function getSubscribedEvents()
    {
        return [
            KernelEvents::REQUEST => [
                ['requestStart', 10000],
            ],
            KernelEvents::CONTROLLER => [
                ['requestController', -10000],
            ],
            KernelEvents::TERMINATE => [
                ['requestFinish', -9999], // process before asyncQueue jobs
            ],
        ];
    }

    /** @var CollectorRegistry */
    private $registry;

    /** @var PrometheusWrapper */
    private $prometheus;

    /** @var SQLTimeLogger */
    private $doctrineLogger;

    /** @var float */
    private $timestamp;

    /** @var string */
    private $controllerClassName;

    /** @var string */
    private $actionName;

    private $doctrineDebugStack;

    #[Required]
    public RequestUtil $requestUtil;

    public function __construct(PrometheusRegistryAccessor $registryAccessor, PrometheusWrapper $prometheus, Connection $connection)
    {
        $this->registry = $registryAccessor->getRegistry();
        $this->prometheus = $prometheus;
        if (isProduction()) {
            $timeLogger = new SQLTimeLogger();
            $connection->getConfiguration()->setSQLLogger($timeLogger);
        }
        $this->doctrineLogger = $connection->getConfiguration()->getSQLLogger();
    }

    public function requestStart(RequestEvent $event)
    {
        $this->timestamp = microtime(true);

        // Disable redirect to https or correct domain
        if ($event->getRequest()->getPathInfo() === '/_prometheus/metrics/') {
            $event->getRequest()->attributes->set('ignore_checks', true);
        }
    }

    public function requestController(ControllerEvent $event)
    {
        [$className, $actionName] = $this->requestUtil->getControllerFromEvent($event);

        // skip fragments
        if ($className === FragmentController::class) {
            return;
        }
        $this->controllerClassName = $className;
        $this->actionName = $actionName;
    }

    public function requestFinish(TerminateEvent $event)
    {
        // Ignore requests without timestamp - requestStart not called
        if (!$this->timestamp) {
            return;
        }

        $wpjTransactionInfo = $this->requestUtil->getTransactionInfo($event->getRequest());

        /*
         * Use info from wpj_transaction attribute if available.
         * With response_cache module, the HttpCache symfony bundle omits request attributes before calling the terminate event,
         * so the wpj_transaction attribute on request doesnt have to be available in every case
         */
        if ($wpjTransactionInfo) {
            $this->controllerClassName = $wpjTransactionInfo['controller'] ?? '';
            $this->actionName = $wpjTransactionInfo['action'] ?? '';
            $query = $wpjTransactionInfo['query'] ?? null;
        }

        $labels = ['controller' => $this->controllerClassName, 'action' => $this->actionName, 'query' => $query ?? null] + $this->prometheus->getLabels();

        if (findModule(\Modules::COMPONENTS) || findModule(\Modules::METRICS, \Modules::SUB_REQUESTS_HISTOGRAM)) {
            // try histograms only for components or submodule, so it doesn't generate so much series
            $this->prometheus->setHistogram(
                'request',
                'duration',
                'Complete symfony request duration in milliseconds',
                (microtime(true) - $this->timestamp) * 1000,
                $labels,
                [100, 300, 500, 750, 1000, 2000]
            );
        } else {
            $this->prometheus->setCounter(
                'request',
                'duration_count',
                'Complete symfony request count',
                1,
                $labels,
            );

            $this->prometheus->setCounter(
                'request',
                'duration_sum',
                'Complete symfony request duration in milliseconds',
                (microtime(true) - $this->timestamp) * 1000,
                $labels,
            );
        }

        $queryTime = 0.0;
        $queryCount = 0;
        if ($this->doctrineLogger instanceof SQLTimeLogger) {
            $queryTime = $this->doctrineLogger->time;
            $queryCount = $this->doctrineLogger->count;
        }
        if ($this->doctrineLogger instanceof DebugStack) {
            foreach ($this->doctrineDebugStack->queries ?? [] as $query) {
                $queryTime += $query['executionMS']; // executionMS contains value in seconds wtf
            }
            $queryCount = count($this->doctrineDebugStack->queries);
        }

        $labels = ['controller' => $this->controllerClassName, 'action' => $this->actionName, 'query' => $query ?? null];

        $this->prometheus->setCounter(
            'request',
            'query_time_count',
            'Database queries count',
            $queryCount,
            $labels,
        );

        $this->prometheus->setCounter(
            'request',
            'query_time_sum',
            'Database queries execution time in milliseconds',
            $queryTime * 1000,
            $labels,
        );

        $this->prometheus->flush();
    }
}