There are so many loggers already, surely one of them will work

Recently I've been working on a few projects that run as background tasks on our servers. Since there's no user interface, I wanted robust logging so that we can monitor the tasks and troubleshoot them when things go wrong. Specifically, I wanted:

  1. Logging to multiple locations, in this case the console and a daily log file.
  2. Customizable formatting. On the console, I want pretty colors and concise timestamps. In the log file, I want monochrome and full dates and times.
  3. Tags. We have multiple data pipelines running in parallel, so it's imperative to know which one is talking.
  4. Thread-safe silencing. Some people think that silencing is a code smell; we use the Sequel gem, where logging SQL queries is an all-or-nothing proposition.
  5. Simple configuration, either in code or a config file.

I tested several logging gems (ActiveSupport::Logger, Lumberjack, Log4r) and found that none of them did everything in that list. I tried to add the missing features with varying degrees of success, and eventually decided to build a new logger that does exactly what I want.

The result is the composite_logging gem, which is available on Github.

How to use composite_logging

Here's how the logger is configured:

def self.logger
  @logger ||= do
    level ::Logger.const_get(Suzanne.env.log_level.upcase)

    logger do
      output          STDOUT
      formatter       CompositeLogging::ColorFormatter
      datetime_format "%T"

    logger do
      output          File.join(Suzanne.env.log_path, "etl-#{"%Y%m%d")}.log")
      formatter       CompositeLogging::Formatter
      datetime_format "%F %T"
      decolorize      true

As you can see, it writes to standard output and to a file. Standard output is in color and doesn't show the date. The file includes both date and time. It also has all ANSI codes stripped out because one of the gems we use outputs log messages in color.

How it's called:

# Create some lookup tables from CSV data
def create_tables
  logger.tagged("Lookups") do "Lookup table creation started."

    each_table do |table, csv| "create table #{table} (...)"
      logger.silence do
        csv.each { |row| db[table].insert(row.to_hash) }
    end "Lookup table creation done."

The console output looks like this:

08:28:23 [INFO ] [Lookups] Lookup table creation started.
08:28:24 [DEBUG] [Lookups] (0.000148s) create table ...
08:28:24 [INFO ] [Lookups] Lookup table creation done.

And the log file looks like this:

2014-08-05 08:28:23 [INFO ] [Lookups] Lookup table creation started.
2014-08-05 08:28:24 [DEBUG] [Lookups] (0.000148s) create table ...
2014-08-05 08:28:24 [INFO ] [Lookups] Lookup table creation done.