RSpec: 如何测试Rails日志记录器消息的期望？

Question

我试图在我的一些测试中测试Rails日志记录器是否接收到消息。我使用了Logging gem。

假设我有一个像这样的类:

class BaseWorker

  def execute
    logger.info 'Starting the worker...'
  end

end

还有一个类似这样的规范：

describe BaseWorker do

  it 'should log an info message' do
    base_worker = BaseWorker.new
    logger_mock = double('Logging::Rails').as_null_object
    Logging::Rails.stub_chain(:logger, :info).and_return(logger_mock)

    logger_mock.should_receive(:info).with('Starting the worker...')
    base_worker.execute
    Logging::Rails.unstub(:logger)
  end

end

我收到以下失败消息：

 Failure/Error: logger_mock.should_receive(:info).with('Starting worker...')
   (Double "Logging::Rails").info("Starting worker...")
       expected: 1 time
       received: 0 times

我尝试了几种不同的方法来使规范通过。例如，这个方法可行：

class BaseWorker

  attr_accessor :log

  def initialize
    @log = logger
  end

  def execute
    @log.info 'Starting the worker...'
  end

end

describe BaseWorker do
  it 'should log an info message' do
    base_worker = BaseWorker.new
    logger_mock = double('logger')
    base_worker.log = logger_mock

    logger_mock.should_receive(:info).with('Starting the worker...')
    base_worker.execute
  end
end

但是，必须设置一个可访问的实例变量似乎不太合理。(实际上，我甚至不确定为什么将logger复制到@log会使其通过。)

有没有测试日志记录的好方法？

- keruilin

---

这个问题在SO上出现了几次，例如这里和这里，普遍的共识是，除非项目要求，否则不需要测试日志记录。 - Art Shayderov

Art，感谢您的评论。我确实阅读了那些内容。那可能是最终答案。 - keruilin

Answer 1

虽然我同意通常不希望测试日志记录器，但有时它可能很有用。

我已经成功地使用期望（expectations）来测试 Rails.logger。

使用 RSpec 的已弃用的 should 语法：

Rails.logger.should_receive(:info).with("some message")

使用RSpec的新版expect语法：

expect(Rails.logger).to receive(:info).with("some message")

注意: 在控制器和模型的规范中，你必须在记录信息之前放置这行代码。如果你将其放置在之后，你将会得到如下错误信息：

