99blues
記事一覧に戻る
DynamoDBRailsDocker

DynamoDB Local で update_attributes しても値が更新されない怪現象を追いかけたら、同一キーのアイテムが2つ存在していた話

7分で読めます

TL;DR

  • Rails + Dynamoid の開発環境で、update_attributes が成功しているのに読み直すと更新前の値が返ってきた
  • 調べたら、まったく同じプライマリキーを持つアイテムがテーブル内に2つ存在していた。UpdateItem が既存アイテムを更新せず、同じキーの行を新規追加していた
  • DynamoDB Local の起動オプション -optimizeDbBeforeStartup と永続ボリュームの組み合わせで DB ファイルが壊れたと見ている。テーブルを作り直し、オプションを外して解決した

更新したはずの値が戻ってくる

開発環境の rails console で、DynamoDB 上のセンサーデータの属性を更新しようとしたときのこと。

irb> Sensor::Reading.first.update_attributes(measuredValue: 1)
=> true
irb> Sensor::Reading.first.measuredValue
=> nil   # 更新前のまま…?

update_attributes は true を返しているのに、読み直すと値が変わっていない。エラーも出ない。

容疑者を順に潰す

環境は Rails + Dynamoid(DynamoDB 用 ODM)、それに devcontainer 内の DynamoDB Local 2.6.0。モデルは device_id をハッシュキー、time をレンジキーとする複合キーのテーブルだ。

まずバリデーション失敗を疑ったが、このモデルにバリデーションはないし戻り値も true なので違う。

次にレンジキーの round-trip を疑った。このモデルはレンジキーにカスタムアダプタを使っていて、dynamoid_dump が obj.utc.iso8601 を返す実装になっている。保存されている文字列にミリ秒や +09:00 オフセットが混ざっていると、dump した文字列が保存値と一致せず、別キーへの書き込みになりうる。検証すると round-trip が一致しないケースは確かに存在した。ただ今回のデータは秒精度の UTC 文字列で、キーは完全に一致していた。これも違う。

最後に .first の挙動。Dynamoid の .first は Scan の先頭1件を返すだけで、最新のレコードではない。ただし Scan の順序は安定しているので、更新した対象と読み直した対象は同じレコードのはずだ。ここも空振り。

同一キーのアイテムが2つあった

Dynamoid を介さず AWS SDK で直接 Scan したところ、目を疑う結果が返ってきた。

client.scan(table_name: table).items
# => [
#   { "device_id" => "abc123...", "time" => "2026-05-25T04:36:53Z", "measuredValue" => nil },
#   { "device_id" => "abc123...", "time" => "2026-05-25T04:36:53Z", "measuredValue" => 1 },  # !?
# ]

ハッシュキーもレンジキーもバイト単位で完全に同一のアイテムが2つ。DynamoDB はプライマリキーでアイテムを一意に識別するので、本物の DynamoDB ではあり得ない。片方は更新前の行で、もう片方は update_attributes が書き込んだ行だった(updated_at も更新時刻になっていた)。

つまり update_attributes は失敗していなかった。UpdateItem が既存アイテムを置き換えず、同じキーの行を追加していたのだ。.first は Scan なので古い方の行を先に返す。だから更新されていないように見えていた。

追い打ちで、このキーに対して GetItem や DeleteItem を実行すると DynamoDB Local が InternalFailure を返す。内部の一意性の前提が壊れていることの傍証だと思う。

どのレイヤーが壊れているか

原因のレイヤーを特定するため、3つ試した。

  1. Dynamoid が送る UpdateItem リクエストをフックしてダンプする。キーは保存値と完全一致していて、リクエスト自体は正常だった
  2. SDK を直叩きして PutItem のあと UpdateItem を投げる。それでも同一キーの行が2つに増えた。アプリ側のコードは無関係だと確定
  3. 同じ DynamoDB Local インスタンスに新規テーブルを作って同じ操作をする。こちらは正常で、1行のまま更新された

壊れているのは特定のテーブルだけ、というところまで絞れた。

犯人は -optimizeDbBeforeStartup か

このテーブルが壊れた原因として浮上したのが、docker compose の起動コマンドだ。

dynamodb:
  image: amazon/dynamodb-local:2.6.0
  restart: unless-stopped
  command: -jar DynamoDBLocal.jar -sharedDb -dbPath . -optimizeDbBeforeStartup
  volumes:
    - dynamodb-data:/home/dynamodblocal

-optimizeDbBeforeStartup は、起動前に DB ファイル内部のテーブルを最適化(再構築)する任意オプションで、肥大化した DB ファイル向けのパフォーマンス改善用だ。開発環境の数十行のデータには何の恩恵もない。

一方この構成だと、コンテナが起動するたびに永続ボリューム上の DB ファイルで再構築処理が走る。devcontainer は起動と停止が頻繁だし、restart: unless-stopped のせいで再起動も多い。再構築の最中にコンテナが落ちれば、共有 SQLite の DB ファイルが中途半端な状態で残る。今回はプライマリキーの一意インデックスが壊れて、Scan や Query では見えるのにキー指定の書き込みでは既存行にヒットせず新規行が挿入される、という状態になったと推定している。

復旧手順

壊れた行は DeleteItem でも消せない(InternalFailure)ので、テーブルごと作り直した。

  1. 全行を Scan してバックアップ
  2. キーごとに残す行を決めて重複を排除
  3. delete_table してから同じスキーマで create_table
  4. put_item で復元

そのうえで -optimizeDbBeforeStartup を compose.yaml から削除した。

-    command: -jar DynamoDBLocal.jar -sharedDb -dbPath . -optimizeDbBeforeStartup
+    command: -jar DynamoDBLocal.jar -sharedDb -dbPath .

教訓

ORM のバグも自分のコードも疑い尽くしたら、次はストレージが不変条件を破っている可能性を考えたほうがいい。エミュレータは本物のサービスの保証を破ることがある。今回でいえばプライマリキーの一意性がそれだった。

エミュレータの起動オプションは、意味を理解してから付けるべきだった。-optimizeDbBeforeStartup は必須ではないし、永続ボリューム + 頻繁な再起動という構成では破損リスクにしかなっていない。

切り分けはレイヤーを1枚ずつ剥がすのが結局いちばん早い。ODM から生 SDK、そして新規テーブルへと落としていけば、どの層の問題かは機械的に特定できる。

おまけとして、Dynamoid の .first は Scan の先頭であって最新レコードではない。最新の1件が欲しいならレンジキーで scan_index_forward(false).first を使うこと。

ローカルエミュレータは便利だが、本物なら絶対に起きないことが起きる。「DB がそんな壊れ方をするはずがない」という思い込みが、今回いちばんの回り道だった。

前の記事RSpecを使ってセレクトボックスに特定のオプションが含まれていないことをテストする方法