search

stompgem / stomp

A ruby gem for sending and receiving messages from a Stomp protocol compliant message queue. Includes: failover logic, ssl support.
http://stomp.github.com
Apache License 2.0
152 stars 80 forks source link

Packet parsing timeout when running a consumer under JRuby #60

Closed rtyler closed 11 years ago

rtyler commented 11 years ago

You'll notice none of the application code being invoked at this point, all I'm doing is a simple:

client.subscribe('/queue/myqueue') do |msg|
   puts msg
end

And the following traceback is thrown under JRuby, but the code works just fine under MRI 1.9.3

Packet parsing timeout
org/jruby/RubyIO.java:2189:in `gets'
/home/tyler/.rvm/gems/jruby-1.7.2@smb/gems/stomp-1.2.10/lib/connection/netio.rb:39:in `_receive'
org/jruby/ext/timeout/Timeout.java:169:in `timeout'
/home/tyler/.rvm/gems/jruby-1.7.2@smb/gems/stomp-1.2.10/lib/connection/netio.rb:34:in `_receive'
org/jruby/ext/thread/Mutex.java:149:in `synchronize'
/home/tyler/.rvm/gems/jruby-1.7.2@smb/gems/stomp-1.2.10/lib/connection/netio.rb:16:in `_receive'
/home/tyler/.rvm/gems/jruby-1.7.2@smb/gems/stomp-1.2.10/lib/connection/utils.rb:231:in `__old_receive'
/home/tyler/.rvm/gems/jruby-1.7.2@smb/gems/stomp-1.2.10/lib/stomp/connection.rb:397:in `receive'
/home/tyler/.rvm/gems/jruby-1.7.2@smb/gems/stomp-1.2.10/lib/client/utils.rb:159:in `start_listeners'
rtyler commented 11 years ago

Reading into the code more, and looking at the #_receive method in Stomp::Connection, I upped the parse_timeout value to 30s. When I enqueue a message in ActiveMQ, the traceback above occurs immediately.

PaulGale commented 11 years ago

Please post the configuration you used to instantiate your client.

I have come across this same problem on JRuby as well. I was using JRuby 1.7.3 on RHEL 6.1.

It appears to be related to the parse_timeout configuration parameter and how it's used. The parameter's purposed is documented as governing the maximum amount of time allowed for parsing a single frame. It doesn't seem to work that way, for some reason.

For example, I configured a consumer with a 10 second parse timeout. I sent it messages from my producer without a problem. However, if I let the consumer sit idle for more than 10 seconds (or whatever the parse_timeout is set to) and then send it another message it crashes with the exception shown above. Clearly if one is running STOMP 1.1 or 1.2 with heart-beating turned on (where the heart beat interval is set to be less than the parse_timeout) then you probably see any issues, but that's beside the point.

PaulGale commented 11 years ago

FYI: I even tried my experiment using JRuby 1.6.7 and STOMP 1.0 and the same problem was observed. In all cases I was using ActiveMQ 5.8.0 as the broker.

rtyler commented 11 years ago

Current configuration:

[4] pry(main)> configatron.stomp.to_hash
=> {:enabled=>true,
 :reliable=>false,
 :parse_timeout=>30,
 :hosts=>[{:host=>"localhost", :port=>61613, :ssl=>false}]}
PaulGale commented 11 years ago

Set reliable to true and re-test. It won't stop the weird timeouts but it will at least re-connect.

Regardless, this seems like a bug to me.

rtyler commented 11 years ago

It appears your hunch about the consumer sitting idle is correct, if I send messages after the consume starts, and before 30s elapses, the consumer receives messages.

If I use :reliable => true, the error is still there, I simply get receive failed: execution expired instead of a traceback.

rtyler commented 11 years ago

As an experiment I ran the same code under Rubinius to see if the true parallelism of JRuby was causing issues. Under rbx, the same code works just fine, and doesn't raise the same exception as it did under JRuby :(

PaulGale commented 11 years ago

If you edit the file connection/netio.rb at line 34, to remove the exception class argument, then you'll get a more revealing stacktrace into the guts of JRuby:

Timeout::timeout(@parse_timeout, Stomp::Error::PacketParsingTimeout) do

becomes

Timeout::timeout(@parse_timeout) do
rtyler commented 11 years ago

That gives me:

execution expired
org/jruby/RubyIO.java:2162:in `gets'
/home/tyler/.rvm/gems/jruby-1.7.4@smb/gems/stomp-1.2.10/lib/connection/netio.rb:40:in `_receive'
org/jruby/ext/timeout/Timeout.java:127:in `timeout'
/home/tyler/.rvm/gems/jruby-1.7.4@smb/gems/stomp-1.2.10/lib/connection/netio.rb:35:in `_receive'
org/jruby/ext/thread/Mutex.java:149:in `synchronize'
/home/tyler/.rvm/gems/jruby-1.7.4@smb/gems/stomp-1.2.10/lib/connection/netio.rb:16:in `_receive'
/home/tyler/.rvm/gems/jruby-1.7.4@smb/gems/stomp-1.2.10/lib/connection/utils.rb:231:in `__old_receive'
/home/tyler/.rvm/gems/jruby-1.7.4@smb/gems/stomp-1.2.10/lib/stomp/connection.rb:397:in `receive'
/home/tyler/.rvm/gems/jruby-1.7.4@smb/gems/stomp-1.2.10/lib/client/utils.rb:159:in `start_listeners'
gmallard commented 11 years ago

This gem has long been in need of a contributor that is focused on JRuby functionality.

Given that, if one or both of you can come up with a JRuby specific fix for this it would be much appreciated.

In the meantime, we'll take a look at it, with zero promises as to a possible ETA.

Regards, Guy

gmallard commented 11 years ago

Difficulty number 1 is that I can not recreate the original parse timeout with a very simple client.

What does happen here is the JRuby client will receive some messages, but then hang, and not receive any new messages. I will try to figure that out, but it probably will not address your original problem.

gmallard commented 11 years ago

My hang example is in the exact same location shown for the timeout exception above (netio.rb:40).

I suspect the fix may change the results ya'll are seeing.

Are either one or both of you willing to take a 1.2.11 beta gem over the wall for testing?

G.

gmallard commented 11 years ago

Please do one of the following:

Changes introduced by a464a6f will surely affect your results.

Regards, Guy

rtyler commented 11 years ago

I think that change fixes the problem, I'm still doing some testing but I'm no longer seeing issues

PaulGale commented 11 years ago

Done with testing. This fixes the problem with JRuby.

How soon do you think before you can merge the changes back to master and bump the gem version?

gmallard commented 11 years ago

Soon. Tonight. I am US New York time.

gmallard commented 11 years ago

1.2.11 is on rubygems.

If there are difficulties, please open a new issue.

I will leave this open for a couple of days.......

G.

PaulGale commented 11 years ago

Fantastic, thanks!

On Sun, Jul 28, 2013 at 6:35 PM, Guy M. Allard notifications@github.comwrote:

1.2.11 is on rubygems.

If there are difficulties, please open a new issue.

I will leave this open for a couple of days.......

G.

— Reply to this email directly or view it on GitHubhttps://github.com/stompgem/stomp/issues/60#issuecomment-21692634 .

rtyler commented 11 years ago

Workyworkies.