mk(pt)-query-digestをもっと活用しよう!

もはやこれが無くては障害対応ができないぐらい中毒になっているmk-query-digestさんについてです。
mk-query-digest - Analyze query execution logs and generate a query report, filter, replay, or transform queries for MySQL, PostgreSQL, memcached, and more.

例えばこんなことが起きたときは、何を差し置いてもまずtcpdumpを取りに行きます。
状況がおさまってしまってからでは遅いのです。

  • Load Averageの高騰
  • Too Many Connections
  • lock wait timeout
tcpdump -i bond0 -s 65535 -x -n -q -tttt 'port 3306' > tcpdump.out 2> /dev/null

ここで素直に

mk-query-digest --type=tcpdump tcpdump.out > tcpdump.log

だけでは何とも勿体ない。
もちろんこれでもとても有意義な情報がとれてしまうわけですが、せっかく色々オプションがあるので試してみてはどうでしょう。

  • テーブルごとのアクセス集計
    • 垂直分割を検討している時や、アクセスが集中しているテーブルを割り出す時なんかに使います
    • order-byとlimitはお好きな値でどうぞ
mk-query-digest --type=tcpdump --group-by=tables --order-by Query_time:cnt --limit 100 tcpdump.out > tcpdump.log.pertable
  • 特定のクエリのみ集計
    • 正規表現部分をイジれば更新クエリだけの抽出もできちゃいます
mk-query-digest --type=tcpdump --filter '$event->{fingerprint} =~ m/^select/'  --order-by Query_time:cnt --limit 100 tcpdump.out > tcpdump.log
  • commit / ping / connect を除いて集計
    • ノイズになるものを除外!
mk-query-digest --type=tcpdump --filter '$event->{fingerprint} !~ m/^(commit|admin|set)/' --limit 100 tcpdump.out > tcpdump.log
  • 接続にかかった時間だけを抽出
mk-query-digest --type tcpdump --no-report --filter '$event->{fingerprint} =~ /Connect/ && printf "%.9f %s %s@%s\n", @{$event}{qw(Query_time host user db)}'
  • 特定のテーブルだけをテーブルごとに集計
    • もうある程度のあたりは付いてる時なんかに。
mk-query-digest --type=tcpdump --group-by=tables --order-by Query_time:cnt --limit 100  --filter 'grep /XXX/, @{$event->{tables}}' tcpdump.out > tcpdump.log.pertable

こうして取れた情報をshow create tableやらshow index、explainと組み合わせて、日々クエリのチューニングを行ったりしています。
qpsがとんでもなく高いDBでtcpdumpをカジュアルに打って放っておくとtoo many connectionsがドバドバ。。。なんてこともあるので目を離してはいけません。
2-3万qpsとかのサーバで10秒も打ったらサイズは150MBぐらい行っちゃいます。

僕がよく使うのはこの辺ですが、他にもたくさんの使い方があると思います。
みなさんの参考になれば幸いです。

LAST_INSERT_IDの限界

こんにちは。

突然ですが32bit/64bitの差を調べていて気づいたのでメモ。
32bitだともちろん32bitを超える数値をそのままでは扱えないわけですが、MySQL的にはどうなのよってことで特に値が大きくなりがちなid発番を見てみました。

弊社ではid発番をauto_incrementではなく、MyISAMなテーブルに対する以下クエリで発番しています。

CREATE TABLE `hoge` (
  `id` bigint(20) unsigned NOT NULL
) ENGINE=MyISAM DEFAULT CHARSET=sjis
update hoge set id=LAST_INSERT_ID(id+1)

で、unsignedなんだから「18446744073709551615」までイケるだろ!
と思ったら

mysql> select * from hoge;
+---------------------+
| id                  |
+---------------------+
| 9223372036854775807 |
+---------------------+
1 row in set (0.00 sec)

mysql> update hoge set id=LAST_INSERT_ID(id+1);
Query OK, 1 row affected, 1 warning (0.00 sec)
Rows matched: 1  Changed: 1  Warnings: 1

mysql> select LAST_INSERT_ID();
+----------------------+
| LAST_INSERT_ID()     |
+----------------------+
| -9223372036854775808 |
+----------------------+
1 row in set (0.00 sec)

mysql> select * from hoge;
+----+
| id |
+----+
|  0 |
+----+
1 row in set (0.00 sec)

工エエェェ(´д`)ェェエエ工

反転した。

ん、Warning出とる。

Rows matched: 1  Changed: 1  Warnings: 1
mysql> show warnings;
+---------+------+---------------------------------------------+
| Level   | Code | Message                                     |
+---------+------+---------------------------------------------+
| Warning | 1264 | Out of range value for column 'id' at row 1 |
+---------+------+---------------------------------------------+
1 row in set (0.00 sec)

あら。。。
これはなんとまぁ、仕様なんですね。

MySQL Bugs: #20964: last_insert(id) does not support bigint unsigned

900京を超えるようなidを発番する機会なんてそうそうないでしょうが、そうなった時はロジックを変えないといけないのかな。

decimalにしてもダメでした。
これがLAST_INSERT_IDの限界か!

ちなみにLAST_INSERT_IDについてこちらの記事が大変わかりやすかったです!

LAST_INSERT_IDを使って採番テーブルを扱う - (゚∀゚)o彡 sasata299's blog

DB KPI取得のススメ

まずそもそもKPIってなんやねん、と。

Key Performance Indicator
業績管理評価のための重要な指標

KPIとは【Key Performance Indicator】(重要業績評価指標) - 意味/解説/説明/定義 : IT用語辞典

用語的な意味はこんなとこですが、ここではざっくり「DB性能評価指標」と考えてください。


うちの会社では定常的にMySQLから情報を吸いあげて、これを蓄積しつつ性能管理に役立てています。
これをDB KPI管理なんて呼んでいます。

著作権が怪しいのでソースを載せるのは控えますが、延々とshow statusの60秒間の平均を取るスクリプトをdaemontoolsで回し続けています。

取得対象はCom_[insert|delete|update|select]、Innodb_rows_% (うちはInnoDBばかりなので) あたりです。
累積値が取れるので、実行タイミングごとで差分を見てあげればいいですね。
mysqladmin extended-statusでもいいかと思います。

あとThreads_runningを「concurrency」として合わせて取得してます。
(これは累積値取ってもしょうがないので、1秒未満のとても短いサイクルで瞬間値を取って平均に丸めています。)


特にこのconcurrencyを重要視しています。

Threads_running、すなわちその時何かを実行中のthreadの数なので、これが異様に溜まっているとその時MySQLでは何かが起きているわけです。
詳しくは以下の論文が参考になるわけですが、この値がHWのCPU実コア数を超えると性能限界に達するのだ、と考えています。

Percona | Forecasting MySQL Scalability with the Universal Scalability Law
(難しい数式がたくさん出てきますが、途中に出てくるグラフを見たら言いたいことはわかります。)


なのでこのconcurrencyに対して適切な閾値を定めてあげて、それを超えてくるようならアラートを上げる、なんてしてあげるとスケールアウトの時期なんかが定量的に測れてしまうわけなのです。

もちろんこれは大前提として、洗練されたselectと適切な行数への更新が行われているDB上でのベンチマーク結果なので、実際はここまでの性能は出せないかもしれません。
経験則ですが12コア、メモリ60GBぐらいのサーバならトータル2-3万QPSは捌けるはずなので、これに満たない場合はクエリチューニングを頑張りましょう。


僕が作った仕組みじゃないですが、日々の業務にとっっっっっっっても役に立っています。
このデータを活かすとこんなことができてしまうわけです。

  • 一時的にslaveのレプリを止めて溜まった更新が追いつく時のスピードで更新qpsの限界値を見る
    • HWスペックとかそのDBの用途、クエリの性質ごとで数値は変わってくるのですが、そろそろ分割かなぁとかshard追加するかぁとかの目星がつけやすくなります。
    • QPSだけだとバルクインサートとか複数行updateがいると数字がやたら小さくなるので、そういう時はInnoDB_rows_XXXが参考になります。
  • ある特定の時間にconcurrencyが高まる
    • その時間に実行されるバッチに質の悪いクエリが潜んでいるかも!
    • long_query_timeを短くしてslow-logで炙りだす!
  • QPSは低いのにconcurrencyが高い
    • indexの効いていないクエリがいるかも・・・
      • tcpdump & pt-query-digestの出番です!
    • 実はやたらとlock wait timeoutしていたり・・・

などなど。


まだまだ活用の方法はあったりするんですが、ほんとに役に立つのでDBAな方は騙されたと思って仕組みを作ってみるとのちのちHappyになれると思いますよ!!

localport枯渇・・・

忘れないうちにもう1つ。
最近のサーバはスペックがとてもよろしいので、ついつい待機FCGIの数を増やしたくなってしまうのですが、これでハマるところを直近2回ほど見たのでメモ。

FCGIを増やしたのに全然さばけなくてなんかこんなエラー出るし!みたいなときは

Can't connect to MySQL server on 'hostname' (99)

接続先のMySQLに対するlocalportが枯渇してた、なんてことがあります。

netstat -na | grep tcp | wc -l

これが3万近かったら以下を打ってみましょう。

> cat /proc/sys/net/ipv4/ip_local_port_range 
32768   61000

こうなってたらlocalport枯渇してるのかもしれません。
どんくらいの数字を入れるのがいいかは人それぞれあるみたいですが、そのときは

> echo "2048 64512" > /proc/sys/net/ipv4/ip_local_port_range 

なんてして6万強確保しました。
相手先のIP:PORTに対する数なので、DBが相手だったらslave増やしてあげるとか、masterだったらさっさとdisconnectするとか、webをKVMにしてリソースを分散してFCGIの数を抑えてあげるとかしないといけないんですね。


※追記

どうやらこれだけじゃTIME_WAIT残っちゃって焼け石に水なこともあり、不特定多数のクライアントからの接続を受ける環境では難あり。

ちなみにlocalport問題に対しては、こんなこと↓をするって記事も見かけますが、

> echo 1 > /proc/sys/net/ipv4/tcp_tw_recycle
> echo 10 > /proc/sys/net/ipv4/tcp_fin_timeout

これだと↓の記事にあるようにタイムスタンプつけたパケットがドロップされてしまうこともあるようで、外部接続を受けるwebサービスなんかでは余計な障害を引き起こしてしまうやも。。。

2007-05-21 - LowPriority

じゃーどうすんねん!!!
ってことでお隣の部署では

Linux kernelのTCP_TIMEWAIT_LENをチューニング

しているとのこと。

ざっくり↓の記事のようにkernelをリビルドしてあげちゃうのが効果てきめんだそうです。

TIME_WAITのチューニングとkernelリビルド for CentOS 6.0 - 逆襲のWebエンジニア

突き詰めるとkernelハックまで行っちゃうんですね。
TCP接続奥ふけぇぇぇぇぇ( ゚д゚)


  • TCPの状態遷移をど忘れしたら見る。

netstatコマンドを使いこなす − @IT

skip-name-resolve

記事がかぶって悔しかったのでもいっこ書いておきます。

やたら監視応答が遅いということで、色々追ってみた結果これじゃあないかということで
my.cnfに

skip-name-resolve

を書いてrestartして回りました。

んでまぁDNS逆引きをしなくなって状況は改善したわけですが、これの確認をしていて困った。

> show global variables like 'skip%';

なぁんて打つわけですが、サーバによってskip-name-resolve ONが出たり出なかったり。

ググってみたら5.1.46からじゃないとvariablesに出てこないそうで。
MySQL Bugs: #23606: --skip-name-resolve missing from SHOW VARIABLES (other skip options are shown)

じゃあどうやって確認するんですかね。

my.cnfのloose-*ってなによ

書くって載せてたリストとは全然関係ないですが、今日覚えたのでメモ。

お手元のmy.cnfにこんな記述見たことありませんか?

loose-default-character-set = utf8

リファレンスによれば
MySQL :: MySQL 4.1 リファレンスマニュアル :: 4.1.2 my.cnf オプション設定ファイル

バージョン 4.0.2 より、loose プリフィックスをコマンドラインオプション(または my.cnf のオプション)に使用できます。
オプションの前に loose を付けると、オプションが未知の場合でも、それを読み取ったプログラムはエラー終了せず、以下の警告を出力します。

だそうです。
以下の警告の「以下」ってどれやねんて話ですが、とりあえず新しいバージョンのMySQLを使って見たい時にこれを付けて、どれで怒られるかmysqld.errを眺めるのがいいかもしれません。

[client]セクションにdefalut-character-setを書いてて、mysqlbinlog叩いて怒られた方もいらっしゃるのではないでしょうか。
実際今日そんなところを見かけたので、--no-defaultを付けるのもいいですがlooseを使ってみてもいいかも!!
でもこれ過信してると、効いてて欲しかったオプションが実は効いてないとかありそうなんでお気をつけあそばせ。

全然別件ですが、pt-query-digestはbinlogをそのままでは食べられませんでした。
mysqlbinlogを1回噛ませて上げるとうまく咀嚼してくれます。

と思ったらボスがおんなじ内容でブログ書いてた。
でももう書いちゃったから消しません。あえて晒します。

ブログネタのメモ

時間なくて書こうと思ってたことすら忘れそうなので、一旦メモ。
ここに書いたことで執筆意欲があとから湧いてくるはず。

  • mroonga 3.0.0のインストールまで ~Mecabを添えて~
  • rename/truncate tableの怖さまとめ
  • DB KPI取得のススメ
  • mk(pt)-query-digestをもっと活用しよう!

おい、お前これも書けるだろ的なものがあったらご指摘ください。