Skip to content
This repository

Nested timeout supercedes enclosing timeout #312

Closed
roidrage opened this Issue September 26, 2012 · 5 comments

3 participants

Mathias Meyer Charles Oliver Nutter Sam Goldman
Mathias Meyer

We ran into an issue recently where, using Timeout.timeout(), we had two nested timeouts set up. The outer one had a smaller timeout than the inner one, which we expected to trigger first, but it didn't. The inner one fired when it's timeout ran out, but the outer one never fired. Here's some code to reproduce the issue:

require 'timeout'

begin
  Timeout.timeout(1) do
    begin
      Timeout.timeout(2) do
        sleep(5)
      end
    rescue Timeout::Error
      puts 'Timeout 2 triggered'
    end
  end
rescue Timeout::Error
  puts 'Timeout 1 triggered'
end

On MRI, the outer timeout triggers after one second, so the inner one never fires. On JRuby (reproduced on 1.6.6 and 1.7.0-preview2), it's the other way around, so the error message will be "Timeout 2 triggered".

I guess given MRI's behaviour it could be assumed to be the expected behaviour in this case?

Let me know if there's any more information I can provide you with!

Thanks!

Charles Oliver Nutter
Owner

The odd thing here is that the JRuby behavior seems more correct based on how Timeout works.

Look at it this way: if a Timeout::Error gets raised during the sleep(5) call, what's the first rescue block to handle it? It gets raised at the point of sleep(5) and rescued by the block immediately after. It then prints the exception and returns quietly.

The fact that MRI only prints the "Timeout 1" message is actually very confusing to me, since it means the exception is somehow skipping the inner rescue Timeout::Error block.

Investigating.

Charles Oliver Nutter
Owner

Ok, I think I understand how MRI is doing what it does.

For each timeout, it is constructing a new exception class. It rescues this new exception class explicitly, allowing exceptions from the inner timeout to be distinguished from the outer timeout. The exception propagates past all rescue logic at Timeout 2's level because nothing there rescues that new exception type or any parent type.

This is an incredibly heavyweight mechanism for something that's often called repeatedly (like for every read from a remote channel), but we can emulate the behavior with a builtin exception that's tagged with a unique identifier.

Charles Oliver Nutter
Owner

I have a temporary fix on the way. It still creates a new anonymous exception class every time, but it does it lazily only if the timeout fires. This is not great, but it will at least resolve the issue until I can rig up a more efficient mechanism.

Charles Oliver Nutter headius referenced this issue from a commit September 26, 2012
Charles Oliver Nutter Temporary fix for #312
I am creating a new exception as MRI does, but deferring that
until the timeout actually fires. This means for the majority of
cases that don't timeout, no anonymous exception class is ever
created.

I still don't like that a timeout-heavy system would spin through
classes like this, so I'm going to come up with a better
mechanism (and probably submit something to MRI as well).
69a6115
Charles Oliver Nutter headius referenced this issue from a commit September 26, 2012
Charles Oliver Nutter Improved fix for #312
In this version, the anonymous exceptions raised have an
__identifier__ internal variable that's a new Object every time.
This allows localizing the exception to the timeout triggering it,
avoiding creating a new anonymous exception class completely.
f590057
Charles Oliver Nutter headius closed this September 26, 2012
Mathias Meyer

Thanks for the quick fix!

Sam Goldman

I tried running rake test19 on master @ 55fa98c and this is the only test that failed for me:

I tried running the same suite @ f590057, the commit which provides an improved fix for this issue, and I see the same failure.

  1) Failure:
test_nested_timeout(TestTimeout) [/Users/sam/Documents/Code/jruby/test/test_timeout.rb:149]:
<["Timeout 2: Non-timeout exception",
 "Timeout 2: ensure",
 "Timeout 1: triggered",
 "Timeout 1: ensure"]> expected but was
<["Timeout 2: triggered",
 "Timeout 2: ensure",
 "Timeout 1: triggered",
 "Timeout 1: ensure"]>.

I imagine this is probably an issue with my configuration. I'd like to contribute more, so I would appreciate any guidance on what I can do to guarantee a sane build/test platform.

प्रथमेश prathamesh-sonpatki referenced this issue from a commit in prathamesh-sonpatki/jruby September 26, 2012
Charles Oliver Nutter Temporary fix for #312
I am creating a new exception as MRI does, but deferring that
until the timeout actually fires. This means for the majority of
cases that don't timeout, no anonymous exception class is ever
created.

I still don't like that a timeout-heavy system would spin through
classes like this, so I'm going to come up with a better
mechanism (and probably submit something to MRI as well).
69c807e
प्रथमेश prathamesh-sonpatki referenced this issue from a commit in prathamesh-sonpatki/jruby September 26, 2012
Charles Oliver Nutter Improved fix for #312
In this version, the anonymous exceptions raised have an
__identifier__ internal variable that's a new Object every time.
This allows localizing the exception to the timeout triggering it,
avoiding creating a new anonymous exception class completely.
b3a753e
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Something went wrong with that request. Please try again.