CLI Applications Tips & Tricks - Logging Outputs

In this series, I'm going to tell you about my experience and best practices with command line applications. I'm sure these will help you to write better command line applications.

Log output or it didn't happen!

Logging is fundamental for any kind of application. For a command, it's too important to log whatever the command does and its results in detail.

I generally output to a file so that in future you can check when the command ran and what it did.

/var/www/artisan some:command >  $HOME/logs/some-command/`date +%Y-%m-%d-%H-%M-%S`.log 2>&1

I'm saving output to a file with named its creation date. This is really helpful for debugging if command ran or not. And of course running date will be helpful!

So what will the file contain? It depends on what command does, but you can print literally anything! Don't hesitate to write something into logs. Anything will be useful!

Example command:

Assume that you have a command which checks current subscription status of users. And disables users if they're no longer paying. Why we're doing this: You can use webhook for any kind of subscription status update, but sometimes it may not work as expected and you may need command line job to check everything is ok. So let's do this!

<?php

$users = User::where('is_active', true)->get(); // TODO: use cursors instead of getting whole data. This will be fixed in the next chapters!

$this->output->writeln('There are '.$users->count().' users to be checked.');

foreach ($users as $user) {
    if (!$this->stripeService->isUserActive($user)) {
        $this->userService->disableUser($user);
        $this->output->writeln('User have been disabled: user_id_'.$user->id);
    }
}

$this->output->writeln('Done');

return 0;

Output file will be like this:

There are 1989 users to be checked. 
User have been disabled: user_id_100
User have been disabled: user_id_157
...
...
Done.

Advantage of this method over using a logging system is you can watch output (with tail) anytime. And of course, you can connect your output files to any kind of log management system like ELK, Datadog, Coralogix, Papertrail etc.

Find data on log files

Most of time, you may not have a log management system and you may need to find something on logs. You can definitely use grep for this!

grep -Ril -e 'user_id_100' $HOME/logs/some-command/

Ta da! You'll see on when user have been disabled. If you wouldn't log this info, you wouldn't easily understand why user have been disabled.

Log cronjob output on Laravel Framework

I'm using Laravel's scheduler for running my cronjobs. With scheduler, you can send output to a file easily.

https://laravel.com/docs/8.x/scheduling#task-output

$schedule->command('emails:send')
         ->daily()
         ->appendOutputTo(storage_path('cronjob-logs/emails_send_'.date('YmdHis'));

Conclusion

Logging is most critical thing on an application. Saving output is easy. But you have find whatever is precious for you, what you want to log and a structure for yourself. Then you don't have to do nothing, unless debug is required. I hope it won't be required any time, but let's be prepared anyway :)