Verified Commit 6ce7171c authored by Bob Van Landuyt's avatar Bob Van Landuyt 💬
Browse files

Include context data in all log messages 

This way, the callers of this logger don't need to explicitly add the
context, we'll add it in every log message automatically.
parent 56f59d24

lib/labkit/logging/json_logger.rb

+1 −1
Original line number Diff line number Diff line
@@ -31,7 +31,7 @@ module Labkit 
        data = default_attributes

        data[:severity] = severity

        data[:time] = timestamp.utc.iso8601(3)

        data[Labkit::Correlation::CorrelationId::LOG_KEY] = Labkit::Correlation::CorrelationId.current_id

        data.merge!(Labkit::Context.current.to_h)



        case message

        when String

spec/labkit/logging/json_logger_spec.rb

+26 −4
Original line number Diff line number Diff line
@@ -7,8 +7,8 @@ RSpec.describe Labkit::Logging::JsonLogger do 


  let(:now) { Time.now }



  before do

    allow(Labkit::Correlation::CorrelationId).to receive(:current_id).and_return("new-correlation-id")

  around do |example|

    Labkit::Context.with_context { example.run }

  end



  describe ".initialize" do
@@ -107,7 +107,7 @@ RSpec.describe Labkit::Logging::JsonLogger do 
    expect(data["severity"]).to eq("INFO")

    expect(data["time"]).to eq(now.utc.iso8601(3))

    expect(data["message"]).to eq("Hello world")

    expect(data["correlation_id"]).to eq("new-correlation-id")

    expect(data["correlation_id"]).to be_present

  end



  it "formats hashes" do
@@ -118,7 +118,7 @@ RSpec.describe Labkit::Logging::JsonLogger do 
    expect(data["time"]).to eq(now.utc.iso8601(3))

    expect(data["hello"]).to eq(1)

    expect(data["message"]).to be_nil

    expect(data["correlation_id"]).to eq("new-correlation-id")

    expect(data["correlation_id"]).to be_present

  end



  it "uses indifferent log key access" do
@@ -129,6 +129,28 @@ RSpec.describe Labkit::Logging::JsonLogger do 
    expect(data["world"]).to eq(2)

  end



  it "includes the logging context in the message" do

    Labkit::Context.with_context("hello" => "world") do

      output = subject.format_message("INFO", now, "test", "Log message")

      data = JSON.parse(output)



      expect(data).to include(

        "correlation_id" => Labkit::Correlation::CorrelationId.current_id, "#{Labkit::Context::LOG_KEY}.hello" => "world",

      )

    end

  end



  it "does not override logging context passed directly into the message" do

    Labkit::Context.with_context("hello" => "world") do

      output = subject.format_message("INFO", now, "test", { "#{Labkit::Context::LOG_KEY}.hello" => "brave world" })

      data = JSON.parse(output)



      expect(data).to include(

        "correlation_id" => Labkit::Correlation::CorrelationId.current_id, "#{Labkit::Context::LOG_KEY}.hello" => "brave world",

      )

    end

  end



  describe "reserved log keys" do

    let(:reserved_key_data) { described_class::RESERVED_LOG_KEYS.to_h { |k| [k, 42] } }

    let(:expected_error) { /^The following log keys used are reserved: #{described_class::RESERVED_LOG_KEYS.join(", ")}.*/ }