サーバ障害時のトラブルシューティング ~クリスマスイブでも早く帰ろう~

お決まり

こんにちは。
Advent Calendarも残すところ2日となりました。毎日色々なブログや投稿を見ているのがなくなるのは寂しい限りです。

CYBIRDエンジニア Advent Calendar24日目の新卒2年目のインフラ・ミドルウェアが主な担当の@gotyooooです。
すこーしコードも書いてます。

昨日は@umiyoshさんのドキュメント書くのを限界までラクにするでした。
僕個人的にもドキュメントを書くのがすごく苦手・・・。(というか好きになれない。本当に好きな人なんているのだろうか。)
とはいえやはり残すものは残していかないといけないので、こういった取り組みは素晴らしいですね。「エンジニアなら技術で楽にしてやれ！」という気持ちが伝わってきます。

本日の内容

今日はクリスマス・イブですね！
そんなときに起きてほしくないのは・・・そうサーバの障害。
「全体のレスポンスが遅い」「全くつながらない」「特定の処理だけできない」等現象は様々ですが、システムを動かす上で障害はつきものです。

「早く帰りたいのに帰れない。」そんな問題を少しでも早く解決するために、何かが起こった時のインフラ目線でのトラブルシューティング方法を列挙します。

前提

今回の確認するべきことはあくまで一例で、以下の様な構成が基準になっております。
特殊な環境・ミドルウェアが違う際は別のアプローチも必要になりますのでご注意ください。

• いわゆるLAMP環境(Linux(CentOS) + Apache + MySQL + PHPとか)
• サーバはわけている
• WEBサーバ(Apache)
• DBサーバ(MySQL)
• 監視をしている
• プロセス数
• CPU LoadAverage
• CPU Usage
• などなど
• 問題が起こっていることが通知されるようになっていること <- 重要

障害が起こる前にやるべきこと

• 監視を入れましょう！ZABBIXやらnagiosやらなんでもいいので！
• 重要なのは先述したとおり何かがあったことがわかるようになっていることです
• 更に過去ログも含めてグラフで負いたいですよね
• ソースのバグやダメな部分を直しましょう・・・当たり前ですが、一番重要です。
• スロークエリとかも潰しといていただけるとインフラエンジニアやDBエンジニアが喜びます。
• 前にPHPカンファレンスでスロークエリについて、SlowQueryとの戦いというタイトルで発表したのでこちらもご参考いただければと！

最初にやること(全サーバで確認すべき)

いきなり「ここだ！」と決めつけて次に進めるのは非常に危険です。
一旦落ち着いて広い視野で確認していきましょう。
ここですぐにボトルネックが分かれば儲けものです。

そしてこの部分はせめてでも監視ソフトウェア(ZABBIX,nagiosなど)で見れるようにしておくべきです。

全体の確認(topコマンド)

メモリの確認(freeコマンド)

メモリは使い切っていないか？SWAP使ったりしていないか？

# free -m
             total       used       free     shared    buffers     cached
Mem:          1877       1557        320          0        130        492
-/+ buffers/cache:        933        944
Swap:            0          0          0

プロセスの確認(psコマンド)

正常時に比べてプロセス数が増えたりしていないか？

# ps aux| wc -l
159

ディスクの確認(dfコマンド)

ディスク使い切っていないか？

# df -Th
Filesystem     Type   Size  Used Avail Use% Mounted on
/dev/sda1      ext4    15G  5.2G  8.9G  38% /
tmpfs          tmpfs  939M     0  939M   0% /dev/shm

※Tオプションをつけることでファイルシステムも確認します。

I/Oの確認(iostat)

I/O自体が問題になっていないか？

# iostat 1
Linux 2.6.32-431.el6.x86_64 (hoge) 	2014年12月23日 	_x86_64_	(32 CPU)

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           0.26    0.00    0.09    0.00    0.00   99.65

Device:            tps   Blk_read/s   Blk_wrtn/s   Blk_read   Blk_wrtn
sda               0.78         0.32        16.86    3424458  179631456
dm-0              2.09         0.20        16.69    2160354  177784512

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           0.22    0.00    0.06    0.00    0.00   99.72

Device:            tps   Blk_read/s   Blk_wrtn/s   Blk_read   Blk_wrtn
sda               1.00        16.00         0.00         16          0
dm-0              0.00         0.00         0.00          0          0

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           0.13    0.00    0.09    0.00    0.00   99.78

