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:
- Logging to multiple locations, in this case the console and a daily log file.
- Customizable formatting. On the console, I want pretty colors and concise timestamps. In the log file, I want monochrome and full dates and times.
- Tags. We have multiple data pipelines running in parallel, so it's imperative to know which one is talking.
- 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.
- 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.