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 ||= CompositeLogging.build do
    level ::Logger.const_get(Suzanne.env.log_level.upcase)

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

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

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
    logger.info "Lookup table creation started."

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

    logger.info "Lookup table creation done."
  end
end

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.