Skip to content

Instantly share code, notes, and snippets.

@hkdnet

hkdnet/log.log Secret

Last active December 19, 2019 10:31
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save hkdnet/bcaf0885045c457199d137c11c28eaab to your computer and use it in GitHub Desktop.
Save hkdnet/bcaf0885045c457199d137c11c28eaab to your computer and use it in GitHub Desktop.
Download ZIP
Raw
log.log
for version in "5.2.4" "5.2.3" "5.1.7" "5.0.7.2" "4.2.11.1"; do echo $version; AR_VERSION=$version ruby repro.rb; done
5.2.4
Fetching gem metadata from https://rubygems.org/..........
Resolving dependencies...
Using concurrent-ruby 1.1.5
Using i18n 1.7.0
Using minitest 5.13.0
Using thread_safe 0.3.6
Using tzinfo 1.2.5
Using activesupport 5.2.4
Using activemodel 5.2.4
Using arel 9.0.0
Using activerecord 5.2.4
Using bundler 2.0.2
Using sqlite3 1.3.13
-- create_table(:people, {:force=>true})
D, [2019-12-19T19:30:08.469066 #66087] DEBUG -- : (0.0ms) DROP TABLE IF EXISTS "people"
D, [2019-12-19T19:30:08.469811 #66087] DEBUG -- : (0.6ms) SELECT sqlite_version(*)
D, [2019-12-19T19:30:08.470097 #66087] DEBUG -- : (0.2ms) CREATE TABLE "people" ("id" integer PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar)
-> 0.0029s
-- create_table(:matriculations, {:force=>:true})
D, [2019-12-19T19:30:08.470306 #66087] DEBUG -- : (0.0ms) DROP TABLE IF EXISTS "matriculations"
D, [2019-12-19T19:30:08.470451 #66087] DEBUG -- : (0.1ms) CREATE TABLE "matriculations" ("id" integer PRIMARY KEY AUTOINCREMENT NOT NULL, "person_id" bigint)
-> 0.0003s
D, [2019-12-19T19:30:08.488608 #66087] DEBUG -- : (0.1ms) CREATE TABLE "ar_internal_metadata" ("key" varchar NOT NULL PRIMARY KEY, "value" varchar, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
D, [2019-12-19T19:30:08.494730 #66087] DEBUG -- : ActiveRecord::InternalMetadata Load (0.1ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = ? LIMIT ? [["key", "environment"], ["LIMIT", 1]]
D, [2019-12-19T19:30:08.497716 #66087] DEBUG -- : (0.0ms) begin transaction
D, [2019-12-19T19:30:08.498410 #66087] DEBUG -- : ActiveRecord::InternalMetadata Create (0.1ms) INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["key", "environment"], ["value", "default_env"], ["created_at", "2019-12-19 10:30:08.497921"], ["updated_at", "2019-12-19 10:30:08.497921"]]
D, [2019-12-19T19:30:08.498556 #66087] DEBUG -- : (0.0ms) commit transaction
Run options: --seed 57200
# Running:
D, [2019-12-19T19:30:08.506597 #66087] DEBUG -- : (0.0ms) begin transaction
D, [2019-12-19T19:30:08.507080 #66087] DEBUG -- : Person Create (0.1ms) INSERT INTO "people" ("name") VALUES (?) [["name", "Jhon"]]
D, [2019-12-19T19:30:08.507228 #66087] DEBUG -- : (0.0ms) commit transaction
D, [2019-12-19T19:30:08.511168 #66087] DEBUG -- : (0.0ms) begin transaction
D, [2019-12-19T19:30:08.511596 #66087] DEBUG -- : Matriculation Create (0.1ms) INSERT INTO "matriculations" ("person_id") VALUES (?) [["person_id", 1]]
D, [2019-12-19T19:30:08.511704 #66087] DEBUG -- : (0.0ms) commit transaction
D, [2019-12-19T19:30:08.511797 #66087] DEBUG -- : (0.0ms) begin transaction
D, [2019-12-19T19:30:08.512139 #66087] DEBUG -- : Person Update (0.1ms) UPDATE "people" SET "name" = ? WHERE "people"."id" = ? [["name", nil], ["id", 1]]
D, [2019-12-19T19:30:08.512235 #66087] DEBUG -- : (0.0ms) commit transaction
D, [2019-12-19T19:30:08.512534 #66087] DEBUG -- : Matriculation Load (0.1ms) SELECT "matriculations".* FROM "matriculations" ORDER BY "matriculations"."id" ASC LIMIT ? [["LIMIT", 1]]
D, [2019-12-19T19:30:08.514653 #66087] DEBUG -- : Person Load (0.1ms) SELECT "people".* FROM "people" WHERE "people"."id" = ? LIMIT ? [["id", 1], ["LIMIT", 1]]
.
Finished in 0.010678s, 93.6505 runs/s, 187.3010 assertions/s.
1 runs, 2 assertions, 0 failures, 0 errors, 0 skips
5.2.3
Fetching gem metadata from https://rubygems.org/..........
Resolving dependencies...
Using concurrent-ruby 1.1.5
Using i18n 1.7.0
Using minitest 5.13.0
Using thread_safe 0.3.6
Using tzinfo 1.2.5
Using activesupport 5.2.3
Using activemodel 5.2.3
Using arel 9.0.0
Using activerecord 5.2.3
Using bundler 2.0.2
Using sqlite3 1.3.13
-- create_table(:people, {:force=>true})
D, [2019-12-19T19:30:10.686008 #66305] DEBUG -- : (0.1ms) DROP TABLE IF EXISTS "people"
D, [2019-12-19T19:30:10.686794 #66305] DEBUG -- : (0.6ms) SELECT sqlite_version(*)
D, [2019-12-19T19:30:10.687088 #66305] DEBUG -- : (0.2ms) CREATE TABLE "people" ("id" integer PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar)
-> 0.0030s
-- create_table(:matriculations, {:force=>:true})
D, [2019-12-19T19:30:10.687366 #66305] DEBUG -- : (0.0ms) DROP TABLE IF EXISTS "matriculations"
D, [2019-12-19T19:30:10.687532 #66305] DEBUG -- : (0.1ms) CREATE TABLE "matriculations" ("id" integer PRIMARY KEY AUTOINCREMENT NOT NULL, "person_id" bigint)
-> 0.0004s
D, [2019-12-19T19:30:10.704340 #66305] DEBUG -- : (0.1ms) CREATE TABLE "ar_internal_metadata" ("key" varchar NOT NULL PRIMARY KEY, "value" varchar, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
D, [2019-12-19T19:30:10.711138 #66305] DEBUG -- : ActiveRecord::InternalMetadata Load (0.1ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = ? LIMIT ? [["key", "environment"], ["LIMIT", 1]]
D, [2019-12-19T19:30:10.713629 #66305] DEBUG -- : (0.0ms) begin transaction
D, [2019-12-19T19:30:10.714391 #66305] DEBUG -- : ActiveRecord::InternalMetadata Create (0.2ms) INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["key", "environment"], ["value", "default_env"], ["created_at", "2019-12-19 10:30:10.713866"], ["updated_at", "2019-12-19 10:30:10.713866"]]
D, [2019-12-19T19:30:10.714531 #66305] DEBUG -- : (0.0ms) commit transaction
Run options: --seed 20583
# Running:
D, [2019-12-19T19:30:10.722555 #66305] DEBUG -- : (0.0ms) begin transaction
D, [2019-12-19T19:30:10.722965 #66305] DEBUG -- : Person Create (0.0ms) INSERT INTO "people" ("name") VALUES (?) [["name", "Jhon"]]
D, [2019-12-19T19:30:10.723100 #66305] DEBUG -- : (0.0ms) commit transaction
D, [2019-12-19T19:30:10.727057 #66305] DEBUG -- : (0.0ms) begin transaction
D, [2019-12-19T19:30:10.727539 #66305] DEBUG -- : Matriculation Create (0.1ms) INSERT INTO "matriculations" ("person_id") VALUES (?) [["person_id", 1]]
D, [2019-12-19T19:30:10.727646 #66305] DEBUG -- : (0.0ms) commit transaction
D, [2019-12-19T19:30:10.727732 #66305] DEBUG -- : (0.0ms) begin transaction
D, [2019-12-19T19:30:10.728050 #66305] DEBUG -- : Person Update (0.0ms) UPDATE "people" SET "name" = ? WHERE "people"."id" = ? [["name", nil], ["id", 1]]
D, [2019-12-19T19:30:10.728146 #66305] DEBUG -- : (0.0ms) commit transaction
D, [2019-12-19T19:30:10.728480 #66305] DEBUG -- : Matriculation Load (0.1ms) SELECT "matriculations".* FROM "matriculations" ORDER BY "matriculations"."id" ASC LIMIT ? [["LIMIT", 1]]
D, [2019-12-19T19:30:10.731593 #66305] DEBUG -- : Person Load (0.1ms) SELECT "people".* FROM "people" WHERE "people"."id" = ? LIMIT ? [["id", 1], ["LIMIT", 1]]
F
Finished in 0.016815s, 59.4707 runs/s, 118.9414 assertions/s.
1) Failure:
BugTest#test_case [repro.rb:62]:
Expected: true
Actual: false
1 runs, 2 assertions, 1 failures, 0 errors, 0 skips
5.1.7
Fetching gem metadata from https://rubygems.org/..........
Resolving dependencies...
Using concurrent-ruby 1.1.5
Using i18n 1.7.0
Using minitest 5.13.0
Using thread_safe 0.3.6
Using tzinfo 1.2.5
Using activesupport 5.1.7
Using activemodel 5.1.7
Using arel 8.0.0
Using activerecord 5.1.7
Using bundler 2.0.2
Using sqlite3 1.3.13
-- create_table(:people, {:force=>true})
D, [2019-12-19T19:30:12.816799 #66467] DEBUG -- : (0.0ms) DROP TABLE IF EXISTS "people"
D, [2019-12-19T19:30:12.817448 #66467] DEBUG -- : (0.5ms) SELECT sqlite_version(*)
D, [2019-12-19T19:30:12.817710 #66467] DEBUG -- : (0.2ms) CREATE TABLE "people" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar)
-> 0.0026s
-- create_table(:matriculations, {:force=>:true})
D, [2019-12-19T19:30:12.817893 #66467] DEBUG -- : (0.0ms) DROP TABLE IF EXISTS "matriculations"
D, [2019-12-19T19:30:12.818034 #66467] DEBUG -- : (0.1ms) CREATE TABLE "matriculations" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "person_id" bigint)
-> 0.0003s
D, [2019-12-19T19:30:12.835991 #66467] DEBUG -- : (0.1ms) CREATE TABLE "ar_internal_metadata" ("key" varchar NOT NULL PRIMARY KEY, "value" varchar, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
D, [2019-12-19T19:30:12.841304 #66467] DEBUG -- : ActiveRecord::InternalMetadata Load (0.1ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = ? LIMIT ? [["key", "environment"], ["LIMIT", 1]]
D, [2019-12-19T19:30:12.843577 #66467] DEBUG -- : (0.0ms) begin transaction
D, [2019-12-19T19:30:12.844536 #66467] DEBUG -- : SQL (0.2ms) INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["key", "environment"], ["value", "default_env"], ["created_at", "2019-12-19 10:30:12.843809"], ["updated_at", "2019-12-19 10:30:12.843809"]]
D, [2019-12-19T19:30:12.844721 #66467] DEBUG -- : (0.0ms) commit transaction
Run options: --seed 57649
# Running:
D, [2019-12-19T19:30:12.853180 #66467] DEBUG -- : (0.0ms) begin transaction
D, [2019-12-19T19:30:12.853800 #66467] DEBUG -- : SQL (0.1ms) INSERT INTO "people" ("name") VALUES (?) [["name", "Jhon"]]
D, [2019-12-19T19:30:12.853941 #66467] DEBUG -- : (0.0ms) commit transaction
D, [2019-12-19T19:30:12.857869 #66467] DEBUG -- : (0.0ms) begin transaction
D, [2019-12-19T19:30:12.858368 #66467] DEBUG -- : SQL (0.1ms) INSERT INTO "matriculations" ("person_id") VALUES (?) [["person_id", 1]]
D, [2019-12-19T19:30:12.858486 #66467] DEBUG -- : (0.0ms) commit transaction
D, [2019-12-19T19:30:12.858568 #66467] DEBUG -- : (0.0ms) begin transaction
D, [2019-12-19T19:30:12.858964 #66467] DEBUG -- : SQL (0.0ms) UPDATE "people" SET "name" = ? WHERE "people"."id" = ? [["name", nil], ["id", 1]]
D, [2019-12-19T19:30:12.859063 #66467] DEBUG -- : (0.0ms) commit transaction
D, [2019-12-19T19:30:12.859318 #66467] DEBUG -- : Matriculation Load (0.1ms) SELECT "matriculations".* FROM "matriculations" ORDER BY "matriculations"."id" ASC LIMIT ? [["LIMIT", 1]]
D, [2019-12-19T19:30:12.862471 #66467] DEBUG -- : Person Load (0.1ms) SELECT "people".* FROM "people" WHERE "people"."id" = ? LIMIT ? [["id", 1], ["LIMIT", 1]]
F
Finished in 0.017135s, 58.3601 runs/s, 116.7202 assertions/s.
1) Failure:
BugTest#test_case [repro.rb:62]:
Expected: true
Actual: false
1 runs, 2 assertions, 1 failures, 0 errors, 0 skips
5.0.7.2
Fetching gem metadata from https://rubygems.org/..........
Resolving dependencies...
Using concurrent-ruby 1.1.5
Using i18n 1.7.0
Using minitest 5.13.0
Using thread_safe 0.3.6
Using tzinfo 1.2.5
Using activesupport 5.0.7.2
Using activemodel 5.0.7.2
Using arel 7.1.4
Using activerecord 5.0.7.2
Using bundler 2.0.2
Using sqlite3 1.3.13
-- create_table(:people, {:force=>true})
D, [2019-12-19T19:30:15.049647 #66625] DEBUG -- : (0.2ms) CREATE TABLE "people" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar)
-> 0.0157s
-- create_table(:matriculations, {:force=>:true})
D, [2019-12-19T19:30:15.049999 #66625] DEBUG -- : (0.1ms) CREATE TABLE "matriculations" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "person_id" bigint)
-> 0.0003s
D, [2019-12-19T19:30:15.056933 #66625] DEBUG -- : (0.1ms) CREATE TABLE "ar_internal_metadata" ("key" varchar NOT NULL PRIMARY KEY, "value" varchar, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
D, [2019-12-19T19:30:15.064894 #66625] DEBUG -- : ActiveRecord::InternalMetadata Load (0.1ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = ? LIMIT ? [["key", "environment"], ["LIMIT", 1]]
D, [2019-12-19T19:30:15.068752 #66625] DEBUG -- : (0.0ms) begin transaction
D, [2019-12-19T19:30:15.069621 #66625] DEBUG -- : SQL (0.1ms) INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["key", "environment"], ["value", "default_env"], ["created_at", "2019-12-19 10:30:15.069036"], ["updated_at", "2019-12-19 10:30:15.069036"]]
D, [2019-12-19T19:30:15.069747 #66625] DEBUG -- : (0.0ms) commit transaction
Run options: --seed 36122
# Running:
D, [2019-12-19T19:30:15.079934 #66625] DEBUG -- : (0.1ms) begin transaction
D, [2019-12-19T19:30:15.080844 #66625] DEBUG -- : SQL (0.1ms) INSERT INTO "people" ("name") VALUES (?) [["name", "Jhon"]]
D, [2019-12-19T19:30:15.081054 #66625] DEBUG -- : (0.0ms) commit transaction
D, [2019-12-19T19:30:15.085762 #66625] DEBUG -- : (0.1ms) begin transaction
D, [2019-12-19T19:30:15.086610 #66625] DEBUG -- : SQL (0.1ms) INSERT INTO "matriculations" ("person_id") VALUES (?) [["person_id", 1]]
D, [2019-12-19T19:30:15.086807 #66625] DEBUG -- : (0.0ms) commit transaction
D, [2019-12-19T19:30:15.086923 #66625] DEBUG -- : (0.0ms) begin transaction
D, [2019-12-19T19:30:15.087505 #66625] DEBUG -- : SQL (0.1ms) UPDATE "people" SET "name" = ? WHERE "people"."id" = ? [["name", nil], ["id", 1]]
D, [2019-12-19T19:30:15.087636 #66625] DEBUG -- : (0.0ms) commit transaction
D, [2019-12-19T19:30:15.088058 #66625] DEBUG -- : Matriculation Load (0.1ms) SELECT "matriculations".* FROM "matriculations" ORDER BY "matriculations"."id" ASC LIMIT ? [["LIMIT", 1]]
D, [2019-12-19T19:30:15.091358 #66625] DEBUG -- : Person Load (0.1ms) SELECT "people".* FROM "people" WHERE "people"."id" = ? LIMIT ? [["id", 1], ["LIMIT", 1]]
F
Finished in 0.021475s, 46.5658 runs/s, 93.1315 assertions/s.
1) Failure:
BugTest#test_case [repro.rb:62]:
Expected: true
Actual: false
1 runs, 2 assertions, 1 failures, 0 errors, 0 skips
4.2.11.1
Fetching gem metadata from https://rubygems.org/..........
Resolving dependencies...
Using concurrent-ruby 1.1.5
Using i18n 0.9.5
Using minitest 5.13.0
Using thread_safe 0.3.6
Using tzinfo 1.2.5
Using activesupport 4.2.11.1
Using builder 3.2.4
Using activemodel 4.2.11.1
Using arel 6.0.4
Using activerecord 4.2.11.1
Using bundler 2.0.2
Using sqlite3 1.3.13
/Users/ko.sato/.anyenv/envs/rbenv/versions/2.6.3/lib/ruby/gems/2.6.0/gems/activesupport-4.2.11.1/lib/active_support/core_ext/object/duplicable.rb:111: warning: BigDecimal.new is deprecated; use BigDecimal() method instead.
-- create_table(:people, {:force=>true})
D, [2019-12-19T19:30:17.073164 #66836] DEBUG -- : (0.2ms) CREATE TABLE "people" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar)
-> 0.0026s
-- create_table(:matriculations, {:force=>:true})
D, [2019-12-19T19:30:17.073472 #66836] DEBUG -- : (0.1ms) CREATE TABLE "matriculations" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "person_id" bigint)
-> 0.0002s
Run options: --seed 37865
# Running:
D, [2019-12-19T19:30:17.096847 #66836] DEBUG -- : (0.1ms) begin transaction
D, [2019-12-19T19:30:17.099183 #66836] DEBUG -- : SQL (0.2ms) INSERT INTO "people" ("name") VALUES (?) [["name", "Jhon"]]
D, [2019-12-19T19:30:17.099519 #66836] DEBUG -- : (0.0ms) commit transaction
D, [2019-12-19T19:30:17.104337 #66836] DEBUG -- : (0.0ms) begin transaction
D, [2019-12-19T19:30:17.104951 #66836] DEBUG -- : SQL (0.1ms) INSERT INTO "matriculations" ("person_id") VALUES (?) [["person_id", 1]]
D, [2019-12-19T19:30:17.105209 #66836] DEBUG -- : (0.0ms) commit transaction
D, [2019-12-19T19:30:17.105335 #66836] DEBUG -- : (0.0ms) begin transaction
D, [2019-12-19T19:30:17.108308 #66836] DEBUG -- : SQL (0.1ms) UPDATE "people" SET "name" = ? WHERE "people"."id" = ? [["name", nil], ["id", 1]]
D, [2019-12-19T19:30:17.108500 #66836] DEBUG -- : (0.0ms) commit transaction
D, [2019-12-19T19:30:17.108957 #66836] DEBUG -- : Matriculation Load (0.0ms) SELECT "matriculations".* FROM "matriculations" ORDER BY "matriculations"."id" ASC LIMIT 1
D, [2019-12-19T19:30:17.113669 #66836] DEBUG -- : Person Load (0.1ms) SELECT "people".* FROM "people" WHERE "people"."id" = ? LIMIT 1 [["id", 1]]
F
Finished in 0.029069s, 34.4009 runs/s, 68.8018 assertions/s.
1) Failure:
BugTest#test_case [repro.rb:62]:
Expected: true
Actual: false
1 runs, 2 assertions, 1 failures, 0 errors, 0 skips
Raw
repro.rb
# frozen_string_literal: true
begin
require "bundler/inline"
rescue LoadError => e
$stderr.puts "Bundler version 1.10 or later is required. Please update your Bundler"
raise e
end
gemfile(true) do
source "https://rubygems.org"
git_source(:github) { |repo| "https://github.com/#{repo}.git" }
# Activate the gem you are reporting the issue against.
gem "activerecord", ENV['AR_VERSION']
gem "sqlite3", "~> 1.3.6"
end
require "active_record"
require "minitest/autorun"
require "logger"
# Ensure backward compatibility with Minitest 4
Minitest::Test = MiniTest::Unit::TestCase unless defined?(Minitest::Test)
# This connection will do for database-independent bug reports.
ActiveRecord::Base.establish_connection(adapter: "sqlite3", database: ":memory:")
ActiveRecord::Base.logger = Logger.new(STDOUT)
ActiveRecord::Schema.define do
create_table :people, force: true do |t|
t.string :name
end
create_table :matriculations, force: :true do |t|
t.bigint :person_id
end
end
class Matriculation < ActiveRecord::Base
belongs_to :person, autosave: true
end
class Person < ActiveRecord::Base
has_many :matriculations
validates :name, presence: true
end
class BugTest < Minitest::Test
def test_case
person = Person.create!(name: 'Jhon')
Matriculation.create!(person: person)
person.name = nil
person.save! validate: false # In this moment the object person is invalid. But matriculation isn't.
matriculation = Matriculation.first
assert_equal true, matriculation.valid? # First call
matriculation.person.present?
assert_equal true, matriculation.valid? # Second call
end
end
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment