tests fail

[joevandyk]

Haven't dug into this yet, but it happens repeatably for me on the latest master, running on ubuntu 12.04 on a vm:

$ rake
/usr/local/stow/ruby-2.0.0-p247/bin/ruby -S rspec ./spec/adapters/active_record_spec.rb ./spec/adapters/connection_pool_spec.rb ./spec/adapters/pg_spec.rb ./spec/adapters/sequel_spec.rb ./spec/unit/connection_spec.rb ./spec/unit/customization_spec.rb ./spec/unit/enqueue_spec.rb ./spec/unit/helper_spec.rb ./spec/unit/logging_spec.rb ./spec/unit/migrations_spec.rb ./spec/unit/pool_spec.rb ./spec/unit/states_spec.rb ./spec/unit/stats_spec.rb ./spec/unit/work_spec.rb ./spec/unit/worker_spec.rb
.F.FF. [THEN HANGS FOREVER]

I see about three failures, then it hangs forever. apparently there's a few other test ruby processes that have been forked.

When I stop those other processes, I see the following:

Failures:

  1) Que using the ActiveRecord adapter should wake up a Worker after queueing a job in async mode, waiting for a transaction to commit if necessary
     Failure/Error: sleep_until { Que::Worker.workers.all?(&:sleeping?) && DB[:que_jobs].empty? }
     RuntimeError:
       Thing never happened!
     # ./spec/support/helpers.rb:7:in `block in sleep_until'
     # ./spec/support/helpers.rb:5:in `loop'
     # ./spec/support/helpers.rb:5:in `sleep_until'
     # ./spec/adapters/active_record_spec.rb:58:in `block (2 levels) in <top (required)>'

  2) Que using the ActiveRecord adapter should instantiate args as ActiveSupport::HashWithIndifferentAccess
     Failure/Error: $passed_args.first[:param].should == 2
     NoMethodError:
       undefined method `first' for nil:NilClass
     # ./spec/adapters/active_record_spec.rb:37:in `block (2 levels) in <top (required)>'

  3) Que using the ActiveRecord adapter should support Rails' special extensions for times
     Failure/Error: DB[:que_jobs].get(:run_at).should be_within(3).of Time.now - 60
       expected 2014-01-28 08:59:03 -0800 to be within 3 of 2014-01-28 16:59:03 -0800
     # ./spec/adapters/active_record_spec.rb:46:in `block (2 levels) in <top (required)>'

  4) Que using the ActiveRecord adapter behaves like a multi-threaded Que adapter should allow multiple workers to complete jobs simultaneously
     Failure/Error: $q1.pop
     SignalException:
       SIGTERM
     Shared Example Group: "a multi-threaded Que adapter" called from ./spec/adapters/active_record_spec.rb:14
     # ./spec/support/shared_examples/multi_threaded_adapter.rb:31:in `block (2 levels) in <top (required)>'

  5) Que using the ActiveRecord adapter behaves like a multi-threaded Que adapter behaves like a Que adapter should be able to queue and work a job
     Failure/Error: result[:event].should == :job_worked
       expected: :job_worked
            got: :job_race_condition (using ==)
       Diff:
       @@ -1,2 +1,2 @@
       -:job_worked
       +:job_race_condition

     Shared Example Group: "a Que adapter" called from ./spec/support/shared_examples/multi_threaded_adapter.rb:2
     # ./spec/support/shared_examples/adapter.rb:15:in `block (2 levels) in <top (required)>'

Finished in 10.05 seconds
116 examples, 5 failures

Failed examples:

rspec ./spec/adapters/active_record_spec.rb:52 # Que using the ActiveRecord adapter should wake up a Worker after queueing a job in async mode, waiting for a transaction to commit if necessary
rspec ./spec/adapters/active_record_spec.rb:34 # Que using the ActiveRecord adapter should instantiate args as ActiveSupport::HashWithIndifferentAccess
rspec ./spec/adapters/active_record_spec.rb:41 # Que using the ActiveRecord adapter should support Rails' special extensions for times
rspec ./spec/support/shared_examples/multi_threaded_adapter.rb:28 # Que using the ActiveRecord adapter behaves like a multi-threaded Que adapter should allow multiple workers to complete jobs simultaneously
rspec ./spec/support/shared_examples/adapter.rb:12 # Que using the ActiveRecord adapter behaves like a multi-threaded Que adapter behaves like a Que adapter should be able to queue and work a job

[joevandyk]

This started happening at 7c27845, tests all run fine before that.

[chanks]

I can't reproduce it on my machine, either on master or that commit, and things seem to be fine on Travis on 2.0.0 (just the same old intermittent errors on rbx and jruby). I don't know why there would be forked processes running - I played around with forking a bit locally, but it never made it into master. I notice that all the errors relate to ActiveRecord - what version is in your Gemfile.lock? I'm using 4.0.0.

[joevandyk]

4.0.2. Gemfile.lock is here: https://gist.github.com/joevandyk/e5a7233fef94d072266b/raw/a5bbef1c89cf9c629b9847f0655356eb45ab5116/gistfile1.txt

I'll try to dig some more.

[joevandyk]

Nevermind about the fork.

When the process was hanging, I used ctrl-c to stop the process, but for some reason, the ruby process still sticks around, see https://gist.github.com/joevandyk/e88eced0ae2c4d8f94a1 for the transcript. (then when I tried running rake again, there'd be multiples of these left-over ruby processes.

[chanks]

I just updated to 4.0.2, still no issue on 2.0.0-p247 or 2.0.0-p353.

Yeah, I've seen that issue with Ctrl+C not killing test processes properly, I'm not sure why it happens. Usually it just results in advisory-lock lint warnings, nothing like this.

[joevandyk]

Weird. I can replicate it on two separate ubuntu 12.04 machines and two separate OSX machines.

[chanks]

That's very, very strange. I'm running Linux Mint 15, which is derived from Ubuntu 13.04. I'll try to reproduce this on 12.04 tomorrow.

[chanks]

Figured it out. I have the TZ environment variable on my machine set to "UTC" so that Time.now returns values in that time zone. I set it up that way forever ago to emulate Heroku, but it's doing something unexpected with ActiveRecord here. I'm not sure what the fix is yet, but deleting that environment variable lets me recreate the problem on my machine, so I can figure it out from here. Thanks!

[joevandyk]

Looks good!