主にアプリケーション開発者向けに、Linuxサーバ上の問題を調査するために、ウェブオペレーションエンジニアとして日常的にやっていることを紹介します。
とりあえず調べたことを羅列しているのではなく、本当に自分が現場で使っているものだけに情報を絞っています。
普段使っているけれども、アプリケーション開発者向きではないものはあえて省いています。
MySQLやNginxなど、個別のミドルウェアに限定したノウハウについては書いていません。
●ログインしたらまず確認すること
●他にログインしている人がいるか確認︵w︶
●サーバの稼働時間の確認 (uptime)
●プロセスツリーをみる (ps)
●NICやIPアドレスの確認 (ip)
●ファイルシステムの確認︵df︶
●負荷状況確認
●top
●iostat
●netstat / ss
●ログ調査
●/var/log/messages or /var/log/syslog
●/var/log/secure
●/var/log/cron
●/var/log/nginx, /var/log/httpd, /var/log/mysql
●/etc
●lsof
●関連
●あとがき
のような記事を以前書いています。
ログインしたらまず確認すること
他にログインしている人がいるか確認︵w︶
wコマンドにより現在サーバにログインしてるユーザ情報をみれます。$ w 11:49:57 up 72 days, 14:22, 1 user, load average: 0.00, 0.01, 0.05 USER TTY FROM LOGIN@ IDLE JCPU PCPU WHAT y_uuki pts/0 x.x.x.x 11:49 1.00s 0.02s 0.00s w再起動などシステム影響がありうるオペレーションをする場合、同僚が他の作業をしていないかどうかをチェックします。
サーバの稼働時間の確認 (uptime)
サーバが前回再起動してから現在までの稼働している時間をみれます。下記の例の場合、72日間稼働しています。$ uptime 11:55:39 up 72 days, 14:28, 1 user, load average: 0.00, 0.02, 0.05DOWNアラートがきたときに、このコマンドをよく打ちます。DOWNアラートが来ていても、実際にOSが再起動していないということはよくあります。 これは監視システムと対象ホスト間のネットワーク不調が原因で、DOWNアラートが来ることがあるためです。 AWS EC2のようなVM環境の場合、ハイパーバイザ側のネットワークスタック不調などにより、監視システムと疎通がなくなるということがありえます。 uptimeコマンドにより、前回のシャットダウンから現在までの経過時間を知れます。上記の例の場合、72日間ですね。OSが再起動している場合、MySQLサーバのようなデータベースのデータが壊れている可能性があるので、チェックする必要があります。
プロセスツリーをみる (ps)
サーバにログインしたときに必ずと言っていいほどプロセスツリーを確認します。 そのサーバで何が動いているのかをひと目で把握できます。ps auxfpsコマンドのオプションに何を選ぶかはいくつか流派があるようです。自分はずっと auxf を使っています。 aux でみてる人もみたりしますが、fをつけるとプロセスの親子関係を把握しやすいのでおすすめです。 親子関係がわからないと、実際には同じプロセスグループなのに、同じプロセスが多重起動していておかしいと勘違いしやすいです。
... root 25805 0.0 0.1 64264 4072 ? Ss 2015 0:00 nginx: master process /usr/sbin/nginx -g daemon on; master_process on; nginx 25806 2.6 0.7 70196 15224 ? S 2015 2691:21 \_ nginx: worker process nginx 25807 2.7 0.8 71700 16416 ? S 2015 2725:39 \_ nginx: worker process nginx 25808 2.7 0.7 70672 15336 ? S 2015 2725:30 \_ nginx: worker process nginx 25809 2.7 0.7 71236 15976 ? S 2015 2709:11 \_ nginx: worker process nginx 25810 2.6 0.9 74084 18888 ? S 2015 2646:32 \_ nginx: worker process nginx 25811 2.6 0.6 69296 14040 ? S 2015 2672:49 \_ nginx: worker process nginx 25812 2.6 0.8 72932 17564 ? S 2015 2682:30 \_ nginx: worker process nginx 25813 2.6 0.7 70752 15468 ? S 2015 2677:45 \_ nginx: worker process ...pstree でも可。ただし、プロセスごとのCPU利用率やメモリ使用量をみることも多いので、
ps をつかっています。
NICやIPアドレスの確認 (ip)
ifconfig コマンドでもよいですが、ifconfig は今では非推奨なので、ipコマンドを使っています。ipコマンドはタイプ数が少なくて楽ですね。$ ip a
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN
link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
inet 127.0.0.1/8 scope host lo
valid_lft forever preferred_lft forever
2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP qlen 1000
link/ether 00:16:3e:7d:0d:f9 brd ff:ff:ff:ff:ff:ff
inet 10.0.0.10/22 brd z.z.z.z scope global eth0
valid_lft forever preferred_lft forever
inet 10.0.0.20/22 scope global secondary eth0
valid_lft forever preferred_lft forever
上記の出力例ではよくみているとセカンダリIPがついています。セカンダリIPがついているということは、なんらかの特殊な役割をもつホストである可能性が高いですね。
特にVIPを用いた冗長構成をとっている場合、VIPがついているならばマスタであると判断できます。
社内では、eth0に対するセカンダリIPや、eth1にプライマリIPをVIPとして利用することが多いです。
このような事情もあり、サーバにログインするとIPアドレスのチェックを癖でやってしまっています。
ファイルシステムの確認︵df︶
ファイルシステムの容量確認はdfコマンドを使います。-T をつけると、ファイルシステムの種別を確認できます。-h をつけると、サイズ表記がヒューマンリーダブルになります。
$ df -Th Filesystem Type Size Used Avail Use% Mounted on rootfs rootfs 20G 2.4G 17G 13% / udev devtmpfs 10M 0 10M 0% /dev tmpfs tmpfs 3.0G 176K 3.0G 1% /run /dev/disk/by-uuid/2dbe52e8-a50b-45d9-a2ee-2c240ab21adb ext4 20G 2.4G 17G 13% / tmpfs tmpfs 5.0M 0 5.0M 0% /run/lock tmpfs tmpfs 6.0G 0 6.0G 0% /run/shm /dev/xvdf ext4 100G 31G 69G 4% /data/redisdfコマンドにより、ディスク容量以外にも、いくつかわかることがあります。 例えば、MySQLのようなデータをもつストレージサーバは、本体とは別の専用のディスクデバイスをマウントして使う︵EC2のEBSボリュームやFusion-IOの ioDriveなど︶ことがあります。 上記の出力例の場合、
/data/redis に着目します。前述の﹁プロセスツリーをみる﹂により、Redisが動いていることもわかるので、RedisのRDBやAOFのファイルが配置されていると想像できます。
負荷状況確認
次は、Linuxサーバの負荷を確認する方法です。そもそも負荷とは何かということについて詳しく知りたい場合は、﹁サーバ/インフラを支える技術﹂の第4章を読むとよいです。 Mackerelのような負荷状況を時系列で可視化してくれるツールを導入していても、以下に紹介するコマンドが役に立つことは多いと思います。 秒単位での負荷の変化やCPUコアごと、プロセスごとの負荷状況など、可視化ツールで取得していない詳細な情報がほしいことがあるからです。 Mackerelである程度あたりをつけて、サーバにログインしてみて様子をみるというフローが一番多いです。top
top -c をよく打ってます。 -c をつけると、プロセスリスト欄に表示されるプロセス名が引数の情報も入ります。(psコマンドでみれるのでそっちでも十分ですが︶
さらに重要なのが、top 画面に遷移してから、 キーの 1をタイプすることです。1 をタイプすると、各CPUコアの利用率を個別にみることができます。学生時代のころから当たり前に使ってたので、たまにご存知ない人をみつけて、意外に思ったことがあります。(mpstat -P ALL でもみれますが︶
かくいう自分も これを書きながら、top の man をみてると知らない機能が結構あることに気づきました。
top - 16:00:24 up 22:11, 1 user, load average: 1.58, 1.43, 1.38 Tasks: 131 total, 2 running, 129 sleeping, 0 stopped, 0 zombie %Cpu0 : 39.7 us, 4.1 sy, 0.0 ni, 48.6 id, 0.3 wa, 0.0 hi, 6.9 si, 0.3 st %Cpu1 : 24.4 us, 1.7 sy, 0.0 ni, 73.9 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st %Cpu2 : 14.7 us, 1.7 sy, 0.0 ni, 83.7 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st %Cpu3 : 0.0 us, 2.0 sy, 98.0 ni, 0.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st %Cpu4 : 3.3 us, 0.7 sy, 0.0 ni, 96.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st %Cpu5 : 2.0 us, 0.3 sy, 0.0 ni, 97.7 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st %Cpu6 : 2.3 us, 0.3 sy, 0.0 ni, 97.3 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st %Cpu7 : 0.7 us, 0.3 sy, 0.0 ni, 99.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st KiB Mem: 7199160 total, 5764884 used, 1434276 free, 172496 buffers KiB Swap: 0 total, 0 used, 0 free, 5161520 cached PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 16659 root 39 19 8612 632 440 R 100.3 0.0 0:12.94 /bin/gzip 2343 nginx 20 0 60976 14m 1952 S 23.2 0.2 112:48.51 nginx: worker process 2328 nginx 20 0 61940 15m 1952 S 19.9 0.2 111:49.12 nginx: worker process 2322 nginx 20 0 61888 15m 1952 S 19.3 0.2 113:44.95 nginx: worker process 2324 nginx 20 0 61384 14m 1952 S 16.6 0.2 113:30.52 nginx: worker process 2340 nginx 20 0 61528 14m 1952 S 11.0 0.2 114:02.36 nginx: worker process ...上記の出力例は結構おもしろいタイミングを示していて、下のプロセスリストをみると、
/bin/gzip がCPU 100%使いきっています。
これはlogrotateがアクセスログを圧縮している様子を表しています。
上段のCPU利用率欄をみると、Cpu3 が 0.0 idとなっています。idは idle の略であり、idが 0% ということはCpu3を使いきっているということです。これらの状況から gzip プロセスが Cpu3 を使いきっているということが推測できます。
CPU利用率欄には他にも、us, sy、ni、wa、hi、si、stがあります。︵カーネルバージョンにより多少異なります︶
これらは、CPU利用率の内訳を示しています。よくみるのは、us、sy、waの3つですね。
●us(user): OSのユーザランドにおいて消費されたCPU利用の割合。userが高いということは、アプリケーション︵上記の場合nginx︶の通常の処理にCPU処理時間を要していることです。
●sy(system): OSのカーネルランドにおいて消費されたCPU利用の割合。systemが高い場合は、OSのリソース︵ファイルディスクリプタやポートなど︶を使いきっている可能性があります。カーネルのパラメータチューニングにより、負荷を下げることができるかもしれません。fork 回数が多いなど、負荷の高いシステムコールをアプリケーションが高頻度で発行している可能性があります。straceでより詳細に調査できます。
●wa(iowait): ディスクI/Oに消費されたCPU利用の割合。iowaitが高い場合は、次の iostat でディスクI/O状況をみましょう。
基本は各CPUコアのidleをざっと眺めて、idle が 0 に近いコアがないかを確認し、次に iowait をみてディスクI/Oが支配的でないかを確認し、user や system をみます。
ちなみに、自分は si (softirq) についてこだわりが強くて、 Linuxでロードバランサやキャッシュサーバをマルチコアスケールさせるためのカーネルチューニング - ゆううきブログ
のような記事を以前書いています。
iostat
ディスクI/O状況を確認できます。-d でインターバルを指定できます。だいたい5秒にしています。ファイルシステムのバッファフラッシュによるバーストがあり、ゆらぎが大きいので、小さくしすぎないことが重要かもしれません。 -x で表示する情報を拡張できます。$ iostat -dx 5 Linux 3.10.23 (blogdb17.host.h) 02/18/16 _x86_64_ (16 CPU) Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util xvda 0.00 3.09 0.01 3.25 0.13 36.27 22.37 0.00 1.45 1.59 1.45 0.52 0.17 xvdb 0.00 0.00 0.00 0.00 0.00 0.00 7.99 0.00 0.07 0.07 0.00 0.07 0.00 xvdf 0.01 7.34 49.36 33.05 841.71 676.03 36.83 0.09 8.08 2.68 16.13 0.58 4.80 Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util xvda 0.00 3.20 0.40 2.80 2.40 30.40 20.50 0.00 0.25 0.00 0.29 0.25 0.08 xvdb 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 xvdf 0.00 5.00 519.80 4.00 8316.80 96.00 32.12 0.32 0.61 0.60 1.40 0.52 27.36iostat コマンドは癖があり、1度目の出力はディスクデバイスが有効になってから現在まのの累積値になります。 現在の状況を知る場合は、2度目以降の出力をみます。 自分の場合、IOPS (r/s、w/s︶と%utilに着目することが多いです。 上記の場合、r/s が519と高めで、%util が 27%なので、そこそこディスクの読み出し負荷が高いことがわかります。
netstat / ss
netstat はネットワークに関するさまざまな情報をみれます。 TCPの通信状況をみるのによく使っています。-t でTCPの接続情報を表示し、 -n で名前解決せずIPアドレスで表示します。-n がないと連続して名前解決が走る可能性があり、接続が大量な状況だとつまって表示が遅いということがありえます。(-n なしでも問題ないことも多いので難しい︶
-l でLISTENしているポートの一覧をみれます。下記の場合、LISTENしているのは 2812, 5666, 3306, 53549, 111, 49394, 22, 25 ですね。
$ netstat -tnl Active Internet connections (only servers) Proto Recv-Q Send-Q Local Address Foreign Address State tcp 0 0 0.0.0.0:2812 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:5666 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:3306 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:53549 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:111 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:49394 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:22 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:25 0.0.0.0:* LISTEN tcp6 0 0 :::54282 :::* LISTEN tcp6 0 0 :::111 :::* LISTEN tcp6 0 0 :::22 :::* LISTEN tcp6 0 0 :::53302 :::* LISTEN tcp6 0 0 :::25 :::* LISTENTCPの全部のステートをみるには
-a を指定します。 -o はTCP接続のタイマー情報、 -pはプロセス名の表示 (-p には root権限が必要) ができます。
$ sudo netstat -tanop ... tcp 0 0 10.0.0.10:3306 10.0.0.11:54321 ESTABLISHED 38830/mysqld keepalive (7190.69/0/0) tcp 0 0 10.0.0.10:3306 10.0.0.12:39150 ESTABLISHED 38830/mysqld keepalive (7157.92/0/0) tcp 0 0 10.0.0.10:3306 10.0.0.13:49036 TIME_WAIT 38830/mysqld timewait (46.03/0/0) tcp 0 0 10.0.0.10:3306 10.0.0.14:41064 ESTABLISHED 38830/mysqld keepalive (7223.46/0/0) tcp 0 0 10.0.0.10:3306 10.0.0.15:34839 ESTABLISHED 38830/mysqld keepalive (7157.92/0/0) ...一番、よくみるのは、このホストはどのホストから接続されているかです。 なぜか本番サーバなのに、ステージングサーバから接続されているというようなことがわかったりすることもあります。 他にも、単にやたらと接続が多いなとかざっくりした見方もします。そのときに、TCPのステートでESTABLISHED以外がやたらと多くないかなどをみたりします。 netstat は非推奨なので、ssコマンドをつかったほうがよいようです。 ただし、自分の場合、ssコマンドの出力の余白の取り方があまり好きではないので、netstat をつかっています。
ログ調査
いうまでもなくログ調査は重要です。 ログをみるためには、OSや、各種ミドルウェア、アプリケーションが吐くログがどこに履かれているのかを知る必要があります。 基本的には /var/log 以下を眺めてそれっぽいものをみつけて tail してみます。/var/log/messages or /var/log/syslog
まずはここを見ましょう。カーネルやOSの標準的なプロセスのログをみることができます。他にもcron実行するコマンドの標準出力や標準エラー出力を明示的に logger にパイプしている場合などはここにログが流れます。/var/log/secure
ssh 接続の情報がみれます。他の人がssh接続しているのに接続できない場合、ここに吐かれているログをみると原因がわかることがあります。/var/log/cron
cronが実行されたかどうかがわかります。ただし、cronが実行したコマンドの標準出力または標準エラー出力が/var/log/cron に出力されるわけではなく、あくまでcronのスケジューラが動いたかどうかがわかるだけです。cronが実行したコマンドの標準出力または標準エラー出力はどこに出力されるか決まっているわけではなく、crontab内でloggerコマンドにパイプしたり、任意のログファイルにリダイレクトしたりすることになります。
/var/log/nginx, /var/log/httpd, /var/log/mysql
ミドルウェアのログは/var/log/{ミドルウェア名} 以下にあることが多いです。
特によくみるのはリバースプロキシのアクセスログやDBのスロークエリログですね。
自分が開発しているシステムのログの位置は確認しておいたほうがよいです。
/etc
/var/log 以下にログを吐くというのは強制力があるものではないので、ログがどこにあるのか全くわからんということがあります。
ログファイルのパスは設定ファイルに書かれていることもあります。 設定ファイルは /etc 以下にあることが多いので、 /etc/{ミドルウェア名} あたりをみて、設定ファイルの中身を cat してログファイルのファイルパスがないかみてみましょう。
lsof
/etcをみてもわからんというときは最終手段で、lsofを使います。psや top でログをみたいプロセスのプロセスIDを調べて、lsof -p <pid> を打ちます。
そのプロセスが開いたファイルディスクリプタ情報がみえるので、ログを書き込むためにファイルを開いていれば、出力からログのファイルパスがわかります。
他には例えば、daemontools を使っていると、 /service 、もしくは /etc/service 以下に multilog が吐かれているなど、使用しているスーパーバイザによっては、特殊なディレクトリを使っている可能性があります。
関連
●The Netflix Tech Blog: Linux Performance Analysis in 60,000 Milliseconds
