No terminal output with caypbara / rspec / selenium-webdriver

Question

I have been writing rspec tests using capybara and selenium-webdriver. Almost without fail, whenever I run one of these tests, the console output is gone.

For instance:

~/code/code> bundle exec rspec spec/features/interactions_spec.rb 

InteractionsSpec
~/code/code>

Thats just about all I ever see. The browser launches, performs the action's I've coded, but I don't see the usual output.

Sometimes I'll see this as output instead (yay!):

InteractionsSpec
  login as admin works
  login as user works

Finished in 16.84 seconds (files took 7.9 seconds to load)
2 examples, 0 failures

What could be causing the output from the tests to disappear? This makes it nearly impossible to write tests - as I have no idea what has run, what has passed, what has failed, or why they have failed.

I'm using these Gems, but performing a bundle update does not change the behavior.

capybara (2.4.4)
capybara-screenshot (1.0.3)
rspec (3.0.0)
rspec-activemodel-mocks (1.0.1)
rspec-collection_matchers (1.0.0)
rspec-core (3.0.3)
rspec-expectations (3.0.3)
rspec-mocks (3.0.3)
rspec-rails (3.0.2)
rspec-support (3.0.3)
selenium-webdriver (2.44.0)
shoulda-matchers (2.6.2)

Other involved software:

Firefox 33.1.1 (Chrome 39.0.2171.65 (64-bit) has the same behavior)
OSX 10.9.5
Rails 4.1.4

Update This seemed to fix the problem for a while, even with a sleep of 1ms. However, that was only a temporary fix and this problem persists.

RSpec.configure do |config|
  config.before(:each, :type => :feature) do
    sleep(0.5)
  end
end

Some things I've tried: reinstalling ruby and all gems, upgrading chrome, upgrading chrome driver, changing the sleep before each spec (random, long, short) — John Naegle

Rob Rob · Accepted Answer · 2015-02-13T15:24:40

Looks to me like the logger is getting silenced via a call to logger.silence() by some other thread.

When you put the sleep() in the code, then you yielded to some other thread that fixed the logging level - that's why it didn't matter how long the sleep was, it was the context switch that was fixing the issue.

When you upgraded the activesupport gem, this commit here https://github.com/rails/activerecord-session_store/commit/f92d1135fc620cb4d65239ef286b267945bbbbc6 fixes the issue (as you said). Reading that commit, notice a new threadsafe implementation of logger.silence. That's why it fixes your issue.

The old implementation of active_support/logger_silence.rb here isn't threadsafe:

require 'active_support/concern'

module LoggerSilence
  extend ActiveSupport::Concern

  included do
    cattr_accessor :silencer
    self.silencer = true
  end

  # Silences the logger for the duration of the block.
  def silence(temporary_level = Logger::ERROR)
    if silencer
      begin
        old_logger_level, self.level = level, temporary_level
        yield self
      ensure
        self.level = old_logger_level
      end
    else
      yield self
    end
  end
end

No terminal output with caypbara / rspec / selenium-webdriver

2 Answers