この記事はHamee Advent Calendar 2017の17日目の記事です。

概要

処理が止まる系(または、リロードしてるっぽい挙動がずっと続く)の調査をして見たので抑えていたところをまとめて見た。足りないところがあればコメントお願いします。

前提

ローカルで処理待ちが再現する。
ローカルで再現しない時に本番にログを仕込まねばならず、
調整(社内での政治的なあれこれ・・・)についてはベテランの方にお任せしましょ。

これは言わずもがなかもしれません。

ping -l [データサイズ] [調査するURL]

などで少し大きめのpingを送って見て遅いようならまずこれが原因となっているかも。

クエリが遅いかどうかは発行されているクエリが見れれば良いです。
スロークエリを出すようにしておけば、基本的には見れるはず。

スロークエリの設定についてはMySQLにログインした状態で

show variables like 'slow%';

例としては以下の通り。

slow_query_log がOFFになっているとスロークエリの出力は行われない。

set global slow_query_log_file = '/tmp/mysql-slow.log';
set global long_query_time = 5;
set global slow_query_log = ON;

$ sudo vim /etc/my.cnf

my.cnf

[mysqld]
slow_query_log 
slow_query_log-file = /var/log/mysql/mysql-slow.sql # これらを追加する
long_query_time = 5

設定を変更したら反映させるためにrestartする。

これは実はなってました。パターンもあるので必ずチェックしておく。

まずはデッドロックがログで出力されるかを見る。

show variables like 'innodb_print_all_deadlocks';

Variable_name	Value
innodb_print_all_deadlocks	OFF

mysql> set global innodb_print_all_deadlocks=ON;
 
Query OK, 0 rows affected (0.00 sec)

mysql> show variables like 'innodb_print_all_deadlocks';

Variable_name	Value
innodb_print_all_deadlocks	ON

sudo vi /etc/my.cnf


[mysqld]
innodb_print_all_deadlocks=ON # この行を追加する

Javascript系統 => for文、while文や処理が重そうなところにtimeを仕込んで計測。またはconsole.logで中身を表示させることで重くなっている原因となりそうな要素がないかを探す。この辺りは自分の中でうまくまとまっていないので後日まとめ出すかも。

PHP => こちらもMVCフレームワークなど使っていれば、使っている箇所はわかりやすいのでその辺りにログを仕込んでいく。(仕込めるという前提ではある)

最初のログの設計時点でこれをしなくて良いようにするのが最善。