inanzzz | Creating a custom monolog logger and formatter in symfony

Sometimes you'll want to log things the way you want with your custom loggers. Example below creates a custom channel, handler and formatter to log our data. We're going to log how long a search functionality takes and log some useful information in our custom log file.

Config.yml

monolog:
    channels: [search]   # Custom channel
    handlers:
        search:   # Custom handler
            type: stream
            path:  %kernel.logs_dir%/search_%kernel.environment%.log   # Custom log file
            channels: [search]   # Custom channel
            formatter: application_search.formatter.search   # Custom formatter

SearchController

Logging logic doesn't actually belong here but I'll keep it here at this time just to keep the post shorter.

namespace Application\SearchBundle\Controller;

use Psr\Log\LoggerInterface;
use Sensio\Bundle\FrameworkExtraBundle\Configuration\Route;
use Sensio\Bundle\FrameworkExtraBundle\Configuration\Method;
use Symfony\Bundle\FrameworkBundle\Controller\Controller;
use Symfony\Component\HttpFoundation\Request;
use Symfony\Component\HttpFoundation\Response;

/**
 * @Route("/search", service="application_search.controller.search")
 */
class SearchController extends Controller
{
    private $nativeLogger;
    private $searchLogger;

    public function __construct(
        LoggerInterface $nativeLogger,
        LoggerInterface $searchLogger
    ) {
        $this->nativeLogger = $nativeLogger;
        $this->searchLogger = $searchLogger;
    }

    /**
     * @param Request $request
     *
     * @Method({"GET"})
     * @Route("")
     *
     * @return Response
     */
    public function indexAction(Request $request)
    {
        $seconds = [1, 2, 3];

        $start = microtime(true);
        sleep($seconds[array_rand($seconds)]); // Pretend like you did a search and it took 1, 2 or 3 seconds
        $end = microtime(true);

        $data = [
            'start_microseconds' => $start,
            'end_microseconds' => $end,
            'query_string' => [
                'field' => $request->query->get('field', 'name'),
                'keyword' => $request->query->get('keyword', 'inanzzz')
            ]
        ];

        if ($request->query->get('logger', 'native') == 'native') {
            $this->nativeLogger($data);
        } else {
            $this->customLogger($data);
        }

        return new Response('All logged!');
    }

    /**
     * @param array $data
     */
    private function nativeLogger(array $data)
    {
        $this->nativeLogger->info('Native Search Logger', $data);
    }

    /**
     * @param array $data
     */
    private function customLogger(array $data)
    {
        $this->searchLogger->info('Custom Search Logger', $data);
    }
}

Controllers.yml

services:
    application_search.controller.search:
        class: Application\SearchBundle\Controller\SearchController
        arguments:
            - @logger
            - @monolog.logger.search

SearchFormatter

You could inject other services to this class such as "session" if you wanted log session data as well.

namespace Application\SearchBundle\Util;

use Monolog\Formatter\FormatterInterface;

class SearchFormatter implements FormatterInterface
{
    public function format(array $record)
    {
        $start = $record['context']['start_microseconds'];
        $end = $record['context']['end_microseconds'];

        return json_encode([
            'message' => $record['message'],
            'timestamp' => date(DATE_ISO8601),
            'elapsed_milliseconds' => round(($end-$start) * 1000),
            'query_string' => $record['context']['query_string']
        ]).PHP_EOL;
    }

    public function formatBatch(array $records)
    {
        foreach ($records as $key => $record) {
            $records[$key] = $this->format($record);
        }

        return $records;
    }
}

Utils.yml

services:
    application_search.formatter.search:
        class: Application\SearchBundle\Util\SearchFormatter

Tests

Native logger

If you call GET /app_dev.php/search?logger=native&field=title&keyword=inanzzz, your "app/log/dev.log" file will contain log entry below.

# Original version
[2016-03-27 19:39:57] app.INFO: Native Search Logger {"start_microseconds":1459103996.8535,"end_microseconds":1459103997.8542,"query_string":{"field":"title","keyword":"inanzzz"}} []

# Beautified version
[
  2016-03-2719: 39: 57
]
app.INFO: NativeSearchLogger{
  "start_microseconds": 1459103996.8535,
  "end_microseconds": 1459103997.8542,
  "query_string": {
    "field": "title",
    "keyword": "inanzzz"
  }
}
[
]

Custom logger

If you call GET /app_dev.php/search?logger=custom&field=title&keyword=inanzzz, your "app/log/search_dev.log" file will contain log entry below.

# Original version
{"message":"Custom Search Logger","timestamp":"2016-03-27T19:41:50+0100","elapsed_milliseconds":2001,"query_string":{"field":"title","keyword":"inanzzz"}}

# Beautified version
{
  "message": "Custom Search Logger",
  "timestamp": "2016-03-27T19:41:50+0100",
  "elapsed_milliseconds": 2001,
  "query_string": {
    "field": "title",
    "keyword": "inanzzz"
  }
}