クラウドワークス エンジニアブログ

日本最大級のクラウドソーシング「クラウドワークス」の開発の裏側をお届けするエンジニアブログ

ログ解析初心者に贈る便利なコマンドの使い方

f:id:Tomato-360:20160809192528p:plain

好きなMH(今はGTM?)はヴァイオラの那須(@nasum)です(アイスブレーク)。レッドミラージュも捨てがたいですが、ヴァイオラが一番好きですね。ちなみに好きなファティマは京です。

Webサービスを運営している以上、避けて通れないのがログ解析です。このログ解析あまり経験がないと何をどう始めたらいいのかよくわからないと思います。私自身今までログ解析の仕事をしたことがなかったので、わからない状態が続いているという危機感がありました。

そこで最近はできるだけ率先してログ解析の仕事があればそれをやるようにしてコマンド力を鍛えています。今回は教えていただいたり自分で調べたりして得られたログ解析するときに使うコマンドの使い方を紹介したいと思います。

以下簡単にログ解析の流れとともにコマンドを紹介します。やっていることは「ログに記録されたファイルサイズを合計して1日に配信される特定の条件を満たした応答のサイズを調べる」ということをやっていきます。

headでまずは中身を見る

まずログの中身がどうなっているかを知らなければ調べることはできません。そのために head コマンドを使ってログファイルの先頭数行を出力し内容を確認します。今回は -n オプションを利用して1行のみ出力してみます。

[masaya]$ head -n 1 access.log.1
2016-08-04T02:48:11+09:00    access.log.1    {"method":"GET","path":"/public/","code":"200","size":"16978","agent":"Mozilla/5.0 (Windows NT 10.0; WOW64; Trident/7.0; rv:11.0) like Gecko","response_time":"1.234","forwarded_to":"","http_x_forwarded_proto":"https","@timestamp":"2016-08-04T02:48:11+0900"}

これで対象となるログの構造がわかりました。

cutで必要な部分のみ取り出す

先ほどのログを見てみるとはじめに日付、タブで区切られてファイル名、更にタブで区切られてJSON形式のログのようになっています。必要なのはJSON形式のログのみなので他の情報はとりあえず捨てておきたいところです。そこで使えるのは cut コマンドです。

cut コマンドはタブ区切りの文字列をパースし、パースしたものから表示するフィールドを選択することができます。フィールドは -f オプションで選択します。例えば3つ目のフィールドを指定したいときは -f3 と指定します。

またファイルの形式はタブ区切りである必要はなく、区切り文字を-d オプションで指定して cut することもできます。例えば,区切りの場合は-d,と指定します。出力されるログに合わせて選択すると良いと思います。

今回は3つ目のフィールドにJSON形式のログがあるため以下の様なコマンドでJSONのみを出力します。先ほど出した結果をパイプで渡して cut してみます。

[masaya]$ head -n 1 access.log.1 | cut -f3
{"method":"GET","path":"/public/","code":"200","size":"16978","agent":"Mozilla/5.0 (Windows NT 10.0; WOW64; Trident/7.0; rv:11.0) like Gecko","response_time":"1.234","forwarded_to":"","http_x_forwarded_proto":"https","@timestamp":"2016-08-04T02:48:11+0900"}

解析したいJSON形式のログのみを取得することができました。

jqでJSONをパースする

さて、ログを取得することができたので中身を見ていきたいと思います。ですがこのままでは1行にまとめられてしまいとても見づらいです。いくら黒い画面に慣れている人だとしても、目を皿のようにしてログを見るのは避けたいところです。

そこで使えるのがJSONを扱うのに特化した jq というコマンドです。

https://stedolan.github.io/jq/

このコマンドは標準でインストールされているわけではないので、各環境に合わせてインストールする必要があります。Macでは、

brew install jq

ですぐ入れることができます。

jq にJSON形式のテキストをパイプで渡すと、見やすく整形して表示してくれます。先ほどのコマンドの結果をパイプで渡して表示してみます。

[masaya]$ head -n 1 access.log.1 | cut -f3 | jq
{
  "method": "GET",
  "path": "/public/",
  "code": "200",
  "size": "16978",
  "agent": "Mozilla/5.0 (Windows NT 10.0; WOW64; Trident/7.0; rv:11.0) like Gecko",
  "response_time": "1.234",
  "forwarded_to": "",
  "http_x_forwarded_proto": "https",
  "@timestamp": "2016-08-04T02:48:11+0900"
}

