Save Symfony's Stopwatch data to log — Aleksander Cyrkulewski — To Get You Started

Save Symfony's Stopwatch data to log — Aleksander Cyrkulewski — To Get You Started

In one of our services we use a lot of API calls. At certain point I realised the need of speed-tracking for those API calls. On the dev environment it's pretty easy to do with @debug.stopwatch. But I wanted to measure the speed on production and save data to log file. To solve it I wrapped original stopwatch service with logger functionality. It's pretty much of configuration + small service class. I also have done it in the way when I can turn service on/off via configuration parameter stopwatch_enable: true or stopwatch_enable: false

As a result log file (the name could be prod.api.watch.log, you can specify any name you want inconfig_{env}.yml) will contain entries like following

[2014-11-26 18:56:53] api.DEBUG: API_getSomething, 1938 {"extraParamIfNeeded":"value"}

So, lets start with adding the parameter to environment we want to have stopwatch enabled:app/config/parameters_prod.yml.

stopwatch_enable: true

Next is service by self. Simple class, dependent on:

1. Symfony Stopwatch,
2. Logger,
3. turn on/off parameter.

/**
 * Wrapper for basic Symfony's Stopwatch service
 * It add logging functionality for basic one
 */
namespace CompanyName\CompanyBundle\Service;

use Symfony\Component\HttpKernel\Log\LoggerInterface;
use Symfony\Component\Stopwatch\Stopwatch;
use Symfony\Component\Stopwatch\StopwatchEvent;

class StopwatchService
{
    /**
     * @var Stopwatch
     */
    private $stopwatch;

    /**
     * @var LoggerInterface
     */
    private $logger;

    /**
     * @var bool
     */
    private $stopwatchEnabled;

    /**
     * @param Stopwatch $stopwatch
     * @param LoggerInterface $logger
     * @param bool $stopwatchEnabled
     */
    public function __construct(
        Stopwatch $stopwatch, 
        LoggerInterface $logger, 
        $stopwatchEnabled = false
    ) {
        $this->stopwatch = $stopwatch;
        $this->logger = $logger;
        $this->stopwatchEnabled = $stopwatchEnabled;
    }

    /**
     * @see Stopwatch::start
     * @param string $eventName
     * @return false|StopwatchEvent
     */
    public function start($eventName)
    {
        return ($this->stopwatchEnabled) ? $this->stopwatch->start($eventName) : false;
    }

    /**
     * @see Stopwatch::stop
     * @param string $eventName
     * @param array $extraParams
     * @return false|StopwatchEvent
     */
    public function stop($eventName, array $extraParams = array())
    {
        if (! $this->stopwatchEnabled) {
            return false;
        }
        $event = $this->stopwatch->stop($eventName);
        $this->logEvent($event, $eventName, $extraParams);
        return $event;
    }

    /**
     * Save event data to the log
     *
     * @param StopwatchEvent $event
     * @param string $eventName
     * @param array $params
     */
    private function logEvent(StopwatchEvent $event, $eventName, array $params)
    {
        $this->logger->debug($eventName . ', ' . $event->getDuration(), $params);
    }
}

Now we need to specify StopwatchService in service config
src/CompanyName/CompanyBundle/Resources/config/services.yml

symfony.stopwatch.service:
    class: Symfony\Component\Stopwatch\Stopwatch

api.stopwatch:
    class: CompanyName\CompanyBundle\Service\StopwatchService
    arguments: [ @symfony.stopwatch.service, @logger, %stopwatch_enable% ]
    tags:
        - { name: monolog.logger, channel: api }

And configure new logger. You need to do this in config_{env}.yml file.

main:
    type:         fingers_crossed
    action_level: error
    handler:      nested
    channels:     [!api]
api:
    type: stream
    path: %kernel.logs_dir%/%kernel.environment%.api.watch.log
    level: debug
    channels: [api]

And finally call the service from the place where you want to measure execution time. Here I give the example of how to call stopwatch in controller. In real life you probably make an API calls from withing other services or models. In this case you need to inject stopwatch service to your model.

$stopwatch = $this->container->get('api.stopwatch'); 
$stopwatch->start('API_getSomething');

// ... API call or some other code you need to measure ...

$stopwatch->stop('API_getSomething', array('extraParamIfNeeded' => 'value'));