base.rb in semantic_logger-4.2.0

- old
+ new

@@ -122,12 +122,20 @@
 
     # Backward compatibility
     alias_method :benchmark, :measure
 
     # Log a thread backtrace
-    def backtrace(thread: Thread.current, level: :warn, message: 'Backtrace:', payload: nil, metric: nil, metric_amount: 1)
-      log       = Log.new(name, level)
+    def backtrace(thread: Thread.current,
+                  level: :warn,
+                  message: 'Backtrace:',
+                  payload: nil,
+                  metric: nil,
+                  metric_amount: nil)
+
+      log = Log.new(name, level)
+      return false unless meets_log_level?(log)
+
       backtrace =
         if thread == Thread.current
           Log.cleanse_backtrace
         else
           log.thread_name = thread.name
@@ -140,12 +148,14 @@
       if backtrace
         message += "\n"
         message << backtrace.join("\n")
       end
 
-      if log.assign(message: message, backtrace: backtrace, payload: payload, metric: metric, metric_amount: metric_amount) && should_log?(log)
+      if log.assign(message: message, backtrace: backtrace, payload: payload, metric: metric, metric_amount: metric_amount) && !filtered?(log)
         self.log(log)
+      else
+        false
       end
     end
 
     # Add the tags or named tags to the list of tags to log for this thread whilst the supplied block is active.
     #
@@ -230,17 +240,20 @@
     def payload
       warn '#payload is deprecated, use SemanticLogger.named_tags'
       SemanticLogger.named_tags
     end
 
-    protected
-
     # Write log data to underlying data storage
     def log(log_)
       raise NotImplementedError.new('Logging Appender must implement #log(log)')
     end
 
+    # Whether this log entry meets the criteria to be logged by this appender.
+    def should_log?(log)
+      meets_log_level?(log) && !filtered?(log)
+    end
+
     private
 
     # Initializer for Abstract Class SemanticLogger::Base
     #
     # Parameters
@@ -279,37 +292,44 @@
     def level_index
       @level_index || SemanticLogger.default_level_index
     end
 
     # Whether to log the supplied message based on the current filter if any
-    def include_message?(log)
-      return true if @filter.nil?
+    def filtered?(log)
+      return false if @filter.nil?
 
       if @filter.is_a?(Regexp)
-        (@filter =~ log.name) != nil
+        (@filter =~ log.name) == nil
       elsif @filter.is_a?(Proc)
-        @filter.call(log) == true
+        @filter.call(log) != true
+      else
+        raise(ArgumentError, "Unrecognized semantic logger filter: #{@filter.inspect}, must be a Regexp or a Proc")
       end
     end
 
-    # Whether the log message should be logged for the current logger or appender
-    def should_log?(log)
-      # Ensure minimum log level is met, and check filter
-      (level_index <= (log.level_index || 0)) && include_message?(log)
+    # Ensure minimum log level is met
+    def meets_log_level?(log)
+      (level_index <= (log.level_index || 0))
     end
 
     # Log message at the specified level
     def log_internal(level, index, message = nil, payload = nil, exception = nil, &block)
       log        = Log.new(name, level, index)
       should_log =
         if payload.nil? && exception.nil? && message.is_a?(Hash)
-          log.assign(message)
+          # Check if someone just logged a hash payload instead of meaning to call semantic logger
+          if message.has_key?(:message) || message.has_key?(:payload) || message.has_key?(:exception) || message.has_key?(:metric)
+            log.assign(message)
+          else
+            log.assign_positional(nil, message, nil, &block)
+          end
         else
           log.assign_positional(message, payload, exception, &block)
         end
 
-      self.log(log) if should_log && include_message?(log)
+      # Log level may change during assign due to :on_exception_level
+      self.log(log) if should_log && should_log?(log)
     end
 
     # Measure the supplied block and log the message
     def measure_internal(level, index, message, params)
       exception = nil
@@ -344,27 +364,64 @@
           else
             params[:duration] || raise('Mandatory block missing when :duration option is not supplied')
           end
 
         # Extract options after block completes so that block can modify any of the options
-        payload   = params[:payload]
+        payload = params[:payload]
 
+        # May return false due to elastic logging
         should_log = log.assign(
           message:            message,
           payload:            payload,
           min_duration:       params[:min_duration] || 0.0,
           exception:          exception,
           metric:             params[:metric],
-          metric_amount:      1,
+          metric_amount:      params[:metric_amount],
           duration:           duration,
-          backtrace:          nil,
           log_exception:      params[:log_exception] || :partial,
           on_exception_level: params[:on_exception_level]
         )
 
-        self.log(log) if should_log && include_message?(log)
+        # Log level may change during assign due to :on_exception_level
+        self.log(log) if should_log && should_log?(log)
         raise exception if exception
         result
+      end
+    end
+
+    # For measuring methods and logging their duration.
+    def measure_method(index:,
+                       level:,
+                       message:,
+                       min_duration:,
+                       metric:,
+                       log_exception:,
+                       on_exception_level:,
+                       &block)
+
+      # Ignores filter, silence, payload
+      exception = nil
+      start     = Time.now
+      begin
+        yield
+      rescue Exception => exc
+        exception = exc
+      ensure
+        log = Log.new(name, level, index)
+        # May return false due to elastic logging
+        should_log = log.assign(
+          message:            message,
+          min_duration:       min_duration,
+          exception:          exception,
+          metric:             metric,
+          duration:           1000.0 * (Time.now - start),
+          log_exception:      log_exception,
+          on_exception_level: on_exception_level
+        )
+
+        # Log level may change during assign due to :on_exception_level
+        log(log) if should_log && should_log?(log)
+        raise exception if exception
       end
     end
 
   end
 end