Archives


Master Symfony2 fundamentals

Be trained by SensioLabs experts (2 to 6 day sessions -- French or English).
trainings.sensiolabs.com

Discover the SensioLabs Support

Access to the SensioLabs Competency Center for an exclusive and tailor-made support on Symfony
sensiolabs.com

Tobias Schultze
New in Symfony 2.4: Show logs in console
by Tobias Schultze – August 27, 2013 – 6 comments

Contributed by
Tobias Schultze
in #8167.

I'm happy to announce a new feature that will be available in Symfony 2.4: You can automatically show your log messages in the console output of commands. This eases giving feedback in your console commands dramatically. Before I show you how to use this feature, let's take a look at what problem it solves.

When you want to output text to the console you usually used the OutputInterface instance that is passed when your command gets executed like in the following example:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
protected function execute(InputInterface $input, OutputInterface $output)
{
    $data = $input->getArgument('data');
    $myService = $this->getContainer()->get('my_service');

    if ($output->getVerbosity() >= OutputInterface::VERBOSITY_DEBUG) {
        $output->writeln(sprintf('Received data: %s', $data));
    }

    if ($output->getVerbosity() >= OutputInterface::VERBOSITY_VERBOSE) {
        $output->writeln('Processing data...');
    }

    $returnValue = $myService->process($data, $output);

    if ($returnValue) {
        $output->writeln('<info>Succeeded</info>');
    } else {
        $output->writeln('<error>Failed</error>');
    }
}

But there are two problems:

  • It's cumbersome to print information depending on the verbosity settings (-v, -vv, -vvv) because you need to wrap the calls in conditions.
  • If the service you call also wants to give feedback you would need to pass on the $output as with $myService->process($data, $output). But this is really bad code in terms of separation of concerns and coupling. What if this service has a dependency on another service? Working with the OutputInterface and passing around the instance is not the way to go.

To solve these things I thought it would be much easier to rely on the logger which is highly related. So I added integration between Symfony Console Component and Symfonys logging library Monolog. It features a new handler for Monolog (ConsoleHandler) that listens to the console events and upon activation will write log messages to the console output depending on the current log level and the console verbosity. By default this mapping between log level and verbosity is as follows:

  • OutputInterface::VERBOSITY_NORMAL will show all WARNING and higher logs,
  • OutputInterface::VERBOSITY_VERBOSE (-v) will show all NOTICE and higher logs,
  • OutputInterface::VERBOSITY_VERY_VERBOSE (-vv) will show all INFO and higher logs,
  • OutputInterface::VERBOSITY_DEBUG (-vvv_) will show all DEBUG and higher logs, i.e. all logs.

Now let's see how we can activate and configure this feature in your Symfony project. With PR #42 on the MonologBundle, I made this handler just as configurable as any other Monolog handler. All it needs is an additional handler of type console in your config_dev.yml and config_prod.yml files:

monolog:
    handlers:
        main:
            type:   stream
            path:   %kernel.logs_dir%/%kernel.environment%.log
            level:  debug
        console:
            type:   console

With this in place, all messages that are logged while running a command get nicely displayed on the console. With _nicely_ I mean that the messages are timestamped, colored depending on the log level and error logs are even written to the error output (php://stderr). Now you don't need to conditionally handle the verbosity settings anymore and you can consistently use the logger instead of the OutputInterface in your commands and the services. Your services simply use a logger as usual (injected with dependency injection) and are not coupled to the console.

In the standard edition of Symfony 2.4 this feature is now included by default with PR #557. You can even customize the behavior as in the following example. With the verbosity_levels option you can adapt the above mentioned mapping between verbosity and log level. In the given example it will also show notices in normal verbosity mode (instead of warnings only). Additionally, it will only use messages logged with the custom my_channel channel and it changes the display style via a custom formatter. See also the documentation for more information:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
services:
    my_formatter:
        class: Symfony\Bridge\Monolog\Formatter\ConsoleFormatter
        arguments:
            - "[%%datetime%%] %%start_tag%%%%message%%%%end_tag%% (%%level_name%%) %%context%% %%extra%%\n"

monolog:
    handlers:
        console:
            type:   console
            verbosity_levels:
                VERBOSITY_NORMAL: NOTICE
            channels: my_channel
            formatter: my_formatter

I think this solves a common problem when working with console commands. For your information, a different approach using AOP has been described by Matthias Noback. Now it's your turn to make your commands more user and developer friendly by exposing clear information on what is happening without having to resort to verbose or dirty code.

Comments RSS

  • Aleksandr Ryzhov
    #1 Aleksandr Ryzhov said on the 2013/08/27 at 14:49
    Wow it`s great!
  • Peter Kokot
    #2 Peter Kokot said on the 2013/08/27 at 14:51
    That will be useful.
  • Pablo Godel
    #3 Pablo Godel said on the 2013/08/27 at 20:55
    I am a heavy user of console commands, this is great! Thanks!
  • Balázs Varga
    #4 Balázs Varga said on the 2013/08/27 at 23:56
    I've been using console logging for ages with the following configuration:
    ...
    handlers:
    console:
    type: stream
    path: php://STDOUT

    Anyway it'll be great to do it less tricky.
  • Hugo Hamon
    #5 Hugo Hamon said on the 2013/08/28 at 08:24
    Very nice improvments.
  • Julien DIDIER
    #6 Julien DIDIER said on the 2013/09/19 at 20:12
    Genius!