Logger option to specify ignored locations

Introduce option :ignored_locations for Steno::Logger. When provided all
frames from the callstack matching the regex are ignored, i.e. the first
non-matching frame denotes the record's location.

This option can also be set via a Steno::Config instance that is passed
to Steno.init before using Steno.logger to get a (cached) Steno::Logger
instance.

Inspired by Sequel's caller_logging extension [1].

[1] https://sequel.jeremyevans.net/rdoc-plugins/classes/Sequel/
    CallerLogging.html#attribute-i-caller_logging_ignore

Author: philippthun

.rubocop.yml

@@ -6,3 +6,9 @@ require:
 
 AllCops:
   NewCops: enable
+
+RSpec/NestedGroups:
+  Max: 4
+
+RSpec/MultipleExpectations:
+  Max: 7

lib/steno.rb

@@ -47,7 +47,8 @@ def logger(name)
 
           logger = Steno::Logger.new(name, @config.sinks,
                                      level: level,
-                                     context: @config.context)
+                                     context: @config.context,
+                                     ignored_locations: @config.ignored_locations)
 
           @loggers[name] = logger
         end

lib/steno/config.rb

@@ -70,12 +70,13 @@ def symbolize_keys(hash)
     end
   end
 
-  attr_reader :sinks, :codec, :context, :default_log_level
+  attr_reader :sinks, :codec, :context, :ignored_locations, :default_log_level
 
   def initialize(opts = {})
     @sinks             = opts[:sinks] || []
     @codec             = opts[:codec] || Steno::Codec::Json.new
     @context           = opts[:context] || Steno::Context::Null.new
+    @ignored_locations = opts[:ignored_locations]
 
     @sinks.each { |sink| sink.codec = @codec }
 

lib/steno/log_level.rb

@@ -6,7 +6,7 @@ class Steno::LogLevel
 
   attr_reader :name, :priority
 
-  # @param [String]  name      "info", "debug", etc.
+  # @param [Symbol]  name      :info, :debug, etc.
   # @param [Integer] priority  "info" > "debug", etc.
   def initialize(name, priority)
     @name = name

lib/steno/logger.rb

