Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Reimplement Timeout.timeout with a single thread and a Queue #15

Merged
merged 5 commits into from
May 18, 2022

Conversation

eregon
Copy link
Member

@eregon eregon commented May 12, 2022

Related to discussion in #14.

I wrote all of the changed code myself, so there is no worry about relicensing or so (notably the rubysl-timeout repository which had the Rubinius timeout.rb no longer exists).

This seems to work great.
I'd like a review, and I'll self-review in more details later.

@eregon eregon requested review from headius and hsbt May 12, 2022 14:32
@eregon
Copy link
Member Author

eregon commented May 12, 2022

For some reason it seems I can't push to eregon/timeout anymore, it sounds like a GitHub bug (I can push to other repos, filed as https://support.github.com/ticket/personal/0/1623804).
I have a change locally to use a Mutex around both usages of the ConditionVariable.

@eregon eregon marked this pull request as ready for review May 12, 2022 20:01
@eregon eregon force-pushed the single-timeout-thread-pure-ruby branch from ea02069 to 64c91e6 Compare May 13, 2022 10:38
@eregon
Copy link
Member Author

eregon commented May 13, 2022

I can now push again to this PR.
test_skip_rescue currently fails on TruffleRuby, because apparently the semantics of Thread#raise is to call .exception twice, once in the caller with the passed args, once the callee/thread with no args:

