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.

Sign up for GitHub

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

Jump to bottom

Testsuite fails with ruby3.3.0dev #459

Closed
mtasaka opened this issue Nov 17, 2023 · 6 comments · Fixed by #460
Closed

Testsuite fails with ruby3.3.0dev #459

mtasaka opened this issue Nov 17, 2023 · 6 comments · Fixed by #460

Comments

@mtasaka
Copy link
Contributor

mtasaka commented Nov 17, 2023

Tried with ruby/ruby@3bc41f4 , bootsnap git head ( ff04a20 ) testsuite fails like:

$ env RUBYLIB=$(pwd)/lib:$(pwd)/ext:$(pwd)/test  ruby -e 'Dir.glob "./test/**/*_test.rb", &method(:require)'
/usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:3: warning: mutex_m which will no longer be part of the default gems since Ruby 3.4.0. Add mutex_m to your Gemfile or gemspec. Also contact author of minitest-5.20.0 to add mutex_m into its gemspec.
<internal:gc>:285: warning: double_heap is deprecated, please use expand_heap instead
Run options: --seed 23722

# Running:

............................................../usr/share/gems/gems/bundler-2.5.0.dev/lib/bundler/rubygems_integration.rb:250:in `require': unexpected invocation: #<Mock:0x16f8>.to_path() (Minitest::Assertion)
unsatisfied expectations:
- expected exactly twice, invoked 3 times: #<Mock:0x16f8>.to_path(any_parameters)
satisfied expectations:
- expected exactly twice, invoked twice: #<Mock:0x1720>.to_str(any_parameters)

	from /usr/share/gems/gems/bundler-2.5.0.dev/lib/bundler/rubygems_integration.rb:250:in `block (2 levels) in replace_require'
	from /builddir/build/GIT/bootsnap/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:17:in `require'
	from /builddir/build/GIT/bootsnap/test/load_path_cache/core_ext/kernel_require_test.rb:24:in `block in test_uses_the_same_duck_type_as_require'
	from /builddir/build/GIT/bootsnap/test/load_path_cache/core_ext/kernel_require_test.rb:14:in `fork'
	from /builddir/build/GIT/bootsnap/test/load_path_cache/core_ext/kernel_require_test.rb:14:in `test_uses_the_same_duck_type_as_require'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest/test.rb:94:in `block (3 levels) in run'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest/test.rb:191:in `capture_exceptions'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest/test.rb:89:in `block (2 levels) in run'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:299:in `time_it'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest/test.rb:88:in `block in run'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:408:in `on_signal'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest/test.rb:239:in `with_info_handler'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest/test.rb:87:in `run'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:1094:in `run_one_method'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:374:in `run_one_method'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:361:in `block (2 levels) in run'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:360:in `each'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:360:in `block in run'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:408:in `on_signal'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:395:in `with_info_handler'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:359:in `run'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:185:in `block in __run'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:185:in `map'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:185:in `__run'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:162:in `run'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:86:in `block in autorun'
F.....................................................................S..................

Finished in 3.523728s, 38.3117 runs/s, 81.1640 assertions/s.

  1) Failure:
Bootsnap::KernelRequireTest#test_uses_the_same_duck_type_as_require [/builddir/build/GIT/bootsnap/test/load_path_cache/core_ext/kernel_require_test.rb:28]:
Expected #<Process::Status: pid 79 exit 1> to be success?.

135 runs, 286 assertions, 1 failures, 0 errors, 1 skips

Looking at :

bootsnap/test/load_path_cache/core_ext/kernel_require_test.rb

Lines 20 to 22 in ff04a20

stringish.expects(:to_str).returns("a").twice # bootsnap + ruby
pathish = mock
pathish.expects(:to_path).returns(stringish).twice # bootsnap + ruby

actually with the latest ruby3.3.0dev, both :to_str and :to_path are invoked 3 times for both (perhaps before .to_str is invoked for 3rd time, the test was "stopped" due to the intermediate exception error) , on the other hand with ruby3.2.2 both :to_str and :to_path are to be invoked twice.

Looking at the commit this code is introduced: 671d1d4 , looks like this test is to verify that both bootsnap and ruby side invokes :to_str and :to_path, so I guess the below is sufficient:

diff --git a/test/load_path_cache/core_ext/kernel_require_test.rb b/test/load_path_cache/core_ext/kernel_require_test.rb
index 1a07725..8b212d6 100644
--- a/test/load_path_cache/core_ext/kernel_require_test.rb
+++ b/test/load_path_cache/core_ext/kernel_require_test.rb
@@ -17,9 +17,9 @@ module Bootsnap
           $LOAD_PATH.push(dir)
           FileUtils.touch("#{dir}/a.rb")
           stringish = mock
-          stringish.expects(:to_str).returns("a").twice # bootsnap + ruby
+          stringish.expects(:to_str).returns("a").at_least(2) # bootsnap + ruby
           pathish = mock
-          pathish.expects(:to_path).returns(stringish).twice # bootsnap + ruby
+          pathish.expects(:to_path).returns(stringish).at_least(2) # bootsnap + ruby
           assert pathish.respond_to?(:to_path)
           require(pathish)
           FileUtils.rm_rf(dir)
@casperisfine
Copy link
Contributor

