Rspec after hook being called before spec finishs

[rafaels]

I am having trouble with a scenario where I only do:

• click_link, which will fire an ajax request
• find something
• on a after(:each), I run DatabaseCleaner.clean

The problem is, the ajax request is running at the same moment of the after(:each) block, which causes me to have a nil association in the model code.

It is the real issue. I think that if I have a spec, it's after hooks should only run after all requests from this test are terminated. In my case I was getting controller and model code running at the same time as my DatabaseCleaner.clean, driving me to random errors when associations were not at the database anymore.

I think it is a way important issue, cause I heard from people problems that fits it.

For example, if I have an js: true spec and inside this spec I interact with the page and some ajax requests are fired, but my spec isn't testing this specific ajax requests, this problem can easily arrive. Say this ajax request is slow and the real spec finished without needing the response from this ajax. The example will pass at the beginning but the ajax will fail the example later because it needs somethings at the database.

Please, if I can help more, get in touch.

I am using capybara + rspec + poltergeist.

PS. I resolved my problem with a better find, which will only be true when the ajax request returns and js renders the stuff. But this 'issue' showed me the above issue.

[jnicklas]

Try moving DatabaseCleaner to an around hook instead. Those are executed after the after hook. This way Capybara.reset_sessions! is called before the database is cleaned out, which should hopefully prevent errors like this.

[jnicklas]

Essentially, you want to end up with this:

Capybara.reset_sessions!
DatabaseCleaner.clean

Not this:

DatabaseCleaner.clean
Capybara.reset_sessions!

[rafaels]

I tried the around hook with:

config.around(:each) do |example|
    puts 'database.cleaner.start.before'
    DatabaseCleaner.start
    puts 'database.cleaner.start.after'
    example.run
    puts 'database.cleaner.clean.before'
    DatabaseCleaner.clean
    puts 'database.cleaner.clean.after'
end

And something similar in my application code. (pry doesn't help here)
Still getting 'database.cleaner.clean.before' being executed side by side with my application code.

Any thoughts why? Maybe poltergeist reset! is asynchronous or something like that?

[rafaels]

Also, with this around approach I am having deadlock problems.

PG::Error: ERROR: deadlock detected
DETAIL: Process 7591 waits for AccessExclusiveLock on relation 148666 of database 148517; blocked by process 7660.
Process 7660 waits for RowExclusiveLock on relation 148636 of database 148517; blocked by process 7591.

[jopotts]

I hit this deadlock issue too, but discovered what was causing it in my situation so I'll explain for the good of all:

click_on 'signup_button'  # Which does an AJAX redirect to /dashboard
# then either
assert_equal dashboard_path, current_path  # Fail: This causes the deadlock as Capybara doesn't wait.
# or
assert page.has_selector?("#dashboard")  # Works: This works as it causes Capybara to wait for the new page.

Here's the ultimate writeup (by Capybara author) to aid understanding: http://www.elabs.se/blog/53-why-wait_until-was-removed-from-capybara

[filipegiusti]

@rafaels could you find the issue?

[jnicklas]

Since visit is async in a lot of drivers, this could actually mean that reset! is async as well, since it basically does visit "about:blank" for most drivers. Not sure how best to solve this. Waiting for the page to be blank might be slow. We should probably enforce that reset! is sync.

[sjmadsen]

I believe I'm seeing this same problem, with both capybara-webkit and poltergeist drivers. A set of my specs all pass when run individually, but if I use :focus to run 2-3 of them at once, one of them will randomly fail with an error in the server while rendering an Ajax response. Pausing the spec run with a debugger and analyzing the database reveals it to be empty.

In my case, all of the specs that I've seen fail have Capybara assertions that look for something on the page, and therefore should be waiting for the Ajax to complete.

[kbaum]

@sjmadsen - i am also seeing this problem sporadically. Seems like i have proper assertions too. Would it be possible to just kill all database pids before running DatabaseCleaner? I am using postgres and i tried doing this but it didn't seem to help:

  config.after(:each) do
    ActiveRecord::Base.connection.execute( %Q{
      SELECT 
          pg_cancel_backend(procpid) 
      FROM 
          pg_stat_activity 
      WHERE 
          procpid <> pg_backend_pid()
          AND datname = '#{ActiveRecord::Base.connection.current_database}'
      ;
    })
    DatabaseCleaner.clean
  end

Not sure why that didn't help...

[sjmadsen]

I also saw deadlocks when moving DatabaseCleaner.clean to an around hook. For now I am tolerating the false positive failures and hoping for some traction here.

@kbaum The problem isn't deadlocks for me, but rather DatabaseCleaner getting to run too soon. Even in the case of a deadlock, though, killing the connection is addressing a symptom, not the root cause.

[kbaum]

@sjmadsen - In one sense, i agree that it is addressing the symptom, but at the point DatabaseCleaner is cleaning the database the tests are over. I can see an argument that DatabaseCleaner is supposed to clear everything from the database including data and locks. Why should the developer have to worry about this? Isn't the point to make testing easier?

[sjmadsen]

@kbaum The original problem in this issue was that the tests are not over, and yet DatabaseCleaner has cleaned out the database. In my case, an Ajax request is still in-flight and the response blows up because an associated record is suddenly gone.

To your larger point, I agree that the programmer should not have to worry about stale locks. If this is a Capybara problem, then only Capybara developers (or someone willing to dig into the code) has to think about it. Everyone else benefits from the fix. In general, papering over a symptom is bad practice. You might fix a deadlock by killing the process, but since the root cause has not been resolved, it will likely cause other failures elsewhere.

I may have time later today to dig into this. I'll send a PR if I come up with anything.

[sjmadsen]

Like @rafaels, my issue ultimately ended up being a badly designed finder. This stuff can get tricky with Ajax, so for any future person stumbling across this:

In my case, I have a section of the page that expands and collapses via a link. Inside the expanded section, I have a form that allows the user to add a new record. Upon clicking the submit button, the new record is created and only that part of the page is refreshed. Here's the key part: I don't want the expanded part to stay expanded.

So I wrote two examples: one to test that the new record was properly added, the second that the "expand" link didn't appear (it should be "collapse").

The issue is that merely testing for the lack of the "expand" link wasn't enough. The link isn't there when the Ajax request starts, and so Capybara is happy and continues on. I had to add an extra expect() for something that wasn't on the page so that Capybara would properly wait for the Ajax request to complete, then test to ensure the expand link didn't exist. I end up testing that the new record was created twice, although the "success" example checks for a couple of other things, too.

Moving DatabaseCleaner to an around(:each) hook still causes deadlocks for me, but that is a separate issue from what this started as. If it's a real issue for someone, a new issue should probably be opened.

[mhuggins]

+1, I worked around this by duplicating a find call instead of working with an existing instance I previously assigned to a variable.

[kianw]

For me, checking current_path.should... was enough to ensure that Capybara hung around and waiting for the request to finish before running DatabaseCleaner. Previous code just reloaded some model objects and checked whether they had been updated, but that wasn't enough for Capybara to wait before it ran the cleaner. Interestingly, adding an "expect { ... }.to change(...).by(1)" around the click_on didn't keep it from running the cleaner too early. I didn't try the around hook, since so many are having trouble with it. Lesson learned: always check something on the page or the current_path as the last thing in a feature spec.

[jnicklas]

So I added 6b1e42d, which should hopefully make sure that reset is always synchronous. This plus ensuring the hooks are called in the right order, should resolve this issue.

[tmorris-fiksu]

I back-ported this to 2.0.3, and it has resolved the deadlocking problems that have been plaguing our specs. Any chance that we can get an official 2.0.4 release with this change? I'll be happy to pull together a pull request, if that would help.

[jnicklas]

Sounds sensible to me :) Are you having trouble upgrading to 2.1? There are some default changes, but largely I don't think we break compatibility anywhere between 2.0 and 2.1.

[tmorris-fiksu]

I was having the trouble detailed in this thread: thoughtbot/capybara-webkit#510 . Thanks for encouraging me to take another look at 2.1 - especially with the config work-around that you gave there, I think that upgrading will be a better option. So, don't count on a pull request from me! Looking forward to a 2.1.x versioned release with this deadlocking fix in it.

[ghost]

I follow what you said and use this in my spec_helper file

  config.after(:each) do
    Capybara.reset_sessions!
    DatabaseCleaner.clean
  end

and the version of capybara is 2.1 and I still get deadlock problem

hope it will be fixed soon

[tmorris-fiksu]

Capybara 2.2 includes the commit with the deadlocking fix. Have you tried 2.2? I was able to upgrade from 2.1 to 2.2 with no issues.

[ghost]

Sad news. Even I upgrade from 2.1 to 2.2 the deadlock bug still show up.

An error occurred in an after hook
  ActiveRecord::StatementInvalid: PG::TRDeadlockDetected: ERROR:  deadlock detected
