ichirin2501's diary

いっちりーん。

ファミコンエミュレータ実装の感想

とりあえずスーパーマリオが動いて一段落したので覚えているうちに感想書いていく。

(この記事の情報量は、デバッグは大変、以上)

動機

単に好奇心。ただ、ファミコンエミュレータに着手したのはこれで3回目になる。
1度目は10年前の身内ハッカソンのとき。このときはC言語で実装してて強引にHELLO, WORLD!を表示するだけで終わった。 実装の続きをしたかったけど、この後は忙しくなってしまって挫折している。
2度目は2年前で、過去の心残りを精算するためにGo言語で着手したのだけど、CPUの実装が終わった後ぐらいからまた忙しくなって挫折している。
今回は2年前のGoコードの続きからコミットを積んでここまで来たので、一応リベンジ成功....と言って良いんじゃないかな、たぶん。

過程

PPUの実装は最初からinternal register(v,t,x,w)を使う方法にした(PPU scrolling)。
hello world表示するだけでも地味にデバッグが大変になってしまって、最初は少し後悔した。

これは見切れているhello world


見切れるbugは修正したけど、次は左寄りになってるhello world
これはppu shift registersのbufferが1tile分足りなくて、1tileずれて表示されていた。

https://www.nesdev.org/wiki/PPU_rendering#Cycles_1-256
Note: At the beginning of each scanline, the data for the first two tiles is already loaded into the shift registers (and ready to be rendered), so the first tile that gets fetched is Tile 3.


hello world!!


正常なhello worldを確認して意気揚々とnestest.nesを読み込ませたらメモリアクセス違反でクラッシュしたんだけど、無視して強引に表示させた様子。 めっちゃバグってて草。画面表示なしだとnestest.nesのCPUテストはクリアするので、ここで少しデバッグに苦しんだ。


画面表示ありでnestest.nesが正常に動いた様子。
原因としては以下の一文を見落としており、メモリアクセス違反が発生していた。

https://www.nesdev.org/wiki/PPU_scrolling#PPU_internal_registers
Note that while the v register has 15 bits, the PPU memory space is only 14 bits wide. The highest bit is unused for access through $2007.


sprite実装に着手したがきもい色になった。
ここからギコ猫でもわかるファミコンプログラミングの各種ROMにお世話になる。


正常なgiko猫さん


背景動いている


sprite 0 hit の実装も(bugがあるが)比較的にすんなり進んでしまってgiko猫のラスタスクロールは動いた。ただ、この後の実装でこのgiko猫ラスタスクロールは動かなくなる、下記に従った実装すると動かなくなってしまった(今も)。

これと、

https://www.nesdev.org/wiki/PPU_registers#OAM_data($2004)%3C%3E_read/write
Writes to OAMDATA during rendering (on the pre-render line and the visible lines 0-239, provided either sprite or background rendering is enabled) do not modify values in OAM

これ

https://www.nesdev.org/wiki/PPU_registers#OAM_address($2003)%3E_write
Values during rendering
OAMADDR is set to 0 during each of ticks 257-320 (the sprite tile loading interval) of the pre-render and visible Scanlines.


公開されている2048.nes。このときはまだコントローラ実装が雑だったので操作感が微妙だったが、ぎり遊べた。

ここからは公開されているPPU系のテストROMと格闘することになる。
bug取り作業で印象に残っているのは3つ。

1. CPUとPPUのタイミング実装を変えたこと

まず、実機だとCPUとPPUは独立して動作し、clock差は1:3の関係になっている。対してエミュ実装の基本的な方針としては並列ではなくCPUを動かしてその後にPPUを動かす。 自分の実装でも方針は同じだけど、CPU命令を1つ実行したらその命令にかかったclock数に応じて最後にPPUを動かしていた。
各命令毎のclock数の表はこことか: https://www.nesdev.org/wiki/6502_cycle_times
例えばLDA ABSなら4clockなので、その命令の処理が全部終わってからPPU側を12clock動かす。 この実装のエミュだと、実機の挙動と比較してCPUとPPUの状態に差があるのでrace conditionの再現度がいまいち。それが原因でどうにもvbl flag timing系のテストが通らなかった。 https://www.nesdev.org/wiki/PPU_frame_timing#VBL_Flag_Timing

再現度を上げるためにも各命令の実行途中で良い感じにPPUを進ませたい (良い感じとは?)。 なんとかしてえ〜って思って各命令にかかるclock数に着目していたら、最低でもメモリの読み/書きする回数以上であることが分かった。 CPUから1回メモリを読み/書きするときにPPU 3clock進ませる方針にして、余ったclock数は最後に調節する設計に切り替えた。 これが良い感じにハマって多くのvbl flag timingu系のテストを通すことが出来た。 その後になって命令毎にどのタイミングでCPU 1clock相当の処理になるのか詳細に書かれた資料を見つけてさらにハッピー。
https://www.nesdev.org/6502_cpu.txt
dummy read/write はこの辺から来てるのか〜となった。

2. CPUから見たときのPPUの状態の定義

メモリの読み書き時にPPUを動かすようにしても一部のtiming testが通らなかった。デバッグするとテストROMが期待する状態に対してPPU 1clock分ずれていた。 CPU 1clock分ずれるのは分かるけどPPU 1clockずれることに心当たりがなくて???だった。 自分の最初の実装だと、「PPUのscanline=241,cycle=1のときにvblankが発生する」というのを、cycle 1 ~ 2 の間で発生すると解釈して実装していた。これだとCPUから見てPPUの状態がちょうどscanline=241,cycle=1のときはまだvblankが発生していないことになっていた。対してテストROMが期待していたのはvblankが発生済み、というものだったので、自分の解釈が間違っていた。 cycle 1 ~ 2 の間で発生する〜実装をやめて、CPUから見てPPU cycle=1状態だとcycle=1で発生するPPU側のイベントは全部終わっているように修正した。 これで当初こけてたテストも通った。

3. sprite 0 hitのbug


めっちゃハマった。上記はこのbugにハマっていたときのもの。 このbugに向き合う前は散々cpuとppuのタイミングのずれと格闘していたので、絶対それ関連だろうと憶測を立ててしまったのが誤り。 不幸なことにこの時点でsprite_hit_tests_2005.10.05のテストは全部OKだったので、既存のテストROMで検知出来ない部分のsprite 0 hit処理がバグってると考えるのにかなり時間がかかってしまった。 wikiの通りにoamはprimaryとsecondaryを用意する実装にしていたんだけど、"0 index"の対象をsecondary oam側にしてしまっていたのが原因だった。普通にbugである。 RasterDemoの画面の動きを観察したときに、背景を1本の軸で回転させてるなぁ〜 => ラスタスクロールはタイミングを捉えるのが重要だからこの1本の軸のところがsprite 0 hitだろう => 常に固定だろう => あれ、なんでsprite 0 hitが固定なのに画面がちらつくんだ? という思考による気付きだった。観察は重要。 primary oam側の0 indexを見るように修正して解決。