Device:            tps   Blk_read/s   Blk_wrtn/s   Blk_read   Blk_wrtn
sda               5.00         0.00        72.00          0         72
dm-0              9.00         0.00        72.00          0         72

ログの確認

変な[WARN]とか出てないか？

• syslog(/var/log/messages)

各ミドルウェアの状態を確認

Apache

Apacheが問題になる際は、経験則ですがメモリが問題になっていることが多いです。
子プロセスが立ち上がりすぎて、SWAPに乗っちゃった。なんて目も当てられません。

正常に動いているか?

まずはpsコマンドで見てみましょう。
この時に設定しているプロセス数の限界まで達していたら要注意です。

# ps aux| egrep 'httpd|USER'| grep -v grep
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
apache   21325  0.6  3.5 655632 68880 ?        S    17:46   0:27 /usr/sbin/httpd
apache   21326  0.9  3.5 649616 68084 ?        S    17:46   0:39 /usr/sbin/httpd
apache   21327  0.4  3.2 645300 62912 ?        S    17:46   0:17 /usr/sbin/httpd
apache   21328  0.6  2.9 646916 55812 ?        S    17:46   0:29 /usr/sbin/httpd
apache   24755  1.1  3.0 649480 57800 ?        S    18:24   0:22 /usr/sbin/httpd
apache   25161  0.7  3.1 654524 59936 ?        S    18:27   0:13 /usr/sbin/httpd
apache   25859  0.5  2.7 648124 53212 ?        S    18:34   0:08 /usr/sbin/httpd
root     27937  0.0  1.5 624836 29028 ?        Ss   Oct30   1:40 /usr/sbin/httpd

メモリどれぐらい使っているか？

• いちいち計算するのは面倒なので、以下の様なスクリプト流したりする。

check_apache_memory.sh

#!/bin/sh
MEMTOTAL=`grep 'MemTotal' /proc/meminfo | awk '{print $2}'`
UNIT=`grep 'MemTotal' /proc/meminfo | awk '{print $3}'`

PARENT_PID=`ps auxw | grep httpd | grep root | grep -v grep | awk '{print $2}'`
PARENT_MEM=`grep 'VmHWM' /proc/${PARENT_PID}/status | awk '{print $2}'`

PID=`ps auxw | grep httpd | grep -v root | awk '{print $2}'`
COUNT=0
CHILED_MEM_TOTAL=0
CHILED_MEM_TOTAL_NO_SHARE=0

echo -e "[apacheプロセスメモリ使用量]" 
echo -e "(親プロセス)" 
echo -e "PID\tMEM" 
echo -e "${PARENT_PID}\t${PARENT_MEM}${UNIT}" 
echo -e "(子プロセス)" 
echo -e "PID\tMEM\tSHARED\tPRIVATE" 
for pid in $PID
do
    #cat /proc/$pid/status | egrep '(^Pid:|VmHWM)'
    #メモリ使用量
    PMEM=`grep 'VmHWM' /proc/${pid}/status | awk '{print $2}'`
    #共有メモリ使用量
    SHARE_MEM=`awk 'BEGIN{shared=0;}/Shared/{shared+=$2;}END{printf("%d",shared);}' /proc/${pid}/smaps`
    #プライベートメモリ使用量
    PRIVATE_MEM=`expr $PMEM - $SHARE_MEM`
    #メモリ合計計算
    CHILED_MEM_TOTAL=`expr $CHILED_MEM_TOTAL + $PMEM`
    CHILED_MEM_TOTAL_NO_SHARE=`expr $CHILED_MEM_TOTAL_NO_SHARE + $PRIVATE_MEM`

    #カウントアップ
    COUNT=`expr $COUNT + 1`
    echo -e "${pid}\t${PMEM}${UNIT}\t${SHARE_MEM}${UNIT}\t${PRIVATE_MEM}${UNIT}" 
done

#平均値計算
CHILED_MEM_AVE=`expr $CHILED_MEM_TOTAL / $COUNT`
CHILED_MEM_AVE_NO_SHARE=`expr $CHILED_MEM_TOTAL_NO_SHARE / $COUNT`

echo -e "子プロセス数 \t\t\t: ${COUNT}" 
echo -e "子プロセスメモリ使用量合計 \t: ${CHILED_MEM_TOTAL} ${UNIT}" 
echo -e "子プロセスメモリ使用量平均 \t: ${CHILED_MEM_AVE} ${UNIT}" 
echo -e "子プロセスメモリ使用量合計(共有除く) \t: ${CHILED_MEM_TOTAL_NO_SHARE} ${UNIT}" 
echo -e "子プロセスメモリ使用量平均(共有除く) \t: ${CHILED_MEM_AVE_NO_SHARE} ${UNIT}" 