Failure/Error: expect(Rails.logger).to receive(:info).with("some message")
       (#<ActiveSupport::Logger:0x007f27f72136c8>).info("some message")
           expected: 1 time with arguments: ("some message")
           received: 0 times

- Tanzeeb Khalili

---

我有一个类似的情况，但我的期望字符串是部分字符串，到目前为止我还无法弄清楚如何处理它，需要帮助吗？ - Amol Pujari

希望(Rails.logger).to接收(:info).with(/partial_string/)，其中"partial_string"是您要查找的字符串。简单的正则表达式比较。 - absessive

太棒了，我正在检查是否没有任何内容记录到错误日志，并使用Rspec的anything匹配器进行检查：expect(Rails.logger).to_not receive(:error).with(anything) - mr_than

“你需要在记录信息之前放置这行代码” 是什么意思？期望是在生成日志的代码之前出现吗？我已经这样做了，但是会出现错误，因为记录器会获取在“it”块运行之前在我的 let 表达式中完成的工作所记录的消息。 - sixty4bit

@sixty4bit 这意味着，expext.. receive 作为事件侦听器工作 - 您必须先设置它，然后启动将记录您想要捕获的消息的代码。 - banesto

这在特性规范中不起作用（与控制器规范相反）吗？我正在使用上面的代码：expect(Rails.logger).to receive(:info).with(/foobar/)，放置在将生成日志的规范代码之前。我可以在规范运行后的 test.log 中清楚地看到 foobar 语句，但规范失败并显示上述错误。 - Sasgorilla

Answer 2

使用RSpec 3+版本

实际包含单个Rails.logger.error调用的代码：

Rails.logger.error "Some useful error message"

规格代码：

expect(Rails.logger).to receive(:error).with(/error message/)

如果您希望在规范运行时实际记录错误消息，请使用以下代码：

expect(Rails.logger).to receive(:error).with(/error message/).and_call_original

包含多个调用Rails.logger.error的实际代码：

Rails.logger.error "Technical Error Message"
Rails.logger.error "User-friendly Error Message"

规格代码：

expect(Rails.logger).to receive(:error).ordered
expect(Rails.logger).to receive(:error).with(/User-friendly Error /).ordered.and_call_original

如果只关心第一条消息而不是后续的消息，则可以使用以下方法匹配

  expect(Rails.logger).to receive(:debug).with("Technical Error Message").ordered.and_call_original
  expect(Rails.logger).to receive(:debug).at_least(:once).with(instance_of(String)).ordered

注意，在上面的变量设置中，.ordered 很重要，否则期望设置将开始失败。

参考文献：

http://www.relishapp.com/rspec/rspec-mocks/v/3-4/docs/setting-constraints/matching-arguments

http://www.relishapp.com/rspec/rspec-mocks/v/3-4/docs/setting-constraints/message-order

- Jignesh Gohel

Answer 3

不要在消息被记录之前使用以下这行代码：

expect(Rails.logger).to receive(:info).with("some message")
something that triggers the logger...

你可以将Rails日志记录器设置为间谍，并使用have_received代替：

allow(Rails.logger).to receive(:info).at_least(:once)

something that triggers the logger...

expect(Rails.logger).to have_received(:info).with("some message").once

- akira

---

我使用了第一种方法，但为什么这个 expect(Rails.logger).to receive(:info).with("A Report processing is already scheduled for: #{report.inspect}") 出现了错误： expected: ("A Report processing is already scheduled for: #<Report id: 2677, org_id: 6649, user_id: ...tion: nil, life_state: \"ideation\", chat_link: nil, discarded_at: nil, registrants_count: 2>") ---> got: ("A Report processing is already scheduled for: [#<Report id: 2677, org_id: 6649, user_id:...ion: nil, life_state: \"ideation\", chat_link: nil, discarded_at: nil, registrants_count: 2>]") (1 time)。 - alexventuraio

Answer 4

如果你的目标是测试日志记录功能，你也可以考虑验证输出到标准流的结果。

这将免去模拟过程，并测试消息是否实际上会到达它们应该到达的位置（STDOUT/STDERR）。

使用RSpec的output matcher（从3.0版本开始引入），你可以执行以下操作：

expect { my_method }.to output("my message").to_stdout
expect { my_method }.to output("my error").to_stderr

如果涉及到类库，例如Logger或Logging，您可能需要使用output.to_<>_from_any_process。

- thisismydesign

---

“_from_any_process” 是我一直缺少的！找了很久才找到。谢谢！ - Sean

Answer 5

如果您希望测试保持一致性，但在最后设置期望结果，您需要在设置中添加以下内容：

setup do
 allow(Rails.logger).to receive(:info)
end
...

it 'should log an info message' do
 {code}

  expect(Rails.logger).to have_received(:info).with('Starting the worker...')
end

- Paulo Fidalgo

Answer 6

已经有很多回答关于如何使用 RSpec 断言 Rails.logger.info 消息。

我将解释：如何在 Ruby on Rails 应用程序中的单元测试中断言 Rails.logger.info 消息，而不使用 RSpec。

require "stringio"
class MyTest < ActiveSupport::TestCase
  def test_log_output
    output = StringIO.new
    Rails.logger = Logger.new(output)
    
    # Make the API call or method that generates the log message
    some_method_that_logs()
    
    # Assert the log message
    assert_match("Expected log message", output.string)
  end
end

1. 你可以通过创建一个 StringIO 对象并将其设置为日志记录器的输出来捕获 Rails.logger 的输出。
2. 这将重定向所有日志消息到 StringIO 对象，允许你在测试后检查日志消息。

祝学习愉快 :)

- Anmol Shrivastav

Answer 7

即使我遇到了非常类似的错误：

Failure/Error: expect(Rails.logger).to receive(:info).with("some message")
       (#<ActiveSupport::Logger:0x007f27f72136c8>).info("some message")
           expected: 1 time with arguments: ("some message")
           received: 0 times

以下对我有效：

expect { my_method }.
            to output(/error messsage/).to_stdout_from_any_process

参考资料: https://relishapp.com/rspec/rspec-expectations/docs/built-in-matchers/output-matcher

- Nivetha R