Bug #16973: Rails Active Support unit test fails since 41582d5866

• Status: Third Party's Issue
• Assignee: -
• Target version: -
• ruby -v: ruby 2.8.0dev (2020-06-18T15:18:31Z master 41582d5866) [x86_64-linux]
• Backport: 2.5: UNKNOWN, 2.6: UNKNOWN, 2.7: UNKNOWN

[yahonda (Yasuo Honda)]

Recently Rails CI against Ruby 2.8.0dev has been failing since https://buildkite.com/rails/rails/builds/70219#79d96882-6c51-4854-8cab-28f50ac8bca1 .
The last successful one is https://buildkite.com/rails/rails/builds/70207#ff70c57d-1d72-493b-be63-0ac1827ea44d .

Compared Ruby commit https://github.com/ruby/ruby/compare/41a4c80d284a24360d3a6c5b6e5ca408ccca6efc...adbdf11f94afd52d276c7891515e0eb808f6003f then Based on git bisect between 41a4c80d284a24360d3a6c5b6e5ca408ccca6efc and adbdf11f94afd52d276c7891515e0eb808f6003f, I've found commit 41582d5866 triggers these failures.

Script to reproduce. saved as "rep.rb"

# frozen_string_literal: true

require "bundler/inline"

gemfile(true) do
  source "https://rubygems.org"

  git_source(:github) { |repo| "https://github.com/#{repo}.git" }

  gem "activesupport"
end

require 'active_support/all'
require "minitest/autorun"
require "logger"

class ToJsonTest < Minitest::Test
  def test_json_time_format
    ActiveSupport::JSON::Encoding.use_standard_json_time_format = false
    assert_equal '{"time":"2009/01/01 00:00:00 +0000"}', { time: Time.utc(2009) }.to_json
  end
end

Actual result with Ruby 2.8.0dev 41582d5866

$ ruby -v
ruby 2.8.0dev (2020-06-18T15:18:31Z master 41582d5866) [x86_64-linux]
$ ruby rep.rb 
Fetching gem metadata from https://rubygems.org/........
Resolving dependencies...
Using minitest 5.14.1
Using concurrent-ruby 1.1.6
Using thread_safe 0.3.6
Using zeitwerk 2.3.0
Using bundler 2.2.0.dev
Using tzinfo 1.2.7
Using i18n 1.8.3
Using activesupport 6.0.3.2
Run options: --seed 43482

# Running:

F

Finished in 0.004782s, 209.1063 runs/s, 209.1063 assertions/s.

  1) Failure:
ToJsonTest#test_json_time_format [rep.rb:20]:
--- expected
+++ actual
@@ -1 +1 @@
-"{\"time\":\"2009/01/01 00:00:00 +0000\"}"
+"{\"time\":\"2009-01-01 00:00:00 UTC\"}"


1 runs, 1 assertions, 1 failures, 0 errors, 0 skips
$

Expected result with Ruby 2.8.0dev 750203c514

$ ruby -v rep.rb 
ruby 2.8.0dev (2020-06-18T14:43:48Z master 750203c514) [x86_64-linux]
/home/yahonda/.rbenv/versions/2.8.0-dev/lib/ruby/2.8.0/bundler/vendored_persistent.rb:34: warning: instance variable @socket not initialized
Fetching gem metadata from https://rubygems.org/........
Resolving dependencies...
Using minitest 5.14.1
Using zeitwerk 2.3.0
Using concurrent-ruby 1.1.6
Using thread_safe 0.3.6
Using bundler 2.2.0.dev
Using i18n 1.8.3
Using tzinfo 1.2.7
Using activesupport 6.0.3.2
/home/yahonda/.rbenv/versions/2.8.0-dev/lib/ruby/gems/2.8.0/gems/activesupport-6.0.3.2/lib/active_support/core_ext/hash/except.rb:12: warning: method redefined; discarding old except
Run options: --seed 11397

# Running:

.

Finished in 0.002117s, 472.3315 runs/s, 472.3315 assertions/s.

1 runs, 1 assertions, 0 failures, 0 errors, 0 skips
$

[yahonda (Yasuo Honda)]

I have added some print debug code and found the Hash#to_json method changed

• rep.rb

# frozen_string_literal: true

require "bundler/inline"

gemfile(true) do
  source "https://rubygems.org"

  git_source(:github) { |repo| "https://github.com/#{repo}.git" }

  gem "activesupport"
end

require 'active_support/all'
require "minitest/autorun"
require "logger"

class ToJsonTest < Minitest::Test
  def test_json_time_format
    ActiveSupport::JSON::Encoding.use_standard_json_time_format = false
    h = { time: Time.utc(2009) }
    pp h.method(:to_json).inspect
    pp h.class.ancestors
    assert_equal '{"time":"2009/01/01 00:00:00 +0000"}', h.to_json
  end
end

• With Ruby 2.7.1