[:exception, #<Thread:0x0000000001c2aff0 sleep>, #<Thread:0x000000000245ce30 /home/eregon/code/timeout/lib/timeout.rb:98 run>, ["execution expired"]]
/home/eregon/code/timeout/lib/timeout.rb:41:in `exception'
/home/eregon/code/timeout/lib/timeout.rb:85:in `raise'
/home/eregon/code/timeout/lib/timeout.rb:85:in `interrupt'
/home/eregon/code/timeout/lib/timeout.rb:115:in `block (3 levels) in ensure_timer_thread_created'
/home/eregon/code/timeout/lib/timeout.rb:114:in `each'

[:exception, #<Thread:0x0000000001c2aff0 run>, #<Thread:0x0000000001c2aff0 run>, []]
/home/eregon/code/timeout/lib/timeout.rb:41:in `exception'
/home/eregon/code/timeout/test/test_timeout.rb:44:in `sleep'
/home/eregon/code/timeout/test/test_timeout.rb:44:in `block (2 levels) in test_skip_rescue'
/home/eregon/code/timeout/lib/timeout.rb:168:in `block in timeout'
/home/eregon/code/timeout/lib/timeout.rb:36:in `block in catch'

JRuby already has this behavior, so it passes the test.
I'll implement it in TruffleRuby shortly.

@eregon eregon force-pushed the single-timeout-thread-pure-ruby branch from 64c91e6 to bda299c Compare May 13, 2022 11:13
@headius
Copy link

headius commented May 13, 2022

This implementation appears to be the slowest at this point, but I think there's a bug or leak of some kind. My naive benchmark of repeatedly timing out an empty block gets progressively slower over time:

  3.220000   0.140000   3.360000 (  0.662429)
  1.430000   0.100000   1.530000 (  0.337033)
  0.640000   0.060000   0.700000 (  0.230855)
  0.310000   0.030000   0.340000 (  0.214395)
  0.370000   0.040000   0.410000 (  0.265558)
  0.400000   0.040000   0.440000 (  0.301773)
  0.470000   0.040000   0.510000 (  0.352947)
  0.500000   0.050000   0.550000 (  0.400549)
  0.570000   0.040000   0.610000 (  0.451679)
  0.600000   0.050000   0.650000 (  0.490104)
  0.650000   0.040000   0.690000 (  0.541781)
  0.710000   0.040000   0.750000 (  0.579973)
  0.730000   0.050000   0.780000 (  0.620071)
  0.780000   0.040000   0.820000 (  0.668899)
  0.850000   0.050000   0.900000 (  0.710506)
  0.860000   0.040000   0.900000 (  0.751403)
  0.950000   0.060000   1.010000 (  0.805190)
  0.950000   0.040000   0.990000 (  0.838300)
  1.000000   0.040000   1.040000 (  0.882479)
  1.090000   0.060000   1.150000 (  0.936747)

@headius
Copy link

headius commented May 13, 2022

The effect is even more pronounced on TruffleRuby 21.3:

  1.969755   0.272882   2.242637 (  0.510549)
  1.719021   0.110678   1.829699 (  0.550959)
  0.865643   0.073941   0.939584 (  0.705021)
  1.262547   0.056139   1.318686 (  0.889787)
  1.235676   0.050018   1.285694 (  1.115480)
  1.577690   0.050819   1.628509 (  1.355579)
  1.615203   0.050036   1.665239 (  1.585228)
  1.884731   0.055752   1.940483 (  1.828664)
  2.120939   0.056803   2.177742 (  2.066626)
  2.362214   0.060254   2.422468 (  2.303767)
  2.630854   0.069365   2.700219 (  2.586945)
  2.918658   0.111934   3.030592 (  2.947546)
  3.140192   0.085695   3.225887 (  3.095570)
  3.339673   0.076553   3.416226 (  3.281839)
  3.572319   0.079379   3.651698 (  3.508616)
  3.836364   0.081716   3.918080 (  3.763093)
  4.163373   0.111359   4.274732 (  4.142380)
  4.305321   0.084561   4.389882 (  4.250139)
  4.569104   0.088801   4.657905 (  4.518466)
  4.797161   0.089402   4.886563 (  4.766448)

@eregon
Copy link
Member Author

eregon commented May 13, 2022

Indeed.
The problem is I used Mutex#try_lock like an atomic flag, but because it's not unlocked it stays in a list/array on the Ruby Thread and is never removed (except on process shutdown).
Those semantics of a Thread automatically releasing its Mutex when it dies are really ugly and in such a case they cause a leak and a lot of performance. On CRuby the process hangs for a long time just to release those locks.
I fixed it now.

@eregon
Copy link
Member Author

eregon commented May 13, 2022

Performance:

require 'timeout'
require 'benchmark/ips'

Benchmark.ips do |x|
  x.report("timeout") do
    Timeout.timeout(1, Timeout::Error) {}
  end
end
CRuby 3.0.3
stdlib:
             timeout    106.778k (±20.5%) i/s -    511.511k in   5.041715s
this branch:
             timeout    356.527k (± 6.0%) i/s -      1.799M in   5.062773s

TruffleRuby dev
stdlib:
             timeout      1.282M (±57.1%) i/s -      3.449M in   5.111266s
this branch:
             timeout      1.069M (±17.5%) i/s -      5.328M in   5.099024s

JRuby dev
stdlib:
             timeout    287.614k (±14.4%) i/s -      1.424M in   5.081483s
this branch:
             timeout    411.755k (± 9.4%) i/s -      2.069M in   5.072408s

It seems a clear win for all on this benchmark.

@eregon
Copy link
Member Author

eregon commented May 13, 2022

The results above are with an explicit Timeout.timeout(1, Timeout::Error) {} which avoids the catch+throw way.
Here are the results for Timeout.timeout(1) {}:

CRuby 3.0.3
stdlib:
             timeout     79.900k (±15.7%) i/s -    396.118k in   5.096547s
this branch:
             timeout    262.823k (± 7.5%) i/s -      1.320M in   5.046642s

TruffleRuby dev
stdlib:
             timeout      1.336M (±57.9%) i/s -      3.450M in   5.008162s
this branch:
             timeout    690.218k (± 9.7%) i/s -      3.438M in   5.033590s

JRuby dev
stdlib:
             timeout    261.070k (±12.5%) i/s -      1.289M in   5.016722s
this branch:
             timeout    350.589k (± 8.8%) i/s -      1.762M in   5.076461s

Still a clear gain for all.
That is a bit slower than Timeout.timeout(1, Timeout::Error) {}, due to the extra catch call.

graalvmbot pushed a commit to oracle/truffleruby that referenced this pull request May 13, 2022
* This is needed by Timeout.timeout in ruby/timeout#15
* Reuse Kernel#raise for convenience to both
  call #build_exception_for_raise and set the backtrace and print if $DEBUG.
@eregon eregon force-pushed the single-timeout-thread-pure-ruby branch from 2b8a2d4 to 306ebe0 Compare May 13, 2022 21:11
@eregon eregon force-pushed the single-timeout-thread-pure-ruby branch from 306ebe0 to 74add5e Compare May 13, 2022 22:44
@eregon
Copy link
Member Author

eregon commented May 13, 2022

All green now.

eregon added 3 commits May 15, 2022 13:57
* So it is trivially correct.
* Performance seems the same overall.
* It's already checked inside #interrupt.
@eregon eregon force-pushed the single-timeout-thread-pure-ruby branch from ecbe290 to 5f43254 Compare May 15, 2022 11:58
@headius
Copy link

headius commented May 15, 2022

Perf on JRuby seems to be best with this implementation. I vote to merge and release this change.

@headius
Copy link

headius commented May 18, 2022

Anything holding this up? I've got folks at RailsConf interested in trying out JRuby 9.4 but I don't want them to have a poor experience due to the multi-thread timeout.

@hsbt hsbt merged commit 701ac78 into ruby:master May 18, 2022
Strech pushed a commit to Strech/truffleruby that referenced this pull request May 23, 2022
* This is needed by Timeout.timeout in ruby/timeout#15
* Reuse Kernel#raise for convenience to both
  call #build_exception_for_raise and set the backtrace and print if $DEBUG.
eregon added a commit to ruby/spec that referenced this pull request Jun 26, 2022
* This is needed by Timeout.timeout in ruby/timeout#15
* Reuse Kernel#raise for convenience to both
  call #build_exception_for_raise and set the backtrace and print if $DEBUG.
matrix:
ruby: [ '3.0', 2.7, 2.6, 2.5, 2.4, head ]
ruby: [ '3.0', 2.7, 2.6, 2.5, 2.4, head, jruby, truffleruby-head ]
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👍

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

Successfully merging this pull request may close these issues.

5 participants