Recursive locking bug when terminating

[pitr-ch]

http://pastie.org/8682008

[iNecas]

Another example:

$ bundle exec rake test
/home/travis/.rvm/rubies/ruby-2.1.0/bin/ruby -I"lib:lib:test" -I"/home/travis/.rvm/gems/ruby-2.1.0/gems/rake-10.2.2/lib" "/home/travis/.rvm/gems/ruby-2.1.0/gems/rake-10.2.2/lib/rake/rake_test_loader.rb" "test/action_test.rb" "test/clock_test.rb" "test/execution_plan_test.rb" "test/executor_test.rb" "test/middleware_test.rb" "test/persistance_adapters_test.rb" "test/remote_via_socket_test.rb" "test/testing_test.rb" "test/web_console_test.rb" 
/home/travis/build/Dynflow/dynflow/test/testing_test.rb:5: warning: already initialized constant Dynflow::CWE
/home/travis/build/Dynflow/dynflow/test/action_test.rb:95: warning: previous definition of CWE was here
Run options: --seed 55042

# Running:

.........[2014-04-10 10:57:20.921 #1748] ERROR --  action: undefined method `to_hash' for #<Object:0x000000026fa660> (NoMethodError)
/home/travis/build/Dynflow/dynflow/lib/dynflow/serializable.rb:50:in `recursive_to_hash'
/home/travis/build/Dynflow/dynflow/lib/dynflow/serializable.rb:48:in `block in recursive_to_hash'
/home/travis/build/Dynflow/dynflow/lib/dynflow/serializable.rb:48:in `each'
/home/travis/build/Dynflow/dynflow/lib/dynflow/serializable.rb:48:in `inject'
/home/travis/build/Dynflow/dynflow/lib/dynflow/serializable.rb:48:in `recursive_to_hash'
/home/travis/build/Dynflow/dynflow/lib/dynflow/action.rb:453:in `check_serializable'
/home/travis/build/Dynflow/dynflow/lib/dynflow/action.rb:401:in `block in execute_plan'
/home/travis/build/Dynflow/dynflow/lib/dynflow/action.rb:353:in `call'
/home/travis/build/Dynflow/dynflow/lib/dynflow/action.rb:353:in `block in with_error_handling'
/home/travis/build/Dynflow/dynflow/lib/dynflow/action.rb:353:in `catch'
/home/travis/build/Dynflow/dynflow/lib/dynflow/action.rb:353:in `with_error_handling'
/home/travis/build/Dynflow/dynflow/lib/dynflow/action.rb:381:in `execute_plan'
/home/travis/build/Dynflow/dynflow/lib/dynflow/action.rb:222:in `execute'
/home/travis/build/Dynflow/dynflow/lib/dynflow/testing/factories.rb:41:in `plan_action'
/home/travis/build/Dynflow/dynflow/lib/dynflow/testing/factories.rb:47:in `create_and_plan_action'
/home/travis/build/Dynflow/dynflow/test/action_test.rb:80:in `block (4 levels) in <module:Dynflow>'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest/assertions.rb:293:in `assert_raises'
(eval):6:in `must_raise'
/home/travis/build/Dynflow/dynflow/test/action_test.rb:80:in `block (3 levels) in <module:Dynflow>'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest/test.rb:106:in `block (3 levels) in run'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest/test.rb:204:in `capture_exceptions'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest/test.rb:103:in `block (2 levels) in run'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest/test.rb:256:in `time_it'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest/test.rb:102:in `block in run'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:317:in `on_signal'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest/test.rb:276:in `with_info_handler'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest/test.rb:101:in `run'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:759:in `run_one_method'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:293:in `run_one_method'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:287:in `block (2 levels) in run'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:286:in `each'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:286:in `block in run'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:317:in `on_signal'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:306:in `with_info_handler'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:285:in `run'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:149:in `block in __run'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:149:in `map'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:149:in `__run'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:126:in `run'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:55:in `block in autorun'
.[2014-04-10 10:57:20.924 #1748] ERROR --  action: undefined method `to_hash' for #<Object:0x00000002623908> (NoMethodError)
/home/travis/build/Dynflow/dynflow/lib/dynflow/serializable.rb:50:in `recursive_to_hash'
/home/travis/build/Dynflow/dynflow/lib/dynflow/serializable.rb:48:in `block in recursive_to_hash'
/home/travis/build/Dynflow/dynflow/lib/dynflow/serializable.rb:48:in `each'
/home/travis/build/Dynflow/dynflow/lib/dynflow/serializable.rb:48:in `inject'
/home/travis/build/Dynflow/dynflow/lib/dynflow/serializable.rb:48:in `recursive_to_hash'
/home/travis/build/Dynflow/dynflow/lib/dynflow/action.rb:453:in `check_serializable'
/home/travis/build/Dynflow/dynflow/lib/dynflow/action.rb:430:in `block in execute_run'
/home/travis/build/Dynflow/dynflow/lib/dynflow/action.rb:353:in `call'
/home/travis/build/Dynflow/dynflow/lib/dynflow/action.rb:353:in `block in with_error_handling'
/home/travis/build/Dynflow/dynflow/lib/dynflow/action.rb:353:in `catch'
/home/travis/build/Dynflow/dynflow/lib/dynflow/action.rb:353:in `with_error_handling'
/home/travis/build/Dynflow/dynflow/lib/dynflow/action.rb:422:in `execute_run'
/home/travis/build/Dynflow/dynflow/lib/dynflow/action.rb:222:in `execute'
/home/travis/build/Dynflow/dynflow/lib/dynflow/testing/factories.rb:73:in `run_action'
/home/travis/build/Dynflow/dynflow/test/action_test.rb:90:in `block (4 levels) in <module:Dynflow>'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest/assertions.rb:293:in `assert_raises'
(eval):6:in `must_raise'
/home/travis/build/Dynflow/dynflow/test/action_test.rb:90:in `block (3 levels) in <module:Dynflow>'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest/test.rb:106:in `block (3 levels) in run'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest/test.rb:204:in `capture_exceptions'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest/test.rb:103:in `block (2 levels) in run'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest/test.rb:256:in `time_it'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest/test.rb:102:in `block in run'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:317:in `on_signal'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest/test.rb:276:in `with_info_handler'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest/test.rb:101:in `run'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:759:in `run_one_method'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:293:in `run_one_method'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:287:in `block (2 levels) in run'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:286:in `each'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:286:in `block in run'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:317:in `on_signal'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:306:in `with_info_handler'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:285:in `run'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:149:in `block in __run'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:149:in `map'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:149:in `__run'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:126:in `run'
/home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:55:in `block in autorun'
..............................................................................................S.........................................

Finished in 16.338110s, 8.9362 runs/s, 37.8869 assertions/s.

146 runs, 619 assertions, 0 failures, 0 errors, 1 skips

You have skipped tests. Run with --verbose for details.
/home/travis/build/Dynflow/dynflow/lib/dynflow/future.rb:129:in `synchronize': deadlock; recursive locking (ThreadError)
    from /home/travis/build/Dynflow/dynflow/lib/dynflow/future.rb:129:in `ready?'
    from /home/travis/build/Dynflow/dynflow/lib/dynflow/micro_actor.rb:47:in `terminated?'
    from /home/travis/build/Dynflow/dynflow/lib/dynflow/clock.rb:47:in `ping'
    from /home/travis/build/Dynflow/dynflow/lib/dynflow/future.rb:120:in `block in wait'
    from /home/travis/build/Dynflow/dynflow/lib/dynflow/future.rb:117:in `synchronize'
    from /home/travis/build/Dynflow/dynflow/lib/dynflow/future.rb:117:in `wait'
    from /home/travis/build/Dynflow/dynflow/test/test_helper.rb:199:in `call'
    from /home/travis/build/Dynflow/dynflow/test/test_helper.rb:199:in `block (3 levels) in <top (required)>'
    from /home/travis/build/Dynflow/dynflow/lib/dynflow/future.rb:164:in `block (3 levels) in clock'
/home/travis/build/Dynflow/dynflow/test/test_helper.rb:186:in `block (2 levels) in <top (required)>': there were 1 non_ready_futures: (RuntimeError)
--- 1: [70263819543160]
/home/travis/build/Dynflow/dynflow/lib/dynflow/micro_actor.rb:23:in `ask'
/home/travis/build/Dynflow/dynflow/lib/dynflow/future.rb:164:in `block (3 levels) in clock'
    from /home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:51:in `call'
    from /home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:51:in `reverse_each'
    from /home/travis/.rvm/gems/ruby-2.1.0/gems/minitest-5.3.2/lib/minitest.rb:51:in `block (2 levels) in autorun'
rake aborted!
Command failed with status (1): [ruby -I"lib:lib:test" -I"/home/travis/.rvm/gems/ruby-2.1.0/gems/rake-10.2.2/lib" "/home/travis/.rvm/gems/ruby-2.1.0/gems/rake-10.2.2/lib/rake/rake_test_loader.rb" "test/action_test.rb" "test/clock_test.rb" "test/execution_plan_test.rb" "test/executor_test.rb" "test/middleware_test.rb" "test/persistance_adapters_test.rb" "test/remote_via_socket_test.rb" "test/testing_test.rb" "test/web_console_test.rb" ]
/home/travis/.rvm/gems/ruby-2.1.0/bin/ruby_executable_hooks:15:in `eval'
/home/travis/.rvm/gems/ruby-2.1.0/bin/ruby_executable_hooks:15:in `<main>'
Tasks: TOP => test
(See full trace by running task with --trace)

�[31;1mThe command "bundle exec rake test" exited with 1.�[0m

Done. Your build exited with 1.