【apache】 flock_lock_file_wait しているとき

Tweet

Category apache 2013/06/11

問題

Webサーバーがどうも様子がおかしく、httpd のプロセスがたくさん発生して、flock_lock_file_wait がたくさん出てるらしい。

答え

プロセスがスリープしている状況を確認（どこで止まっているか）

# ps -o pid,tt,user,fname,wchan -C httpd

  PID TT       USER     COMMAND  WCHAN
 8930 ?        root     httpd    -
12198 ?        apache   httpd    -
12299 ?        apache   httpd    flock_lock_file_wait
12619 ?        apache   httpd    flock_lock_file_wait
12621 ?        apache   httpd    flock_lock_file_wait
12629 ?        apache   httpd    -
12631 ?        apache   httpd    flock_lock_file_wait
12640 ?        apache   httpd    flock_lock_file_wait
（以下たくさん略）

なんだか大変そうだ。

特定のプロセスが使用中のファイルを調べる

# lsof -p 12299

COMMAND   PID     USER   FD   TYPE   DEVICE  SIZE/OFF      NODE NAME
httpd   12299 apache    cwd    DIR    253,0      4096  59082247 /home/foo/bar/htdocs
httpd   12299 apache    rtd    DIR    253,0      4096         2 /
httpd   12299 apache    txt    REG    253,0   1210254  12714320 /usr/local/apache2/bin/httpd
httpd   12299 apache    mem    REG    253,0     45432  92408476 /lib/libcrypt-2.5.so
（中略）
（アクセスログのファイルとかいろいろ）
（中略）
httpd   12299 apache     20u  IPv4 95837180       0t0       TCP 192.168.123.13:58301->192.168.123.12:mysql (ESTABLISHED)
httpd   12299 apache     21u   REG    253,0       100  38235319 /tmp/sess_a104b06c9257ee578b6d287077a2aca9

最後にセッションファイルが出てきた。

確かにphpのデフォルトのセッションはファイルをロックするけど、これが直接の原因ということはないんじゃないか。

逆にこのファイルを使っているのは誰？

# lsof /tmp/sess_a104b06c9257ee578b6d287077a2aca9
 
COMMAND   PID     USER   FD   TYPE DEVICE SIZE/OFF     NODE NAME
httpd   12198 apache     21uW  REG  253,0      100 38235319 /tmp/sess_a104b06c9257ee578b6d287077a2aca9
httpd   12299 apache     21u   REG  253,0      100 38235319 /tmp/sess_a104b06c9257ee578b6d287077a2aca9
httpd   13161 apache     21u   REG  253,0      100 38235319 /tmp/sess_a104b06c9257ee578b6d287077a2aca9

あるプロセスがファイルをつかんでいて、2つのプロセスは待ちをしているっぽい。

12299、13161 が flock_lock_file_wait してて、それは 12198 がファイルをつかんでいるのが原因っぽい感じ。

12198 は何をしているの？

# lsof –p 12198
（前略）
httpd   16765 apache     18r  0000     0,11         0  96194490 eventpoll
httpd   16765 apache     19u  IPv4 96195573       0t0       TCP 192.168.123.123:http->pw1262052
httpd   16765 apache     20u  IPv4 96195574       0t0       TCP 192.168.123.124:39790->192.16
httpd   16765 apache     21uW  REG    253,0       370  40006494 /tmp/sess_17e7954240033a6d55
httpd   16765 apache     22r   DIR    253,0 312377344  37584897 /tmp

あれ？ /tmp を読むのがそんなに大変？？？

ここで /tmp の中身が気になる。

ちょっと /tmp の中身何個あるの

# ls /tmp | wc
2735929 2735929 175389370

(　д)　ﾟ　ﾟ

サーバーさん大変でしたね… 1つのフォルダに300万個近いファイルが作られていたとは… すみません今消します…

別の切り口からもっと早くここにたどり着けたかもしれない。vmstat みたらなんかおかしいし。

みたいなことをしている日もあります。