Investigate stalled tests on Ruby 3.1 #3543
Closed
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
|
CI is timed out here on both Ubuntu & macOS: |
|
And succeded case: Probably it's stalled in |
|
It can be reproduced with rbenv's 3.1.0-dev. It's reproduced only when running whole tests: can't be reproduced when I specify the test file: I'm not sure why but the following |
ashie
force-pushed
the
investigate-test-timeout-on-ruby-head
branch
2 times, most recently
from
d382873
to
2e09aae
Compare
ashie
changed the title
ashie
force-pushed
the
investigate-test-timeout-on-ruby-head
branch
from
aef1e3c
to
26351a5
Compare
ashie
changed the title
ashie
changed the title
ashie
force-pushed
the
investigate-test-timeout-on-ruby-head
branch
from
26351a5
to
b17020f
Compare
e.g.) stack trace for it by sigdump: |
|
I've searched the problematic commit of Ruby by $ git bisect bad
2d98593bf54a37397c6e4886ccc7e3654c2eaf85 is the first bad commit
commit 2d98593bf54a37397c6e4886ccc7e3654c2eaf85
Author: Jeremy Evans <code@jeremyevans.net>
Date: Mon Aug 23 15:22:14 2021 -0700
Support tracing of attr_reader and attr_writer
In vm_call_method_each_type, check for c_call and c_return events before
dispatching to vm_call_ivar and vm_call_attrset. With this approach, the
call cache will still dispatch directly to those functions, so this
change will only decrease performance for the first (uncached) call, and
even then, the performance decrease is very minimal.
This approach requires that we clear the call caches when tracing is
enabled or disabled. The approach currently switches all vm_call_ivar
and vm_call_attrset call caches to vm_call_general any time tracing is
enabled or disabled. So it could theoretically result in a slowdown for
code that constantly enables or disables tracing.
This approach does not handle targeted tracepoints, but from my testing,
c_call and c_return events are not supported for targeted tracepoints,
so that shouldn't matter.
This includes a benchmark showing the performance decrease is minimal
if detectable at all.
Fixes [Bug #16383]
Fixes [Bug #10470]
Co-authored-by: Takashi Kokubun <takashikkbn@gmail.com>
benchmark/attr_accessor.yml | 29 ++++++++++++++++++++++++
iseq.c | 29 ++++++++++++++++++++++++
test/ruby/test_settracefunc.rb | 50 ++++++++++++++++++++++++++++++++++++++++++
vm_eval.c | 22 +++++++++++++++++--
vm_insnhelper.c | 47 +++++++++++++++++++++++++++++++++++----
vm_trace.c | 5 +++++
6 files changed, 176 insertions(+), 6 deletions(-)
create mode 100644 benchmark/attr_accessor.yml |
Signed-off-by: Takuro Ashie <ashie@clear-code.com>
I don't know why yet but "test: has plugin logger" are stalled on Ruby 3.1.0 test/plugin/test_filter.rb:147: test 'has plugin logger' do test/plugin/test_bare_output.rb:77: test 'has plugin logger' do test/plugin/test_input.rb:67: test 'has plugin logger' do Signed-off-by: Takuro Ashie <ashie@clear-code.com>
Signed-off-by: Takuro Ashie <ashie@clear-code.com>
The following test in test/plugin_helper/test_timer.rb is also stalled on Ruby 3.1: * test: aborts timer which raises exceptions Signed-off-by: Takuro Ashie <ashie@clear-code.com>
ashie
force-pushed
the
investigate-test-timeout-on-ruby-head
branch
from
b17020f
to
0f7b012
Compare
|
I've found a simplified test case. test_stall.rb: require 'fluent/test'
require 'fluent/plugin/bare_output'
class StallTest < Test::Unit::TestCase
class DummyPlugin < Fluent::Plugin::BareOutput
end
setup do
Fluent::Test.setup
end
20.times do |i|
test "stall #{i}" do
p = DummyPlugin.new
assert { p.log }
end
end
endWhen I run it, duration of later tests are exponentially increased. |
|
More simplified test case: require 'fluent/test'
class StallTest < Test::Unit::TestCase
class Stall
attr_reader :log
def initialize
@log = $log # https://github.com/fluent/fluentd/blob/c7a2cf0d21976a907055864b9638803179ef43c2/lib/fluent/log.rb#L651
end
end
setup do
Fluent::Test.setup
end
20.times do |i|
test "stall #{i}" do
assert { Stall.new.log }
end
end
end
|
ashie
added a commit
that referenced
this pull request
Dec 21, 2021
Several tests are stalled since Ruby 3.1, I found that it's caused by the followig Ruby's change: ruby/ruby@2d98593 It seems that there are some conditions to reproduce it: * `attr_reader` is defined in a class * `$log` is accessed by it * `assert` is called with a block * `assert` refers the `$log` via the `attr_reader` * ... (some other conditions seem needed but not clarified yet) Here is the sample test case to reproduce it: ``` require 'fluent/test' class StallTest < Test::Unit::TestCase class Stall attr_reader :log def initialize @log = $log end end setup do Fluent::Test.setup end 20.times do |i| test "stall #{i}" do assert { Stall.new.log } end end end ``` Becasue all stalled tests don't need to use block, I remove these blocks to avoid this issue. Fix #3543 Signed-off-by: Takuro Ashie <ashie@clear-code.com>
ashie
added a commit
that referenced
this pull request
Dec 21, 2021
Several tests are stalled since Ruby 3.1, I found that it's caused by the followig Ruby's change: ruby/ruby@2d98593 It seems that there are some conditions to reproduce it: * `attr_reader` is defined in a class * `$log` is accessed by it * `assert` is called with a block * `assert` refers the `$log` via the `attr_reader` * ... (some other conditions seem needed but not clarified yet) Here is the sample test case to reproduce it: ```ruby require 'fluent/test' class StallTest < Test::Unit::TestCase class Stall attr_reader :log def initialize @log = $log end end setup do Fluent::Test.setup end 20.times do |i| test "stall #{i}" do assert { Stall.new.log } end end end ``` Becasue all stalled tests don't need to use block, I remove these blocks to avoid this issue. Fix #3543 Signed-off-by: Takuro Ashie <ashie@clear-code.com>
|
As I mentioned in #3577, there are some conditions to reproduce it:
|
I've found that this test case increases test duration on Ruby 2.7 too, but Ruby 3.1 is 2 times longer than it. Ruby 2.7 Ruby 3.1 |
|
I've created a more simplified test case that doesn't require Fluentd's code. require 'test/unit'
module Fluent
class EventRouter
def initialize(default_collector)
@default_collector = default_collector
end
end
class NoMatchMatch
def initialize(log)
@log = log
end
end
class Agent
def initialize(log:)
@log = log
@event_router = Fluent::EventRouter.new(Fluent::NoMatchMatch.new(log))
end
end
class EngineClass
def initialize
@agent = Fluent::Agent.new(log: $log)
end
end
class Log
def initialize
@engine = Fluent.const_get('Engine')
end
end
Engine = EngineClass.new
end
class StallTest < Test::Unit::TestCase
class Stall
attr_reader :log
def initialize
@log = $log
end
end
setup do
$log = Fluent::Log.new
Fluent.__send__(:remove_const, :Engine)
engine = Fluent.const_set(:Engine, Fluent::EngineClass.new)
end
23.times do |i|
test "stall #{i}" do
assert { Stall.new.log }
end
end
end |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
Signed-off-by: Takuro Ashie ashie@clear-code.com
Which issue(s) this PR fixes:
Fixes #
What this PR does / why we need it:
Docs Changes:
Release Note: