Test cases as described in mhfs/devise-async#96 They fail as described in mhfs/devise-async#96 (comment)
While debugging what I faced is as below:
User was created without issue & it went for login as below
7: setup do
8: @user = User.create!(
9: email: "herbertm1970#{SecureRandom.hex}@gmail.com",
10: password: 'testtest',
11: password_confirmation: 'testtest',
12: )
=> 13: login_as(user, scope: :user)
14: end
[78] pry(#<SomethingTest>)> user
=> #<User:0x007f94fc570c40
id: 179,
email: "herbertm1970fdf339d43f1eea5fe3382192840cd017@gmail.com",
encrypted_password: "$2a$04$GKRCFMNLaHlK0fcAiPN0LOo0dDAvQFsgM6RtDOciDGbzRW.cifuQa",
reset_password_token: nil,
reset_password_sent_at: nil,
remember_created_at: nil,
sign_in_count: 0,
current_sign_in_at: nil,
last_sign_in_at: nil,
current_sign_in_ip: nil,
last_sign_in_ip: nil,
created_at: Thu, 06 Oct 2016 07:31:34 UTC +00:00,
updated_at: Thu, 06 Oct 2016 07:31:34 UTC +00:00>
[79] pry(#<SomethingTest>)> step
From: /Users/SwapnilChincholkar/.rvm/gems/ruby-2.3.0@devise-async-repro/gems/warden-1.2.6/lib/warden/test/helpers.rb @ line 18 Warden::Test::Helpers#login_as
17: def login_as(user, opts = {})
=> 18: Warden.on_next_request do |proxy|
19: opts[:event] ||= :authentication
20: proxy.set_user(user, opts)
21: end
22: end
After successful login it went till get request without issue.
[80] pry(#<SomethingTest>)> next
From: /Users/SwapnilChincholkar/work/cloned_repos/devise-aync-issue96/test/integration/something_test.rb @ line 28 SomethingTest#test_returns_smth_#2
26: test 'returns smth #2' do
27: init
=> 28: params = {
29: format: :json
30: }
31:
32: binding.pry
33: # /something.json does not exist
34: get '/something.json', params
35: end
[80] pry(#<SomethingTest>)> next
[80] pry(#<SomethingTest>)> next
From: /Users/SwapnilChincholkar/work/cloned_repos/devise-aync-issue96/test/integration/something_test.rb @ line 34 SomethingTest#test_returns_smth_#2
26: test 'returns smth #2' do
27: init
28: params = {
29: format: :json
30: }
31:
32: binding.pry
33: # /something.json does not exist
=> 34: get '/something.json', params
35: end
Here intresting thing start happening.
[80] pry(#<SomethingTest>)> step
From: /Users/SwapnilChincholkar/.rvm/gems/ruby-2.3.0@devise-async-repro/gems/actionpack-4.2.7/lib/action_dispatch/testing/integration.rb @ line 337 ActionDispatch::Integration::Runner#get
336: define_method(method) do |*args|
=> 337: reset! unless integration_session
338:
339: # reset the html_document variable, except for cookies/assigns calls
340: unless method == 'cookies' || method == 'assigns'
341: @html_document = nil
342: @html_scanner_document = nil
343: reset_template_assertion
344: end
345:
346: integration_session.__send__(method, *args).tap do
347: copy_session_variables!
348: end
349: end
Here I entered into loop from line 346 i.e inside integrate_session. I am skipping in between steps here & getting to place where I saw changed object.
[81] pry(#<Rack::Test::Session>)> next
From: /Users/SwapnilChincholkar/.rvm/gems/ruby-2.3.0@devise-async-repro/gems/rack-test-0.6.3/lib/rack/test.rb @ line 46 Rack::Test::Session#initialize:
36: def initialize(mock_session)
37: @headers = {}
38: @env = {}
39:
40: if mock_session.is_a?(MockSession)
41: @rack_mock_session = mock_session
42: else
43: @rack_mock_session = MockSession.new(mock_session)
44: end
45:
=> 46: @default_host = @rack_mock_session.default_host
47: end
[81] pry(#<Rack::Test::Session>)> next
From: /Users/SwapnilChincholkar/.rvm/gems/ruby-2.3.0@devise-async-repro/gems/actionpack-4.2.7/lib/action_dispatch/testing/integration.rb @ line 297 ActionDispatch::Integration::Session#process:
292:
293: session = Rack::Test::Session.new(_mock_session)
294:
295: # NOTE: rack-test v0.5 doesn't build a default uri correctly
296: # Make sure requested path is always a full uri
=> 297: session.request(build_full_uri(path, env), env)
298:
299: @request_count += 1
300: @request = ActionDispatch::Request.new(session.last_request.env)
301: response = _mock_session.last_response
302: @response = ActionDispatch::TestResponse.from_response(response)
83] pry(#<ActionDispatch::Integration::Session>)> next
From: /Users/SwapnilChincholkar/.rvm/gems/ruby-2.3.0@devise-async-repro/gems/activerecord-4.2.7/lib/active_record/core.rb @ line 517 ActiveRecord::Core#sync_with_transaction_state:
515: def sync_with_transaction_state
516: #binding.pry
=> 517: update_attributes_from_transaction_state(@transaction_state, 0)
518: end
[83] pry(#<User>)> self
=> #<User:0x007f94faad7438
id: nil,
email: "herbertm1970aea36f4041da3d55d186027f337b010a@gmail.com",
encrypted_password: "$2a$04$lsduTZ5BsFxnRTEVgzqKTOfetW/Ogqpk6v0BX.LuwUqTkTLwibl0C",
reset_password_token: nil,
reset_password_sent_at: nil,
remember_created_at: nil,
sign_in_count: 0,
current_sign_in_at: nil,
last_sign_in_at: nil,
current_sign_in_ip: nil,
last_sign_in_ip: nil,
created_at: Thu, 06 Oct 2016 07:08:54 UTC +00:00,
updated_at: Thu, 06 Oct 2016 07:08:54 UTC +00:00>
Here, while getting into the request User object was altered. Seems hence its going into create_record
[110] pry(User)> step
From: /Users/SwapnilChincholkar/.rvm/gems/ruby-2.3.0@devise-async-repro/gems/activerecord-4.2.7/lib/active_record/timestamp.rb @ line 49 ActiveRecord::Timestamp#_create_record:
45: def _create_record
46: if self.record_timestamps
47: current_time = current_time_from_proper_timezone
48:
=> 49: all_timestamp_attributes.each do |column|
50: column = column.to_s
51: if has_attribute?(column) && !attribute_present?(column)
52: write_attribute(column, current_time)
53: end
54: end
55: end
56:
57: super
58: end
After create when it gets into _run_create_callbacks as below where it faces error
[128] pry(#<User>)> step
From: /Users/SwapnilChincholkar/.rvm/gems/ruby-2.3.0@devise-async-repro/gems/activerecord-4.2.7/lib/active_record/callbacks.rb @ line 306 ActiveRecord::Callbacks#_create_record:
305: def _create_record #:nodoc:
=> 306: _run_create_callbacks { super }
307: end
From: /Users/SwapnilChincholkar/.rvm/gems/ruby-2.3.0@devise-async-repro/gems/activesupport-4.2.7/lib/active_support/callbacks.rb @ line 88 ActiveSupport::Callbacks#__run_callbacks__:
86: def __run_callbacks__(callbacks, &block)
87: if callbacks.empty?
=> 88: yield if block_given?
89: else
90: runner = callbacks.compile
91: e = Filters::Environment.new(self, false, nil, block)
92: runner.call(e).value
93: end
94: end
& below it gets into exception block
[133] pry(#<User>)> next
From: /Users/SwapnilChincholkar/.rvm/gems/ruby-2.3.0@devise-async-repro/gems/activerecord-4.2.7/lib/active_record/connection_adapters/abstract/transaction.rb @ line 186 ActiveRecord::ConnectionAdapters::TransactionManager#within_new_transaction:
182: def within_new_transaction(options = {})
183: transaction = begin_transaction options
184: yield
185: rescue Exception => error
=> 186: rollback_transaction if transaction
187: raise
188: ensure
189: unless error
190: if Thread.current.status == 'aborting'
191: rollback_transaction if transaction
192: else
193: begin
194: commit_transaction
195: rescue Exception
196: transaction.rollback unless transaction.state.completed?
197: raise
198: end
199: end
200: end
201: end