ひでメモ

プログラムについて勉強したことを書きます。たぶん。

PHP ≒ Apach が参照している回数が多いファイルをコマンドで確認する

概要

先日 NFS でマウントしているストレージへのアクセス過多がボトルネックとなりサービスへのアクセスがしづらくなるという状態が発生しました。

調査の中で、サーバのプロセスをトレースするコマンドを使ってプロセスがアクセスしたファイルを取得、内容をパースしてアクセスが多いファイル・ディレクトリをカウントしたのでメモです。

やったこと

参照ファイルをトレースする

Webサーバは Apach を使っており httpd が実質 PHP のプロセスになります。 そのため、httpd をトレースして一番参照回数が多いファイルを取得しました。
以下のコマンドで httpd をトレースして参照したファイルなどをテキストファイルへ出力しています。

strace -o ./strace-httpd_$(date +'%m%d%H%M').txt -p $(ps axuw | grep 'httpd .*FOREGROUND' | head -1 | awk '{​​​​​​​​print $2}​​​​​​​​')

コマンドを実行するとプロセスが生きている間は出力し続けるため、5~10分程度の時間放置します。
適当なところで control + c で中断します。

補足:httpd のプロセスは複数あるはずなので一番 PID が小さいプロセスを参照しています。

続けて以下のコマンドでトレース結果からカウントします。

ディレクトリ単位でカウント

grep '"/' ./strace-httpd_日時分.txt | awk -F\( '{​​​​​​​​​​​​print $1,$2}​​​​​​​​​​​​' | awk '{​​​​​​​​​​​​print $1,$2}​​​​​​​​​​​​' | awk '{​​​​​​​​​​​​print $2}​​​​​​​​​​​​' | sed 's#/[^/]*",##' | sort | uniq -c | sort -g

ファイル単位でカウント

grep '"/' ./strace-httpd_日時分.txt | awk -F\( '{​​​​​​​print $1,$2}​​​​​​​​​​​​​​' | awk '{​​​​​​​​​​​​​​print $1,$2}​​​​​​​​​​​​​​' | awk '{​​​​​​​​​​​​​​print $2}​​​​​​​​​​​​​​' | sort | uniq -c | sort -g

ディレクトリ単位でカウントした場合以下のようになります。
左に表示されているのが参照回数です。

    317 "/vendor/laravel/framework/src/Illuminate/Database
    366 "/vendor/laravel/framework/src/Illuminate/Support/Facades
    371 "/app/Models
    389 "/vendor/symfony/http-foundation
    430 "/vendor/laravel/framework/src/Illuminate/Support
    480 "/vendor/laravel/framework/src/Illuminate/View/Compilers/Concerns
    660 "/vendor/nesbot/carbon/src/Carbon/Traits
    758 "/vendor/laravel/framework/src/Illuminate/Routing

おまけ:プロセスがあんまり動いていない場合

検証環境で使っている人がほとんどいない場合、動いてないプロセスIDにあたってしまうとほぼ何も出力されないので数でゴリ押ししました…!

# プロセス名を指定して全プロセスIDを取得
$ pidof httpd
56139 56138 56137 56136 56135 56134 56133 56132 56131 56130 56129 56128 56127 56126 56125 56124 56123 56122 56121 56120 56119 56106

# 全プロセスIDを指定
$ sudo strace -o ./strace-httpd_$(date +'%m%d%H%M').txt -p 56139 -p 56138 -p 56137 -p 56136 -p 56135 -p 56134 -p 56133 -p 56132 -p 56131 -p 56130 -p 56129 -p 56128 -p 56127 -p 56126 -p 56125 -p 56124 -p 56123 -p 56122 -p 56121 -p 56120 -p 56119 -p 56106

余談

カウントした結果、config 系のファイルが一番参照されていたので config キャッシュを有効にしたら1割程度ストレージへのアクセスが減りました…
ちゃんとドキュメントが推奨していることはやりましょうという話でした(なんでやってなかったんだろう)
キャッシュ有効にするだけでつまづいたこともあったのでまた今後書きたいです。