Skip to content

Calling original failed when stubbing logger for ActiveSupport::TaggedLogging #2594

Open
@kimyu-ng

Description

@kimyu-ng

What Ruby, Rails and RSpec versions are you using?

Ruby version: 2.7+
Rails version: 7.0.2.3
RSpec version: 5.1.1

Observed behaviour

Tag from tagged logger is lost in between and content is not being honored when calling original if any logging (warn/info/debug/...) method is stubbed

Expected behaviour

The tagged logger content should be preserved when using and_call_original for stubbing any logging (warn/info/debug/...) methods

Can you provide an example app?

# frozen_string_literal: true

require 'bundler/inline'

gemfile(true) do
  source 'https://rubygems.org'

  git_source(:github) { |repo| "https://github.com/#{repo}.git" }

  gem 'rails', '~> 7.0.2.3'
  gem 'rspec-rails', '~> 5.1.1'
end

require 'active_support'
require 'active_support/core_ext/object/blank'

require 'action_controller/railtie'
require 'action_view/railtie'

require 'minitest/autorun'
class BugTest < Minitest::Test
  def test_custom_logger
    io = StringIO.new
    logger = ActiveSupport::Logger.new(io)
    tagged_logger = ActiveSupport::TaggedLogging.new(logger)

    tagged_logger.tagged('FOO') { |logger| logger.info 'bar 2333' }
    assert_equal "[FOO] bar 2333\n", io.string
  end
end

require 'rspec/autorun'
require 'rspec/rails'

RSpec.configure do |config|
  config.filter_run_excluding skip: true
  config.run_all_when_everything_filtered = true
  config.filter_run focus: true
end

RSpec.describe 'TaggedLogging' do
  let(:io) { StringIO.new }
  let(:logger) { Logger.new(io) }

  before do
    # commenting this out would allow the message pass through correctly
    allow(logger).to receive(:info).and_call_original

    tagged_logger = ActiveSupport::TaggedLogging.new(logger)
    tagged_logger.tagged('FOO') { |logger| logger.info 'bar 2333' }
  end

  it { expect(logger).to have_received(:info).once }

  it 'includes tags' do
    # Expectation: [FOO] bar 2333
    # Result: I, [2022-04-16T23:23:44.481396 #12280]  INFO -- : bar 2333
    expect(io.string).to eq("[FOO] bar 2333\n")
  end
end

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions