Ruby
MySQL
RubyOnRails
Rails5

Rails4.2 → Rails5アップデートで苦労した事例(その1)

この記事は、Business Bank Group Developers Advent Calendar 1日目の記事です。

ご挨拶

 株式会社ビジネスバンクグループ CTOの牧(@Kirika)です。  
 普段はALL-INという中小企業向けの経営ツールのクラウドサービスの開発を行っています。
 主に以下のような技術スタックで開発をしています。

  • フロントエンド … TypeScript(ES6を一部含む)・Angular
  • バックエンド … Ruby・Ruby on Rails
  • DB … MySQL・Elasticsearch・Redis・MongoDB
  • クラウドインフラ … AWS(一部GCP)
  • その他 … GKE・CircleCI・AWS CodeBuild・AWS CodeDeploy等のDevOps系ツール

 私は主にサービス全体の技術選定とアーキテクチャ選択、技術領域としてはRubyとRuby on Railsが得意なので、そのあたりを中心に開発作業にも関わっています。また役割上、採用活動等や開発者のメンタリングもしています。

 今日は私が関わっているRuby on Rails 4.2.8 → Rails5.0.7アップデートの作業の中で得られた知見を紹介しようと思います。

Rails5から入ったActiveRecord::Attributeと、それによって発生した(と思われる)問題について

Rails5からActiveRecord::Attributeというという機能が入りました。これは従来のActiveRecordはデータベースのテーブルで定義した型が自動的にRubyのインスタンスにマッピングされていたのですが、データベースのテーブルの型とは関係なく、ActiveRecord側でattributeの型を再定義してあげることで、任意の型でデータベースのデータを変換できる機能です。詳しい話はy-yagiさんのブログでも紹介されてますので、併せて参考にしてください。

この機能の導入によって、型変換に関するロジックが書き換わり、Rails4.2からのアップデート時に問題になった事例を紹介します。

Rails5のActiveRecordはかなり高い割合で、テーブル結合時の型判定を間違えているのでは疑惑

 どのような問題が起こっていたかというと、ActiveRecordでクエリを書いた時に、ActiveRecordが対応する型判定に失敗し、SQLの生成に失敗する、という問題です。

再現ケース

 最小のテストケースを用意してみました。

 以下を動かすにはmysqlなどを用意する必要があるので、試してみたい方はDocker等でMySQLを用意してください。

# 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" }

  gem "rails", "= 5.0.7"
  gem "mysql2", "= 0.4.10"
  gem "uuidtools"
  gem "attr_uuid"
  gem 'pry'
  gem 'pry-stack_explorer'
end

require "active_record"
require "minitest/autorun"
require "logger"
require "uuidtools"
require "attr_uuid"
require 'pry'
require 'pry-stack_explorer'

# This connection will do for database-independent bug reports.
db_config_admin = {
  adapter: "mysql2",
  username: ENV["USERNAME"] || "root",
  password: ENV["PASSWORD"] || "mysql",
  host: ENV["HOST"] || "localhost",
  port: ENV["PORT"] || 3306
}
db_config = db_config_admin.merge(
  database: "rails_test_database"
)

ActiveRecord::Base.include AttrUuid
ActiveRecord::Base.establish_connection db_config_admin
ActiveRecord::Base.connection.drop_database db_config[:database] rescue nil
ActiveRecord::Base.connection.create_database db_config[:database]
ActiveRecord::Base.connection.close
ActiveRecord::Base.establish_connection db_config
ActiveRecord::Base.logger = Logger.new(STDOUT)

ActiveRecord::Schema.define do
  create_table :posts, force: true, id: false do |t|
    t.column :uuid, :tinyblob
    t.string :title
  end
  execute "ALTER TABLE posts ADD PRIMARY KEY(`uuid`(16))"

  create_table :comments, force: true, id: false do |t|
    t.column :uuid, :tinyblob
    t.column :post_id, :tinyblob
    t.string :comment
  end
  execute "ALTER TABLE comments ADD PRIMARY KEY(`uuid`(16))"
end

class ApplicationRecord < ActiveRecord::Base
  self.abstract_class = true
end

class Post < ApplicationRecord
  self.primary_key = "uuid"
  attr_uuid :id, column_name: "uuid", autofill: true
  has_many :cmnts, foreign_key: :post_id, class_name: "Comment"
end

class Comment < ApplicationRecord
  self.primary_key = "uuid"
  attr_uuid :id, column_name: "uuid", autofill: true
end

class BugTest < Minitest::Test
  def test_association
    post = Post.create(title: "aaa")
    comment = post.cmnts.create(comment: "aaaaa")
    assert_equal Post.joins(:cmnts).where(comments: { uuid: comment.id }).first, post
  end
end

実行結果

$ PORT=3307 HOST=127.0.0.1 PASSWORD=mysql ruby wrong_type_cast_on_simple_association.rb                                                         Fetching gem metadata from https://rubygems.org/..........
Fetching gem metadata from https://rubygems.org/.
Resolving dependencies....
Using rake 12.3.1
Using concurrent-ruby 1.1.3
Using minitest 5.11.3
Using thread_safe 0.3.6
Using builder 3.2.3
Using erubis 2.7.0
Using mini_portile2 2.3.0
Using crass 1.0.4
Using rack 2.0.6
Using nio4r 2.3.1
Using websocket-extensions 0.1.3
Using mini_mime 1.0.1
Using uuidtools 2.1.5
Using arel 7.1.4
Using bundler 1.16.1
Using debug_inspector 0.0.3
Using method_source 0.9.2
Using mysql2 0.4.10
Using coderay 1.1.2
Using i18n 1.1.1
Using tzinfo 1.2.5
Using nokogiri 1.8.5
Using thor 0.20.3
Using websocket-driver 0.6.5
Using rack-test 0.6.3
Using sprockets 3.7.2
Using mail 2.7.1
Using binding_of_caller 0.8.0
Using activesupport 5.0.7
Using loofah 2.2.3
Using pry 0.12.2
Using globalid 0.4.1
Using activemodel 5.0.7
Using rails-dom-testing 2.0.3
Using activejob 5.0.7
Using pry-stack_explorer 0.4.9.3
Using activerecord 5.0.7
Using rails-html-sanitizer 1.0.4
Using attr_uuid 1.1.0
Using actionview 5.0.7
Using actionpack 5.0.7
Using actioncable 5.0.7
Using railties 5.0.7
Using sprockets-rails 3.2.1
Using actionmailer 5.0.7
Using rails 5.0.7
-- create_table(:posts, {:force=>true, :id=>false})
D, [2018-12-01T13:26:28.605899 #96516] DEBUG -- :    (14.1ms)  CREATE TABLE `posts` (`uuid` tinyblob, `title` varchar(255)) ENGINE=InnoDB
   -> 0.0595s
-- execute("ALTER TABLE posts ADD PRIMARY KEY(`uuid`(16))")
D, [2018-12-01T13:26:28.622900 #96516] DEBUG -- :    (16.7ms)  ALTER TABLE posts ADD PRIMARY KEY(`uuid`(16))
   -> 0.0170s
-- create_table(:comments, {:force=>true, :id=>false})
D, [2018-12-01T13:26:28.662196 #96516] DEBUG -- :    (34.6ms)  CREATE TABLE `comments` (`uuid` tinyblob, `post_id` tinyblob, `comment` varchar(255)) ENGINE=InnoDB
   -> 0.0392s
-- execute("ALTER TABLE comments ADD PRIMARY KEY(`uuid`(16))")
D, [2018-12-01T13:26:28.702054 #96516] DEBUG -- :    (39.6ms)  ALTER TABLE comments ADD PRIMARY KEY(`uuid`(16))
   -> 0.0398s
D, [2018-12-01T13:26:28.739823 #96516] DEBUG -- :    (12.9ms)  CREATE TABLE `ar_internal_metadata` (`key` varchar(255) PRIMARY KEY, `value` varchar(255), `created_at` datetime NOT NULL, `updated_at` datetime NOT NULL) ENGINE=InnoDB
D, [2018-12-01T13:26:28.755416 #96516] DEBUG -- :   ActiveRecord::InternalMetadata Load (1.8ms)  SELECT  `ar_internal_metadata`.* FROM `ar_internal_metadata` WHERE `ar_internal_metadata`.`key` = 'environment' LIMIT 1
D, [2018-12-01T13:26:28.777960 #96516] DEBUG -- :    (2.2ms)  BEGIN
D, [2018-12-01T13:26:28.781115 #96516] DEBUG -- :   SQL (1.9ms)  INSERT INTO `ar_internal_metadata` (`key`, `value`, `created_at`, `updated_at`) VALUES ('environment', 'development', '2018-12-01 04:26:28', '2018-12-01 04:26:28')
D, [2018-12-01T13:26:28.796281 #96516] DEBUG -- :    (13.9ms)  COMMIT
Run options: --seed 51835

# Running:

D, [2018-12-01T13:26:28.849465 #96516] DEBUG -- :    (1.4ms)  BEGIN
D, [2018-12-01T13:26:28.896843 #96516] DEBUG -- :   SQL (1.4ms)  INSERT INTO `posts` (`uuid`, `title`) VALUES (x'45cba6cef52111e896c9a45e60ba8387', 'aaa')
D, [2018-12-01T13:26:28.902071 #96516] DEBUG -- :    (4.8ms)  COMMIT
D, [2018-12-01T13:26:28.917688 #96516] DEBUG -- :    (3.5ms)  BEGIN
D, [2018-12-01T13:26:28.942727 #96516] DEBUG -- :   SQL (2.8ms)  INSERT INTO `comments` (`uuid`, `post_id`, `comment`) VALUES (x'45d9380cf52111e896c9a45e60ba8387', x'45cba6cef52111e896c9a45e60ba8387', 'aaaaa')
D, [2018-12-01T13:26:28.952346 #96516] DEBUG -- :    (8.0ms)  COMMIT
E, [2018-12-01T13:26:28.977325 #96516] ERROR -- : Could not log "sql.active_record" event. ArgumentError: invalid byte sequence in UTF-8 ["/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/log_subscriber.rb:74:in `==='", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/log_subscriber.rb:74:in `sql_color'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/log_subscriber.rb:43:in `sql'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activesupport-5.0.7/lib/active_support/subscriber.rb:95:in `finish'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activesupport-5.0.7/lib/active_support/log_subscriber.rb:83:in `finish'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activesupport-5.0.7/lib/active_support/notifications/fanout.rb:102:in `finish'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activesupport-5.0.7/lib/active_support/notifications/fanout.rb:46:in `block in finish'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activesupport-5.0.7/lib/active_support/notifications/fanout.rb:46:in `each'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activesupport-5.0.7/lib/active_support/notifications/fanout.rb:46:in `finish'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activesupport-5.0.7/lib/active_support/notifications/instrumenter.rb:42:in `finish_with_state'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activesupport-5.0.7/lib/active_support/notifications/instrumenter.rb:27:in `instrument'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/connection_adapters/abstract_adapter.rb:583:in `log'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:218:in `execute'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/connection_adapters/mysql/database_statements.rb:31:in `execute'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:225:in `execute_and_free'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/connection_adapters/mysql/database_statements.rb:36:in `exec_query'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/connection_adapters/abstract/database_statements.rb:373:in `select'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/connection_adapters/abstract/database_statements.rb:41:in `select_all'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/connection_adapters/abstract/query_cache.rb:95:in `select_all'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/connection_adapters/mysql/database_statements.rb:10:in `select_all'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/querying.rb:39:in `find_by_sql'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/relation.rb:706:in `exec_queries'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/relation.rb:583:in `load'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/relation.rb:260:in `records'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/relation.rb:256:in `to_a'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/relation/finder_methods.rb:563:in `find_nth_with_limit'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/relation/finder_methods.rb:592:in `find_nth_with_limit_and_offset'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/relation/finder_methods.rb:545:in `find_nth'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/relation/finder_methods.rb:122:in `first'", "wrong_type_cast_on_simple_association.rb:86:in `test_association'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest/test.rb:98:in `block (3 levels) in run'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest/test.rb:195:in `capture_exceptions'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest/test.rb:95:in `block (2 levels) in run'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest.rb:265:in `time_it'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest/test.rb:94:in `block in run'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest.rb:360:in `on_signal'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest/test.rb:211:in `with_info_handler'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest/test.rb:93:in `run'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest.rb:960:in `run_one_method'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest.rb:334:in `run_one_method'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest.rb:321:in `block (2 levels) in run'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest.rb:320:in `each'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest.rb:320:in `block in run'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest.rb:360:in `on_signal'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest.rb:347:in `with_info_handler'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest.rb:319:in `run'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest.rb:159:in `block in __run'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest.rb:159:in `map'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest.rb:159:in `__run'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest.rb:136:in `run'", "/Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest.rb:63:in `block in autorun'"]
.

Finished in 0.141061s, 7.0891 runs/s, 7.0891 assertions/s.
1 runs, 1 assertions, 0 failures, 0 errors, 0 skips

最後のCould not log "sql.active_record" event. ArugumentError: invalid byte sequence in UTF-8のところがポイントです。テストは通っているので、SQL自体は無事にデータベースに到達し、望む形の結果を得られているのですが、Post.joins(:cmnts).where(comments: { uuid: comment.id }).firstのクエリがロギングされていません。なぜ出なかったかは、上記のコードに、以下のようなデバッグコードを仕込むことで知ることが出来ます。

module LogSubscriberInjector
  def sql_color(sql)
    super
  rescue
    binding.pry
  end
end
ActiveRecord::LogSubscriber.prepend LogSubscriberInjector
From: /Users/maki/.anyenv/envs/rbenv/versions/2.5.0/lib/ruby/gems/2.5.0/gems/activerecord-5.0.7/lib/active_record/log_subscriber.rb @ line 43 ActiveRecord::LogSubscriber#sql:

    23: def sql(event)
    24:   self.class.runtime += event.duration
    25:   return unless logger.debug?
    26:
    27:   payload = event.payload
    28:
    29:   return if IGNORE_PAYLOAD_NAMES.include?(payload[:name])
    30:
    31:   name  = "#{payload[:name]} (#{event.duration.round(1)}ms)"
    32:   sql   = payload[:sql]
    33:   binds = nil
    34:
    35:   unless (payload[:binds] || []).empty?
    36:     casted_params = type_casted_binds(payload[:type_casted_binds])
    37:     binds = "  " + payload[:binds].zip(casted_params).map { |attr, value|
    38:       render_bind(attr, value)
    39:     }.inspect
    40:   end
2.5.0 (#<ActiveRecord::LogSubscriber:0x00007f92be2709b8>):0 > payload[:sql]
=> "SELECT  `posts`.* FROM `posts` INNER JOIN `comments` ON `comments`.`post_id` = `posts`.`uuid` WHERE `comments`.`uuid` = '\\\xCCP\x87\xBC\xF5#\u0011豝\xA4^`\xBA\x83\x87' ORDER BY `posts`.`uuid` ASC LIMIT 1"

SQLの中にバイナリが直接含まれていることが確認できると思います。
ちなみにRails 4.2.8においては以下のような結果になり、バイナリはバイナリリテラルに適切に変換され、このような問題は起こりません。

# Running:

D, [2018-12-01T13:46:28.317628 #97006] DEBUG -- :    (3.4ms)  BEGIN
D, [2018-12-01T13:46:28.367351 #97006] DEBUG -- :   SQL (1.6ms)  INSERT INTO `posts` (`title`, `uuid`) VALUES ('aaa', x'10bc88a6f52411e8b185a45e60ba8387')
D, [2018-12-01T13:46:28.371938 #97006] DEBUG -- :    (4.0ms)  COMMIT
D, [2018-12-01T13:46:28.403836 #97006] DEBUG -- :    (1.3ms)  BEGIN
D, [2018-12-01T13:46:28.410376 #97006] DEBUG -- :   SQL (2.3ms)  INSERT INTO `comments` (`comment`, `post_id`, `uuid`) VALUES ('aaaaa', x'10bc88a6f52411e8b185a45e60ba8387', x'10c996fef52411e8b185a45e60ba8387')
D, [2018-12-01T13:46:28.422115 #97006] DEBUG -- :    (9.4ms)  COMMIT
D, [2018-12-01T13:46:28.452631 #97006] DEBUG -- :   Post Load (3.1ms)  SELECT  `posts`.* FROM `posts` INNER JOIN `comments` ON `comments`.`post_id` = `posts`.`uuid` WHERE `comments`.`uuid` = x'10c996fef52411e8b185a45e60ba8387'  ORDER BY `posts`.`uuid` ASC LIMIT 1

何故このようなことが起こるのか

 私もまだ完全にこの問題について理解したわけではないのですが、Rails5では正しく渡された値を変換するためには、クエリを発行する対象のmodel classが、渡される変数の型を理解している必要があります。

 例えば、上記のpostsテーブルにおける型は以下のようになります。

2.5.0 (#<BugTest:0x00007fc6b117a190>):0 > Post.column_types
=> {"uuid"=>#<ActiveRecord::Type::Binary:0x00007fc6b1183e70 @limit=255, @precision=nil, @scale=nil>,
 "title"=>#<ActiveRecord::ConnectionAdapters::AbstractMysqlAdapter::MysqlString:0x00007fc6b1181a80 @limit=255, @precision=nil, @scale=nil>}

 もし存在しないカラム名を問い合わせた場合、ActiveRecord::Type::Valueを返します。これは変換せずに渡された値をそのまま使う、という意味になります。

2.5.0 (#<BugTest:0x00007fc6b117a190>):0 > Post.type_for_attribute("unknown_column_name")
=> #<ActiveRecord::Type::Value:0x00007fc6b11810f8 @limit=nil, @precision=nil, @scale=nil>

 関連テーブルの型はどう解釈されるかというと、詳細な解説は避けるのですがwhere(comments: {uuid: comment.id})の部分からcommentsに関するアソシエーションを探しに行こうとします。ところが、今回のケースではhas_many :cmnts foreign_key: :post_id, class_name: "Comment"としたため、commentsという名前のアソシエーションを探せず、ActiveRecord::Type::Valueを返したため、上記のような事象が起こったと考えています。

 ただ、ほとんどのケースに於いてはこのようなテーブル結合や条件を指定するキーにバイナリ型を置くという人はいないと思うので、仮にこれがStringやIntegerであれば、ActiveRecord::Type::Valueを返しても変換で死ぬ、ということは発生せず、大部分の人は問題に気づいていないのではないかと思います。

解決策

 もう少し事象を把握したら、きちんとIssueを立てて、パッチを投稿したいのですが、今はRailsアップデートに集中したいので、後回しにするとして、以下のようなアソシエーションを足すことで、とりあえず解決します。

class Post < ApplicationRecord
  self.primary_key = "uuid"
  attr_uuid :id, column_name: "uuid", autofill: true
+  has_many :comments # FIXME remove it later
  has_many :cmnts, foreign_key: :post_id, class_name: "Comment"
end

このアソシエーションを追加することで、Railsはcomments → uuidの経路をたどることが出来、正しくバイナリを変換することが出来ます。

2.5.0 (#<BugTest:0x00007fdd47538870>):0 > Post.joins(:cmnts).where(comments: { uuid: comment.id }).to_sql
=> "SELECT `posts`.* FROM `posts` INNER JOIN `comments` ON `comments`.`post_id` = `posts`.`uuid` WHERE `comments`.`uuid` = x'4c2649e6f52811e8841ea45e60ba8387'"

まとめ

 このケース、現状のRailsでほとんど認知されてないためか、他にも沢山似たような問題があり、今の所以下を確認しています。

  • has_and_belongs_to_manyを使ったケースで型判定に失敗する
  • has_many throughを使ったケースで型判定に失敗する(Rails 5.1.3で解消)
  • uniqueness validatorを使ったケースで型判定に失敗する(Rails 5.1.0で解消)

 修正された問題もあるみたいなので、頑張ってRailsのバージョンアップを継続し、なんとか対策していきたいです。(その前にバイナリをPK・FKにするのをやめるのが先かも…)

明日の担当

 明日は、最近フロントエンド開発者として入社した、@tronperidotが担当します。よろしくお願いします。