Rubinius + examples/websockets.rb leads to "ArgumentError: Data object has already been freed" on master intermittently

[justindarby]

Just did a fresh clone and loaded up examples/websockets.rb to do some testing, keep getting "ArgumentError: Data object has already been freed" during my tests (and a reset client connection) when reusing connections.. only setup the example to reproduce another issue with a broken websocket client, but this is occuring during a GET /...

This is probably broken, though I don't have time right now to chase down who is causing that.

Full bt from console:

E, [2014-02-11T18:36:31.359193 #26780] ERROR -- : WebServer crashed!
ArgumentError: Data object has already been freed
        /usr/local/rubinius/gems/gems/reel-0.5.0.pre/lib/reel/request/parser.rb:46:in `readpartial'
        /usr/local/rubinius/gems/gems/reel-0.5.0.pre/lib/reel/request/parser.rb:39:in `current_request'
        /usr/local/rubinius/gems/gems/reel-0.5.0.pre/lib/reel/connection.rb:57:in `request'
        ./ReproTastic.rb:54:in `on_connection'
        kernel/common/method.rb:71:in `call'
        kernel/bootstrap/proc.rb:18:in `call'
        /usr/local/rubinius/gems/gems/reel-0.5.0.pre/lib/reel/server.rb:56:in `handle_connection'
        /usr/local/rubinius/gems/gems/celluloid-0.15.2/lib/celluloid/calls.rb:25:in `dispatch'
        /usr/local/rubinius/gems/gems/celluloid-0.15.2/lib/celluloid/calls.rb:122:in `dispatch'
        /usr/local/rubinius/gems/gems/celluloid-0.15.2/lib/celluloid/actor.rb:322:in `handle_message'
        /usr/local/rubinius/gems/gems/celluloid-0.15.2/lib/celluloid/actor.rb:416:in `task'
        /usr/local/rubinius/gems/gems/celluloid-0.15.2/lib/celluloid/tasks.rb:54:in `initialize'
        /usr/local/rubinius/gems/gems/celluloid-0.15.2/lib/celluloid/tasks/task_fiber.rb:13:in `create'
        kernel/bootstrap/proc.rb:20:in `call'

Let me know if you need more details.

[justindarby]

Looks like this might be related to celluloid/celluloid-io#95 and Rubinius 2.2.3+ (I'm using 2.2.5).

[tmornini]

Just observed on 2.2.6, though not websocket related here.

Benching with siege, Rubinius becomes progressively more likely to crash this way as I increase concurrent connections.

For a given siege run, it either crashes very quickly, or completes the entire run flawlessly. That suggests to me that it's related to opening connections concurrently, and that the probability of the crash is directly related to how many connections are being opened in parallel.

[tmornini]

Here's some more information, including reproducible example, output from siege, and exceptions involved for both 2.1.1 and Rubinius 2.2.6: https://gist.github.com/tmornini/9986499

[tmornini]

There's some discussion of this issue here: https://groups.google.com/forum/#!topic/celluloid-ruby/qx9f4ai9Q3Y

[tmornini]

Repro repo: https://github.com/subledger/celluloid-reel-136-repro

[tmornini]

Having this same issue on JRuby 1.7.11

E, [2014-04-13T14:26:40.148000 #33826] ERROR -- : MyServer crashed!
Reel::StateError: already processing a request
    /Users/tmornini/.rbenv/versions/jruby-1.7.11/lib/ruby/gems/shared/bundler/gems/reel-dba5c521b8f4/lib/reel/connection.rb:55:in `request'
    /Users/tmornini/.rbenv/versions/jruby-1.7.11/lib/ruby/gems/shared/bundler/gems/reel-dba5c521b8f4/lib/reel/connection.rb:78:in `each_request'
    ./my_server.rb:17:in `on_connection'
    org/jruby/RubyProc.java:271:in `call'
    /Users/tmornini/.rbenv/versions/jruby-1.7.11/lib/ruby/gems/shared/bundler/gems/reel-dba5c521b8f4/lib/reel/server.rb:56:in `handle_connection'
    org/jruby/RubyKernel.java:1965:in `public_send'
    /Users/tmornini/.rbenv/versions/jruby-1.7.11/lib/ruby/gems/shared/gems/celluloid-0.15.2/lib/celluloid/calls.rb:25:in `dispatch'
    /Users/tmornini/.rbenv/versions/jruby-1.7.11/lib/ruby/gems/shared/gems/celluloid-0.15.2/lib/celluloid/calls.rb:122:in `dispatch'
    /Users/tmornini/.rbenv/versions/jruby-1.7.11/lib/ruby/gems/shared/gems/celluloid-0.15.2/lib/celluloid/actor.rb:322:in `handle_message'
    /Users/tmornini/.rbenv/versions/jruby-1.7.11/lib/ruby/gems/shared/gems/celluloid-0.15.2/lib/celluloid/actor.rb:416:in `task'
    /Users/tmornini/.rbenv/versions/jruby-1.7.11/lib/ruby/gems/shared/gems/celluloid-0.15.2/lib/celluloid/tasks.rb:55:in `initialize'
    /Users/tmornini/.rbenv/versions/jruby-1.7.11/lib/ruby/gems/shared/gems/celluloid-0.15.2/lib/celluloid/tasks/task_fiber.rb:13:in `create'
W, [2014-04-13T14:26:40.160000 #33826]  WARN -- : Terminating task: type=:call, meta={:method_name=>:run}, status=:iowait

[digitalextremist]

Issue is no longer present in jruby 1.7.16.1+

[digitalextremist]

Released in 0.6.0.pre1