Update build deps by sodabrew · Pull Request #551 · eventmachine/eventmachine

sodabrew · 2014-12-01T03:14:32Z

Working through Travis failures seen in 3349891

sodabrew · 2014-12-01T03:55:14Z

Huh. Tests are consistently hanging and getting timed out after 10 minutes on Travis. Verbose isn't pointing to the problem just yet.

sodabrew · 2014-12-12T23:56:07Z

I updated to test-unit 3.0 and set it to verbose. Now I know that the tests are hanging here:

TestFileWatch: 
  test_events:

sodabrew · 2014-12-13T01:13:00Z

Bunch of unit test fixes, this is looking better now! However #457 is absolutely still broken, both on my Mac (Ruby 2.0.0-p481) and on Travis Ubuntu 12.04 (Ruby 2.0.0-p598)

/home/travis/.rvm/rubies/ruby-2.0.0-p598/lib/ruby/2.0.0/thread.rb:188:in `synchronize': Attempt to unlock a mutex which is not locked (ThreadError)
    from /home/travis/.rvm/rubies/ruby-2.0.0-p598/lib/ruby/2.0.0/thread.rb:188:in `block in pop'
    from /home/travis/.rvm/rubies/ruby-2.0.0-p598/lib/ruby/2.0.0/thread.rb:187:in `handle_interrupt'
    from /home/travis/.rvm/rubies/ruby-2.0.0-p598/lib/ruby/2.0.0/thread.rb:187:in `pop'
    from /home/travis/build/eventmachine/eventmachine/lib/eventmachine.rb:1045:in `block in spawn_threadpool'

sodabrew · 2014-12-13T15:47:15Z

I think the hanging file watcher test is due to this Travis CI issue, wherein the OpenVZ simfs filesystem isn't sending inotify file deletion events: travis-ci/travis-ci#2342

sodabrew · 2014-12-17T18:18:01Z

Only Rubinius and JRuby are failing now. I could mark them as allowed_failures to get the build green, which would help a lot for testing future pull requests.

I am testing JRuby in C extension mode. Should I try it in Pure Ruby mode, instead?

I can reproduce the Rbx failure locally; the tests that have some form of cpid = fork { sleep } the child is crashing.

sodabrew · 2015-01-03T00:42:25Z

Ping to @rubinius peeps - @brixen @yorickpeterse - Could you take a look at the Rbx failures in Travis and help me out? I'm trying to figure out why the forked process child explodes in some of these unit tests. Any advise or pointer in the right direction for debugging much appreciated!

yorickpeterse · 2015-01-03T01:12:52Z

I tried running the tests locally but some of them seem to hang as well. I'll take closer look (in particular using gdb) this Saturday to see what's going on.

sodabrew · 2015-01-03T06:54:19Z

Open issues:

Ruby 2.0: thread.rb:188:insynchronize': Attempt to unlock a mutex which is not locked (ThreadError)` is a problem in Ruby.

Ruby 2.1, 2.2: I'm seeing test_dispatch_completion hang on Ruby 2.1 and 2.2 about 50% of the time. I don't know what's up yet, but I suspect this is a real problem.

I omitted a few more tests from JRuby that aren't implemented for that platform, but the remaining failures looks real. @tmm1 could you advise on what to do with JRuby?

Thanks @yorickpeterse for looking into the Rubinius fork failures!

yorickpeterse · 2015-01-03T19:06:06Z

Attached GDB to the most inner child process of the fork test that hangs, the backtrace output is as following: https://gist.github.com/YorickPeterse/e70846827ad9d9ef2f62. The list of threads and what they are doing is as following (in order of the GDB output):

Thread 8: Finalizer thread
Thread 7: Signal handler thread
Thread 6: JIT thread
Thread 5: Console requests
Thread 4: Console responses
Thread 3: Rbx metrics
Thread 2: Immix GC
Thread 1: Main thread

The main thread appears to be stuck in the following:

#0  0x00007fc830a91193 in select () from /usr/lib/libc.so.6
#1  0x00007fc83058e8e6 in _SelectDataSelect (v=0x7fff9999ea88) at ../../../../ext/em.cpp:824
#2  0x000000000088a1e1 in rb_thread_call_without_gvl (func=0x7fc83058e8c0 <_SelectDataSelect(void*)>, 
    data1=0x7fff9999ea88, ubf=<optimized out>, ubf_data=<optimized out>) at vm/capi/thread.cpp:179
