スロー クエリ ログは数多く見てきましたが、次のようなログは見たことがありません。
/usr/sbin/mysqld, Version: 5.1.46-log (SUSE MySQL RPM). started with:
Tcp port: 3306 Unix socket: /var/run/mysql/mysql.sock
Time Id Command Argument
# Time: 160627 9:10:05
# User@Host: sysop[sysop] @ [127.0.0.1]
# Query_time: 3.768728 Lock_time: 0.034402 Rows_sent: 734 Rows_examined: 734
use asterisk;
SET timestamp=1467033005;
select PostID, lead_id, list_id from vdlist_temp where Posted is null;
# Time: 160627 10:35:11
# User@Host: sysop[sysop] @ [192.168.0.248]
# Query_time: 35.563521 Lock_time: 0.000054 Rows_sent: 1222017 Rows_examined: 2444034
SET timestamp=1467038111;
SELECT `vicidial_list`.`lead_id`, `vicidial_list`.`source_id` FROM `vicidial_list` ORDER BY `vicidial_list`.`source_id`;
# User@Host: sysop[sysop] @ [127.0.0.1]
# Query_time: 0.000095 Lock_time: 18446744073699.406250 Rows_sent: 2 Rows_examined: 1
SET timestamp=1467038111;
call spUpdate_VDList_from_temp(0, 0, 1324903);
# Time: 160627 10:35:12
# User@Host: sysop[sysop] @ [127.0.0.1]
# Query_time: 0.000055 Lock_time: 18446744073699.359375 Rows_sent: 0 Rows_examined: 0
SET timestamp=1467038112;
call spMoveXDrop(10376163);
# Time: 160627 11:26:14
# User@Host: sysop[sysop] @ [127.0.0.1]
# Query_time: 0.000057 Lock_time: 18446744073697.218750 Rows_sent: 3 Rows_examined: 0
SET timestamp=1467041174;
call spUpdate_VDList_from_temp(10795520, 616062301, 1955758);
これは、ロックを 500,000 年以上待っているクエリがあることを示しているようです。(私はストアド プロシージャを書きましたが、それほど年をとっていません!) どういうわけか、それは正しくないと思います。これらはすべて MyISAM テーブルです。(私の選択ではありません。) mysqldump を実行してデータベースを復元し、サーバーを再起動しましたが、このようなロック時間が表示されます。
問題を探す場所を誰かに教えてもらえますか? (サーバー時間はすべて良好です。)
編集: この MySql バージョン: 5.1.46-log は、オープンソース プロジェクト Vicidial に付属しています。Lock_time がバグであることは明らかです。問題は、遅いクエリ ログを調べて、Web サーバーの応答が遅いというユーザーの苦情を追跡していることです。実際の問題を特定するために、このバグの原因を誰かが知っていることを望んでいました。ログからわかるように、ほとんどの遅いクエリは適切な Lock_times を持っています。ストアド プロシージャと PHP によって生成されたクエリの両方が、非常識な Lock_time を生成します。唯一の共通点は、それらすべてがテーブル vicidial_list から選択または更新することです。そのテーブルをダンプ、ドロップ、再作成しましたが、役に立ちませんでした。