[ACCEPTED]-Ruby - share logger instance among module/classes-class-design

I like to have a logger method available in my 8 classes, but I don't like sprinkling @logger = Logging.logger in 7 all my initializers. Usually, I do this:

module Logging
  # This is the magical bit that gets mixed into your classes
  def logger
    Logging.logger
  end

  # Global, memoized, lazy initialized instance of a logger
  def self.logger
    @logger ||= Logger.new(STDOUT)
  end
end

Then, in 6 your classes:

class Widget
  # Mix in the ability to log stuff ...
  include Logging

  # ... and proceed to log with impunity:
  def discombobulate(whizbang)
    logger.warn "About to combobulate the whizbang"
    # commence discombobulation
  end
end

Because the Logging#logger method can access 5 the instance that the module is mixed into, it 4 is trivial to extend your logging module 3 to record the classname with log messages:

module Logging
  def logger
    @logger ||= Logging.logger_for(self.class.name)
  end

  # Use a hash class-ivar to cache a unique Logger per class:
  @loggers = {}

  class << self
    def logger_for(classname)
      @loggers[classname] ||= configure_logger_for(classname)
    end

    def configure_logger_for(classname)
      logger = Logger.new(STDOUT)
      logger.progname = classname
      logger
    end
  end
end

Your 2 Widget now logs messages with its classname, and 1 didn't need to change one bit :)

With the design you've laid out, it looks 4 like the easiest solution is to give Crawler 3 a module method that returns a module ivar.

module Crawler
  def self.logger
    @logger
  end
  def self.logger=(logger)
    @logger = logger
  end
end

Or 2 you could use "class <<self magic" if you wanted:

module Crawler
  class <<self
    attr_accessor :logger
  end
end

It 1 does the exact same thing.

As Zenagray points out, logging from class 10 methods was left out of Jacob's answer. A 9 small addition solves that:

require 'logger'

module Logging
  class << self
    def logger
      @logger ||= Logger.new($stdout)
    end

    def logger=(logger)
      @logger = logger
    end
  end

  # Addition
  def self.included(base)
    class << base
      def logger
        Logging.logger
      end
    end
  end

  def logger
    Logging.logger
  end
end

The intended 8 use is via "include":

class Dog
  include Logging

  def self.bark
    logger.debug "chirp"
    puts "#{logger.__id__}"
  end

  def bark
    logger.debug "grrr"
    puts "#{logger.__id__}"
  end
end

class Cat
  include Logging

  def self.bark
    logger.debug "chirp"
    puts "#{logger.__id__}"
  end

  def bark
    logger.debug "grrr"
    puts "#{logger.__id__}"
  end
end

Dog.new.bark
Dog.bark
Cat.new.bark
Cat.bark

Produces:

D, [2014-05-06T22:27:33.991454 #2735] DEBUG -- : grrr
70319381806200
D, [2014-05-06T22:27:33.991531 #2735] DEBUG -- : chirp
70319381806200
D, [2014-05-06T22:27:33.991562 #2735] DEBUG -- : grrr
70319381806200
D, [2014-05-06T22:27:33.991588 #2735] DEBUG -- : chirp
70319381806200

Note the id 7 of the logger is the same in all four cases. If 6 you want a different instance for each class, then 5 don't use Logging.logger, rather use self.class.logger:

require 'logger'

module Logging
  def self.included(base)
    class << base
      def logger
        @logger ||= Logger.new($stdout)
      end

      def logger=(logger)
        @logger = logger
      end
    end
  end

  def logger
    self.class.logger
  end
end

The same program 4 now produces:

D, [2014-05-06T22:36:07.709645 #2822] DEBUG -- : grrr
70350390296120
D, [2014-05-06T22:36:07.709723 #2822] DEBUG -- : chirp
70350390296120
D, [2014-05-06T22:36:07.709763 #2822] DEBUG -- : grrr
70350390295100
D, [2014-05-06T22:36:07.709791 #2822] DEBUG -- : chirp
70350390295100

Note that the first two id's 3 are the same but are different from the 2 2nd two ids showing that we have two instances 1 -- one for each class.

Inspired by this thread I created the easy_logging gem.

It 3 combines all the features discussed such 2 as:

• Adds logging functionality anywhere with one, short, self-descriptive command
• Logger works in both class and instance methods
• Logger is specific to class and contains class name

Installation:

gem install 'easy_logging

Usage:

require 'easy_logging'

class YourClass
  include EasyLogging

  def do_something
    # ...
    logger.info 'something happened'
  end
end

class YourOtherClass
  include EasyLogging

  def self.do_something
    # ...
    logger.info 'something happened'
  end
end

YourClass.new.do_something
YourOtherClass.do_something

Output

I, [2017-06-03T21:59:25.160686 #5900]  INFO -- YourClass: something happened
I, [2017-06-03T21:59:25.160686 #5900]  INFO -- YourOtherClass: something happened

More details 1 on GitHub.

The may be some weird Ruby magic that could 12 let you avoid it, but there's a fairly simple 11 solution that doesn't need weird. Just 10 put the logger into the module and access 9 it directly, with a mechanism to set it. If 8 you want to be cool about it, define a "lazy 7 logger" that keeps a flag to say if it has 6 a logger yet, and either silently drops 5 messages until the logger is set, throws 4 an exception of something is logged before 3 the logger is set, or adds the log message 2 to a list so it can be logged once the logger 1 is defined.

A little chunk of code to demonstrate how 5 this works. I'm simply creating a new basic 4 Object so that I can observe that the object_id 3 remains the same throughout the calls:

module M

  class << self
    attr_accessor :logger
  end

  @logger = nil

  class C
    def initialize
      puts "C.initialize, before setting M.logger: #{M.logger.object_id}"
      M.logger = Object.new
      puts "C.initialize, after setting M.logger: #{M.logger.object_id}"
      @base = D.new
    end
  end

  class D
    def initialize
      puts "D.initialize M.logger: #{M.logger.object_id}"
    end
  end
end

puts "M.logger (before C.new): #{M.logger.object_id}"
engine = M::C.new
puts "M.logger (after C.new): #{M.logger.object_id}"

The 2 output of this code looks like (an object_id of 4 1 means nil):

M.logger (before C.new): 4
C.initialize, before setting M.logger: 4
C.initialize, after setting M.logger: 59360
D.initialize M.logger: 59360
M.logger (after C.new): 59360

Thanks for the help guys!

How about wrapping the logger in a singleton 1 then you could access it using MyLogger.instance

Based on your comment

All of this could 20 be avoided if you could just dynamically 19 change the output location of an already-instantiated 18 Logger (similar to how you change the log 17 level).

If you are not restricted to the 16 default logger you may use another log-gem.

As 15 an example with log4r:

require 'log4r' 

module Crawler
  LOGGER = Log4r::Logger.new('mylog')
  class Runner
    def initialize
        LOGGER.info('Created instance for %s' % self.class)
    end
  end
end

ARGV << 'test'  #testcode

#...
case ARGV.first
  when 'test'
    Crawler::LOGGER.outputters = Log4r::StdoutOutputter.new('stdout')
  when 'prod'
    Crawler::LOGGER.outputters = Log4r::FileOutputter.new('file', :filename => 'test.log') #append to existing log
end
#...
Crawler::Runner.new

In prod mode the logging 14 data are stored in a file (attached to existing 13 file, but there are options to create new 12 log files or implement rolling log files).

The 11 result:

 INFO main: Created instance for Crawler::Runner

If you use the inheritance mechanism 10 of log4r (a), you may define a logger for 9 each class (or in my following example for 8 each instance) and share the outputter.

The 7 example:

require 'log4r' 

module Crawler
  LOGGER = Log4r::Logger.new('mylog')
  class Runner
    def initialize(id)
      @log = Log4r::Logger.new('%s::%s %s' % [LOGGER.fullname,self.class,id])
      @log.info('Created instance for %s with id %s' % [self.class, id])
    end
  end
end

ARGV << 'test'  #testcode

#...
case ARGV.first
  when 'test'
    Crawler::LOGGER.outputters = Log4r::StdoutOutputter.new('stdout')
  when 'prod'
    Crawler::LOGGER.outputters = Log4r::FileOutputter.new('file', :filename => 'test.log') #append to existing log
end
#...
Crawler::Runner.new(1)
Crawler::Runner.new(2)

The result:

 INFO Runner 1: Created instance for Crawler::Runner with id 1
 INFO Runner 2: Created instance for Crawler::Runner with id 2

(a) A logger name like 6 A::B has the name B and is a child of the logger 5 with the name A. As far as I know this is 4 no object inheritance.

One advantage of this 3 approach: If you want to use a single logger 2 for each class, you need only to change 1 the name of the logger.

Although an old question, I thought it worthwhile 8 to document a different approach.

Building 7 on Jacob's answer, I would suggest a module 6 that you can add in as and when needed.

My 5 version is this:

# saved into lib/my_log.rb

require 'logger'

module MyLog

  def self.logger
    if @logger.nil?
      @logger = Logger.new( STDERR)
      @logger.datetime_format = "%H:%M:%S "
    end
    @logger
  end

  def self.logger=( logger)
    @logger = logger
  end

  levels = %w(debug info warn error fatal)
  levels.each do |level|
    define_method( "#{level.to_sym}") do |msg|
      self.logger.send( level, msg)
    end
  end
end

include MyLog

I have this saved into a 4 library of handy modules, and I would use 3 it like this:

#! /usr/bin/env ruby
#

require_relative '../lib/my_log.rb'

MyLog.debug "hi"
# => D, [19:19:32 #31112] DEBUG -- : hi

MyLog.warn "ho"
# => W, [19:20:14 #31112]  WARN -- : ho

MyLog.logger.level = Logger::INFO

MyLog.logger = Logger.new( 'logfile.log')

MyLog.debug 'huh'
# => no output, sent to logfile.log instead

I find this a lot easier and 2 more versatile than other options I've looked 1 at so far, so I hope it helps you with yours.