ryanwhocodes Mar 22, 2018 · 3 min read

How to test Ruby output and logs using RSpec with StringIO

Learn to capture Ruby output with StringIO to make testing your apps easier.

Testing what is logged when you application is run can be done with testing method calls to your logger. However, using StringIO to capture and examine its output can provide several advantages, such as being able to record output and perform tests on it as a String.

Contents

Testing logger method calls

One way is to use the RSpec syntax expect LOGGER to receive METHOD_NAME with INPUT. For example:

expect(logger).to receive(:info).with('test string')

The advantage of this approach is that you know exactly what method is called and what it would output.

However, you can run into issues with needing to stub a series of method calls if the logger is called multiple times during a method call or test example.

allow(logger).to receive(:info) { 'first message' }
allow(logger).to receive(:info) { 'second message' }

expect(logger).to receive(:info).with('test string')

For more examples see RSpec docs: method stubs.

Capture logger output with StringIO

An alternative to testing logger method calls is using StringIO.

Using StringIO means that you do not have to worry about stubbing method calls and messages being sent to the logger. You can simply see what has been logged as a string.

Ruby and Ruby on Rails Loggers can be initialized with a specified output, such as $stdout for Standard Output or $stderr for Standard Error. This means that you can also pass it a StringIO instance instead.

logger = Logger.new($stdout)

See more at Ruby Docs: Logger.

Rails.logger = Logger.new($stdout)

This is explained further in Rails Guides: What is the logger?

Passing a StringIO instance to your logger initialization means you can capture what it outputs.

output = StringIO.new
logger = Logger.new(output)
logger.info 'test string'
puts output.string
 => INFO -- : test string

Now, to write a class that uses a logger: here we are allowing the class to be initialized with an output, which is used when creating its logger.

require 'logger'

class LogPrinter
  def initialize(output = $stdout)
    @logger = Logger.new(output)
  end

  def choose_option(choice)
    @logger.info "You chose #{choice}"
  end
end

To test the Logger output using StringIO, pass the StringIO output object to the Logger instance, then the Logger instance to the class upon initialization.

require 'spec_helper'

RSpec.describe LogPrinter do
  let(:logger_output) { StringIO.new }

  def setup_app
    described_class.new(logger_output)
  end

  describe '#choose_option' do
    subject { setup_app }
    it "logs choice confirmation at INFO level" do
      subject.choose_option(2)
      expect(logger_output.string).to include 'INFO -- : You chose 2'
    end
  end
end

For more complex applications, an alternative design is to initialize a logger with an output, then pass this logger instance to the other classes that use it rather than having multiple logger instances.

Find out more

Writing clear and well-designed tests can help you produce stable and easy to maintain applications. To learn more check out the Ruby docs and my other posts.