DEV Community

Dave Jacoby
Dave Jacoby

Posted on • Originally published at jacoby.github.io on

3

Fighting the Bus Factor with Log::Log4Perl

A Bus[By Littletung - Own work, CC BY-SA 3.0,]https://en.wikipedia.org/wiki/Big\_Blue\_Bus)https://commons.wikimedia.org/w/index.php?curid=26397084

Ever heard the phrase “Bus Factor”? In a nutshell, it relates to what happens if someone in your organization got “hit by a bus”. It doesn’t have to be literal; changing jobs is sufficient.

A co-worker went to part-time here and part-time elsewhere in the organization. He then became available for occasional consulting. His code is now on my lap. It’s mostly bash, organized the way he understood but I certainly do not. I don’t understand how it works and how it is called.

I do understand Perl, and the wonderful power of Log4perl.

Log::Log4perl is Perl’s take on Log4J, with a lot of options.

I wrote a quick thing that would log anything you put in @ARGV.

#!/usr/bin/env perl

use strict;
use warnings;
use utf8;
use feature qw{ postderef say signatures state };
no warnings qw{ experimental::postderef experimental::signatures };

use Log::Log4perl;

my $config = join '/', $ENV{HOME}, '.log.conf';
my $argv = join ' ', @ARGV;

Log::Log4perl::init($config);
my $logger = Log::Log4perl::get_logger('log_me');
$logger->warn($argv);

Enter fullscreen mode Exit fullscreen mode

Log::Log4perl isn’t in Core, but it is very useful.

So, now, if I run log_me.pl test, I get

2018/08/17 11:06:23 WARN localhost.example.com: test

Enter fullscreen mode Exit fullscreen mode

Because most of the magic is in the config.

log4perl.logger.log_me = TRACE, Appender0
log4perl.appender.Appender0 = Log::Log4perl::Appender::File
log4perl.appender.Appender0.filename = /home/jacoby/.log_me.log
log4perl.appender.Appender0.layout = PatternLayout
log4perl.appender.Appender0.layout.ConversionPattern=%d %p %H: %m%n

## log4perl.logger.log_me = TRACE, Appender0
## TRACE is the minimum level that will be logged
## (FATAL,ERROR,WARN,INFO,DEBUG)

## log4perl.appender.Appender0 = Log::Log4perl::Appender::File
## Appender0 is the ID of the appender we're using
## Screen, File, Socket, DBI, RRDs
## We append to file so it can occur without watching

## log4perl.appender.Appender0.filename = /depot/gcore/apps/dev/dave/.log_me.log
## filename is the name of the logfile

## log4perl.appender.Appender0.layout = PatternLayout
## log4perl.appender.Appender0.layout.ConversionPattern=%d %p %H: %m%n
## Date time LogLevel Host: the log test \n
## 2018/08/17 10:59:39-WARN-localhost.example.com-AGAIN

Enter fullscreen mode Exit fullscreen mode

I document the meaning of the five lines above. Presumably, I could add much more complex behavior, but what I need is simple. I need to know what is called, how often, and where.

# Logging usage for triage in understanding and refactoring - DAJ 201808
me="$(basename "$(test -L "$0" && readlink "$0" || echo "$0")")"
/home/jacoby/log_me.pl $me

Enter fullscreen mode Exit fullscreen mode

The me line gets to the right file name when symlinked (according to this answer on Stack Overflow; hey, I am not strong in my bash-fu), and I have pasted that into the top of every shell script in the directory in question.

2018/08/17 13:20:13 WARN localhost.example.com: should_blast_be_queued.sh
2018/08/17 13:30:22 WARN localhost.example.com: should_blast_be_queued.sh
2018/08/17 13:30:22 WARN localhost.example.com: runs_status.sh
2018/08/17 13:30:22 WARN localhost.example.com: runs_status.sh
2018/08/17 13:40:12 WARN localhost.example.com: should_blast_be_queued.sh
2018/08/17 13:45:19 WARN localhost.example.com: user_warning.sh
2018/08/17 13:50:15 WARN localhost.example.com: should_blast_be_queued.sh
2018/08/17 14:00:26 WARN localhost.example.com: should_blast_be_queued.sh
2018/08/17 14:10:12 WARN localhost.example.com: should_blast_be_queued.sh
2018/08/17 14:20:13 WARN localhost.example.com: should_blast_be_queued.sh

Enter fullscreen mode Exit fullscreen mode

The point of this is triage: The program most often run is the program I should understand the most. Looks like should_blast_be_queued.sh is high up in the priority list so far.

As is looking both ways at the intersection.

If you have any questions or comments, I would be glad to hear it. Ask me on Twitter or make an issue on my blog repo.

Sentry image

Hands-on debugging session: instrument, monitor, and fix

Join Lazar for a hands-on session where you’ll build it, break it, debug it, and fix it. You’ll set up Sentry, track errors, use Session Replay and Tracing, and leverage some good ol’ AI to find and fix issues fast.

RSVP here →

Top comments (0)

Some comments may only be visible to logged-in visitors. Sign in to view all comments.

Billboard image

The Next Generation Developer Platform

Coherence is the first Platform-as-a-Service you can control. Unlike "black-box" platforms that are opinionated about the infra you can deploy, Coherence is powered by CNC, the open-source IaC framework, which offers limitless customization.

Learn more

👋 Kindness is contagious

Please leave a ❤️ or a friendly comment on this post if you found it helpful!

Okay