他にも色んなデバッグ苦労話があるがだいたいこんなところ

テストROMがある程度通したところで、FCダンパー購入


メルカリで購入したスーパーマリオをダンパーに指した様子

そしていざROM吸い出し....


これはカセットとROM吸い出しの接触不良によって生み出された謎のゲーム。
めっちゃわくわくして自作エミュに読み込ませたらこれだったので「えっ、自作エミュばぐってる?... 念入りにテスト通してきたのに?....」ってなった。 急遽別のエミュを落としてきて同ROMを読み込ませたら同じ現象になって安堵した。

カセットを抜き差しして何度か試すものの、毎回ハッシュ値が違ってて笑ってしまった。
念願のハッシュ値で吸い出し成功したら平和が訪れた。

だめだと分かってても懐かしさに負けてカセットをふーふーしてしまった。反省してます。

その他

実装の骨格はfogleman/nesを参考にさせていただいた。シンプルに書かれててすごい。自分のエミュではAPUは未実装、サウンドは...仕組みにあまり興味がないのでたぶん実装しない。vbl_nmi_timing/7.nmi_timing.nesppu_vbl_nmi/05-nmi_timing.nesはNMI発生をppu 2clock delayさせるhackをしてしまった。今の自作エミュだとcpuを動かした後にppuを動かす実装なので、ppuの動作が実際より遅れることはあっても早くなることはない、という理解なのだけど、テストROMが期待するよりもNMI発生が早い...という状態っぽくて ??? 状態。よくわかってない。あと、decay ppu openbusがよくわからず未実装。ppu openbusのテスト通しておきたい気持ちはある。ぽよよ

github.com

現時点で自分が主に使ったテストROMたち

Test SingleRom Result
blargg_ppu_tests_2005.09.15b palette_ram.nes OK
blargg_ppu_tests_2005.09.15b sprite_ram.nes OK
blargg_ppu_tests_2005.09.15b vbl_clear_time.nes OK
blargg_ppu_tests_2005.09.15b vram_access.nes OK
branch_timing_tests 1.Branch_Basics.nes OK
branch_timing_tests 2.Backward_Branch.nes OK
branch_timing_tests 3.Forward_Branch.nes OK
cpu_dummy_reads cpu_dummy_reads.nes OK
cpu_dummy_writes cpu_dummy_writes_oam.nes OK
cpu_dummy_writes cpu_dummy_writes_ppumem.nes OK
cpu_exec_space test_cpu_exec_space_apu.nes Failed
cpu_exec_space test_cpu_exec_space_ppuio.nes OK
cpu_timing_test6 cpu_timing_test.nes OK
instr_misc 01-abs_x_wrap.nes OK
instr_misc 02-branch_wrap.nes OK
instr_misc 03-dummy_reads.nes OK
instr_misc 04-dummy_reads_apu.nes Failed
instr_test-v5 01-basics.nes OK
instr_test-v5 02-implied.nes OK
instr_test-v5 03-immediate.nes OK
instr_test-v5 04-zero_page.nes OK
instr_test-v5 05-zp_xy.nes OK
instr_test-v5 06-absolute.nes OK
instr_test-v5 07-abs_xy.nes OK
instr_test-v5 08-ind_x.nes OK
instr_test-v5 09-ind_y.nes OK
instr_test-v5 10-branches.nes OK
instr_test-v5 11-stack.nes OK
instr_test-v5 12-jmp_jsr.nes OK
instr_test-v5 13-rts.nes OK
instr_test-v5 14-rti.nes OK
instr_test-v5 15-brk.nes OK
instr_test-v5 16-special.nes OK
nestest nestest.nes OK
oam_read oam_read.nes OK
oam_stress oam_stress.nes OK
ppu_open_bus ppu_open_bus.nes Failed
ppu_read_buffer test_ppu_read_buffer.nes OK
ppu_vbl_nmi 01-vbl_basics.nes OK
ppu_vbl_nmi 02-vbl_set_time.nes OK
ppu_vbl_nmi 03-vbl_clear_time.nes OK
ppu_vbl_nmi 04-nmi_control.nes OK
ppu_vbl_nmi 05-nmi_timing.nes OK
ppu_vbl_nmi 06-suppression.nes OK
ppu_vbl_nmi 07-nmi_on_timing.nes OK
ppu_vbl_nmi 08-nmi_off_timing.nes OK
ppu_vbl_nmi 09-even_odd_frames.nes OK
ppu_vbl_nmi 10-even_odd_timing.nes Failed
sprite_hit_tests_2005.10.05 01.basics.nes OK
sprite_hit_tests_2005.10.05 02.alignment.nes OK
sprite_hit_tests_2005.10.05 03.corners.nes OK
sprite_hit_tests_2005.10.05 04.flip.nes OK
sprite_hit_tests_2005.10.05 05.left_clip.nes OK
sprite_hit_tests_2005.10.05 06.right_edge.nes OK
sprite_hit_tests_2005.10.05 07.screen_bottom.nes OK
sprite_hit_tests_2005.10.05 08.double_height.nes OK
sprite_hit_tests_2005.10.05 09.timing_basics.nes OK
sprite_hit_tests_2005.10.05 10.timing_order.nes OK
sprite_hit_tests_2005.10.05 11.edge_timing.nes OK
sprite_overflow_tests 1.Basics.nes OK
sprite_overflow_tests 2.Details.nes OK
sprite_overflow_tests 3.Timing.nes Failed
sprite_overflow_tests 4.Obscure.nes Failed
sprite_overflow_tests 5.Emulator.nes OK
vbl_nmi_timing 1.frame_basics.nes OK
vbl_nmi_timing 2.vbl_timing.nes OK
vbl_nmi_timing 3.even_odd_frames.nes OK
vbl_nmi_timing 4.vbl_clear_timing.nes OK
vbl_nmi_timing 5.nmi_suppression.nes OK
vbl_nmi_timing 6.nmi_disable.nes OK
vbl_nmi_timing 7.nmi_timing.nes OK

References

今年?

前回から1年ほど経つらしい。