#3  0x00007fc83058e099 in _Select (this=0x800) at ../../../../ext/em.cpp:836
#4  EventMachine_t::_RunSelectOnce (this=0x3d30050) at ../../../../ext/em.cpp:913
#5  0x00007fc83058d4f3 in _RunOnce (this=0x3d30050) at ../../../../ext/em.cpp:515
#6  EventMachine_t::Run (this=0x3d30050) at ../../../../ext/em.cpp:497
#7  0x00007fc830594e66 in t_run_machine_without_threads (self=12) at ../../../../ext/rubymain.cpp:223
#8  0x00000000008424a7 in invoke (state=<optimized out>, env=<optimized out>, nm=<optimized out>, args=...)
    at vm/builtin/native_method.cpp:223
#9  rubinius::NativeMethod::executor_implementation<rubinius::ZeroArguments> (state=0x3493660, 
    previous=<optimized out>, exec=0x7fc82d6a24d0, mod=<optimized out>, args=...)
    at vm/builtin/native_method.cpp:710

If I kill the process using GDB the test suite continues running and doesn't get stuck anywhere else by the looks of it. The final test output in this case is as following:

Run options: 

# Running tests:

[151/226] TestProcesses#test_em_system = 0.02 s                                                            
  1) Failure:
TestProcesses#test_em_system [/home/yorickpeterse/Private/Projects/ruby/eventmachine/tests/test_processes.rb:40]:
<nil> expected but was
<0>.

[153/226] TestProcesses#test_em_system_pid = 0.01 s                  
  2) Failure:
TestProcesses#test_em_system_pid [/home/yorickpeterse/Private/Projects/ruby/eventmachine/tests/test_processes.rb:51]:
<13470> expected but was
<nil>.

[155/226] TestProcesses#test_em_system_with_proc = 0.01 s               
  3) Failure:
TestProcesses#test_em_system_with_proc [/home/yorickpeterse/Private/Projects/ruby/eventmachine/tests/test_processes.rb:60]:
<nil> expected but was
<0>.

[169/226] TestResolver#test_localhost = 0.28 s                                
  4) Failure:
TestResolver#test_localhost [/home/yorickpeterse/Private/Projects/ruby/eventmachine/lib/em/resolver.rb:174]:
Failed assertion, no message given.

[208/226] TestSystem#test_system = 0.01 s                                  
  5) Failure:
TestSystem#test_system [/home/yorickpeterse/Private/Projects/ruby/eventmachine/tests/test_system.rb:21]:
<0> expected but was
<nil>.

[209/226] TestSystem#test_system_with_string = 0.01 s
  6) Failure:
TestSystem#test_system_with_string [/home/yorickpeterse/Private/Projects/ruby/eventmachine/tests/test_system.rb:35]:
<0> expected but was
<nil>.

Finished tests in 495.321605s, 0.4563 tests/s, 0.7248 assertions/s.     
226 tests, 359 assertions, 6 failures, 0 errors, 0 skips

ruby -v: rubinius 2.4.1.n349 (2.1.0 402d7259 2014-12-15 3.5.0 JI) [x86_64-linux-gnu]
rake aborted!
Command failed with status (6): [ruby -w -I"lib:tests:lib" -I"/home/yorickpeterse/.rubies/rbx-git/gems/gems/rake-10.4.2/lib" "/home/yorickpeterse/.rubies/rbx-git/gems/gems/rake-10.4.2/lib/rake/rake_test_loader.rb" "tests/**/test_*.rb" ]
kernel/bootstrap/proc.rb:20:in `call'
kernel/bootstrap/proc.rb:20:in `call'
kernel/bootstrap/array.rb:76:in `each'
/home/yorickpeterse/.rubies/rbx-git/gems/gems/rubysl-monitor-2.0.0/lib/rubysl/monitor/monitor.rb:211:in `synchronize (mon_synchronize)'
kernel/bootstrap/array.rb:76:in `each'
kernel/common/kernel.rb:497:in `load'
kernel/delta/code_loader.rb:66:in `load_script'
kernel/delta/code_loader.rb:152:in `load_script'
kernel/loader.rb:645:in `script'
kernel/loader.rb:799:in `main'
Tasks: TOP => test
(See full trace by running task with --trace)

yorickpeterse · 2015-01-03T19:08:12Z

Looking at the offending code (

eventmachine/ext/em.cpp

Line 824 in 4873051

    
           sd->nSockets = select (sd->maxsocket+1, &(sd->fdreads), &(sd->fdwrites), &(sd->fderrors), &(sd->tv));

) I'm not really sure how this would get stuck other than the handles used for select() not being available.

yorickpeterse · 2015-01-03T19:09:53Z

@sodabrew To recap, the fork tests do work on MRI, or do they also hang at random times?

sodabrew · 2015-01-03T20:16:18Z

Thanks for digging in! Yes, the fork tests work on MRI.

sodabrew · 2015-01-21T09:48:29Z

I've rebased this branch to remove the Rubinius popen work. That will be a separate PR.