% ruby -v ; ruby rep.rb
ruby 2.7.1p83 (2020-03-31 revision a0c7c23c9c) [x86_64-darwin19]
Fetching gem metadata from https://rubygems.org/........
Resolving dependencies...
Using concurrent-ruby 1.1.6
Using i18n 1.8.3
Using minitest 5.14.1
Using thread_safe 0.3.6
Using tzinfo 1.2.7
Using zeitwerk 2.3.0
Using activesupport 6.0.3.2
Using bundler 2.1.4
Run options: --seed 47648

# Running:

"#<Method: Hash(ActiveSupport::ToJsonWithActiveSupportEncoder)#to_json(options=...) /Users/yahonda/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activesupport-6.0.3.2/lib/active_support/core_ext/object/json.rb:36>"
[ActiveSupport::ToJsonWithActiveSupportEncoder,
 Hash,
 JSON::Ext::Generator::GeneratorMethods::Hash,
 Enumerable,
 ActiveSupport::ToJsonWithActiveSupportEncoder,
 Object,
 PP::ObjectMixin,
 Minitest::Expectations,
 JSON::Ext::Generator::GeneratorMethods::Object,
 ActiveSupport::Tryable,
 Kernel,
 BasicObject]
.

Finished in 0.004683s, 213.5383 runs/s, 213.5383 assertions/s.

1 runs, 1 assertions, 0 failures, 0 errors, 0 skips
%

• With ruby 2.8.0dev

% ruby -v ; ruby rep.rb
ruby 2.8.0dev (2020-06-20T05:07:45Z master d1af2345c9) [x86_64-darwin19]
Fetching gem metadata from https://rubygems.org/........
Resolving dependencies...
Using concurrent-ruby 1.1.6
Using minitest 5.14.1
Using thread_safe 0.3.6
Using zeitwerk 2.3.0
Using bundler 2.2.0.dev
Using i18n 1.8.3
Using tzinfo 1.2.7
Using activesupport 6.0.3.2
Run options: --seed 42466

# Running:

"#<Method: Hash(JSON::Ext::Generator::GeneratorMethods::Hash)#to_json(*)>"
[Hash,
 JSON::Ext::Generator::GeneratorMethods::Hash,
 ActiveSupport::ToJsonWithActiveSupportEncoder,
 Enumerable,
 ActiveSupport::ToJsonWithActiveSupportEncoder,
 Object,
 PP::ObjectMixin,
 Minitest::Expectations,
 JSON::Ext::Generator::GeneratorMethods::Object,
 ActiveSupport::Tryable,
 Kernel,
 BasicObject]
F

Finished in 0.014171s, 70.5667 runs/s, 70.5667 assertions/s.

  1) Failure:
ToJsonTest#test_json_time_format [rep.rb:23]:
--- expected
+++ actual
@@ -1 +1 @@
-"{\"time\":\"2009/01/01 00:00:00 +0000\"}"
+"{\"time\":\"2009-01-01 00:00:00 UTC\"}"


1 runs, 1 assertions, 1 failures, 0 errors, 0 skips
%

[yahonda (Yasuo Honda)]

Looks like this is an expected change in Ruby, which actually introduces incompatibilities with Rails. I'm wondering which needs to be fixed.

[jeremyevans0 (Jeremy Evans)]

yahonda (Yasuo Honda) wrote in #note-2:

Looks like this is an expected change in Ruby, which actually introduces incompatibilities with Rails. I'm wondering which needs to be fixed.

Correct, it is an expected change that prepend now affects iclasses. Is ActiveSupport::ToJsonWithActiveSupportEncoder prepended to Hash by ActiveSupport? Could you prepare an example that doesn't depend on ActiveSupport? That will more easily allow us to determine if this a bug or not.

[yuki24 (Yuki Nishijima)]

Not sure if this is helpful but here is a link to the place where ActiveSupport::ToJsonWithActiveSupportEncoder is prepended on a number of classes: https://github.com/rails/rails/blob/0b9a57d2/activesupport/lib/active_support/core_ext/object/json.rb#L48-L50
And here is a related pull request that introduced it: https://github.com/rails/rails/pull/19413

[jeremyevans0 (Jeremy Evans)]

• Status changed from Open to Third Party's Issue

yuki24 (Yuki Nishijima) wrote in #note-4:

Not sure if this is helpful but here is a link to the place where ActiveSupport::ToJsonWithActiveSupportEncoder is prepended on a number of classes: https://github.com/rails/rails/blob/0b9a57d2/activesupport/lib/active_support/core_ext/object/json.rb#L48-L50
And here is a related pull request that introduced it: https://github.com/rails/rails/pull/19413

Thanks, that was helpful. Rails should move Hash after Enumerable in that array, so that it is prepended to first. Currently in Ruby, prepending a module to a class that already includes the module does nothing. Since Hash already includes ActiveSupport::ToJsonWithActiveSupportEncoder at the time prepend is called (because it has already been prepended to Enumerable), Hash.prepend ActiveSupport::ToJsonWithActiveSupportEncoder does nothing.

[naruse (Yui NARUSE)]

• Related to Bug #9573: descendants of a module don't gain its future ancestors, but descendants of a class, do added

[yahonda (Yasuo Honda)]

Opened a pull request at Rails https://github.com/rails/rails/pull/39697 Thank you for the useful information.