あれからorchestratorで中間マスターありの構成管理にしてリスク*1を減らし、マスターDB切り替えによる影響を約200ms程度*2に抑えるやつを作って、深夜ノーメンテでMySQL-5.6から5.7に上げていったりした。 GTIDの世界が到来して、P-GTID&MSRのHAのために作ったgohmsrは概ね役目を終えたのだが、GTID&MSRのサポートもしてるのでgohmsrは今も元気。OSSにしても良いと思うけど、めんどくささが勝ってしまう。

gh-ostも使ってる。MIXEDかつレプリカ側のみでtriggerが仕込まれてる運用だとROW fallbackしてつらぽよだけど、ROW fallbackしないフェーズになったタイミングでレプリカ側をうまく調整してmigrationしている。なかなかつらいですね。

Goを書く機会を得るために春ぐらいにNES emuを書き始めたんだけど、CPUだけ書いて止まっている。時間の余裕がなくなったタイミングかな。

数年振りにコードを書く機会が増えてきて、良い機会だと思ったのでEmacsバインドからVimバインドに改宗した。(VSCodeだけど)

Debeziumに触れる機会もあって、わけあってbinlog使ってごにょごにょするツールも書いたりしてた。debeziumもgo-mysqlももうちょっとなんとかならんかな.....。

Github Actionsで少し遊んだ。公開されているskeema-diffのgithub actionsは気になるところがあったので、少し手を入れたりしてcommitの山を築いた。 f:id:ichirin2501:20201227140302p:plain

英語は去年の7月ぐらいから、続けたりさぼったりしている。オンライン/コーチ付きで毎週10時間を約一ヶ月間続けてみたこともあったが全く効果はなく脱落とか。 今のところ、自分にとって最も学習効果を得られているのは「ビジュアル英文解釈 (Part1)*3」。「英語ドキュメントが読めないのでコードを見に行く」というスタンスから「まぁ英語ドキュメント読むか...」に変わったのは大きな進歩のはず。

これはベランダで飼い始めたメダカたち。 f:id:ichirin2501:20201116125808j:plain

*1:最新のbinlog問題

*2:色々オーバーヘッドがある関係でこれぐらい、速くはない

*3:結婚祝いでいただいた本、感謝

最近

たまにはブログも書いてみる。

最近?は、2019-07-04 Mercari meetup for SRE Vol. 2 にて登壇。ちょうどPercona XtraDB Cluster導入とかをやってたのでネタ自体は決まってたがネタが薄くてどうしようって直前まで呟いてた気がする。別にいいかって思って資料は公開していない。

mercari.connpass.com

既存のMySQLから移行するときに本番マスターDB(MySQL-5.7) -> PXC(5.7系、1台のみ) の非同期レプリの状態で、MTS-onでも夜中のピーク時にはレプリ遅延する箇所だったのでロールバック体制は準備していたものの、切替時は結構怖かったなぁ(これがPXC初導入)。


他には 2019-09-26 db tech showcase Tokyo 2019 にて登壇。タイトル「メルカリにおけるMySQLの運用」で発表して、こちらは資料が公開されている。
www.db-tech-showcase.com

主にorchestrator導入の話をした。登壇後にTwitter眺めてて2段階F/Oの話は意外と好評だったのでほっとしたのを覚えている。あと db tech showcase はこれが初参加だった。会場だと一人で良い感じに休む場所がなくてずっとウロウロぼっちしてた。

そんな感じ。

2019-11-02 10:46 追記:
こちらがいただいたイルカさんです。
f:id:ichirin2501:20191018143008j:plain

MySQL-5.6のMRRにデッドロック回避の夢を見る

この記事は、はてなエンジニアアドベントカレンダー2016の7日目の記事です。
昨日は id:haya14busa さんのSum/Union/Variant Type in Go and Static Check Tool of switch-case handlingでした。

こんにちは、ドラゴンボールヤムチャ状態になってるichirin2501です。

技術ネタとして何を書こうかと考えたのですが、
またMySQLでロックの話をする運びとなってしまいました。

技術ネタついでに今年最後の記事になると思われるので、
この1年のアウトプットを振り返ってみますと、

はてな・ペパポ技術大会 〜インフラ技術基盤〜
計算量と僕とWeb開発 / computational complexity and I and Web // Speaker Deck

Haten Engineering Seminar #6 〜インフラ編〜
MySQL運用とらぶるすとーり〜^2 / MySQL-Troubleshooting-Story // Speaker Deck

おお、なんと2つも。
MySQL芸人一歩手前などと冗談で言われたりしてますが、私は元気です。
斧もお待ちしております。
でも、そろそろMySQL以外の話がしたいと思ってる次第です。

目次

はじめに

 MySQLの行ロックはインデックスレコードロックであり、異なるセカンダリインデックスからのロック獲得時にデッドロックが発生する問題があります。今回はMySQL-5.6で追加されたMRR(Multi-Range Read)機能によってそれを解決できないか調査した記事です。以前にも5.6で追加されたICP(Index Condition Pushdown)機能によるロック挙動を調査したことがあるので、興味のある方はそちらもご参照ください。気が付けば2015年10月に5.7が正式リリースされ、5.6の正式リリースは2013年2月らしいので既に3年以上経っていますね。はやいものです。

検証環境

MRR(Multi-Range Read)とは

 MySQL-5.6 から新しく追加された機能の一つで、なるべくランダムアクセスを減らしてシーケンシャルアクセスにする最適化のことです。HDDなどのランダムとシーケンシャルアクセス速度に差があり、その影響が支配的な環境下において効果がありそうです。

公式にも丁寧に書かれています。

セカンダリインデックスでの範囲スキャンを使用して行を読み取ると、テーブルが大きく、ストレージエンジンのキャッシュに格納されていない場合、ベーステーブルへのランダムディスクアクセスが多発する結果になることがあります。Disk-Sweep Multi-Range Read (MRR) 最適化を使用すると、MySQL は、最初にインデックスだけをスキャンし、該当する行のキーを収集することによって、範囲スキャンのランダムディスクアクセスの回数を軽減しようとします。続いてキーがソートされ、最後に主キーの順序を使用してベーステーブルから行が取得されます。Disk-Sweep MRR の目的は、ランダムディスクアクセスの回数を減らし、その代わりに、ベーステーブルデータの順次スキャンを増やすことです。

MySQL 5.6 リファレンスマニュアル | Multi-Range Read の最適化

確かにセカンダリインデックスと実レコードの順序には相関がないため、単純にセカンダリインデックスの走査順で引くとランダムアクセスになってしまいます。ただ、一旦ソートする必要がありCPUを使うのと、SSDだとアドバンテージが小さくなります。また、バッファプールに乗ってる状態なら効果も見込めないので、一般的にMRRによって改善が見込めるケースは少なそうな感触です。

MRRの機能を図にするとこんな感じのようです。