DETAIL:  Process 12565 waits for AccessExclusiveLock on relation 227931 of database 227855; blocked by process 12563.
Process 12563 waits for RowExclusiveLock on relation 227916 of database 227855; blocked by process 12565.
HINT:  See server log for query details.
: TRUNCATE TABLE "messages", "topics", "users", "nodes", "replies", "stars", "watchings", "likes" RESTART IDENTITY CASCADE;
  occurred at /home/kkeys/.rvm/gems/ruby-2.0.0-p247/gems/activerecord-4.0.0/lib/active_record/connection_adapters/postgresql/database_statements.rb:128:in `exec'

[justin808]

I get this error as well with the latest versions and parallel rspec

    capybara (2.2.0)
    poltergeist (1.5.0)
    database_cleaner (1.2.0)
    parallel (0.9.0)
    parallel_tests (0.16.3)

I use rspec-retry:
rspec-retry (0.2.1)

And that prevents the suite from failing.

An error occurred in an after hook
  ActiveRecord::StatementInvalid: PG::TRDeadlockDetected: ERROR:  deadlock detected
DETAIL:  Process 49771 waits for AccessExclusiveLock on relation 3511516 of database 3479264; blocked by process 49689.
Process 49689 waits for AccessShareLock on relation 3511325 of database 3479264; blocked by process 49771.
HINT:  See server log for query details.
: ALTER TABLE "global_options" ENABLE TRIGGER USER;ALTER TABLE "schema_migrations" ENABLE TRIGGER USER;ALTER TABLE "shoot_types" ENABLE TRIGGER USER;ALTER TABLE "schedule_holidays" ENABLE TRIGGER USER;ALTER TABLE "images" ENABLE TRIGGER USER;ALTER TABLE "users" ENABLE TRIGGER USER;ALTER TABLE "locations" ENABLE TRIGGER USER;ALTER TABLE "tags" ENABLE TRIGGER USER;ALTER TABLE "delayed_jobs" ENABLE TRIGGER USER;ALTER TABLE "cancelled_photo_sessions" ENABLE TRIGGER USER;ALTER TABLE "website_images" ENABLE TRIGGER USER;ALTER TABLE "image_tags" ENABLE TRIGGER USER;ALTER TABLE "location_schedules" ENABLE TRIGGER USER;ALTER TABLE "schedSaved file /Users/justin/j/blink/bpos/tmp/capybara/screenshot_2013-12-14-16-12-50.456.html
ule_days" ENABLE TRIGGER USER;ALTER TABLE "schedules" ENABLE TRIGGER USER;ALTER TABLE "authentications" ENABLE TRIGGER USER;ALTER TABLE "order_items" ENABLE TRIGGER USER;ALTER TABLE "orders" ENABLE TRIGGER USER;ALTER TABLE "photo_sessions" ENABLE TRIGGER USER
  occurred at /Users/justin/.rvm/gems/ruby-2.0.0-p353@rails4/gems/activerecord-4.0.2/lib/active_record/connection_adapters/postgresql/database_statements.rb:128:in `exec'

RSpec::Retry: 3rd try ./spec/features/user_admin_spec.rb:30
Saved file /Users/justin/j/blink/bpos/tmp/capybara/screenshot_2013-12-14-16-12-53.344.html
RSpec::Retry: 4th try ./spec/features/user_admin_spec.rb:30
Saved file /Users/justin/j/blink/bpos/tmp/capybara/screenshot_2013-12-14-16-12-56.294.html
RSpec::Retry: 5th try ./spec/features/user_admin_spec.rb:30

[jaredbeck]

Still getting PG::TRDeadlockDetected in 2.2.0.

  capybara (~> 2.2.0)
  cucumber-rails (~> 1.4.0)
  database_cleaner (~> 1.2.0)
  poltergeist (~> 1.5.0)

I managed to reduce the chances of deadlock by sleeping after every cucumber scenario. Normally, cucumber-rails runs DatabaseCleaner.clean automatically, but that can be turned off with Cucumber::Rails::Database.autorun_database_cleaner = false and then .clean can be called manually in a cucumber hook.

[tmorris-fiksu]

I just saw the first spec deadlock error that I've seen in many weeks: PG::Error: ERROR: deadlock detected
I just went from v1.0.0 of capybara-webkit to v1.1.0; I browsed the changes in those versions, but nothing jumped out at me as the culprit.

[markburns]

For what it's worth, I've also been experiencing deadlocks, so far I can only narrow it down to a combination of parallel_tests and spring.

[andreaslyngstad]

I've also been experiencing deadlocks

