2001/no jira passion logger with context

Gemfile

@@ -10,6 +10,7 @@ group :development do
   gem 'activesupport'
   gem 'bump', '~> 0.6.1'
   gem 'pry'
+  gem 'rake'
   gem 'rubocop', '0.54.0'
   gem 'rubocop-git'
   gem 'ruby-prof'

Gemfile.lock

@@ -1,7 +1,7 @@
 PATH
   remote: .
   specs:
-    contextual_logger (0.3.1)
+    contextual_logger (0.4.pre.2)
       activesupport
       json
 
@@ -38,6 +38,7 @@ GEM
       coderay (~> 1.1.0)
       method_source (~> 0.9.0)
     rainbow (3.0.0)
+    rake (13.0.1)
     rspec (3.8.0)
       rspec-core (~> 3.8.0)
       rspec-expectations (~> 3.8.0)
@@ -89,6 +90,7 @@ DEPENDENCIES
   contextual_logger!
   coveralls
   pry
+  rake
   rspec
   rspec_junit_formatter
   rubocop (= 0.54.0)
@@ -97,4 +99,4 @@ DEPENDENCIES
   ruby-prof-flamegraph
 
 BUNDLED WITH
-   1.16.4
+   1.17.3

Rakefile

@@ -0,0 +1,14 @@
+#!/usr/bin/env rake
+# frozen_string_literal: true
+
+require "bundler/gem_tasks"
+require 'rubygems'
+require 'bundler/setup'
+
+
+require 'rspec/core/rake_task'
+
+RSpec::Core::RakeTask.new(:spec)
+
+task test: :spec
+task default: :spec

contextual_logger.gemspec

@@ -2,7 +2,7 @@
 
 Gem::Specification.new do |spec|
   spec.name        = 'contextual_logger'
-  spec.version     = '0.3.1'
+  spec.version     = '0.4.pre.2'
   spec.license     = 'MIT'
   spec.date        = '2018-10-12'
   spec.summary     = 'Add context to your logger'
@@ -11,7 +11,10 @@ Gem::Specification.new do |spec|
   spec.email       = 'jebentier@invoca.com'
   spec.files       = Dir['lib/**/*']
   spec.homepage    = 'https://rubygems.org/gems/contextual_logger'
-  spec.metadata    = { 'source_code_uri' => 'https://github.com/Invoca/contextual_logger' }
+  spec.metadata    = {
+    "source_code_uri"   => "https://github.com/Invoca/process_settings",
+    "allowed_push_host" => "https://rubygems.org"
+  }
 
   spec.add_runtime_dependency 'json'
   spec.add_runtime_dependency 'activesupport'

lib/contextual_logger.rb

@@ -5,94 +5,98 @@
 require_relative './contextual_logger/context/handler'
 
 module ContextualLogger
-  def self.new(logger)
-    logger.extend(self)
+  class << self
+    def new(logger)
+      logger.extend(LoggerMixin)
+    end
   end
 
-  def global_context=(context)
-    ContextualLogger::Context::Handler.new(context).set!
-  end
+  module LoggerMixin
+    def global_context=(context)
+      Context::Handler.new(context).set!
+    end
 
-  def with_context(context)
-    context_handler = ContextualLogger::Context::Handler.new(current_context_for_thread.deep_merge(context))
-    context_handler.set!
-    if block_given?
-      yield
-    else
-      context_handler
+    def with_context(context)
+      context_handler = Context::Handler.new(current_context_for_thread.deep_merge(context))
+      context_handler.set!
+      if block_given?
+        begin
+          yield
+        ensure
+          context_handler.reset!
+        end
+      else
+        # If no block given, the context handler is returned to the caller so they can handle reset! themselves.
+        context_handler
+      end
     end
-  ensure
-    context_handler.reset! if block_given?
-  end
 
-  def current_context_for_thread
-    ContextualLogger::Context::Handler.current_context
-  end
+    def current_context_for_thread
+      Context::Handler.current_context
+    end
 
-  def format_message(severity, timestamp, progname, message, context)
-    message_with_context = message_with_context(context, message, severity, timestamp, progname)
+    def debug(message = nil, context = {})
+      add_if_enabled(Logger::Severity::DEBUG, message || yield, context: context)
+    end
 
-    if @formatter
-      @formatter.call(severity, timestamp, progname, message_with_context)
-    else
-      "#{message_with_context.to_json}\n"
+    def info(message = nil, context = {})
+      add_if_enabled(Logger::Severity::INFO, message || yield, context: context)
     end
-  end
 
-  def debug(progname = nil, **extra_context, &block)
-    add(Logger::Severity::DEBUG, nil, progname, extra_context, &block)
-  end
+    def warn(message = nil, context = {})
+      add_if_enabled(Logger::Severity::WARN, message || yield, context: context)
+    end
 
-  def info(progname = nil, **extra_context, &block)
-    add(Logger::Severity::INFO, nil, progname, extra_context, &block)
-  end
+    def error(message = nil, context = {})
+      add_if_enabled(Logger::Severity::ERROR, message || yield, context: context)
+    end
 