echo "==============================================================" 
USE_MEM=`expr $PARENT_MEM + $CHILED_MEM_TOTAL_NO_SHARE`
echo -e "apacheメモリ使用量 \t: ${USE_MEM} ${UNIT}" 
echo -e "総メモリ量 \t\t: ${MEMTOTAL} ${UNIT}" 

# ./check_apache_memory.sh
[apacheプロセスメモリ使用量]
(親プロセス)
PID MEM
23190   22144kB
(子プロセス)
PID MEM SHARED  PRIVATE
23193   46056kB 24568kB 21488kB
23194   33976kB 22948kB 11028kB
23195   34512kB 23816kB 10696kB
23196   34196kB 23012kB 11184kB
23197   37972kB 23576kB 14396kB
23198   33844kB 23768kB 10076kB
23199   34352kB 23192kB 11160kB
23200   39264kB 25076kB 14188kB
子プロセス数          : 8
子プロセスメモリ使用量合計   : 294172 kB
子プロセスメモリ使用量平均   : 36771 kB
子プロセスメモリ使用量合計(共有除く)     : 104216 kB
子プロセスメモリ使用量平均(共有除く)     : 13027 kB
==============================================================
apacheメモリ使用量    : 126360 kB
総メモリ量       : 1695216 kB

MySQL

ボトルネックがDBというのはよくあることです。
「スロークエリーがーーー」とか言う前にまずは以下を行いましょう。

なにはともあれプロセス(SHOW PROCESSLIST)

とはいえmysqlプロセスはLinux上だと1つです。
何を見るか？そうMySQL内のプロセスです。

mysql> SHOW FULL PROCESSLIST\G;
*************************** 1. row ***************************
     Id: 38119130
   User: repl
   Host: hoge-repl:46627
     db: NULL
Command: Binlog Dump
   Time: 10183054
  State: Master has sent all binlog to slave; waiting for binlog to be updated
   Info: NULL
*************************** 2. row ***************************
     Id: 516189030
   User: hoge_mon
   Host: localhost:51016
     db: NULL
Command: Sleep
   Time: 2
  State:
   Info: NULL

(略)

*************************** 12. row ***************************
     Id: 2181215594
   User: hoge
   Host: hoge-web1:48547
     db: HOGEDB
Command: Sleep
   Time: 0
  State:
   Info: NULL
12 rows in set (0.00 sec)

特に中止すべきがTimeとStateです。
レプリケーションや監視のユーザによるアクセスなどは無視です。(こういう時のためにユーザわけはやっておいたほうが絶対イイです。)
やたらとTimeが長いまま,[SendingData]など[Sleep]以外のStateになっているプロセスはSQLが問題になっていることが多いです。

※ちなみにFULLがつかないと表示時にSQLが100文字で省略されます。

もし問題のあるクエリがあった時(EXPLAIN , DESC, SHOW INDEX)

問題がクエリにあった時は以下3つを確認しましょう。

mysql> explain select a,b from abc;

SQLの実行計画を確認します。
※細かい見方は有名ブログ「漢のコンピュータ道」のこちらの記事が大変わかり易いので、一度読んだほうがいいです。

mysql> desc abc;

テーブル情報を確認します。

mysql> show index from abc;

Index情報を確認します。

まとめ

色々つらつらと書いてきましたが、今回の記事ははっきり言ってヒントでしかありません。障害と一括りにしようとするほうが間違いです。しかも起きた時には複数の原因が重なっていたりもします。
まずは上記のようなことを使って一時対応を始められれば、なにかしら解決の糸口が見つかるはずです。

某クラウド業者の障害に驚く。

— ごちょー (@gotyoooo) 2014, 1月 29

障害といえどサービスのせいだけではなかったりするのでｗ
某CDNサービスとか。

最後に

CYBIRD エンジニア Advent Calendar 25日目のトリを務めるのは、このAdventCalenderの言い出しっぺでもあり、私の尊敬する先輩である@dekokunさんの「宣言すればコンピューターがいい感じに解決してくれる未来を目指して~理想の世界と現実の壁~」です！コンピュータが得意なことは全てやらせろ的な考えですね。私もそれを目指してます。
お楽しみに！！！！