ライブラリを上げたらテストが落ちたのでその原因を探っていったら他の問題も解決できた話

株式会社MyVisionでエンジニアをしている @sukechannnn です！

直近でgemのバージョンアップ作業を行っていたのですが、謎の原因で Elasticsearch (searchkick) に関するテストが落ちるようになってしまいました。

結論から言うと、原因は multi_json 1.18.0 のアップデートだったのですが、ここに至るまでに他にも判明したことがあって面白かったので、順を追って書いてみたいと思います。

バグの調査や問題の切り分け方について参考になれば幸いです。

先に結論

以下の multi_json の変更により、Elasticsearch に送られる日時のデータが ISO 8601 形式でなくなったために、Elasticsearch の date detection パターンにマッチしなくなってしまいました。

multi_json 1.18.0 のアップデートによる変更は以下の通りです。
https://github.com/sferik/multi_json/commit/dfdfd7fb401f501be3b36da81ebeb18376490a62

• JsonGem アダプタの実装が object.to_json から JSON.generate に変更された
• これにより Time や ActiveSupport::TimeWithZone オブジェクトをシリアライズした結果がISO 8601形式じゃなくなってしまった (Time オブジェクトを to_s した形式になってしまった）
  • → Elasticsearch の自動型判定の結果が文字列になってしまった

※この問題は 1.19.0 で解消したようです。
https://github.com/sferik/multi_json/commit/03a367813ebd7ed87eb22ea05249cc6453bb3c10

ここから改めて、問題の発生から調査、解明に至るまでの流れを順を追って説明します。

発生した問題

まとめていくつかの gem をアップデートしている作業中、Elasticsearch を使った検索機能のテストが失敗するようになりました。

Searchkick::InvalidQueryError:
  [400] {"error":{"root_cause":[{"type":"illegal_argument_exception",
  "reason":"Text fields are not optimised for operations that require
  per-document field data like aggregations and sorting...
  set fielddata=true on [created_at] in order to load field data...

created_at でソートしようとすると、「text フィールドはソートに使えない」というエラーです。

searchkick では #search_data メソッドに検索・ソート対象のデータを指定するとElasticsearchにインデックスしてくれるのですが、以下のように created_at を指定している場合に発生していました。

class Blog
  def search_data
    { content:, created_at: }
  end
end

この時、Searchkick や elasticsearch 関連のgemはアップデートを見送ったので、なぜ created_at が正しく日時としてElasticsearchに認識されなくなったのか謎でした。

ここから原因の調査を開始しました。

原因調査

Elasticsearch のマッピングを確認

まずは、実際に Elasticsearch に作成されたマッピングを確認します。

client = Searchkick.client
index = Blog.search_index
mapping = client.indices.get_mapping(index: index_name)
# => {"created_at" => {"type" => "text", "index" => false}}

本来 {"type" => "date"} であるべき created_at が、text 型になっています。
Elasticsearch のエラーの内容は正しそうです。

正しく動作していたブランチに戻して同様に確認し、{"type" => "date"} になっていることを確認しました。

Elasticsearch がどのように created_at が date だと判定しているかというと、ISO 8601 形式の文字列は date だと認識します。
つまり、送っているデータの形式が変わってしまったのが原因のようです。

ただ、この時点ではどのgemのアップデートが挙動の変更を引き起こしているのかがパッとわかりませんでした。
そこで、Searchkick や Elasticsearch に関連するgemのバージョンを１つずつ元に戻し、挙動が変わるgemがないかを調査しました。

その結果、他のgemの依存でインストールされていた multi_json のバージョンを戻すと、挙動が正しく動くことが分かりました。

MultiJson の挙動を確認

このプロジェクトでは elasticsearch-transport gem が内部で MultiJson を使って JSON シリアライズを行っています。

multi_json 1.15.0 → 1.18.0 に上げたのですが、マイナーバージョンを１つずつ上げていくと、1.17.0 → 1.18.0 で挙動が異なる事がわかりました。

multi_json 1.17.0

time = Time.current
data = { created_at: time }

MultiJson.dump(data)
# => {"created_at":"2025-12-05T21:01:35+09:00"} ISO8601形式

multi_json 1.18.0

multi_json 1.18.0

time = Time.current
data = { created_at: time }

MultiJson.dump(data)
# => {"created_at":"2025-12-05 21:01:35 +0900"} ← Timeオブジェクトをto_sした時の挙動になってる。これが問題！

"2025-12-05 21:01:35 +0900" という形式は ISO 8601 ではないため、Elasticsearch の date detection パターンにマッチしません。

multi_json 1.18.0 の変更点

1.18.0 の変更を調べたところ、JsonGem アダプタの dump メソッドに破壊的変更がありました。

# Before (1.17.0 以前)
def dump(object, options = {})
  object.to_json(options)
end

# After (1.18.0)
def dump(object, options = {})
  ::JSON.generate(object, options)
end

この違いが問題の原因でした。

object.to_json と JSON.generate は挙動が異なります。

time = Time.current

# to_json - ActiveSupport がオーバーライドしている
{ created_at: time }.to_json
# => {"created_at":"2025-12-05T21:01:35.560+09:00"}  ✅ ISO 8601 形式

# JSON.generate - 標準ライブラリの実装
JSON.generate({ created_at: time })
# => {"created_at":"2025-12-05 21:01:35 +0900"}  ❌ Time#to_s の形式

Hash#to_json は ActiveSupport によってオーバーライドされており、内部で各要素の as_json メソッドを呼びます。そのため、Time#as_json は ISO 8601 形式の文字列を返します。

一方、JSON.generate は Ruby 標準ライブラリの実装で、Time オブジェクトに対して to_s を呼ぶため、人が読むための形式になってしまいます。

もう一つの問題: gem のロード順序

ここでもう一つの疑問が浮かびました。パフォーマンスの観点から oj がインストールされていたのですが、なぜか JsonGem アダプタが使われているのです。oj が使われていれば、上記のバグにはひっかかりません。

実際に oj gem はインストールされており、MultiJson は通常、より高速な Oj を優先的に選択するはずです。

MultiJson のアダプタ選択ロジック:

def loaded_adapter
  return :oj if defined?(::Oj)
  return :yajl if defined?(::Yajl)
  return :jr_jackson if defined?(::JrJackson)
  return :json_gem if defined?(::JSON::Ext::Parser)
  return :gson if defined?(::Gson)
  nil
end

gem のロード順序を確認

そこで、他の gem が何かの理由で JsonGem を優先的に読み込んでいるかもしれないと思い、gem のロード順を調べました。

Bundler.definition.specs.to_a.each_with_index do |spec, i|
  puts "#{i}. #{spec.name}" if %w[json-schema oj multi_json json].include?(spec.name)
end

# 99.  multi_json
# 157. json
# 158. json-schema
# 165. oj          ← json-schema より後！

すると、oj を読み込む前に json-schema gem が読み込まれていることが分かりました。
この gem は json-schema でバリデーションできる便利なライブラリなのですが、起動時に以下のコードを実行します。

# json-schema.rb
if Gem::Specification.find_all_by_name('multi_json').any?
  require 'multi_json'
  MultiJson.respond_to?(:adapter) ? MultiJson.adapter : MultiJson.engine
end

MultiJson.adapter が呼ばれた時点で、アダプタが決定されます。しかし、このタイミングでは oj がまだロードされていないため、defined?(::Oj) は nil を返し、結果として JsonGem が選択されてしまいます。

一度 @adapter が設定されると、以降は変更されません。後から oj がロードされても、既に JsonGem で固定されています。

解決策

元々パフォーマンスの観点で oj gem を使いたかったので、明示的に設定することにしました。

config/initializers/multi_json.rb を作成し、以下の設定をしました。

# MultiJson で Oj アダプタを使用する
# gem のロード順序によって JsonGem が選択されてしまう問題があるため、明示的に設定する
MultiJson.use(:oj)

これにより、oj gem が JSON の処理で使われることが確定し、今回発生したバグの解消と併せて、意図したgemが使われるようになりました。
明示的に指定するなら MultiJson いらないのでは？という気持ちにもなりましたが、裏で MultiJson に依存している gem が多いので、この形にするのが最適だろうと判断しました。

まとめ

今回の問題は、以下の2つが重なって発生しました。

1. multi_json 1.18.0 の破壊的変更により、JsonGem アダプタで object.to_json から JSON.generate に処理が変わって日時が ISO 8601 でなくなってしまった
2. json-schema が oj より先にロードされていたため、意図しないアダプタが選択されていた

gem のアップデートでバグった結果2.の問題に気づけたのは棚ぼたでしたが、こうやって深く見ていくと「実は使われてなかった」みたいなことに気づけることもあります。
こういったことは機能実装だけしているとなかなか気づけないので、定期的にライブラリアップデートやリファクタリングなどにきちんと時間を取って深くまで見ていくのは大事だなと感じました。