クラスタインデックスの図がないため、正確ではありませんが意図は伝わるかと思います。
 この機能から何故ロックの挙動調査の話になるかと言うと、MySQL(InnoDB)のロックはインデックスレコードロックだからです。インデックスの走査順にロックを獲得するため、その周辺の挙動が変わるとロック順に影響すると考えたためです。

解決したいデッドロックについて

 さて、当然セカンダリインデックスとクラスタインデックスにも順序の相関はありません。相関がないために発生するデッドロックがあります。
githubに挙げた例をそのまま持ってきますが、図も合わせて簡単に紹介します。

テーブル定義
CREATE TABLE `shadow_lock` (
  `id` INTEGER unsigned NOT NULL auto_increment,
  `code_id` INTEGER unsigned NOT NULL,
  `token_id` INTEGER unsigned NOT NULL,
  `value` INTEGER unsigned NOT NULL,
  PRIMARY KEY (`id`),
  UNIQUE `shadow_lock_code_id` (`code_id`),
  UNIQUE `shadow_lock_token_id` (`token_id`)
) ENGINE=InnoDB DEFAULT CHARACTER SET utf8mb4;

mysql> select * from shadow_lock;
+------+---------+----------+---------+
| id   | code_id | token_id | value   |
+------+---------+----------+---------+
| 1000 |       1 |      299 |   10000 |
| 1001 |       2 |      298 |   20000 |
| 1002 |       3 |      297 |   30000 |
…
| 1099 |     100 |      200 | 1000000 |
| 1100 |     101 |      199 | 1010000 |
| 1101 |     102 |      198 | 1020000 |
| 1102 |     103 |      197 | 1030000 |
| 1103 |     104 |      196 | 1040000 |
| 1104 |     105 |      195 | 1050000 |
| 1105 |     106 |      194 | 1060000 |
| 1106 |     107 |      193 | 1070000 |
| 1107 |     108 |      192 | 1080000 |
| 1108 |     109 |      191 | 1090000 |
| 1109 |     110 |      190 | 1100000 |
| 1110 |     111 |      189 | 1110000 |
| 1111 |     112 |      188 | 1120000 |
...

セカンダリ-クラスタインデックス間はデータ列の相関がなくランダムアクセスですが、理解し易い形にするために意図的に単純な逆順にします。

カラムA(昇順) -> id(昇順)=> code_id
カラムB(昇順) -> id(降順)=> token_id

次にデッドロックになるようなクエリを用意します。

TA> BEGIN;
TB> BEGIN;
TA> SELECT * FROM shadow_lock WHERE code_id  IN('100','101','102','103','104','105','106','107','108','109','110') FOR UPDATE;
TB> SELECT * FROM shadow_lock WHERE token_id IN('190','191','192','193','194','195','196','197','198','199','200') FOR UPDATE;

上記のクエリがどのような流れでデッドロックになるのかを示した図が以下のものです。

 shadow_lock_code_idを利用するのが上のセカンダリインデックス、shadow_lock_token_idを利用するのが下のセカンダリインデックスになります。後者だとクラスタインデックスのアクセス順は降順となり、お互いに被ってる部分でデッドロックが発生します。これを回避するためには、ロックを獲得するときのインデックスは共通させるなどの手が必要です。
 ここで話を戻しましょう。仮にMRRによってクラスタインデックスのロックを獲得する前にソート処理が行われてるのだとしたら、異なるセカンダリインデックスを使ったロックでも順序が固定されてデッドロックが回避できそうですね!

ということで検証します。

MRRのロック動作検証

 先程同様クラスタ-セカンダリインデックス間のデータ対応は逆順で初期データを用意します。

