Request spec order dependent failure (wrong SQL created for devise user update on login)

Question

We currently face a problem when a request spec fails (typo or other exception) it affects other request specs which actually should be unaffected. The problem is we use many gems so I tried to create a minimal reproduction app (without success, https://github.com/tak1n/reproduction)

The problem in detail:

We have a request spec where we need to login a user. For user authentication we use devise and therefore we use Warden::Test::Helpers to log in users in request specs. Devise automatically updates some user related attributes when a user logs in (last_sign_in_at, last_sign_in_ip etc..).

The problem here is that when it tries to save the user for doing this changes the end result is a INSERT INTO user instead of a UPDATE user and therefore it crashes.

Here is an example spec from our app:

require 'rails_helper'

RSpec.describe 'Suggestions API' do
  let(:user) { FactoryGirl.create(:user, :professional) }

  before do
    login(user) # same as in https://github.com/tak1n/reproduction/blob/master/spec/support/request_macros.rb#L6
  end

  describe '/suggestions.json', :vcr do
    context 'with non saved filter' do
      # some setup stuff here (setup proper objects in db)

      # also params are defined here through let(:params) { ... }

      it 'returns proper suggestions' do
        Suggestion.refresh!

        get '/suggestions.json', paramst

        expect(json.count).to eq(2)

        expect(json.first['id']).to eq(sug2.id)
        expect(json.second['id']).to eq(sug1.id)
      end
    end

    context 'with saved filter' do
      # some setup stuff here (setup proper objects in db)

      # also params are defined here through let(:params) { ... }

      it 'returns proper suggestions' do
        Suggestion.refresh!

        get '/suggestions.json', params

        expect(json.count).to eq(2)

        expect(json.first['id']).to eq(sug2.id)
        expect(json.second['id']).to eq(sug1.id)
      end
    end
  end
end

The result of this should be that the first spec fails because of the typo paramst, which it does but it also affects the second spec:

Here is the spec run: https://gist.github.com/tak1n/102c1aa121b66e0ab56602b76f911ec0

I tried to dig deeper and saw that the logic whether save creates or updates a record is depending on https://github.com/rails/rails/blob/master/activerecord/lib/active_record/persistence.rb#L85

Next I tried to output what @new_record was in that case.

def new_record?
  sync_with_transaction_state
  puts "New record: #{@new_record}" if self.class == User
  @new_record
end

I got following: https://gist.github.com/tak1n/330560a3a108abc8fce4d105a48ac444

When the specs run in different order (non failing first then spec with typo or exception in it) I got this: https://gist.github.com/tak1n/6eb24693226d8e6a713c0865ea1bebd5

The difference here is for the "working" spec run New Record: <boolean> is different. When the spec with the exception runs before it New record suddenly becomes true and therefore it generates SQL to create a new record.

Next I assumed some gems are causing this problem, most likely I thought it would be database_cleaner but in the reproduction I do more or less the same and there it works.

The problem is I'm really stuck at debugging and not sure where to proceed. Also I'm not sure which gem or our code itself is causing this.

Feel free to ask any questions if you need further details, thanks in advance.

Answer 1

Seems like the issue is caused by devise-async (https://github.com/mhfs/devise-async).

See https://github.com/rails/rails/issues/26038 and https://github.com/mhfs/devise-async/issues/96 for more information.