I use guard and zeus. When I run all specs by just pressing enter i a guard console all is good, but when I save a controller spec (i.e just run one controller spec) I get

Failure/Error: Unable to find matching line from backtrace
     ActiveRecord::StatementInvalid:
       PG::TRDeadlockDetected: ERROR:  deadlock detected

It happends in this method

def login_user
    before(:each) do
      @request.env["devise.mapping"] = Devise.mappings[:user] 
      @user = FactoryGirl.create(:user) 
      sign_in @user
    end
  end

And I have this in the spec helper

config.after(:each) do
    Capybara.reset_sessions!
    DatabaseCleaner.clean
end

[webhat]

I was suffering from what I though was the same issue and discovered the following answer on SO I don't know if this helps any, and it helped me.

tl;dr: config.use_transactional_fixtures = false

Capybara with :js => true causes test to fail

[kdiogenes]

After upgranding from 2.1 to 2.2 and using the around hook the problem is solved for me.

[andrewhao]

Same issues with DatabaseCleaner running prior to the resolution of an AJAX call, solved with around fix and Capybara 2.3.

[Loremaster]

@markburns Did you find any way to solve this problem? I also have this problem, when run parallel_test (specs) and spring is installed.

[ka8725]

The problem arises because Capybara's hook in Rspec is executed before others. In my case it was DatabaseCleaner's after hook and it was truncating the database randomly. BTW, around hook not worked for me either. So my solution is very simple - just past capybara's initial stuff into bottom of spec/spec_helper.rb file:

ENV['RAILS_ENV'] ||= 'test'
require File.expand_path('../../config/environment', __FILE__)
require 'rspec/rails'
# Require here support files, other gems and init some other stuff
RSpec.configure do |config|
end

require 'capybara/rspec'
require 'capybara/poltergeist'
Capybara.javascript_driver = :poltergeist
# Other configuration of Capybara

Hope it helped you either.

[richkettle]

Im having the same issue.
It seems focused around a single example. Im 99% sure the example is fine:

context 'package details' do
  before do
    step_though_questions
  end

  it 'lets you through to the thank you page' do
    # submit package
    page.find(".standard_package.btn.btn-default").click

    fill_in_customer_details(self)
    # submit customer details
    page.find('.btn.btn-block.btn-call-to-action.green').click
    expect(page).to have_content(/Thank you/)
  end
end

def fill_in_customer_details
  fill_in("full_name", with: "Tester McTesterson")
  fill_in("address_building_name_or_number", with: "12")
  fill_in("address_postcode", with: FactoryGirl.generate(:postcode))
  fill_in("email", with: FactoryGirl.generate(:email))
  fill_in("landline", with: FactoryGirl.generate(:phone_number))
end

def step_though_questions
  visit '/new-thing'

  labels = ["label1", "label2", "label3", "label4"]

  # click through to the customer details step
  labels.each do |label|
    page.find("label[for=#{label}]").click
  end
end

Tried all the methods here. Around hook, moving the include still no luck.

capybara (2.4.1)
capybara-webkit (1.4.1)

Truncate setup looks like:

RSpec.configure do |config|
  config.before(:suite) do
    puts "set to truncate"
    DatabaseCleaner.clean_with :truncation
  end

  config.around(:each) do |example|
    puts "around each start"
    if example.metadata[:type] == :feature
      puts "its a feature spec!"
      DatabaseCleaner.strategy = :truncation
    else
      puts "its NOT a feature spec!"
      DatabaseCleaner.strategy = :transaction
    end
    example.run
    puts "DatabaseCleaner.start"
    DatabaseCleaner.start
    puts "around each end"
  end

  config.after(:each) do
    puts "DatabaseCleaner.clean"
    DatabaseCleaner.clean
  end
end

In my debugging I have found that the /new-thing visit either happens twice or the new action on the controller is being called twice. Logging looks like:

set to truncate
around each start
its a feature spec!
in new action
trying to find something
after finding the thing
DatabaseCleaner.clean
in new action
trying to find the thing *Error occurs here and fails the spec*
DatabaseCleaner.start
around each end

I have accidentally stumbled across two solutions but I have no idea how or why either of them work.

The first one was in the controller action. Where I was getting the no method error on foos.

@foo = Foo::FooType.find_by(:slug => foo_slug).foos.build

became

@foo = Foo::FooType.find_by!(:slug => foo_slug).foos.build

The bang seemingly makes the spec pass 100% of the time????