@@ -9,10 +9,10 @@ module Steno
 class Steno::Logger
   LEVELS = {
     off: Steno::LogLevel.new(:off, 0),
-    fatal: Steno::LogLevel.new(:fatal,   1),
-    error: Steno::LogLevel.new(:error,   5),
-    warn: Steno::LogLevel.new(:warn,   10),
-    info: Steno::LogLevel.new(:info,   15),
+    fatal: Steno::LogLevel.new(:fatal, 1),
+    error: Steno::LogLevel.new(:error, 5),
+    warn: Steno::LogLevel.new(:warn, 10),
+    info: Steno::LogLevel.new(:info, 15),
     debug: Steno::LogLevel.new(:debug, 16),
     debug1: Steno::LogLevel.new(:debug1, 17),
     debug2: Steno::LogLevel.new(:debug2, 18),
@@ -60,18 +60,21 @@ def lookup_level(name)
 
   attr_reader :name
 
-  # @param [String] name The logger name.
+  # @param [String] name  The logger name.
   # @param [Array<Steno::Sink::Base>] sinks
   # @param [Hash] opts
   # @option opts [Symbol] :level  The minimum level for which this logger will
   #         emit log records. Defaults to :info.
   # @option opts [Steno::Context] :context
+  # @option opts [Regex] :ignored_locations  User specified regex matching
+  #         ignored locations.
   def initialize(name, sinks, opts = {})
-    @name           = name
-    @min_level      = self.class.lookup_level(opts[:level] || :info)
-    @min_level_lock = Mutex.new
-    @sinks          = sinks
-    @context        = opts[:context] || Steno::Context::Null.new
+    @name              = name
+    @min_level         = self.class.lookup_level(opts[:level] || :info)
+    @min_level_lock    = Mutex.new
+    @sinks             = sinks
+    @context           = opts[:context] || Steno::Context::Null.new
+    @ignored_locations = opts[:ignored_locations]
   end
 
   # Sets the minimum level for which records will be added to sinks.
@@ -114,7 +117,7 @@ def log_exception(ex, user_data = {})
 
   # Adds a record to the configured sinks.
   #
-  # @param [Symbol] level_name    The level associated with the record
+  # @param [Symbol] level_name  The level associated with the record
   # @param [String] message
   # @param [Hash] user_data
   #
@@ -124,7 +127,7 @@ def log(level_name, message = nil, user_data = nil)
 
     message = yield if block_given?
 
-    callstack = caller
+    callstack = Kernel.caller
     loc = parse_record_loc(callstack)
 
     data = @context.data.merge(user_data || {})
@@ -149,22 +152,16 @@ def tag(user_data = {})
   private
 
   def parse_record_loc(callstack)
-    file = nil
-    lineno = nil
-    method = nil
+    frame = callstack.find { |f| !(f =~ /logger\.rb/ || ignored_location?(f)) } || callstack.last
 
-    callstack.each do |frame|
-      next if frame =~ /logger\.rb/
-
-      file, lineno, method = frame.split(':')
-
-      lineno = lineno.to_i
-
-      method = ::Regexp.last_match(1) if method =~ /in `([^']+)/
-
-      break
-    end
+    file, lineno, method = frame.split(':')
+    lineno = lineno.to_i
+    method = ::Regexp.last_match(1) if method =~ /in `([^`']+)/
 
     [file, lineno, method]
   end
+
+  def ignored_location?(frame)
+    !@ignored_locations.nil? && frame =~ @ignored_locations
+  end
 end

lib/steno/version.rb

@@ -1,3 +1,3 @@
 module Steno
-  VERSION = '1.3.6'
+  VERSION = '1.4.0'
 end

spec/unit/config_spec.rb

@@ -27,6 +27,7 @@
 
         expect(@config.default_log_level).to eq(:debug2)
         expect(@config.context.class).to eq(Steno::Context::Null)
+        expect(@config.ignored_locations).to eq(nil)
         expect(@config.codec.class).to eq(Steno::Codec::Json)
 
         expect(@config.sinks.size).to eq(2)
@@ -76,6 +77,7 @@
 
         expect(@config.default_log_level).to eq(:debug2)
         expect(@config.context.class).to eq(Steno::Context::Null)
+        expect(@config.ignored_locations).to eq(nil)
         expect(@config.codec.class).to eq(Steno::Codec::Json)
 
         expect(@config.sinks.size).to eq(2)
@@ -127,6 +129,8 @@
 
       expect(config.context.class).to eq(Steno::Context::Null)
 
+      expect(config.ignored_locations).to eq(nil)
+
       expect(config.codec.class).to eq(Steno::Codec::Json)
       expect(config.codec.iso8601_timestamps?).to eq(false)
     end
@@ -208,10 +212,13 @@
       write_config(@config_path, { 'default_log_level' => 'debug' })
 
       context = Steno::Context::ThreadLocal.new
+      ignored_locations = /location-to-ignore/
       config = Steno::Config.from_file(@config_path,
                                        default_log_level: 'warn',
-                                       context: context)
+                                       context: context,
+                                       ignored_locations: ignored_locations)
       expect(config.context).to eq(context)
+      expect(config.ignored_locations).to eq(ignored_locations)
       expect(config.default_log_level).to eq(:warn)
     end
   end

spec/unit/logger_spec.rb

@@ -43,22 +43,23 @@
   end
 
   describe '#log' do
-    it 'does not forward any messages for levels that are inactive' do
-      sink = double('sink')
-      expect(sink).not_to receive(:add_record)
+    let(:sink) { instance_double(Steno::Sink::Base) }
+    let(:logger) { Steno::Logger.new('test', [sink]) }
 
-      my_logger = Steno::Logger.new('test', [sink])
+    before do
+      allow(sink).to receive(:add_record)
+    end
 
-      my_logger.debug('test')
+    it 'does not forward any messages for levels that are inactive' do
+      logger.debug('test')
+
+      expect(sink).not_to have_received(:add_record)
     end
 
     it 'forwards messages for levels that are active' do
-      sink = double('sink')
-      expect(sink).to receive(:add_record).with(any_args)
-
-      my_logger = Steno::Logger.new('test', [sink])
+      logger.warn('test')
 
-      my_logger.warn('test')
+      expect(sink).to have_received(:add_record).with(any_args)
     end
 
     it 'does not invoke a supplied block if the level is inactive' do
@@ -74,13 +75,70 @@
     end
 
     it 'creates a record with the proper level' do
-      sink = double('sink')
       expect(Steno::Record).to receive(:new).with('test', :warn, 'message', anything, anything).and_call_original
-      allow(sink).to receive(:add_record)
 
-      my_logger = Steno::Logger.new('test', [sink])
+      logger.warn('message')
+    end
+
+    it 'includes the location where the record was generated' do
+      location = [__FILE__, an_instance_of(Integer), 'log']
+      expect(Steno::Record).to receive(:new).with('test', :warn, 'message', location, anything).and_call_original
+
+      def log(logger)
+        logger.warn('message')
+      end
+
+      log(logger)
+    end
+
+    describe 'option :ignored_locations' do
+      let(:logger) { Steno::Logger.new('test', [sink], ignored_locations: ignored_locations) }
+      let(:callstack) do
+        [
+          '/path/to/lib/steno/logger.rb:12:in `block in define_log_method`',
+          '/path/to/another_file.rb:34:in `yet_another_method`',
+          '/path/to/some_file.rb:56:in `another_method`',
+          '/path/to/some_file.rb:78:in `some_method`',
+          '/path/to/program.rb:90:in `<main>'
+        ]
+      end
+
+      before do
+        allow(Kernel).to receive(:caller).and_return(callstack)
+      end
+
+      context 'when ignoring a file' do
+        let(:ignored_locations) { /another_file\.rb/ }
+
+        it 'includes the next file as location' do
+          location = ['/path/to/some_file.rb', 56, 'another_method']
+          expect(Steno::Record).to receive(:new).with('test', :warn, 'message', location, anything).and_call_original
+
+          logger.warn('message')
+        end
+      end
 
-      my_logger.warn('message')
+      context 'when ignoring multiple files and methods' do
+        let(:ignored_locations) { /(another_file\.rb|some_file\.rb.*another_method)/ }
+
+        it 'includes the next file/method as location' do
+          location = ['/path/to/some_file.rb', 78, 'some_method']
+          expect(Steno::Record).to receive(:new).with('test', :warn, 'message', location, anything).and_call_original
+
+          logger.warn('message')
+        end
+      end
+
+      context 'when regex is too broad' do
+        let(:ignored_locations) { /.*/ }
+
+        it 'still includes a location (the last one) and does not fail' do
+          location = [an_instance_of(String), an_instance_of(Integer), an_instance_of(String)]
+          expect(Steno::Record).to receive(:new).with('test', :warn, 'message', location, anything).and_call_original
+
+          logger.warn('message')
+        end
+      end
     end
   end
 

steno.gemspec

@@ -28,7 +28,7 @@ Gem::Specification.new do |gem|
 
   gem.add_development_dependency('rack-test')
   gem.add_development_dependency('rake')
-  gem.add_development_dependency('rspec', '~>3.13.0')
+  gem.add_development_dependency('rspec', '~> 3.13.0')
   gem.add_development_dependency('rubocop', '~> 1.62.0')
   gem.add_development_dependency('rubocop-rake', '~> 0.6.0')
   gem.add_development_dependency('rubocop-rspec', '~> 2.27.0')