Ruby 2.0 may fail at Queue.pop, so rescue and complain to $stderr

The message is "Attempt to unlock a mutex which is not locked (ThreadError)" and it is caused by a bug in Ruby 2.0. Annoying people with $stderr is arguably better than crashing their app. That said, it might not be worth the loud error because the Queue does not appear to drop any tasks even when this occurs.

…0.0.1 and ::1)

…ts at all

The message is "Attempt to unlock a mutex which is not locked (ThreadError)" and it is caused by a bug in Ruby 2.0. Annoying people with $stderr is arguably better than crashing their app. That said, it might not be worth the loud error because the Queue does not appear to drop any tasks even when this occurs.

Update test-unit dependency and make various test fixes

sodabrew force-pushed the update_build_deps branch 2 times, most recently from 2ee6110 to 65ed80f Compare December 12, 2014 23:51

sodabrew force-pushed the update_build_deps branch 3 times, most recently from 10ab669 to af99792 Compare December 13, 2014 01:07

sodabrew force-pushed the update_build_deps branch 2 times, most recently from a4a2aa7 to 19f4c0b Compare December 13, 2014 01:25

sodabrew force-pushed the update_build_deps branch 6 times, most recently from cc3f270 to 4d87ea3 Compare December 13, 2014 18:13

This was referenced Jan 3, 2015

EventMachine with JRuby, running reactor inside a thread problem #477

Closed

Is pure_ruby.rb obsolete? #541

Closed

sodabrew force-pushed the update_build_deps branch 3 times, most recently from 4c31190 to 394df85 Compare January 3, 2015 06:41

This was referenced Jan 15, 2015

Ruby 2.2 compatibility #558

Closed

Add Ruby 2.0.0 and Ruby 2.1.2 to Travis build matrix #519

Closed

Use clock_gettime and mach_absolute_time to make GetRealTime monotonic #563

Merged

sodabrew force-pushed the update_build_deps branch 4 times, most recently from 49f9eb9 to f0312b6 Compare January 21, 2015 09:47

sodabrew self-assigned this Jan 21, 2015

sodabrew added 13 commits January 27, 2015 12:45

Verbose tests with test-unit 2.x

ae5efa2

Update resolver test in case of IPv6 (localhost resolves to both 127.…

1ad02ab

…0.0.1 and ::1)

Use File.exist? instead of deprecated File.exists?

4c63a12

Sort arrays before assert_equal

36ef572

test_dispatch_completion sometimes hangs on Ruby 2.1, 2.2, and Rubinius

43f8dad

Use containerized Travis CI (sudo: false)

90eddbb

Use omit_if for platform unimplemented tests

1ca8cb6

Flip assertions so that the expected value is first

e51b235

Omit SSL tests when EM.ssl? is false rather than not defining the tes…

cc964a9

…ts at all

Avoid /dev/random for a deterministic test

e29abff

Allow Rubinius and JRuby to fail on Travis for now

cc1e51e

In test_fork_safe let the child exit more gracefully

31cf79d

sodabrew force-pushed the update_build_deps branch from f0312b6 to 31cf79d Compare January 27, 2015 20:46

sodabrew added a commit that referenced this pull request Jan 27, 2015

Merge pull request #551 from sodabrew/update_build_deps

a87f440

Update test-unit dependency and make various test fixes

sodabrew merged commit a87f440 into eventmachine:master Jan 27, 2015

sodabrew deleted the update_build_deps branch January 27, 2015 20:48

sodabrew mentioned this pull request Jan 27, 2015

Rubinius popen and test fixes #568

Merged

sodabrew added this to the v1.0.5 milestone Feb 2, 2015

This was referenced Feb 3, 2015

Mysterious Error while using EM.defer with Ruby 2.0.0 #457

Closed

watch_file DELETE event on OpenVZ kernels #75

Closed

Conversation

sodabrew commented Dec 1, 2014

Uh oh!

sodabrew commented Dec 1, 2014

Uh oh!

sodabrew commented Dec 12, 2014

Uh oh!

sodabrew commented Dec 13, 2014

Uh oh!

sodabrew commented Dec 13, 2014

Uh oh!

sodabrew commented Dec 17, 2014

Uh oh!

sodabrew commented Jan 3, 2015

Uh oh!

yorickpeterse commented Jan 3, 2015

Uh oh!

sodabrew commented Jan 3, 2015

Uh oh!

yorickpeterse commented Jan 3, 2015

Uh oh!

yorickpeterse commented Jan 3, 2015

Uh oh!

yorickpeterse commented Jan 3, 2015

Uh oh!

sodabrew commented Jan 3, 2015

Uh oh!

sodabrew commented Jan 21, 2015

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants