From 2d567ed3400cc2656154045eb6824b0ba103febc Mon Sep 17 00:00:00 2001 From: grosser Date: Tue, 30 Dec 2014 12:51:36 -0800 Subject: [PATCH 1/2] fix done not logging when using with_context in a worker --- lib/sidekiq/logging.rb | 10 ++++------ test/test_logging.rb | 34 ++++++++++++++++++++++++++++++++++ 2 files changed, 38 insertions(+), 6 deletions(-) create mode 100644 test/test_logging.rb diff --git a/lib/sidekiq/logging.rb b/lib/sidekiq/logging.rb index 7dc6fe19..5156275a 100644 --- a/lib/sidekiq/logging.rb +++ b/lib/sidekiq/logging.rb @@ -17,12 +17,10 @@ module Sidekiq end def self.with_context(msg) - begin - Thread.current[:sidekiq_context] = msg - yield - ensure - Thread.current[:sidekiq_context] = nil - end + previous, Thread.current[:sidekiq_context] = Thread.current[:sidekiq_context], msg + yield + ensure + Thread.current[:sidekiq_context] = previous end def self.initialize_logger(log_target = STDOUT) diff --git a/test/test_logging.rb b/test/test_logging.rb new file mode 100644 index 00000000..da789039 --- /dev/null +++ b/test/test_logging.rb @@ -0,0 +1,34 @@ +require 'helper' +require 'sidekiq/logging' + +class TestFetcher < Sidekiq::Test + describe Sidekiq::Logging do + describe "#with_context" do + def context + Sidekiq::Logging.logger.formatter.context + end + + it "has no context by default" do + context.must_equal "" + end + + it "can add a context" do + Sidekiq::Logging.with_context "xx" do + context.must_equal " xx" + end + context.must_equal "" + end + + it "can use multiple contexts" do + Sidekiq::Logging.with_context "xx" do + context.must_equal " xx" + Sidekiq::Logging.with_context "yy" do + context.must_equal " yy" + end + context.must_equal " xx" + end + context.must_equal "" + end + end + end +end From a0baa23644937add5ec2ab77b479bcceb2b88083 Mon Sep 17 00:00:00 2001 From: grosser Date: Tue, 30 Dec 2014 13:01:30 -0800 Subject: [PATCH 2/2] use context as stack --- lib/sidekiq/logging.rb | 9 ++++++--- test/test_logging.rb | 8 ++++---- 2 files changed, 10 insertions(+), 7 deletions(-) diff --git a/lib/sidekiq/logging.rb b/lib/sidekiq/logging.rb index 5156275a..b5863c5f 100644 --- a/lib/sidekiq/logging.rb +++ b/lib/sidekiq/logging.rb @@ -5,6 +5,8 @@ module Sidekiq module Logging class Pretty < Logger::Formatter + SPACE = " " + # Provide a call() method that returns the formatted message. def call(severity, time, program_name, message) "#{time.utc.iso8601(3)} #{::Process.pid} TID-#{Thread.current.object_id.to_s(36)}#{context} #{severity}: #{message}\n" @@ -12,15 +14,16 @@ module Sidekiq def context c = Thread.current[:sidekiq_context] - c ? " #{c}" : '' + " #{c.join(SPACE)}" if c && c.any? end end def self.with_context(msg) - previous, Thread.current[:sidekiq_context] = Thread.current[:sidekiq_context], msg + Thread.current[:sidekiq_context] ||= [] + Thread.current[:sidekiq_context] << msg yield ensure - Thread.current[:sidekiq_context] = previous + Thread.current[:sidekiq_context].pop end def self.initialize_logger(log_target = STDOUT) diff --git a/test/test_logging.rb b/test/test_logging.rb index da789039..b98836a1 100644 --- a/test/test_logging.rb +++ b/test/test_logging.rb @@ -9,25 +9,25 @@ class TestFetcher < Sidekiq::Test end it "has no context by default" do - context.must_equal "" + context.must_equal nil end it "can add a context" do Sidekiq::Logging.with_context "xx" do context.must_equal " xx" end - context.must_equal "" + context.must_equal nil end it "can use multiple contexts" do Sidekiq::Logging.with_context "xx" do context.must_equal " xx" Sidekiq::Logging.with_context "yy" do - context.must_equal " yy" + context.must_equal " xx yy" end context.must_equal " xx" end - context.must_equal "" + context.must_equal nil end end end