The other solution I came up with found was to add page.save_screenshot('screenshot.png') after the expect line of the spec. I'm not sure how or why I put it there, I just did. I did read somewhere that you should always check for something on the page at the end of a spec like this so that capybara waits and starts the next example correctly. It may have something to do with it.

This might help get to the bottom of the problem or at least help someone.

[mkllnk]

We are using Capybara 2.2.1 with Poltergeist 1.5.0 and had deadlocks in feature specs. The problem were unfinished Ajax calls at the end of the spec. The database cleaner tried to change stuff that was still in use.

Our current solution was finding all Ajax calls and waiting for them to finish. That's not ideal and I'm thinking of implementing this: http://blog.salsify.com/engineering/tearing-capybara-ajax-tests

Any better ideas?

[kbaum]

We use an especially after hook that hits a simple page that has no Ajax. This causes capybara to wait until Ajax is complete within the actual spec.

On Wed, Sep 16, 2015 at 12:14 AM, Maikel [email protected] wrote:

We are using Capybara 2.2.1 with Poltergeist 1.5.0 and had deadlocks in feature specs. The problem were unfinished Ajax calls at the end of the spec. The database cleaner tried to change stuff that was still in use.
Our current solution was finding all Ajax calls and waiting for them to finish. That's not ideal and I'm thinking of implementing this: http://blog.salsify.com/engineering/tearing-capybara-ajax-tests

Any better ideas?

Reply to this email directly or view it on GitHub:
#1089 (comment)

[mkllnk]

Is that the same as this?

config.after(:each) do
    Capybara.reset_sessions!
    DatabaseCleaner.clean
end

And isn't there still the case that a request was cancelled but the server is still busy completing the request? We have some computations that take a bit longer...

I'm using a slightly modified version of the rack request blocker from salsify in spec_helper.rb:

  config.after(:each, js:true) do
    Capybara.reset_sessions!
    RackRequestBlocker.wait_for_requests_complete
    DatabaseCleaner.clean
  end

It has been working fine, but increased the run time of the test suite by maybe 5%.

[nambrot]

Has anyone ever found an explicit reason for this failing. For our most recent tests, RSpec seems to induce the teardown by DatabaseCleaner before everything has finished, but for the life of me I cannot figure out why

[twalpole]

@nambrot It's generally caused by ajax requests that don't complete before the test finishes - Capybara does not know about these requests since the app is running separately and therefore doesn't wait for them to finish - There is no universal solution to this (other than maybe using a proxy to detect requests) - but if you know that all your ajax requests are using a specific library (jQuery, etc) then you can add an after hook to wait for the request count to be 0 before continuing

[nambrot]

@twalpole

but if you know that all your ajax requests are using a specific library (jQuery, etc) then you can add an after hook to wait for the request count to be 0 before continuing

I presume you mean to put this in the after hook where I use DatabaseCleaner?

I have a test case such as
expect { action }.to change{ ActionMailer::Base.deliveries.count }.by(1) and even if I have wait_for_ajax statements (based on Jquery ajax) which we use widely in our test suite, it doesnt actually wait.

[twalpole]

The after hook checking for ajax requests would need to execute before reset_sessions! is called (added in capybara/rspec if youve included that) and also before DatabaseCleaner after hook. The problem is that it's really a hack and has a number of weak points , such as the minute you add a JS library that creates native XHR requests , rather than going through jQuery, it no longer works, and if a request is initiated after you check but before the browser session gets reset it no longer works. It's much better to wait for a visible on screen change if possible.

[nambrot]

It's much better to wait for a visible on screen change if possible.

Inside the test or before the after hook in a separate after hook? Most of my tests check for screen changes, but the after hook for cleanup will still be called beforehand unfortunately

[jrochkind]

@jnicklas says:

So I added 6b1e42d, which should hopefully make sure that reset is always synchronous. This plus ensuring the hooks are called in the right order, should resolve this issue.

It is not clear to me the proper/supported/best-practice way to "ensure the hooks are called in the right order" with capybara and database cleaner.

I think I am running into this problem. Should DatabaseCleaner and/or Capybara docs be enhanced to explain the necessity of ensuring the hooks are called in the right order, and how to do that?

[twalpole]

@jorchkind The order hooks are called in is not a feature of Capybara or DatabaseCleaner, its defined by the test framework you're using - rspec, etc. As for the proper/supported/best-practice way, that needs to be defined by the programmer with a knowledge of what their app does. I'm locking this issue now, if you have questions on how to make things work with Capybara please ask them in the mailing list as requested in the README and CONTRIBUTING files.