だいぶ見やすく整形されました。今回はファイルサイズが必要なので size のあたりが使えそうです。jq コマンドは指定したキーの値を取得するには .キー名 で可能です。今回は size を取得したいので以下の様なコマンドで size の値を取得できます。

[masaya]$ head -n 1 access.log.1 | cut -f3 | jq .size
"16978"

ダブルクォーテーションで囲われた数値が得られました。ここで出力されたのは文字列です。あとで出力した一覧を足し合わせるとき、文字列だと困りますね。 jq コマンドは多機能で渡す引数内でパイプを使って処理を拡張できます。得られた文字列の数字を数値に変えるコマンドは以下のようになります。

[masaya]$ head -n 1 access.log.1 | cut -f3 | jq '.size | tonumber'
16978

数値として値を取り出すことができました。 jqコマンドは多機能で sort したり grep したりもできます。詳しくはマニュアルを見るといろいろ書いてあるので読んでみることをおすすめします。

https://stedolan.github.io/jq/manual/

jq については以下のブログ記事も役に立つので英語が苦手な方は以下の記事から参考にするのも良いです。

dev.classmethod.jp

さて、必要な情報が得られました。あとは全ログに対して上記のコマンドを入力することでファイルサイズの一覧は取得できそうです。

awkで操作する

先ほどのコマンドでファイルサイズの一覧は取得できそうですが、合計値を得るにはあともう一歩といったところ。何も考えずにやろうとすれば得られた一覧をExcelに貼り付けて=sum(A:A)としてしまいがちです。そうするのも悪くはないのですが、せっかくなのでコマンドですべてやっつけてしまいたいところです。そこで使えるのはテキストを整形する awk コマンドです。

awk コマンドはスペースで区切られたテキストを扱うのに便利です。簡単な例を以下に書きます

[masaya]$ echo 'hello world' | awk '{print $1}'
hello

これは「hello world」という文字列を受け取った awk コマンドが 一つ目の文字列を示す $1print で出力しています。awk コマンドは機能も多く説明しきれないので、ここでは割愛させていただきます。

さて、今回は数値を受け取ってそれを足し合わせる awk コマンドでファイルの大きさの合計を得てみたいと思います。

[masaya]$ head access.log.1 | cut -f3 | jq '.size | tonumber' | awk '{sum+=$1}END{print sum}'
338508

awk '{sum+=$1}END{print sum}'{sum+=$1}で変数sumに入力した数値を足しあわせていき、最後に END{print sum} で出力しています。

これでhead コマンドで得られた数行のログから、ファイルサイズのみを足しあわせ結果を出力できるようになりました。

1日分のログを集計する

コマンドの組み合わせで必要なことはできました。あとは対象となるログファイルをlsgrepを使って取得し、それを先ほど作ったコマンドのワンライナーに渡して集計します。

[masaya]$ ls | grep access.log | xargs cut -f3 | jq '.size | tonumber' | awk '{sum+=$1}END{print sum}'
707604845804

合計 707GB という結果が得られました。

これで1日分のログから配信されているファイルサイズの合計を求めることができました。いえい。

終わり

以上、コマンドを利用してログファイルから必要な情報を抜き出し、整形して表示する流れを紹介してみました。 head して cut して jq という流れを基本にしていろいろ組み合わせるともっと面白いことができるようになると思います。

効率が悪い!そのやり方は危険だ!等の意見は多々あると思いますが、ブクマのコメント等で教えていただけると勉強になるのでよろしくお願いします(露骨なブクマ稼ぎ)

今回のようなログの調査はElasticsearch+Kibanaのようなツールを用いて行うことも可能です。しかしツールだけではうまく解析できないということは往々にしてあります。基本的なコマンドを組み合わせることで柔軟にログ解析を行うことができるので、コマンドの知識や組み合わせる力は必要になると思います。日々の業務を柔軟に行えるスキルとして是非習得しておきましょう。

あと、注意して欲しいのはこれらのコマンドをログ集積サーバーで直にやらないようにするということ。いきなりCPUが100%に張り付きっぱなしになって少しどよめきます。できるだけログファイルは解析のための専用環境でやることをおすすめします。。

We're Hiring !

クラウドソーシングのクラウドワークスでは、黒い画面でコマンドを打つのが得意なエンジニアとFSSが好きなエンジニアを募集しています。

www.wantedly.com

crowdworks.co.jp

© 2016 CrowdWorks, Inc., All rights reserved.