Thank you for the report, however I'm not able to reproduce, and CI ran against ruby-head just a few minutes ago and passed: https://github.com/Shopify/bootsnap/actions/runs/6927736486/job/18842186171

Perhaps it was just a temporary regression on ruby-head?

@mtasaka
Copy link
Contributor Author

mtasaka commented Nov 20, 2023

I tried ruby/ruby@9aee12c but this issue is still reproducible to me.

@casperisfine casperisfine reopened this Nov 20, 2023
@casperisfine
Copy link
Contributor

That's really weird, could you give more information about your testing environment? Plarform, etc?

@mtasaka
Copy link
Contributor Author

mtasaka commented Nov 20, 2023

So the difference here seems when testsuite is executed via bundler v.s. is executed directly (note that we want to reduce dependency as much as possible so we usually execute testsuite directly):

bash-5.2$ ruby --version
ruby 3.3.0dev (2023-11-19 master 9aee12cc28) [x86_64-linux]
bash-5.2$ bundle exec ruby -w -Ilib:test:lib /usr/share/gems/gems/rake-13.1.0/lib/rake/rake_test_loader.rb test/load_path_cache/core_ext/kernel_require_test.rb
<internal:gc>:285: warning: double_heap is deprecated, please use expand_heap instead
Run options: --seed 7016

# Running:

..

Finished in 0.033745s, 59.2688 runs/s, 148.1719 assertions/s.

2 runs, 5 assertions, 0 failures, 0 errors, 0 skips
bash-5.2$ ruby -w -Ilib:test:lib /usr/share/gems/gems/rake-13.1.0/lib/rake/rake_test_loader.rb test/load_path_cache/core_ext/kernel_require_test.rb
/usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:3: warning: mutex_m which will no longer be part of the default gems since Ruby 3.4.0. Add mutex_m to your Gemfile or gemspec. Also contact author of minitest-5.20.0 to add mutex_m into its gemspec.
<internal:gc>:285: warning: double_heap is deprecated, please use expand_heap instead
Run options: --seed 59856

# Running:

/usr/share/gems/gems/bundler-2.5.0.dev/lib/bundler/rubygems_integration.rb:250:in `require': unexpected invocation: #<Mock:0xbb8>.to_path() (Minitest::Assertion)
unsatisfied expectations:
- expected exactly twice, invoked 3 times: #<Mock:0xbb8>.to_path(any_parameters)
satisfied expectations:
- expected exactly twice, invoked twice: #<Mock:0xbe0>.to_str(any_parameters)

	from /usr/share/gems/gems/bundler-2.5.0.dev/lib/bundler/rubygems_integration.rb:250:in `block (2 levels) in replace_require'
	from /builddir/build/GIT/bootsnap/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:17:in `require'
	from /builddir/build/GIT/bootsnap/test/load_path_cache/core_ext/kernel_require_test.rb:24:in `block in test_uses_the_same_duck_type_as_require'
	from /builddir/build/GIT/bootsnap/test/load_path_cache/core_ext/kernel_require_test.rb:14:in `fork'
	from /builddir/build/GIT/bootsnap/test/load_path_cache/core_ext/kernel_require_test.rb:14:in `test_uses_the_same_duck_type_as_require'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest/test.rb:94:in `block (3 levels) in run'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest/test.rb:191:in `capture_exceptions'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest/test.rb:89:in `block (2 levels) in run'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:299:in `time_it'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest/test.rb:88:in `block in run'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:408:in `on_signal'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest/test.rb:239:in `with_info_handler'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest/test.rb:87:in `run'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:1094:in `run_one_method'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:374:in `run_one_method'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:361:in `block (2 levels) in run'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:360:in `each'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:360:in `block in run'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:408:in `on_signal'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:395:in `with_info_handler'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:359:in `run'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:185:in `block in __run'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:185:in `map'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:185:in `__run'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:162:in `run'
	from /usr/share/gems/gems/minitest-5.20.0/lib/minitest.rb:86:in `block in autorun'
F.

Finished in 0.036410s, 54.9300 runs/s, 137.3249 assertions/s.

  1) Failure:
Bootsnap::KernelRequireTest#test_uses_the_same_duck_type_as_require [/builddir/build/GIT/bootsnap/test/load_path_cache/core_ext/kernel_require_test.rb:28]:
Expected #<Process::Status: pid 32259 exit 1> to be success?.

2 runs, 5 assertions, 1 failures, 0 errors, 0 skips

So bundler seems to be changing environ internally?

@casperisfine
Copy link
Contributor

Hum, even this way I'm not able to reproduce.

But I don't see much harm in your proposed change, so please PR it.

@mtasaka
Copy link
Contributor Author

mtasaka commented Nov 20, 2023

Okay. I will create PR.

mtasaka added a commit to mtasaka/bootsnap that referenced this issue Nov 20, 2023
@mtasaka
TEST: relax method invocation checking for KernelRequireTest
3500caa 
With ruby3.3.0dev, "require" method may invoke :to_str or :to_path
more than once in ruby internal. To rescue this, relax
method invocation checking for KernelRequireTest.

Closes Shopify#459 .
@mtasaka mtasaka mentioned this issue Nov 20, 2023
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

TEST: relax method invocation checking for KernelRequireTest mtasaka/bootsnap
2 participants
@mtasaka @casperisfine