ドーモ、親愛なる読者のみなさん。うんようチームです。
というアイサツをしたいがために、ブログ書きます！と名乗り出てしまった運用本部の湯谷（@yutannihilation）です。今回は、R Advent Calendar 2014 9日目の記事として、Webサーバのレスポンスタイムをざっくり可視化する方法を紹介します。
使うもの
R
Rは、統計解析に特化したプログラミング言語です。
サイボウズ社内にも、手元でデータを解析するツールとしてRを活用している人が多くいます。部署横断の社内勉強会が毎週開催されていて、Rや統計の情報交換やデータ分析の悩み相談をしています。
今回は、世のデータサイエンティストが駆使していそうな華々しい統計手法とは無縁の、地味にグラフを描くだけの話です。統計とか機械学習っぽい話は、いずれ知る人ぞ知る中谷さんが書いてくれるのではないかと勝手に期待しています。
ggplot2
ggplot2は、R界のスターHadley Wickhamさんが作った、いい感じのグラフを簡単に作成できるパッケージです。ggplot2がいかにすばらしいかは...書き始めると長くなりそうなので涙をのんで省略します！
さて、ツールの話はこれくらいにして、実際に使う場面を見ていきたいと思います。
使う場面
「なんか遅くない？」
サイボウズ社内の業務には、自社クラウドサービス cybozu.comの開発版が使われています。開発版なので、たまにパフォーマンス劣化が起こっていることもあります。そんなときは、
「なんか遅くない？」
というつぶやきが増え始めます。この社内のざわめきを受けて運用チームは調査を始めるわけですが、原因がアプリケーションのバグやインフラの不具合かはまだわかりません。
- 社内ネットワークに問題がある
- その人のPCに問題がある
- 気のせい
といった可能性もあります。さあ、この「遅さ」を可視化しましょう！
可視化してみる
「遅さ」を視るために何をするかというと、Webサーバのレスポンスタイムの分布をグラフに描きます。この分布を前の週の分布と比べて、実際に遅くなっているかを調べます。
例
ここでは例として、先日開催されていた社内ハッカソンの日をみてみます。参加者は自社製品を魔改造しようとアクセスしまくっていたという噂です。この無遠慮なアクセス増がパフォーマンスに影響を与えていたのか、白日の下に晒してみたいと思います！
1. データの読み込み
（まず、Webサーバのアクセスログにレスポンスタイムを出すようにしておく必要があります。たとえばApacheであれば、LogFormatに%Dを入れておきましょう）
ここでは、レスポンスタイムだけ抜き出してresponse_thisweek.txt、response_lastweek.txtに保存してあるとします。データを読み込む際は、data.frameでないとggplot2で扱いづらいのでdata.frameにします。
response_thisweek <- read.table("response_thisweek.txt", col.names = "response")
response_thisweek$day <- "this week"
response_lastweek <- read.table("response_lastweek.txt", col.names = "response")
response_lastweek$day <- "last week"
data <- rbind(response_thisweek, response_lastweek)
2. ヒストグラムを描く
まず、ヒストグラムを描いてみます。
ggplot2は、基本的には以下のような文法になります。
ggplot(データ, aes(変数の対応)) + geom_グラフの種類() + その他のオプション...
ヒストグラムはgeom_histogram()を使います。標準だと積み上げになっていますが、ここでは今週と先週のデータを重ね合わせたいのでposition="identity"を指定します。また、重ね合わせてたときどちらも見えるように透過度alphaに1以下の値を設定します。
レスポンスタイムは、数十マイクロ秒のものから数秒かかるものまで幅広いので、横軸は対数軸にします。対数軸にするにはscale_x_log10()を使います。
library(ggplot2)
ggplot(data, aes(x = response, colour = day, fill = day)) +
geom_histogram(position = "identity", alpha = 0.4) +
scale_x_log10()
これを実行すると、以下のグラフになりました（軸の目盛りは表示しない設定を付け加えています）。横軸がレスポンスタイムで、右に行くほど処理に時間がかかったことを表しています。縦軸はアクセスの数です。
むむ、これは...
たしかに先週と比べてアクセスが多いです。しかし、レスポンスタイム分布の形状は割と似ている感じがします。アクセスが多いだけでパフォーマンスには影響が出ていないのかもしれません。そこで次に、アクセス数の差を除外して見てみます。
3. 確率密度曲線を描く
アクセス数の差を除外するには、それぞれアクセス数合計で割って正規化するのもいいですが、ここではgeom_density()を使います。geom_density()はカーネル密度推定によって推定した確率密度の曲線を描いてくれます。また、ヒストグラムでは分からなかった細かな分布パターンが見えることもあります。
コードは以下のようになります。上のgeom_histogram()をgeom_density()に変えるだけです。
ggplot(data, aes(x = response, colour = day, fill = day)) +
geom_density(position = "identity", alpha = 0.4) +
scale_x_log10()
これを実行すると、以下のようなグラフができます。
ピークの2つの山の形が少し違います。 レスポンスタイムが遅いほうに少し流れているように見えます。
これは...
4. もう少しよく考えてみる
というと、なんとなく影響ありそうな感じがしますよね。でも、これは「A秒で済んでいたものがB秒かかるようになった」ということではなく、 「B秒かかるリクエストが増えた」というだけだと思われます。総リクエスト数が多くなっているので、確率密度関数で見るとAが減ったように錯覚してしまいます。
もし仮にハッカソンによる負荷が全体のパフォーマンスに影響を与えているとすると、全体的に遅くなるのでグラフは以下のような形状になるはずです。今回は、ピーク部分以外の分布はほとんど変化がありません。
可視化すると、勘違いもしやすくなります。いくつもグラフを描いてみて落ち着いて考えるのが大事です。
まとめ
ということで、ハッカソン参加者による無慈悲なアクセスにもcybozu.comはびくともしなかったようだ、ということがざっくり分かりました。普通はここから、じゃあ遅かったとしたら社内ネットワークのせいとか？といった仮説を立ててさらに調査が始まるわけですが、今回の記事はここまでです。
今回やったように、Rは手元でデータをいじりながら調査を進める時にとても便利なツールです。Twitter社の例のように、インフラエンジニアがRを使う事例も増えてきています。この記事を読んで「Rちょっと興味出てきたかも…」という方が少しでもいれば幸いです。ぜひぜひ、R Advent Calendar 2014の他の記事も読んでみてください！
