スロウクエリの時間計算にバグがあり、クエリの完了時間 - クエリの開始時間が負数になると、
負数として扱われずにそのまま符号なしで計算される。
http://bugs.mysql.com/bug.php?id=35396
たとえば7/1 08:59:60.53(システム上の扱いは09:00:00.53)~7/1 09:00:00.13にかけて実行されたクエリは、
-0.40秒の実行となり…浮動小数点演算の補数計算できないけど、とにかく最上位のビットが立つので馬鹿みたいな大きな数になる。
⇒スロウログに、馬鹿でっかいQuery_timeのエントリがずらずら並びそう。
5.1系は5.1.63で修正されている。
5.5.0-m2でも再現したけれど、5.5.20-ndb-7.2.5では再現しなかった。
5.5系はどこで修正されたんだろ。
# Time: 120516 0:00:09
# User@Host: root[root] @ localhost []
# Query_time: 18446744062814.714844 Lock_time: 0.053146 Rows_sent: 1 Rows_examined: 5760001
SET timestamp=1337094009;
select 1 from settlement order by rand() limit 1;
Slow_queriesの回数グラフにしてたりする場合は注意。
いやQuery_timeが明らかにおかしいから大丈夫だと思うけれど。
あと、逆に7/1 08:59:60.53(システム上の扱いは09:00:00.53)~7/1 09:00:01.00にかけて実行されたクエリは、
1.47秒かかってるけど時間の差分が0.47秒になっちゃうのでスロウログには載らない。
こっちはどうでも良いかな。
このメモに書いてあるのは、mysqldがCPUをぶん回す問題とは別のバグです。
返信削除CPUをぶん回す件はこちら。
http://bugs.mysql.com/bug.php?id=65778