From 00bdb6dbd991a9b3dadddad3af34d102ef0a87b8 Mon Sep 17 00:00:00 2001 From: Roman Samoilov <2270393+rsamoilov@users.noreply.github.com> Date: Fri, 6 Feb 2026 12:39:21 +0000 Subject: [PATCH] Support inline context for `Rage::Logger` --- lib/rage/logger/logger.rb | 52 ++++++++++++++---- spec/logger_spec.rb | 110 ++++++++++++++++++++++++++++++++++++-- 2 files changed, 148 insertions(+), 14 deletions(-) diff --git a/lib/rage/logger/logger.rb b/lib/rage/logger/logger.rb index 82d28b46..1dd31be9 100644 --- a/lib/rage/logger/logger.rb +++ b/lib/rage/logger/logger.rb @@ -190,19 +190,29 @@ def rebuild! if @logdev.nil? || level_val < @level # logging is disabled or the log level is higher than the current one <<-RUBY - def #{level_name}(msg = nil) + def #{level_name}(msg = nil, context = nil) false end RUBY elsif @external_logger.is_a?(External::Static) # an object that implements Ruby's Logger interface is used as a logger + write_call = <<~RUBY + @external_logger.wrapped.#{level_name}( + #{build_formatter_call(level_name, level_val)} + ) + RUBY + <<~RUBY - def #{level_name}(msg = nil) + def #{level_name}(msg = nil, context = nil) #{with_dynamic_tags_and_context do <<~RUBY - @external_logger.wrapped.#{level_name}( - #{build_formatter_call(level_name, level_val)} - ) + if context + with_context(context) do + #{write_call} + end + else + #{write_call} + end RUBY end} end @@ -223,23 +233,43 @@ def #{level_name}(msg = nil) request_info: "Fiber[:__rage_logger_final].freeze" }) + write_call = <<~RUBY + @external_logger.wrapped.call(#{parameters}) + RUBY + <<~RUBY - def #{level_name}(msg = nil) + def #{level_name}(msg = nil, context = nil) #{with_dynamic_tags_and_context do <<~RUBY - @external_logger.wrapped.call(#{parameters}) + if context + with_context(context) do + #{write_call} + end + else + #{write_call} + end RUBY end} end RUBY else + write_call = <<~RUBY + @logdev.write( + #{build_formatter_call(level_name, level_val)} + ) + RUBY + <<~RUBY - def #{level_name}(msg = nil) + def #{level_name}(msg = nil, context = nil) #{with_dynamic_tags_and_context do <<~RUBY - @logdev.write( - #{build_formatter_call(level_name, level_val)} - ) + if context + with_context(context) do + #{write_call} + end + else + #{write_call} + end RUBY end} end diff --git a/spec/logger_spec.rb b/spec/logger_spec.rb index 4720120b..3106cb5c 100644 --- a/spec/logger_spec.rb +++ b/spec/logger_spec.rb @@ -195,6 +195,39 @@ end end + context "with inline context" do + it "adds a key to an entry" do + subject.info "passed", test_id: "1133" + expect(io.tap(&:rewind).read).to eq("[my_test_tag] timestamp=very_accurate_timestamp pid=777 level=info test_id=1133 message=passed\n") + end + + it "adds multiple keys to an entry" do + subject.info "passed", test_id: "1133", user_id: 12345 + expect(io.tap(&:rewind).read).to eq("[my_test_tag] timestamp=very_accurate_timestamp pid=777 level=info test_id=1133 user_id=12345 message=passed\n") + end + + it "works correctly with multiple nesting levels" do + subject.tagged("rspec") do + subject.debug "debug message", user_id: 123 + + subject.with_context(b: 222) do + subject.tagged("test_tag") do + subject.info "info message", user_id: 456 + + subject.with_context(c: "333", d: "444") do + subject.unknown "unknown message", user_id: 789 + end + end + end + end + + io.rewind + expect(io.readline).to eq("[my_test_tag][rspec] timestamp=very_accurate_timestamp pid=777 level=debug user_id=123 message=debug message\n") + expect(io.readline).to eq("[my_test_tag][rspec][test_tag] timestamp=very_accurate_timestamp pid=777 level=info b=222 user_id=456 message=info message\n") + expect(io.readline).to eq("[my_test_tag][rspec][test_tag] timestamp=very_accurate_timestamp pid=777 level=unknown b=222 c=333 d=444 user_id=789 message=unknown message\n") + end + end + context "outside the request/response cycle" do before do Fiber[:__rage_logger_tags] = nil @@ -294,6 +327,12 @@ subject << "this is a test message" }.not_to raise_error end + + it "doesn't add inline context" do + expect( + subject.fatal("this is a test message", user_id: 567) + ).to be(false) + end end context "with LogDevice options" do @@ -314,9 +353,6 @@ end it "delegates logger calls to external logger" do - p "grep_me !!!!!!!" - p Fiber.current.storage - expect(external_logger).to receive(:info).with("[my_test_tag] timestamp=very_accurate_timestamp pid=777 level=info message=test\n") subject.info "test" @@ -334,6 +370,23 @@ end end + context "with custom inline context" do + it "correctly builds log entry" do + expect(external_logger).to receive(:info).with("[my_test_tag] timestamp=very_accurate_timestamp pid=777 level=info rspec=true message=test\n") + subject.info "test", rspec: true + end + end + + context "with merged context" do + it "correctly builds log entry" do + expect(external_logger).to receive(:info).with("[my_test_tag] timestamp=very_accurate_timestamp pid=777 level=info rspec=true user_id=123 account_id=456 message=test\n") + + subject.with_context(rspec: true) do + subject.info "test", user_id: 123, account_id: 456 + end + end + end + context "with custom tags" do it "correctly builds log entry" do expect(external_logger).to receive(:info).with("[my_test_tag][rspec][tags_test] timestamp=very_accurate_timestamp pid=777 level=info message=test\n") @@ -376,6 +429,13 @@ end end + context "with custom inline context" do + it "correctly builds log entry" do + expect(external_logger).to receive(:info).with("[my_test_tag] timestamp=very_accurate_timestamp pid=777 level=info id=12345 rspec=true message=test\n") + subject.info "test", rspec: true + end + end + context "with custom tags and context" do it "correctly builds log entry" do expect(external_logger).to receive(:info).with("[my_test_tag][rspec][tags_test] timestamp=very_accurate_timestamp pid=777 level=info rspec=true id=12345 message=test\n") @@ -443,6 +503,36 @@ end end + context "with custom inline context" do + it "correctly builds log entry" do + expect(external_logger).to receive(:call).with( + severity: :info, + tags: ["my_test_tag"], + context: { rspec: true }, + message: "test", + request_info: nil + ) + + subject.info "test", rspec: true + end + end + + context "with merged context" do + it "correctly builds log entry" do + expect(external_logger).to receive(:call).with( + severity: :info, + tags: ["my_test_tag"], + context: { rspec: true, user_id: 123 }, + message: "test", + request_info: nil + ) + + subject.with_context(rspec: true) do + subject.info "test", user_id: 123 + end + end + end + context "with custom tags" do it "correctly builds log entry" do expect(external_logger).to receive(:call).with( @@ -523,6 +613,20 @@ end end + context "with custom inline context" do + it "correctly builds log entry" do + expect(external_logger).to receive(:call).with( + severity: :info, + tags: ["my_test_tag"], + context: { id: 12345, rspec: true }, + message: "test", + request_info: nil + ) + + subject.info "test", rspec: true + end + end + context "with custom tags and context" do it "correctly builds log entry" do expect(external_logger).to receive(:call).with(