CREATE TABLE `player` (
  `id` bigint(20) unsigned NOT NULL,
  `level` bigint(20) unsigned NOT NULL,
  `name` varchar(191) NOT NULL,
  PRIMARY KEY (`id`),
  KEY `idx_level` (`level`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4;

mysql> select * from player;
+--------+--------+--------------+
| id     | level  | name         |
+--------+--------+--------------+
|      1 | 100000 | i:1:l:100000 |
|      2 |  99999 | i:2:l:99999  |
|      3 |  99998 | i:3:l:99998  |
|      4 |  99997 | i:4:l:99997  |
|      5 |  99996 | i:5:l:99996  |
|      6 |  99995 | i:6:l:99995  |
|      7 |  99994 | i:7:l:99994  |
|      8 |  99993 | i:8:l:99993  |
|      9 |  99992 | i:9:l:99992  |
...
|  99995 |      6 | i:99995:l:6     |
|  99996 |      5 | i:99996:l:5     |
|  99997 |      4 | i:99997:l:4     |
|  99998 |      3 | i:99998:l:3     |
|  99999 |      2 | i:99999:l:2     |
| 100000 |      1 | i:100000:l:1    |
+--------+--------+-----------------+
100000 rows in set (0.08 sec)

MRR onなら図-xのロック順序から以下のように変わるはずです。

 検証する環境を整えます。MRRはデフォルトでONですがオプティマイザによるコスト計算によるとほぼ?使われないようです。コスト計算を無視して条件を満たすクエリなら必ず使用するようにします。MRRが使用されるときはEXPLAINにUsing MRRと表示されます。

mysql> EXPLAIN SELECT * FROM player WHERE level IN(100,500,1000,5000,10000);
+----+-------------+--------+-------+---------------+-----------+---------+------+------+-----------------------+
| id | select_type | table  | type  | possible_keys | key       | key_len | ref  | rows | Extra                 |
+----+-------------+--------+-------+---------------+-----------+---------+------+------+-----------------------+
|  1 | SIMPLE      | player | range | idx_level     | idx_level | 8       | NULL |    5 | Using index condition |
+----+-------------+--------+-------+---------------+-----------+---------+------+------+-----------------------+
1 row in set (0.00 sec)

mysql> SELECT @@optimizer_switch\G
*************************** 1. row ***************************
@@optimizer_switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,engine_condition_pushdown=on,index_condition_pushdown=on,mrr=on,mrr_cost_based=on,block_nested_loop=on,batched_key_access=off,materialization=on,semijoin=on,loosescan=on,firstmatch=on,subquery_materialization_cost_based=on,use_index_extensions=on
1 row in set (0.00 sec)

mysql> SET optimizer_switch='mrr_cost_based=off';
Query OK, 0 rows affected (0.00 sec)

mysql> SELECT @@optimizer_switch\G
*************************** 1. row ***************************
@@optimizer_switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,engine_condition_pushdown=on,index_condition_pushdown=on,mrr=on,mrr_cost_based=off,block_nested_loop=on,batched_key_access=off,materialization=on,semijoin=on,loosescan=on,firstmatch=on,subquery_materialization_cost_based=on,use_index_extensions=on
1 row in set (0.00 sec)

mysql> EXPLAIN SELECT * FROM player WHERE level IN(100,500,1000,5000,10000);
+----+-------------+--------+-------+---------------+-----------+---------+------+------+----------------------------------+
| id | select_type | table  | type  | possible_keys | key       | key_len | ref  | rows | Extra                            |
+----+-------------+--------+-------+---------------+-----------+---------+------+------+----------------------------------+
|  1 | SIMPLE      | player | range | idx_level     | idx_level | 8       | NULL |    5 | Using index condition; Using MRR |
+----+-------------+--------+-------+---------------+-----------+---------+------+------+----------------------------------+
1 row in set (0.00 sec)

# 検証に使うレコードの確認
mysql> SELECT * FROM player WHERE level IN(100,500,1000,5000,10000) ORDER BY id;
+-------+-------+-----------------+
| id    | level | name            |
+-------+-------+-----------------+
| 90001 | 10000 | i:90001:l:10000 |
| 95001 |  5000 | i:95001:l:5000  |
| 99001 |  1000 | i:99001:l:1000  |
| 99501 |   500 | i:99501:l:500   |
| 99901 |   100 | i:99901:l:100   |
+-------+-------+-----------------+
5 rows in set (0.00 sec)

準備が出来ました。期待通りのロック獲得順になるか確かめるクエリを発行していきます。3つのトランザクションを並行させて実験します。

TA> BEGIN;
TA> SELECT * FROM player WHERE id = 99001 FOR UPDATE;
+-------+-------+----------------+
| id    | level | name           |
+-------+-------+----------------+
| 99001 |  1000 | i:99001:l:1000 |
+-------+-------+----------------+
1 row in set (0.00 sec)

TB> BEGIN;
TB> SELECT * FROM player WHERE level IN(100,500,1000,5000,10000) FOR UPDATE;
# TAのid=99001のロック解放待ち
# 仮にMRRによって事前にソートしてからロック獲得処理が走ってるなら、id=90001, 95001のロックが獲得済みのはず

# 3つ目のトランザクションでid=90001のレコードがロックされてることを確認する
TC> BEGIN;
TC> SELECT * FROM player WHERE id = 90001 FOR UPDATE; 
+-------+-------+-----------------+
| id    | level | name            |
+-------+-------+-----------------+
| 90001 | 10000 | i:90001:l:10000 |
+-------+-------+-----------------+
1 row in set (0.00 sec)

# |'-') ........あれ?


 TCでid=99901のレコードがロックされてることは別途確認しました。MRR-on/offによってロック順序が変化していないことが分かりました。そんな。念のためもう少し調べてみます。まずはソースコードを漁ってきてMRR周りの処理を見てみます。
https://github.com/mysql/mysql-server/blob/71f48ab393bce80a59e5a2e498cd1f46f6b43f9a/sql/handler.cc#L6648-L6704
DsMrr_impl::dsmrr_fill_bufferの最後のほうでソート処理が入っています。如何にもそれっぽいですね。

  my_qsort2(rowids_buf, n_rowids, elem_size, (qsort2_cmp)rowid_cmp,
            (void*)h);

このソート処理の前にロック獲得処理が入ってると、今回のような結果になります。
MySQLソースコードを読むのは難しいので、雑にGDBによる動的デバッグで当たりをつけるためにコンパイルから始めます。

// Debian7
$ sudo apt-get install cmake libncurses5-dev
$ tar zxvf mysql-5.6.25.tar.gz
$ cd mysql-5.6.25
$ cmake -DWITH_DEBUG:BOOL=ON -DMYSQL_DATADIR=/var/lib/mysql
$ make 
$ sudo make install
$ sudo mkdir /var/lib/mysql
$ sudo /usr/local/mysql/scripts/mysql_install_db --user=mysql --datadir=/var/lib/mysql -basedir=/usr/local/mysql 
$ sudo cp /usr/local/mysql/support-files/mysql.server /etc/init.d/mysql
$ sudo service mysql start

GDBでアタッチしてMRRの処理周りとロック獲得周りにブレークポイントを仕込む作業をします。ソート処理部分の手前にブレークポイントをセットしたいので、事前にコード行数を確認します。
githubのsrcと行数が異なっていたので改めてMRRのソート部分のコードを載せます。

# sql/handler.cc
6199 
6200   /* Sort the buffer contents by rowid */
6201   uint elem_size= h->ref_length + (int)is_mrr_assoc * sizeof(void*);
6202   uint n_rowids= (rowids_buf_cur - rowids_buf) / elem_size;
6203
6204   my_qsort2(rowids_buf, n_rowids, elem_size, (qsort2_cmp)rowid_cmp,
6205             (void*)h);
6206   rowids_buf_last= rowids_buf_cur;
6207   rowids_buf_cur=  rowids_buf;
6208   DBUG_RETURN(0);
6209 }

sql/handler.ccの6203行目で良さそうです。コード行数を確認したので仕込みます。

(gdb) b DsMrr_impl::dsmrr_fill_buffer
Breakpoint 1 at 0x68715c: file /home2/ichirin2501/mysql-5.6.25/sql/handler.cc, line 6171.
(gdb) b lock_rec_create
Breakpoint 2 at 0xbcc558: file /home2/ichirin2501/mysql-5.6.25/storage/innobase/lock/lock0lock.cc, line 1803.
(gdb) b /home2/ichirin2501/mysql-5.6.25/sql/handler.cc:6203
Breakpoint 3 at 0x6873be: file /home2/ichirin2501/mysql-5.6.25/sql/handler.cc, line 6203.
(gdb) c
Continuing.
mysql> SET optimizer_switch='mrr_cost_based=off';
Query OK, 0 rows affected (0.00 sec)

mysql> SELECT @@optimizer_switch\G
*************************** 1. row ***************************
@@optimizer_switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,engine_condition_pushdown=on,index_condition_pushdown=on,mrr=on,mrr_cost_based=off,block_nested_loop=on,batched_key_access=off,materialization=on,semijoin=on,loosescan=on,firstmatch=on,subquery_materialization_cost_based=on,use_index_extensions=on
1 row in set (0.00 sec)

mysql>  EXPLAIN SELECT * FROM player WHERE level IN(100,500,1000,5000,10000);
+----+-------------+--------+-------+---------------+-----------+---------+------+------+----------------------------------+
| id | select_type | table  | type  | possible_keys | key       | key_len | ref  | rows | Extra                            |
+----+-------------+--------+-------+---------------+-----------+---------+------+------+----------------------------------+
|  1 | SIMPLE      | player | range | idx_level     | idx_level | 8       | NULL |    5 | Using index condition; Using MRR |
+----+-------------+--------+-------+---------------+-----------+---------+------+------+----------------------------------+
1 row in set (0.01 sec)

mysql> begin;
Query OK, 0 rows affected (0.00 sec)

mysql> SELECT * FROM player WHERE level IN(100,500,1000,5000,10000) FOR UPDATE;

ブレークポイントを仕込んだGDBにハンドリングが移ります。

[Switching to Thread 0x7f8d26f16700 (LWP 121200)]

Breakpoint 1, DsMrr_impl::dsmrr_fill_buffer (this=0x236dfe8) at /home2/ichirin2501/mysql-5.6.25/sql/handler.cc:6171
6171      int res= 0;
(gdb) n
6172      DBUG_ENTER("DsMrr_impl::dsmrr_fill_buffer");
(gdb)
6173      DBUG_ASSERT(rowids_buf < rowids_buf_end);
(gdb)
6175      rowids_buf_cur= rowids_buf;
(gdb)
6176      while ((rowids_buf_cur < rowids_buf_end) &&
(gdb)
6177             !(res= h2->handler::multi_range_read_next(&range_info)))
(gdb)
6176      while ((rowids_buf_cur < rowids_buf_end) &&
(gdb)
Breakpoint 2, lock_rec_create (type_mode=3, block=0x7f8d2ca696c0, heap_no=641, index=0x236ff38, trx=0x239b338, caller_owns_trx_mutex=0) at /home2/ichirin2501/mysql-5.6.25/storage/innobase/lock/lock0lock.cc:1803
1803            ut_ad(lock_mutex_own());
(gdb)
1804            ut_ad(caller_owns_trx_mutex == trx_mutex_own(trx));
(gdb)
1805            ut_ad(dict_index_is_clust(index) || !dict_index_is_online_ddl(index));
(gdb) c
Continuing.

Breakpoint 2, lock_rec_create (type_mode=1027, block=0x7f8d2ca6a480, heap_no=308, index=0x236fc08, trx=0x239b338, caller_owns_trx_mutex=0) at /home2/ichirin2501/mysql-5.6.25/storage/innobase/lock/lock0lock.cc:1803
1803            ut_ad(lock_mutex_own());
(gdb)
Continuing.

Breakpoint 2, lock_rec_create (type_mode=547, block=0x7f8d2ca696c0, heap_no=640, index=0x236ff38, trx=0x239b338, caller_owns_trx_mutex=1) at /home2/ichirin2501/mysql-5.6.25/storage/innobase/lock/lock0lock.cc:1803
1803            ut_ad(lock_mutex_own());
(gdb)
Continuing.

Breakpoint 2, lock_rec_create (type_mode=1027, block=0x7f8d2ca6a740, heap_no=221, index=0x236fc08, trx=0x239b338, caller_owns_trx_mutex=0) at /home2/ichirin2501/mysql-5.6.25/storage/innobase/lock/lock0lock.cc:1803
1803            ut_ad(lock_mutex_own());
(gdb)
Continuing.

Breakpoint 2, lock_rec_create (type_mode=3, block=0x7f8d2ca69980, heap_no=496, index=0x236ff38, trx=0x239b338, caller_owns_trx_mutex=0) at /home2/ichirin2501/mysql-5.6.25/storage/innobase/lock/lock0lock.cc:1803
1803            ut_ad(lock_mutex_own());
(gdb)
Continuing.

Breakpoint 2, lock_rec_create (type_mode=1027, block=0x7f8d2ca6aa00, heap_no=34, index=0x236fc08, trx=0x239b338, caller_owns_trx_mutex=0) at /home2/ichirin2501/mysql-5.6.25/storage/innobase/lock/lock0lock.cc:1803
1803            ut_ad(lock_mutex_own());
(gdb)
Continuing.

Breakpoint 2, lock_rec_create (type_mode=547, block=0x7f8d2ca69980, heap_no=495, index=0x236ff38, trx=0x239b338, caller_owns_trx_mutex=1) at /home2/ichirin2501/mysql-5.6.25/storage/innobase/lock/lock0lock.cc:1803
1803            ut_ad(lock_mutex_own());
(gdb)
Continuing.

Breakpoint 2, lock_rec_create (type_mode=3, block=0x7f8d2ca69c40, heap_no=271, index=0x236ff38, trx=0x239b338, caller_owns_trx_mutex=0) at /home2/ichirin2501/mysql-5.6.25/storage/innobase/lock/lock0lock.cc:1803
1803            ut_ad(lock_mutex_own());
(gdb)
Continuing.

Breakpoint 2, lock_rec_create (type_mode=1027, block=0x7f8d2ca6acc0, heap_no=25, index=0x236fc08, trx=0x239b338, caller_owns_trx_mutex=0) at /home2/ichirin2501/mysql-5.6.25/storage/innobase/lock/lock0lock.cc:1803
1803            ut_ad(lock_mutex_own());
(gdb)
Continuing.

Breakpoint 2, lock_rec_create (type_mode=547, block=0x7f8d2ca69c40, heap_no=270, index=0x236ff38, trx=0x239b338, caller_owns_trx_mutex=1) at /home2/ichirin2501/mysql-5.6.25/storage/innobase/lock/lock0lock.cc:1803
1803            ut_ad(lock_mutex_own());
(gdb)
Continuing.

Breakpoint 2, lock_rec_create (type_mode=3, block=0x7f8d2ca69f00, heap_no=556, index=0x236ff38, trx=0x239b338, caller_owns_trx_mutex=0) at /home2/ichirin2501/mysql-5.6.25/storage/innobase/lock/lock0lock.cc:1803
1803            ut_ad(lock_mutex_own());
(gdb)
Continuing.

Breakpoint 2, lock_rec_create (type_mode=1027, block=0x7f8d2ca6af80, heap_no=239, index=0x236fc08, trx=0x239b338, caller_owns_trx_mutex=0) at /home2/ichirin2501/mysql-5.6.25/storage/innobase/lock/lock0lock.cc:1803
1803            ut_ad(lock_mutex_own());
(gdb)
Continuing.

Breakpoint 2, lock_rec_create (type_mode=547, block=0x7f8d2ca69f00, heap_no=555, index=0x236ff38, trx=0x239b338, caller_owns_trx_mutex=1) at /home2/ichirin2501/mysql-5.6.25/storage/innobase/lock/lock0lock.cc:1803
1803            ut_ad(lock_mutex_own());
(gdb)
Continuing.

Breakpoint 3, DsMrr_impl::dsmrr_fill_buffer (this=0x236dfe8) at /home2/ichirin2501/mysql-5.6.25/sql/handler.cc:6205
6205                (void*)h);
(gdb) s
my_qsort2 (base_ptr=0x2367a28, count=5, size=8, cmp=0x687118 <rowid_cmp(void*, uchar*, uchar*)>, cmp_argument=0x236dd60) at /home2/ichirin2501/mysql-5.6.25/mysys/mf_qsort.c:105
105       if (count <= 1)
(gdb) c
Continuing.

GDBからハンドリングが戻ってきました。

mysql> SELECT * FROM player WHERE level IN(100,500,1000,5000,10000) FOR UPDATE;
+-------+-------+-----------------+
| id    | level | name            |
+-------+-------+-----------------+
| 90001 | 10000 | i:90001:l:10000 |
| 95001 |  5000 | i:95001:l:5000  |
| 99001 |  1000 | i:99001:l:1000  |
| 99501 |   500 | i:99501:l:500   |
| 99901 |   100 | i:99901:l:100   |
+-------+-------+-----------------+
5 rows in set (7 min 46.36 sec)


最初のwhileループ内でロック獲得処理が一通り走りきった後にmy_qsort2を呼び出してます。残念ながらソート処理後にされるわけではないことが分かりました。

まとめ

 MySQL-5.6で追加されたMRR機能におけるロック挙動の調査を行いました。期待した挙動とはならず、抱えていたデッドロック問題の解決には結びつきませんでした。ついでにBKAJによるJOIN先のロック順序も確認しましたが変化はありませんでした。MRRが前提のアルゴリズムなので振る舞いは同じようです。MySQL-5.6から入ったICPではセカンダリ-クラスタインデックス間のロック挙動が変わっていたので、MRRにも少し期待を寄せましたが、こちらは変わらず。実装を深く見てないですが、先にロック獲得しない/できない理由があると見たほうが自然かもしれませんね。


明日のアドベントカレンダーid:cockscomb さんです!!

MySQLでINSERTのデッドロックに嵌る人を1人でも減らすために

この記事ははてなデベロッパーアドベントカレンダー2015の12月24日の記事です。
昨日は id:stefafafan さんのエンジニアと英語でした。


こんにちは、こんばんは。
クリスマス・イヴですね、皆さんはどのような一日を過ごされる(た)のでしょうか。
僕は一人です。

改めまして、先日初めての合コンを経験/失敗して二度と行かないと誓った はてなid:ichirin2501 です。今回は小ネタとしてMySQL(InnoDB)のBULK INSERTにおけるデッドロックの話をしようと思います。ただ、外部キー制約が絡むと複雑になるので今回は触れません。それについてはこちらを参照ください。
あ、タイトルはオマージュです*1

Topic

  • 検証環境
  • INSERTのデッドロック
  • 避けられないケース
    • もしくはロックする
  • リトライ処理に注意
    • 初期データ
    • Duplicateの場合
    • Deadlockの場合
  • まとめ

検証環境

MySQL 5.6.25
InnoDB
REPEATABLE READ

INSERTのデッドロック

INSERT文によるデッドロックは、殆どBULK INSERTでデータの挿入順が原因です。

テーブル定義

CREATE TABLE `player` (
  `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
  `name` varchar(20) NOT NULL,
  `money` bigint(20) unsigned NOT NULL DEFAULT '0',
  PRIMARY KEY (`id`),
  UNIQUE KEY `player_idx_name` (`name`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4;

例えば各トランザクションで同時に以下のようなクエリが発行されたときにデッドロックになる可能性があります。

A> INSERT INTO player (name) VALUES("a"),("b"),("c"),....,("z");
B> INSERT INTO player (name) VALUES("z"),("y"),("x"),....,("a");

 2つのトランザクションで各クエリだけで順番に手動で実行してもデッドロックを再現させることは難しいでしょう。再現させるためにはプログラムで高速に並列実行させればデッドロックになります。よくデッドロックの例としてあるのはトランザクション中に各クエリ単位で獲得するロックの交差によるものです。こちらは実行時間は関係なく、手動で再現するのは簡単です。今回の例はクエリの実行中に発生するロックの交差が原因なので、INSERT文を打って応答が返ってきてはもう遅いのです。BEGIN-COMMITによる明示的なトランザクション関係なく発生するデッドロックということでもあります。
 何故デッドロックが発生するのかを簡単に説明します...というか、見た通りという感じですが、INSERTのVALUESは記述順に実行されます。InnoDBは全ての行が生成出来てから全部のロックを獲得するのではなく、生成しながらロックを獲得します。つまり、nameカラムにユニーク制約があるため、a,b,c,...と昇順にロックを取るのと、z,x,y...と降順にロックを取るのが同時に走ればユニーク制約でデッドロックするのは明らかです。もちろん、nameカラムにユニーク制約がなければデッドロックにはならずに済みます。ちなみにSELECT FOR UPDATE文でIN句などを条件に用いたときの記述順は関係ありません。InnoDB側が実行した走査順に依存します。だいたい使用されたインデックスの昇順になるので、WHERE IN()の中身の順序自体が原因でデッドロックになることはありません。
 解決方法は、ソートすることです。今回のテーブル定義では、nameカラムでソートしてBULK INSERTすれば同時に実行されてもデッドロックはなくなります。あと INSERT IGNORE なら大丈夫...なんてことはないです。クエリ実行中はロック獲得済み状態なので、排他ロックされてる行に対して共有ロックを実行しても待たされるので同じ結果になります。

避けられないケース

 うっ、頭がいたい...。テーブル定義でユニーク性が求められるカラムが主キーのみであれば主キーをソートすれば良い。また、主キーがAUTO_INCREMENTでユニーク制約なカラムが一つしかない場合はユニーク制約なカラムでソートすれば良い...ですが、基本的にはユニーク性のカラムが2つ以上ある場合はBULK INSERTによるデッドロックは避けられません。

テーブル定義

CREATE TABLE `player` (
  `id` bigint(20) unsigned NOT NULL,
  `name` varchar(20) NOT NULL,
  `money` bigint(20) unsigned NOT NULL DEFAULT '0',
  PRIMARY KEY (`id`),
  UNIQUE KEY `player_idx_name` (`name`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4;

AUTO_INCREMENTをはずしました。アプリ実装的にはidは別途生成してINSERT時に渡す仕様に変更しただけです。ここでは id,nameはどちらも衝突する可能性があるものとします。この場合、ソートしてもデータ次第でデッドロックが避けられないのです。

仮にVALUESを(id,name)でソートしたINSERTが偶然以下のようなものだとします。

A> INSERT INTO player (id,name) VALUES(1,"c"),(2,"d"),(3,"e")...;
B> INSERT INTO player (id,name) VALUES(2,"a"),(3,"b"),(4,"c")...;

とっぴろきー!
同時に実行されたと仮定すると、A側で(2,"d")を生成しようとしたとき、既にB側でid=2はロック獲得済みなので待たされてしまいます。B側は(3,"b")の生成が終わった後、(4,"c")の生成をしようとして、name="c"はA側で生成/ロック獲得済みなのでここでデッドロックになります。ユニーク制約のあるカラム同士がなんらかの条件を元に範囲が決まっていればあるいは...という感じですが、それだと独立してカラム定義する価値が失われてしまいます。なので、前提としてどうしても避けられない組み合わせが存在します。現実的には、2つのカラムのうち片方はほとんど衝突しないからもう片方を最優先にソートすれば良い、などでデッドロックはほぼなくなったりします。上記の例は極端で、困るケースはほとんどないと思います。

もしくはロックする

 クエリ単体ではデッドロックするので別の手段で回避するしかありません。例えばトランザクションを発行して別テーブルに対してロックを獲得した上でINSERT文を実行するとかです。外部キー制約によるデッドロック回避も同じ考え方です。実行順序を制限することでINSERTのデッドロックは避けられますが、過度にロックを獲得していることには違いないのでパフォーマンスの低下であったり、それによって別のデッドロックを引き起こす可能性も十分にあります。手段はありますが気をつける必要があります。

リトライ処理に注意

結論から言うと、クエリでエラーになったら即座にリクエスト全体をエラーとして扱うほうが良いです。とは言え、INSERT処理では成功するまでリトライ処理を書いてしまいがちかと思います。罠があるのでご紹介します。例えば以下のような疑似コードがだめな例になります。

BEGIN
UPDATE hogehoge
# uuidが衝突しても最大10回までリトライする
for cnt in 1..10 {
    uuid = get_uuid()
    ok = 0
    try {
        INSERT INTO piyopiyo
        ok = 1
    } catch {
        warn "error retry cnt"
    }
    if ok then break
}
COMMIT

何故だめかと言うと、INSERTのエラー内容次第でトランザクションが継続orロールバックの差があるためです。

上記のような疑似コードではエラーを捕まえた後、内容を見てリトライ処理の粒度を考慮する必要があります。Duplicateエラーの場合は本来の期待された動作をするでしょう。しかし、INSERT時にDeadlockエラーであれば最初に成功したUPDATE文も含めてロールバックされてしまいます。リトライで成功しても情報は一部失われることに、悲しい。

簡単に確認してみましょう。

初期データ
CREATE TABLE `player` (
  `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
  `name` varchar(20) NOT NULL,
  `money` bigint(20) unsigned NOT NULL DEFAULT '0',
  PRIMARY KEY (`id`),
  UNIQUE KEY `player_idx_name` (`name`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4;

SELECT * FROM player;
+----+---------+-------+
| id | name    | money |
+----+---------+-------+
|  1 | ichirin |     0 |
|  2 | hatena  |     0 |
|  3 | beer    |     0 |
|  4 | sushi   |     0 |
+----+---------+-------+
4 rows in set (0.00 sec)
Duplicateの場合

単純に既にある要素を含めたINSERT文を発行します。

BEGIN;
SELECT * FROM player WHERE name = "sushi";
+----+-------+-------+
| id | name  | money |
+----+-------+-------+
|  4 | sushi |     0 |
+----+-------+-------+
1 row in set (0.00 sec)

UPDATE player SET money = money + 1 WHERE name = "sushi";

SELECT * FROM player WHERE name = "sushi";
+----+-------+-------+
| id | name  | money |
+----+-------+-------+
|  4 | sushi |     1 |
+----+-------+-------+
1 row in set (0.00 sec)

INSERT INTO player (name) VALUES("2501"), ("ichirin");
ERROR 1062 (23000): Duplicate entry 'ichirin' for key 'player_idx_name'

COMMIT;
SELECT * FROM player;
+----+---------+-------+
| id | name    | money |
+----+---------+-------+
|  1 | ichirin |     0 |
|  2 | hatena  |     0 |
|  3 | beer    |     0 |
|  4 | sushi   |     1 |
+----+---------+-------+
4 rows in set (0.00 sec)
Deadlockの場合

実際はインデックス作成に刺さるときもあれば、要素がソートされてなくてINSERT文同士でデッドロックするケースが殆どだと思います。今回手動で再現するにあたり、INSERT文をデッドロックさせるためにはインデックス作成をロックさせるのが手頃なので、少し強引にしています。A,B,Cはそれぞれ異なるトランザクションで実行されているのを意味します。

A> BEGIN;
B> BEGIN;
C> BEGIN;
A> SELECT * FROM player WHERE name = "sushi";
+----+-------+-------+
| id | name  | money |
+----+-------+-------+
|  4 | sushi |     0 |
+----+-------+-------+
1 row in set (0.00 sec)

A> UPDATE player SET money = money + 1 WHERE name = "sushi";

A> SELECT * FROM player WHERE name = "sushi";
+----+-------+-------+
| id | name  | money |
+----+-------+-------+
|  4 | sushi |     1 |
+----+-------+-------+
1 row in set (0.00 sec)

C> INSERT INTO player (name) VALUES("b");
B> INSERT INTO player (id,name) VALUES(100,"a"),(101,"b"),(102,"c");
A> INSERT INTO player (id,name) VALUES(102,"a"),(101,"b"),(100,"c");

C> ROLLBACK;

A> # Aがエラーになる
ERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transaction

A> COMMIT;
A> SELECT * FROM player;
+----+---------+-------+
| id | name    | money |
+----+---------+-------+
|  1 | ichirin |     0 |
|  2 | hatena  |     0 |
|  3 | beer    |     0 |
|  4 | sushi   |     0 |
+----+---------+-------+
4 rows in set (0.00 sec)

このようにエラーの種類によって直後の状態が異なってきます。デッドロックor重複エラーとか依存した処理は書きたくありません。エラーになったら即座にリクエスト全体をエラーとして扱うほうが無難です。

まとめ

  • BULK INSERTはソートしよう
  • 避けられないケースは存在するので基本はエラー前提で設計しよう
  • INSERTで内部リトライ処理を書くときはトランザクションの粒度に気をつけよう


はてなでは、ミドルウェアと友達になれるエンジニアを募集しています。
hatenacorp.jp


明日のアドベントカレンダーid:stanaka の担当です。ご期待ください。