-  def warn(progname = nil, **extra_context, &block)
-    add(Logger::Severity::WARN, nil, progname, extra_context, &block)
-  end
+    def fatal(message = nil, context = {})
+      add_if_enabled(Logger::Severity::FATAL, message || yield, context: context)
+    end
 
-  def error(progname = nil, **extra_context, &block)
-    add(Logger::Severity::ERROR, nil, progname, extra_context, &block)
-  end
+    def unknown(message = nil, context = {})
+      add_if_enabled(Logger::Severity::UNKNOWN, message || yield, context: context)
+    end
 
-  def fatal(progname = nil, **extra_context, &block)
-    add(Logger::Severity::FATAL, nil, progname, extra_context, &block)
-  end
+    def log_level_enabled?(severity)
+      severity >= level
+    end
 
-  def unknown(progname = nil, **extra_context, &block)
-    add(Logger::Severity::UNKNOWN, nil, progname, extra_context, &block)
-  end
+    def add_if_enabled(severity, message, context:)
+      if log_level_enabled?(severity)
+        @progname ||= nil
+        write_entry_to_log(severity, Time.now, @progname, message, context: current_context_for_thread.deep_merge(context))
+      end
+      true
+    end
 
-  def add(severity, message = nil, progname = nil, extra_context = nil)
-    severity ||= UNKNOWN
-    if @logdev.nil? || (severity < @level)
-      return true
+    def write_entry_to_log(severity, timestamp, progname, message, context:)
+      @logdev&.write(format_message(format_severity(severity), timestamp, progname, message, context: context))
     end
-    progname ||= @progname
-    if message.nil?
-      if block_given?
-        message = yield
+
+    private
+
+    def format_message(severity, timestamp, progname, message, context: {})
+      message_hash = message_hash_with_context(severity, timestamp, progname, message, context: context)
+
+      if @formatter
+        @formatter.call(severity, timestamp, progname, message_hash)
       else
-        message = progname
-        progname = @progname
+        "#{message_hash.to_json}\n"
       end
     end
-    write_entry_to_log(severity, Time.now, progname, message, current_context_for_thread.deep_merge(extra_context || {}))
-    true
-  end
-
-  def write_entry_to_log(severity, timestamp, progname, message, context)
-    @logdev.write(format_message(format_severity(severity), timestamp, progname, message, context))
-  end
 
-  private
+    def message_hash_with_context(severity, timestamp, progname, message, context:)
+      message_hash =
+        {
+          message:   message,
+          severity:  severity,
+          timestamp: timestamp
+        }
+      message_hash[:progname] = progname if progname
 
-  def message_with_context(context, message, severity, timestamp, progname)
-    context.merge(
-      message: message,
-      severity: severity,
-      timestamp: timestamp,
-      progname: progname
-    )
+      message_hash.merge!(context)
+    end
   end
 end

lib/contextual_logger/logger_with_context.rb

@@ -0,0 +1,65 @@
+# frozen_string_literal: true
+
+module ContextualLogger
+  # A logger that deep_merges additional context and then delegates to the given logger.
+  # Keeps it own log level (called override_level) that may be set independently of the logger it delegates to.
+  # If override_level is non-nil, it takes precedence; if it is nil (the default), then it delegates to the logger.
+  class LoggerWithContext
+    include LoggerMixin
+
+    attr_reader :logger, :override_level, :context
+
+    def initialize(logger, context, level: nil)
+      logger.is_a?(LoggerMixin) or raise ArgumentError, "logger must include ContextualLogger::LoggerMixin (got #{logger.inspect})"
+      @logger = logger
+      self.level = level
+      @context = context
+      @merged_context_cache = {}  # so we don't have to merge every time
+    end
+
+    def level
+      @override_level || @logger.level
+    end
+
+    def level=(override_level)
+      @override_level =
+        if (Logger::Severity::DEBUG..Logger::Severity::UNKNOWN).include?(override_level) || override_level.nil?
+          override_level
+        else
+          case override_level.to_s.downcase
+          when 'debug'
+            Logger::Severity::DEBUG
+          when 'info'
+            Logger::Severity::INFO
+          when 'warn'
+            Logger::Severity::WARN
+          when 'error'
+            Logger::Severity::ERROR
+          when 'fatal'
+            Logger::Severity::FATAL
+          when 'unknown'
+            Logger::Severity::UNKNOWN
+          else
+            raise ArgumentError, "invalid log level: #{override_level.inspect}"
+          end
+        end
+    end
+
+    def write_entry_to_log(severity, timestamp, progname, message, context:)
+      merged_context =
+        if @merged_context_cache.size >= 1000 # keep this cache memory use finite
+          @merged_context_cache[context] || @context.deep_merge(context)
+        else
+          @merged_context_cache[context] ||= @context.deep_merge(context)
+        end
+
+      @logger.write_entry_to_log(severity, timestamp, progname, message, context: merged_context)
+    end
+
+    class << self
+      def for_log_source(logger, log_source, level: nil)
+        new(logger, { log_source: log_source }, level: level)
+      end
+    end
+  end
+end