unit tests occasionally report deadlock in deployment start #253
Description
2020-06-10 22:32:58 +0000: running
/usr/bin/ruby2.5 -S rake test TESTOPTS=--junit --junit-jenkins --junit-filename=/buildbot/wetpaint-build/build/tools/syskit/.test-results/report.junit.xml RUBOCOP=1 JUNIT=1 REPORT_DIR=/buildbot/wetpaint-build/build/tools/syskit/.test-results
in directory /buildbot/wetpaint-build/build/tools/syskit
Roby[WARN]: debugging is disabled because the 'pry' gem cannot be loaded
Run options: --junit --junit-jenkins --junit-filename=/buildbot/wetpaint-build/build/tools/syskit/.test-results/report.junit.xml --junit --junit-jenkins --junit-filename=/buildbot/wetpaint-build/build/tools/syskit/.test-results/gui.junit.xml -- --seed 22562
# Running:
Syskit[WARN]: running tests with logger in FATAL mode
.0.217 [ Warning][TaskContextServer()] CTaskContext 'orocosrb_117536' already bound to CORBA Naming Service.
0.217 [ Warning][TaskContextServer()] Trying to rebind... done. New CTaskContext bound to Naming Service.
.1.486 [ Warning][TaskContextServer()] CTaskContext 'orocosrb_117536' already bound to CORBA Naming Service.
1.486 [ Warning][TaskContextServer()] Trying to rebind... done. New CTaskContext bound to Naming Service.
.............
Finished in 2.347980s, 6.3885 runs/s, 70.2732 assertions/s.
15 runs, 165 assertions, 0 failures, 0 errors, 0 skips
Roby[WARN]: debugging is disabled because the 'pry' gem cannot be loaded
Run options: --junit --junit-jenkins --junit-filename=/buildbot/wetpaint-build/build/tools/syskit/.test-results/report.junit.xml --junit --junit-jenkins --junit-filename=/buildbot/wetpaint-build/build/tools/syskit/.test-results/core.junit.xml -- --seed 10904
# Running:
Syskit[WARN]: running tests with logger in FATAL mode
.........................................................................................E....................................................................................................................................................default[INFO]: setting up source:0x55d67f8a8940<id:1901>(conf: ["default"], orocos_name: stub115)
default[INFO]: starting source:0x55d67f8a8940<id:1901>(conf: ["default"], orocos_name: stub115)
.default[INFO]: setting up pre_operational:0x55d67f21ce78<id:1955>(conf: ["default"], orocos_name: stub119)
default[INFO]: starting pre_operational:0x55d67f21ce78<id:1955>(conf: ["default"], orocos_name: stub119)
..............................................................................................................................................................................................................................................Roby[WARN]: Deprecation Warning: #set_log_level is deprecated, use #capture_log instead at /buildbot/wetpaint-build/build/tools/syskit/test/roby_app/test_configuration.rb:83:in `block (3 levels) in <top (required)>'
Roby[WARN]: Deprecation Warning: #set_log_level is deprecated, use #capture_log instead at /buildbot/wetpaint-build/build/tools/syskit/test/roby_app/test_configuration.rb:84:in `block (3 levels) in <top (required)>'
.Roby[WARN]: Deprecation Warning: #set_log_level is deprecated, use #capture_log instead at /buildbot/wetpaint-build/build/tools/syskit/test/roby_app/test_configuration.rb:83:in `block (3 levels) in <top (required)>'
Roby[WARN]: Deprecation Warning: #set_log_level is deprecated, use #capture_log instead at /buildbot/wetpaint-build/build/tools/syskit/test/roby_app/test_configuration.rb:84:in `block (3 levels) in <top (required)>'
.................default[INFO]: starting :0x55d67ef6de20<id:3503>(conf: ["default"], orocos_name: stub185)
......default[INFO]: applied configuration ["default"] to stub190
default[INFO]: applied configuration ["default"] to stub191
default[INFO]: setting up source:0x55d67f435d40<id:3578>(conf: ["default"], orocos_name: stub190)
default[INFO]: setting up sink:0x55d67e1d2f68<id:3576>(conf: ["default"], orocos_name: stub191)
default[INFO]: starting source:0x55d67f435d40<id:3578>(conf: ["default"], orocos_name: stub190)
default[INFO]: starting sink:0x55d67e1d2f68<id:3576>(conf: ["default"], orocos_name: stub191)
..................................................................................................................................................................................................................................................................................................................................................................................................S......S.................................................................................................................................................................................................................................#<Thread:0x000055d683b337b0@/buildbot/wetpaint-build/build/tools/syskit/lib/syskit/roby_app/unmanaged_process.rb:119 run> terminated with exception (report_on_exception is true):
/buildbot/wetpaint-build/build/tools/syskit/lib/syskit/roby_app/unmanaged_process.rb:182:in `sleep': RuntimeError (RuntimeError)
from /buildbot/wetpaint-build/build/tools/syskit/lib/syskit/roby_app/unmanaged_process.rb:182:in `monitor'
from /buildbot/wetpaint-build/build/tools/syskit/lib/syskit/roby_app/unmanaged_process.rb:120:in `block in resolve_all_tasks'
...........................................................default[INFO]: interrupting :0x55d6843fe2f0<id:7381>(conf: ["default"], orocos_name: stub364)
default[INFO]: stopped :0x55d6843fe2f0<id:7381>(conf: ["default"], orocos_name: stub364)
.default[INFO]: interrupting :0x55d6834c2598<id:7399>(conf: ["default"], orocos_name: stub366)
default[INFO]: stopped :0x55d6834c2598<id:7399>(conf: ["default"], orocos_name: stub366)
.default[INFO]: interrupting :0x55d6811c6f80<id:7419>(conf: ["default"], orocos_name: stub368)
default[INFO]: stopped :0x55d6811c6f80<id:7419>(conf: ["default"], orocos_name: stub368)
.default[INFO]: interrupting :0x55d6841850c8<id:7439>(conf: ["default"], orocos_name: stub370)
default[INFO]: stopped :0x55d6841850c8<id:7439>(conf: ["default"], orocos_name: stub370)
..................................................................................................default[INFO]: applied configuration ["default"] to stub402
default[INFO]: setting up DevDriver:0x55d683740158<id:8122>(conf: ["default"], dev_dev: device(Dev, as: stub401), orocos_name: stub402)
default[INFO]: starting DevDriver:0x55d683740158<id:8122>(conf: ["default"], dev_dev: device(Dev, as: stub401), orocos_name: stub402)
.default[INFO]: applied configuration ["default"] to stub403
default[INFO]: setting up profile:P.test_tag-stub:0x55d681e8ae60<id:8143>(conf: ["default"], orocos_name: stub403)
default[INFO]: starting profile:P.test_tag-stub:0x55d681e8ae60<id:8143>(conf: ["default"], orocos_name: stub403)
..........................................default[INFO]: applied configuration ["default"] to stub414
default[INFO]: setting up sink:0x55d6835be230<id:8471>(conf: ["default"], orocos_name: stub414)
default[INFO]: starting sink:0x55d6835be230<id:8471>(conf: ["default"], orocos_name: stub414)
default[INFO]: not reconfiguring source:0x55d681e46d50<id:8473>(conf: ["default"], orocos_name: stub413): the task is already configured as required
default[INFO]: applied configuration ["default"] to stub413
default[INFO]: source:0x55d681e46d50<id:8473>(conf: ["default"], orocos_name: stub413) was already configured
default[INFO]: starting source:0x55d681e46d50<id:8473>(conf: ["default"], orocos_name: stub413)
.default[INFO]: applied configuration ["default"] to stub415
default[INFO]: setting up Task:0x55d6839c0ce8<id:8490>(conf: ["default"], orocos_name: stub415)
..............default[INFO]: applied configuration ["default"] to stub428
default[INFO]: setting up source:0x55d681480708<id:8709>(conf: ["default"], orocos_name: stub428)
default[INFO]: starting source:0x55d681480708<id:8709>(conf: ["default"], orocos_name: stub428)
default[INFO]: not reconfiguring sink:0x55d67c195638<id:8710>(conf: ["default"], orocos_name: stub429): the task is already configured as required
default[INFO]: applied configuration ["default"] to stub429
default[INFO]: sink:0x55d67c195638<id:8710>(conf: ["default"], orocos_name: stub429) was already configured
default[INFO]: starting sink:0x55d67c195638<id:8710>(conf: ["default"], orocos_name: stub429)
.......................................................................................default[INFO]: starting :0x55d6870d3140<id:9311>(conf: ["default"], orocos_name: stub466)
.............................................................................................................................................................default[INFO]: applied configuration ["default"] to stub525
default[INFO]: setting up :0x55d683f30430<id:10702>(conf: ["default"], orocos_name: stub525)
default[INFO]: starting :0x55d683f30430<id:10702>(conf: ["default"], orocos_name: stub525)
...default[INFO]: starting :0x55d6862d6218<id:10767>(conf: ["default"], orocos_name: stub531)
default[INFO]: interrupting :0x55d6862d6218<id:10767>(conf: ["default"], orocos_name: stub531)
default[INFO]: stopped :0x55d6862d6218<id:10767>(conf: ["default"], orocos_name: stub531)
...........................................................................................................................#<Thread:0x000055d68b0c6fe0@/buildbot/wetpaint-build/build/tools/syskit/test/test_remote_state_getter.rb:102 run> terminated with exception (report_on_exception is true):
/buildbot/wetpaint-build/build/tools/syskit/test/test_remote_state_getter.rb:225:in `rtt_state': #<Syskit::RemoteStateGetter:0x000055d68b0c7eb8>'s poll thread quit with #<Class:0x000055d68b0c84d0> during #wait
from /buildbot/wetpaint-build/build/tools/syskit/lib/syskit/remote_state_getter.rb:74:in `poll_loop'
from /buildbot/wetpaint-build/build/tools/syskit/lib/syskit/remote_state_getter.rb:52:in `block in initialize'
from /buildbot/wetpaint-build/build/tools/syskit/test/test_remote_state_getter.rb:102:in `block (2 levels) in assert_interrupts_wait'
...#<Thread:0x000055d689e787a8@/buildbot/wetpaint-build/build/tools/syskit/test/test_remote_state_getter.rb:102 run> terminated with exception (report_on_exception is true):
/buildbot/wetpaint-build/build/tools/syskit/lib/syskit/remote_state_getter.rb:121:in `wait': #<Syskit::RemoteStateGetter:0x000055d689e798b0>#disconnect called within #wait (ThreadError)
from /buildbot/wetpaint-build/build/tools/syskit/test/test_remote_state_getter.rb:102:in `block (2 levels) in assert_interrupts_wait'
........................................................................................................default[INFO]: applied configuration ["default"] to stub611
default[INFO]: setting up Task:0x55d68bf0e3c8<id:12255>(conf: ["default"], orocos_name: stub611)
default[INFO]: starting Task:0x55d68bf0e3c8<id:12255>(conf: ["default"], orocos_name: stub611)
...........................................................................................................................................................................default[INFO]: starting :0x55d68b40abc0<id:13441>(conf: ["default"], orocos_name: stub695)
.default[INFO]: starting :0x55d68a5121e0<id:13459>(conf: ["default"], orocos_name: stub697)
.default[INFO]: starting :0x55d689277620<id:13477>(conf: ["default"], orocos_name: stub699)
default[INFO]: interrupting :0x55d689277620<id:13477>(conf: ["default"], orocos_name: stub699)
default[INFO]: stopped :0x55d689277620<id:13477>(conf: ["default"], orocos_name: stub699)
.default[INFO]: starting :0x55d685ca55d8<id:13495>(conf: ["default"], orocos_name: stub701)
.default[INFO]: starting :0x55d68c027250<id:13513>(conf: ["default"], orocos_name: stub703)
default[INFO]: stopped :0x55d68c027250<id:13513>(conf: ["default"], orocos_name: stub703)
.default[INFO]: starting :0x55d68b08c048<id:13531>(conf: ["default"], orocos_name: stub705)
default[INFO]: interrupting :0x55d68b08c048<id:13531>(conf: ["default"], orocos_name: stub705)
default[INFO]: stopped :0x55d68b08c048<id:13531>(conf: ["default"], orocos_name: stub705)
.default[INFO]: starting :0x55d68a1c1c70<id:13549>(conf: ["default"], orocos_name: stub707)
default[INFO]: interrupting :0x55d68a1c1c70<id:13549>(conf: ["default"], orocos_name: stub707)
default[INFO]: stopped :0x55d68a1c1c70<id:13549>(conf: ["default"], orocos_name: stub707)
....default[INFO]: applied configuration ["default"] to stub711
default[INFO]: setting up :0x55d68a15f778<id:13622>(conf: ["default"], orocos_name: stub711)
..................................................................................................................................default[FATAL]: terminating :0x55d685fa8d48<id:14422>(conf: ["default"], orocos_name: stub748), its state reader orocosrb_117580.stub748.state.600 is disconnected
................................................................Orocos::RemoteProcesses::Server[INFO]: process server listening on port 40817
Orocos::RemoteProcesses::Server[INFO]: process server listening on port 42455
default[INFO]: created /buildbot/wetpaint-build/build/tools/syskit/logs/20200610-2233 on behalf of
default[INFO]: ---
default[INFO]: time: 20200610-2233
default[INFO]: cmdline: "/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/rake-13.0.1/lib/rake/rake_test_loader.rb
default[INFO]: --simplecov-name=core"
default[INFO]: robot_name: default
default[INFO]: robot_type: default
default[INFO]: app_name: default
default[INFO]: app_dir:
default[INFO]: parent:
default[INFO]: time: 20200610-2233
default[INFO]: cmdline: "/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/rake-13.0.1/lib/rake/rake_test_loader.rb
default[INFO]: --simplecov-name=core"
default[INFO]: robot_name: default
default[INFO]: robot_type: default
default[INFO]: app_name: default
default[INFO]: app_dir:
default[INFO]: parent:
default[INFO]: time: 20200610-2233
default[INFO]: cmdline: "/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/rake-13.0.1/lib/rake/rake_test_loader.rb
default[INFO]: --simplecov-name=core"
default[INFO]: robot_name: default
default[INFO]: robot_type: default
default[INFO]: app_name: default
default[INFO]: app_dir:
default[INFO]: created /buildbot/wetpaint-build/build/tools/syskit/logs/20200610-2233.1 on behalf of
default[INFO]: ---
default[INFO]: time: 20200610-2233
default[INFO]: cmdline: "/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/rake-13.0.1/lib/rake/rake_test_loader.rb
default[INFO]: --simplecov-name=core"
default[INFO]: robot_name: default
default[INFO]: robot_type: default
default[INFO]: app_name: default
default[INFO]: app_dir:
default[INFO]: parent:
default[INFO]: time: 20200610-2233
default[INFO]: cmdline: "/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/rake-13.0.1/lib/rake/rake_test_loader.rb
default[INFO]: --simplecov-name=core"
default[INFO]: robot_name: default
default[INFO]: robot_type: default
default[INFO]: app_name: default
default[INFO]: app_dir:
default[INFO]: parent:
default[INFO]: time: 20200610-2233
default[INFO]: cmdline: "/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/rake-13.0.1/lib/rake/rake_test_loader.rb
default[INFO]: --simplecov-name=core"
default[INFO]: robot_name: default
default[INFO]: robot_type: default
default[INFO]: app_name: default
default[INFO]: app_dir:
.....................................................................................default[INFO]: starting :0x55d68a1a17b8<id:15446>(conf: ["default"], orocos_name: stub798)
default[INFO]: interrupting :0x55d68a1a17b8<id:15446>(conf: ["default"], orocos_name: stub798)
default[INFO]: stopped :0x55d68a1a17b8<id:15446>(conf: ["default"], orocos_name: stub798)
.default[INFO]: applied configuration ["default"] to stub799
default[INFO]: setting up :0x55d687120580<id:15470>(conf: ["default"], orocos_name: stub799)
default[INFO]: starting :0x55d687120580<id:15470>(conf: ["default"], orocos_name: stub799)
.........default[INFO]: applied configuration ["default"] to stub803
default[INFO]: setting up ConcurrentConfigurationTask:0x55d68953a998<id:15529>(conf: ["default"], orocos_name: stub803)
..default[INFO]: applied configuration ["default"] to stub806
default[INFO]: setting up ConcurrentConfigurationTask:0x55d6888c9858<id:15576>(conf: ["default"], orocos_name: stub806)
Roby[WARN]: 1 handled errors
...............
Finished in 386.181919s, 5.9609 runs/s, 8.7705 assertions/s.
1) Error:
Syskit::Deployment::runtime behaviour::monitoring for ready#test_0001_does not emit ready if the process is not ready yet:
fatal: No live threads left. Deadlock?
5 threads, 5 sleeps current:0x000055d677637f60 main thread:0x000055d677637f60
* #<Thread:0x000055d67766cb70 sleep_forever>
rb_thread_t:0x000055d677637f60 native:0x00007f9be146cb80 int:0
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:46:in `sleep'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:46:in `wait'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:46:in `ns_wait'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/abstract_lockable_object.rb:43:in `ns_wait_until'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/atomic/event.rb:87:in `block in wait'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `block in synchronize'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/atomic/event.rb:84:in `wait'
/buildbot/wetpaint-build/build/tools/syskit/test/test_deployment.rb:318:in `block (4 levels) in <module:Syskit>'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest/test.rb:98:in `block (3 levels) in run'
/buildbot/wetpaint-build/build/tools/roby/lib/roby/test/minitest_helpers.rb:129:in `block in capture_exceptions'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest/test.rb:195:in `capture_exceptions'
/buildbot/wetpaint-build/build/tools/roby/lib/roby/test/minitest_helpers.rb:127:in `capture_exceptions'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest/test.rb:95:in `block (2 levels) in run'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest.rb:272:in `time_it'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest/test.rb:94:in `block in run'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest.rb:367:in `on_signal'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest/test.rb:211:in `with_info_handler'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest/test.rb:93:in `run'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest.rb:1029:in `run_one_method'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest.rb:341:in `run_one_method'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest.rb:328:in `block (2 levels) in run'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest.rb:327:in `each'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest.rb:327:in `block in run'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest.rb:367:in `on_signal'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest.rb:354:in `with_info_handler'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest.rb:326:in `run'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest.rb:164:in `block in __run'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest.rb:164:in `map'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest.rb:164:in `__run'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest.rb:141:in `run'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest.rb:68:in `block in autorun'
* #<Thread:0x000055d6786d5278@/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/atomic/ruby_thread_local_var.rb:38 sleep_forever>
rb_thread_t:0x000055d6786a8170 native:0x00007f9bde272700 int:0
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/atomic/ruby_thread_local_var.rb:40:in `pop'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/atomic/ruby_thread_local_var.rb:40:in `block in <class:RubyThreadLocalVar>'
* #<Thread:0x000055d67bbcd390@/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest/parallel.rb:28 sleep_forever>
rb_thread_t:0x000055d67bbdf750 native:0x00007f9bdc10e700 int:0
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest/parallel.rb:30:in `pop'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest/parallel.rb:30:in `block (2 levels) in start'
* #<Thread:0x000055d67bbcd200@/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest/parallel.rb:28 sleep_forever>
rb_thread_t:0x000055d67bbde220 native:0x00007f9bd20da700 int:0
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest/parallel.rb:30:in `pop'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/minitest-5.14.1/lib/minitest/parallel.rb:30:in `block (2 levels) in start'
* #<Thread:0x000055d67daed720@run_promises@/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:322 sleep_forever>
rb_thread_t:0x000055d67cf427c0 native:0x00007f9bc81bc700 int:0
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:46:in `sleep'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:46:in `wait'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:46:in `ns_wait'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/abstract_lockable_object.rb:43:in `ns_wait_until'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/atomic/event.rb:87:in `block in wait'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `block in synchronize'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/atomic/event.rb:84:in `wait'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/concern/obligation.rb:75:in `wait'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/concern/obligation.rb:99:in `value!'
/buildbot/wetpaint-build/build/tools/roby/lib/roby/execution_engine.rb:2526:in `execute'
/buildbot/wetpaint-build/build/tools/roby/lib/roby/promise.rb:107:in `block in run_pipeline_elements'
/buildbot/wetpaint-build/build/tools/roby/lib/roby/droby/event_logging.rb:27:in `log_timepoint_group'
/buildbot/wetpaint-build/build/tools/roby/lib/roby/promise.rb:104:in `run_pipeline_elements'
/buildbot/wetpaint-build/build/tools/roby/lib/roby/promise.rb:83:in `block in run_pipeline'
/buildbot/wetpaint-build/build/tools/roby/lib/roby/droby/event_logging.rb:27:in `log_timepoint_group'
/buildbot/wetpaint-build/build/tools/roby/lib/roby/promise.rb:81:in `run_pipeline'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/safe_task_executor.rb:24:in `block in execute'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `block in synchronize'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/safe_task_executor.rb:19:in `execute'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/promise.rb:563:in `block in realize'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:353:in `run_task'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:342:in `block (3 levels) in create_worker'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `loop'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `block (2 levels) in create_worker'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `catch'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `block in create_worker'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:46:in `sleep'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:46:in `wait'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:46:in `ns_wait'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/abstract_lockable_object.rb:43:in `ns_wait_until'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/atomic/event.rb:87:in `block in wait'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `block in synchronize'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/atomic/event.rb:84:in `wait'
/buildbot/wetpaint-build/build/tools/syskit/test/test_deployment.rb:318:in `block (4 levels) in <module:Syskit>'
2302 runs, 3387 assertions, 0 failures, 1 errors, 2 skips
You have skipped tests. Run with --verbose for details.
rake aborted!
Command failed with status (1)
/home/buildbot/.local/share/autoproj/gems/ruby/2.5.0/gems/rake-13.0.1/exe/rake:27:in `<top (required)>'
Tasks: TOP => test => test:core
(See full trace by running task with --trace)
Exit: pid 117530 exit 1