Maatkit で MySQL チューニング
- 1. Maatkit で MySQL チューニング YAPC::Asia Tokyo 2010 前夜祭
- 2. 自己紹介 金子 健介 (Kensuke Kaneko) プログラマ @ ペパボ 刺身☆ブーメラン id:a666666 @kyanny
- 4. Maatkit とは MySQL 用のユーティリティ集 作者は実践ハイパフォーマンス MySQL の著者 なぜかエジプトっぽいロゴ Perl スクリプトなので読みやすい $ wc -l mk-* ? 127964 total （ 12 万行もあるけど）読みやすい
- 5. MySQL チューニングのいろは EXPLAIN SHOW INDEXES スロークエリログ mysqldumpslow mk-query-digest mk-query-profiler
- 7. 使い方 $ mk-query-digest --fingerprints slow.log # Files: slow.log # Overall: 115 total, 12 unique, 0.00 QPS, 0.03x concurrency _____________ # ? ? ? ? ? ? ? ? ? ?total ? ? min ? ? max ? ? avg ? ? 95% ?stddev ?median # Exec time ? ? ? ? ?2323s ? ? ?3s ? ?338s ? ? 20s ? ? 49s ? ? 43s ? ? ?5s # Lock time ? ? ? ? ? ?6ms ? ?22us ? 270us ?55us ? ?98us ? ?31us ? ?42us # Rows sent ? ? ? ? 22.92k ? ? ? 0 ? ? 664 ? 204.08 ?487.09 ?171.01 ?166.51 # Rows exam ? ? ? ?730.08k ?? 0 123.41k ? 6.35k ?38.40k ?18.22k ?329.68 # Time range ? ? ? ?2010-09-28 05:54:30 to 2010-09-29 04:00:47 # bytes ? ? ? ? ? ? 25.16k ? ? 134 ? 2.45k ?224.03 ?381.65 ?239.90 ?130.47 # Profile # Rank Query ID ? ? ? ? ? Response time ? ?Calls R/Call ? Item # ==== ================== ================ ===== ======== ================ # ? ?1 0x5C552C534D2A3440 ?1114.2297 48.0% ? ?17 ?65.5429 SELECT t3 # ? ?2 0xD9C2EFCBECC526D1 ? 549.2743 23.6% ? ?73 ? 7.5243 SELECT t2 # ? ?3 0x0255F509DADB6455 ? 457.1587 19.7% ? ? 9 ?50.7954 UPDATE t1 オプションはドットファイルに書いておける t3 テーブルへのクエリが非常に遅い
- 8. 結果の見方 # Query 1: 0.00 QPS, 0.04x concurrency, ID 0x5C552C534D2A3440 at byte 3907 # ? ? ? ? ? ? ?pct ? total ? ? min ? ? max ? ? avg ? ? 95% ?stddev ?median # Count ? ? ? ? 14 ? ? ?17 # Exec time ? 47 ? 1114s ? ? ?3s ? ?338s ? ? 66s ? ?258s ? ? 96s ? ? 14s # Lock time ? ? 18 ? ? 1ms ? ?33us ? ?86us ? ?68us ? ?80us ? ?15us ? ?73us # Rows sent ? ?2 ? ? 672 ? ? ?24 ? ? ?90 ? 39.53 ? 88.31 ? 27.42 ? 23.65 # Rows exam ? ? 50 372.21k ? ? 462 ?89.27k ?21.89k ?88.02k ?30.14k ? 4.17k # Users ? ? ? ? ? ? ? ? ?1 ? ?test # Hosts ? ? ? ? ? ? ? ? ?1 # Databases ? ? ? ? ?1 ? ?test # Time range 2010-09-28 05:54:30 to 2010-09-28 13:54:18 # bytes ? ? ? ? 15 ? 3.97k ? ? 237 ? ? 240 ?239.06 ?234.30 ? ? ? 0 ?234.30 統計情報（全てのクエリ、個別のクエリ） ? 注目すべき部分 Exec time これはとてもだめな例 平均 258 秒もかかっている
- 9. mk-query-profiler もう少し詳しい情報を知りたい 例 : ディスク I/O がどれくらい発生しているか？ EXPLAIN だけではわからないことも多い プロファイリングツール SET profiling=1 oprofile mk-query-profiler mk-query-profiler の利点 導入が手軽 deb, rpm あります スクリプト単体で入手可能 実行結果が見やすい
- 10. 使い方 $ mk-query-profiler -u user -D database -vv sql.txt +----------------------------------------------------------+ | ? ? ? ? ? ? ? ? ? ? 1 (303.3715 sec) ? ? ? ? ? ? ? ? ? ? | +----------------------------------------------------------+ __ Overall stats _______________________ Value _____________ ?? Total elapsed time ? ? ? ? ? ? ? ? ? ? ?303.372 ?? Questions ? ? ? ? ? ? ? ? ? ? ? ? ? ? 27350 ?? ? COMMIT ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ?0 ?? ? DELETE ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ?0 ?? ? DELETE MULTI ? ? ? ? ? ? ? ? ? ? ? ? ?0 ?? ? INSERT ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ?0 ?? ? INSERT SELECT ? ? ? ? ? ? ? ? ? ? ? ? ? 0 ?? ? REPLACE ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? 0 ?? ? REPLACE SELECT ? ? ? ? ? ? ? ? ? ? ? ? ?0 ?? ? SELECT ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ?1 ?? ? UPDATE ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ?0 ?? ? UPDATE MULTI ? ? ? ? ? ? ? ? ? ? ? ? ? ?0 ?? Data into server ? ? ? ? ? ? ? ? ? ? ? ?208 ?? Data out of server ? ? ? ? ? ? ? ? ? ?39153 ?? Optimizer cost ? ? ? ? ? ? ? ? ? ? ? ?17504.809 長いので以下略
- 11. 結果の見方 (1) 今回は I/O に関係しそうな部分を重点的にみた +----------------------------------------------------------+ | ? ? ? ? ? ? ? ? ? ? 1 (303.3715 sec) ? ? ? ? ? ? ? ? ? ? | +----------------------------------------------------------+ __ Row operations ____________________ Handler ______ InnoDB ?? Reads ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ?92594 ? ? ? ? ? 1816374 __ I/O Operations _____________________ Memory ________ Disk ?? InnoDB buffer pool ?? ? Reads ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ?2474442 ? ? ? ? ? ? ?34106 ?? ? Random read-aheads ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ?390 ?? ? Sequential read-aheads ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ?36 __ InnoDB Data Operations ____ Pages _____ Ops _______ Bytes ?? Reads ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? 44271 ? ? ? ? 38091 ? ? ? 725336064 ディスクからの読み込みが多い == 遅い
- 12. 結果の見方 (2) 同じクエリのプロファイル結果（連続して実行） +----------------------------------------------------------+ | ? ? ? ? ? ? ? ? ? ? ?1 (0.6755 sec) ? ? ? ? ? ? ? ? ? ? ?| +----------------------------------------------------------+ __ Row operations ____________________ Handler ______ InnoDB ?? Reads ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ?92599 ? ? ? ? ? ? ?94843 __ I/O Operations _____________________ Memory ________ Disk ?? InnoDB buffer pool ?? ? Reads ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ?323664 ? ? ? ? ? ? ? ? ? ?0 ?? ? Random read-aheads ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? 0 ?? ? Sequential read-aheads ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ?0 __ InnoDB Data Operations ____ Pages _____ Ops _______ Bytes ?? Reads ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ?0 ? ? ? ? ? ? ? 0 ? ? ? ? ? ? ? ? ? ? 0 ディスクからの読み込みが減った バッファプール（メモリ）に載っているのではやい
- 13. mk-query-profiler は何をしているか 大半はオプションのパースと出力のフォーマット 実際に仕事をしてるのは get_status_info() sub get_status_info { ?? my ( $o, $dbh, $have_session ) = @_; ?? my $res = $dbh->selectall_arrayref( ?? ? ? $have_session ?? ? ? ? ? ($o->get('external') ? 'SHOW GLOBAL STATUS' : 'SHOW SESSION STATUS') ?? ? ? ? : 'SHOW STATUS' ); ?? my %result = map { @{$_} } @$res; ?? return { map { $_ => $result{$_} || 0 } @important_vars }; } SHOW STATUS の結果を整形してる
- 15. チューニング後 (1) # Files: slow.log # Overall: 68 total, 8 unique, 0.00 QPS, 0.02x concurrency _______________ # ? ? ? ? ? ? ? ? ? ?total ? ? min ? ? max ? ? avg ? ? 95% ?stddev ?median # Exec time ? ? ? ? ?1152s ? ? ?3s ? ? 80s ? ? 17s ? ? 49s ? ? 18s ? ? ?9s # Lock time ? ? ? ? ? ?3ms ? ?22us ? 312us ? ?49us ? ?84us ? ?36us ? ?38us # Rows sent ? ? ? ? 18.11k ? ? ? 0 ? 1.45k ?272.78 ?487.09 ?257.13 ?223.14 # Rows exam ? ? ? ? 75.33k ? ? ? 0 ?46.46k ? 1.11k ? 1.20k ? 5.33k ?271.23 # Time range ? ? ? ?2010-10-02 08:19:13 to 2010-10-03 04:00:46 # bytes ? ? ? ? ? ? 17.99k ? ? 134 ? 4.02k ?270.90 ?363.48 ?499.75 ?130.47 # Profile # Rank Query ID ? ? ? ? ? Response time ? ?Calls R/Call ? Item # ==== ================== ================ ===== ======== ================ # ? ?1 0xD9C2EFCBECC526D1 ? 644.6672 55.9% ? ?51 ?12.6405 SELECT t2 # ? ?2 0x0255F509DADB6455 ? 357.9470 31.1% ? ? 7 ?51.1353 UPDATE t1 # ? ?3 0xE4D15EB8FF64B268 ? ?45.1097 ?3.9% ? ? 5 ? 9.0219 SELECT t3 t3 テーブルへのクエリに改善がみられた
- 16. チューニング後 (2) # Query 3: 0.01 QPS, 0.10x concurrency, ID 0xE4D15EB8FF64B268 at byte 6136 # ? ? ? ? ? ? ?pct ? total ? ? min ? ? max ? ? avg ? ? 95% ?stddev ?median # Count ? ? ? ? ?7 ? ? ? 5 # Exec time ? ? ?3 ? ? 45s ? ? ?6s ? ? 12s ? ? ?9s ? ? 12s ? ? ?2s ? ? ?8s # Lock time ? ? ?8 ? 285us ? ?39us ? ?90us ? ?57us ? ?89us ? ?18us ? ?47us # Rows sent ?? ?0 ? ? 120 ? ? ?24 ? ? ?24 ? ? ?24 ? ? ?24 ? ? ? 0 ? ? ?24 # Rows exam? ?5 ? 4.20k ? ? 586 ? ?1006 ? ? 861 ?964.41 ?144.29 ?918.49 # Users ? ? ? ? ? ? ? ? ?1 ? ?test # Hosts ? ? ? ? ? ? ? ? ?1 # Databases ? ? ? ? ?1 ? ?test # Time range 2010-10-02 15:59:14 to 2010-10-02 16:06:35 # bytes ? ? ? ? ?9 ? 1.69k ? ? 346 ? ? 346 ? ? 346 ? ? 346 ? ? ? 0 ? ? 346
- 17. 考察 mk-query-digest について 統計情報をすばやく把握 平均や 95% など情報量が多い 慣れるまではちょっと多すぎるかも mk-query-profiler について より詳細なデータが取得できる SHOW STATUS や SHOW ENGINE INNODB STATUS も大事ですね 「 たぶん ディスク読み込みが遅いんでメンテします」とか言わずに済む 仮説、調査、裏付け（！）、実行 自信をもってチューニングに取り組める
- 18. まとめ Maatkit は便利で導入も簡単 豊富なオプションと丁寧なドキュメント なぜかエジプトっぽいロゴ MySQL チューニングのお供にぜひどうぞ 参考 http://www.maatkit.org/ http://code.google.com/p/maatkit/ http://d.hatena.ne.jp/marqs/20100515/1273861805 http://d.hatena.ne.jp/hxmasaki/20100726/1280117979
