GAE/GCEのログ監視 & GAE/GCEのエラーログをCloud Logging -> Cloud Pub/Sub からの GASでSlackへ流す

この記事はGoogle Cloud Platform Advent Calendar 2015 10日目に投稿する予定だったのですが筆者が胃腸炎になり書くことができず投稿が遅れてしまった記事です。
楽しみにされてた方申し訳ございませんでした。。。。


システムを運用しているとログってとても重要ですね。
ただエラーログを検知して、問題があるシステムのログを閲覧可能な場所にアクセスし、そのログを特定するのは結構面倒だったりします。
GAEでもLogs Viewerがありますが、そこまでパフォーマンスも良くはなく、わざわざDeveloperコンソールに入ってエラーログを探すのは面倒だったりします。

そこで今回は Cloud Logging(GAEのLog) -> Cloud Pub/Sub -> GAS -> Slackという経路でエラーログをSlackに流す仕組みを紹介したいと思います。

# その前にCloud PlatformにおけるCloud Monitoringを利用したログ監視とその問題点

今回のものを紹介する前に、ログ監視という観点だけで言えば、
このような仕組みを使わずともCloud Monitoringのみでログ監視及びエラー通知ができます。
先に書いておくとこのエラー通知には詳細を通知できないという問題があり、少し片手落ち感が否めません。
そのため、今回の記事の主題の方を行っています。

ただ設定自体はこのCloud Monitoringの方法のほうが簡単なのでやり方自体は紹介したいと思います。

知ってる方は読み飛ばして下さい。

## 手順

おおまかに3段階で設定できます。

1. ログのフィルタ条件の作成
2. ログベース指標の作成
3. ログベース指標を元にしたアラートを作成


## 1. ログのフィルタ条件の作成

Logs Viewerを表示して適当な検索条件を作成します。
個人的には細かく条件を指定する場合は高度なフィルタを使うことをおすすめします。

![image](https://qiita-image-store.s3.amazonaws.com/0/2965/24290630-6998-32c5-edc0-6eb2f4cb2e39.png)

例えば「GAE上で発生するログレベルエラー以上のログを表示(`_ah/`へのリクエストは除く)」という条件だったら以下の様なフィルタになります。

```
metadata.serviceName="appengine.googleapis.com"
log="appengine.googleapis.com/request_log"
metadata.severity>=ERROR
protoPayload.resource!="_ah/"
```
Ctrl + Spaceで補完も効くので便利です。

## 2.  ログベース指標を作成

Cloud Monitoringで閾値を取得するために、「ログベース指標」を作成します。
Logs Viewer上の右はじにあるグラフっぽいボタンを押します。
そして名前入力欄が表示されるので適当な名前を入力して保存します。

![image](https://qiita-image-store.s3.amazonaws.com/0/2965/eb8f0755-2d20-e31b-2201-8bc5d6c203a0.png)


## 3. ログベース指標を元にしたアラートを作成

次にCloud Monitoringの設定を行います。
そのままLogs Viewer上の指標タブをクリックし、先ほど作成した指標探します。
作成した指標のメニューから「指標に基づいて通知を作成する」をクリックします。

![image](https://qiita-image-store.s3.amazonaws.com/0/2965/3c3facf2-caff-bcf5-c369-102e3915eaeb.png)

するとCloud Monitoringのアラート作成画面へ遷移するので設定を行います。
設定するのは「名前」と「閾値(THRESHOLD)」と「間隔」と「通知先」です。

![image](https://qiita-image-store.s3.amazonaws.com/0/2965/c46d7df2-feaa-e39b-31e1-8ba4ea0e62ec.png)


「**名前**」は適当に設定して下さい。
「**閾値**」は**1秒間**で何回このログが出力されるかを設定します。
「**間隔**」はこの状態がどれだけの時間継続したかを設定します。

つまり **閾値**に1、**間隔**に5 minutesを設定した場合「対象のログが **毎秒1回** 出力される状態が **5分間続く**とこのアラートが発生」という条件になります。

...
...
...
...

＼(^o^)／

ということでそんなにエラーログ出るわけ無いですね。
なので**閾値**を1以下にする必要があります。

では1以下にしてみましょう。

![image](https://qiita-image-store.s3.amazonaws.com/0/2965/e2807bee-b1b7-deb8-53dd-d042df283db6.png)

...
...
...
...

＼(^o^)／

エ、、、エラー？
実はエラーの様に見えますが、エラーではありません。
保存できるのです。
なので大体 **0.02** ぐらいにしておいて、**間隔**を**1 minutes**ぐらいにしてくと、対象のログが発生するごとにアラートが出せます。
設定が終わったら下にある、「Save Condition」ボタンを押下して下さい。


次に通知先を設定します。
好きなところを通知先に設定すればいいと思いますが、大抵どの通知先も先に設定が必要なので注意して下さい。
今回はSlackにしておきます。

![image](https://qiita-image-store.s3.amazonaws.com/0/2965/71ea9026-4e62-79c9-f75a-4ad2de4c6c8e.png)

## 実際の通知

では実際にエラーを発生させて通知を見てみましょう。

![image](https://qiita-image-store.s3.amazonaws.com/0/2965/9ae19a5b-4401-71f7-253a-c636da8f3931.png)

お。。。おぅ。。。。
全くどんなエラーが起きたかわかりませんね。
なんかリンクがあるので見てみましょう。

![image](https://qiita-image-store.s3.amazonaws.com/0/2965/678b521c-4750-ef7e-e9d7-043ea16d8ac4.png)

エラーログはどこ。。。。

## Cloud Monitoringのエラー通知の問題点

見ていただいたようにちょっとエラーログの監視と通知の意味合いではCloud Monitoringは正直向いているとは言いづらい状態です。
もちろんシステムに何かが起きていることをいち早く察知する仕組みとしてはありなのですが、
片手落ち感があります。

もともと筆者が運用しているシステムではこのCloud Monitoringによるエラーログ検知を使っていました(まだ使っている)が、
エラーが発生した際、結局どんなエラーがおきているのかLogs Viewerの中から探すという面倒くさい作業をする必要があり、
寝る直前に携帯でやるにはただただ辛い作業だったのが記憶的です。

# Cloud Logging(GAEのLog) -> Cloud Pub/Sub -> GAS -> Slack

超長い前話を書いて、本題です。
上記のCloud Monitoringの通知問題を解決するためにちゃんとしたエラーログをSlackに投げられる仕組みを作ることにしました。

そこで使えるのがCloud Pub/Subです。
もともとGAE LogはCloud Loggingの一部でありCloud LoggingはCloud Pub/SubへのExport機能をもっています。
Cloud Pub/Subにさえ流れればあとは適当なSubscriber(購読者)を用意して、ログを取得・フィルタリング・任意の場所へ通知という段取りが可能になります。

## 用意するもの

* Service Account(json keyを取得しておく)
    * QiitaでService Accountとか調べれば出るともう
* SlackのAPIトークン
    * http://qiita.com/soundTricker/items/43267609a870fc9c7453 のどっかに書いてる

## 手順

以下の流れになります。

1. ログのCloud Pub/SubへのExport設定
2. Cloud Pub/SubにSubscriberを登録
3. GASのコード書く
    1. ライブラリ読み込む
    2. コード書く
4. トリガー登録
 
## 1. ログのCloud Pub/SubへのExport設定

まずログをPub/SubにExportします。
Logs Viewerの「エクスポート」タブをクリックして、エクスポート画面を表示します。
**サービス**に**App Engine**、エクスポート先の「Pub/Subトピックに公開します」にて任意の名前のトピックを作成し選択、保存します。

![image](https://qiita-image-store.s3.amazonaws.com/0/2965/2690ca9b-953e-4050-616c-c3879f3a3d87.png)

## 2. Cloud Pub/SubにSubscriberを登録

次に左メニューからCloud Pub/Subの画面に遷移して、作成したTopicを開き、「新しい登録」ボタンをクリックします。

![image](https://qiita-image-store.s3.amazonaws.com/0/2965/d84d2b37-972c-75d6-6fdf-efa38f66ead3.png)

**登録名**に適当な名前を入力し、**配信タイプ**にプルを選択します。

![image](https://qiita-image-store.s3.amazonaws.com/0/2965/5b193310-8ccf-5efe-23a8-28792b0b0be5.png)

通常Cloud Pub/SubだとCloud Pub/Sub側が設定したURLに対して自動的にPushしてくれるPush送信を利用することが多いのですが、
この際このURLは Google Search Console上でドメイン確認されたURLが必要になり、かつそのURLをDeveloper Console上で登録する必要があります。

GASを利用した場合でも公開URLに対して、上記を行ってPush送信したいところですが、
Search Consoleへの登録は方法があるのですが、現状Developer Consoleへの登録がDeveloper Console側にバグが有りうまく行えません(大文字がURLに含まれると小文字化されてしまう問題)

このため2015/12/15時点ではGASから利用する場合はSubscriber自らがコンテンツを取得しに行くPull配信を利用する必要があります。

## 3. GASのコード書く

次にGASのコードを書いていきます。

### 3. 1. ライブラリ読み込む

まず幾つかのライブラリを読み込みます。

1. GSApp
    * `MJ5317VIFJyKpi9HCkXOfS0MLm9v2IJHf`
    * GASでService Accountを読み込むためのライブラリです。
2. PubSubApp
    * `Mk1rOXBN8cJD6nl0qc9x5ukMLm9v2IJHf`
    * GASでCloud Pub/Subにアクセスするためのライブラリです。
3. Moment
    * `MHMchiX6c1bwSqGM1PZiW_PxhMjh3Sh48`
    * 言わずと知れたJS向け日付操作ライブラリです。 日付の整形で利用しています。
4. SlackApp
    * `M3W5Ut3Q39AaIwLquryEPMwV62A3znfOO`
    * Slack APIとやり取りするためのライブラリです。
    * http://qiita.com/soundTricker/items/43267609a870fc9c7453

### 3. 2. コード書く

コードを書く前にService AccountをScript Propertyとして`jsonKey`というKey名で登録しておいて下さい。
またslackのAPI Tokenも `slackToken`という名前でScript Propertyとして登録しておいて下さい。
そして以下のコードをコピペして一番上の設定値を修正します。
※ ~~めんど~~ GASのアドベントカレンダーじゃないので細かい解説はしません....

```js:コード.gs
var CHECK_SEVERITY = ["ERROR", "CRITICAL", "ALERT", "EMERGENCY"];

// 設定値
var monitoringSets = [
  {
    projectId: "Pub/Subの設定をしたProjectID",
    subscriptionId: "Subscriber登録した時に設定した名称(project/{projectId}/subscription/より後ろ側)",
    channelId: "送信先Slackチャネル名"
}];

var moment = Moment.load();

function everyMinutes() {
  for(var i = 0; i < monitoringSets.length; i++) {
    try {
      doProcess(monitoringSets[i]);
    } catch(e) {
      e.message += " " + JSON.stringify(monitoringSets[i]);
      throw new Error(e)
    }
  }
}


function doProcess(monitorData){
  
  var slackApp = SlackApp.create(PropertiesService.getScriptProperties().getProperty("slackToken"))
  
  PubSubApp.setTokenService(getTokenService());
  subscriptionApp = PubSubApp.SubscriptionApp(monitorData.projectId);
  subscription = subscriptionApp.getSubscription(monitorData.subscriptionId);
  
  
  
  
  var pubsubMessages = subscription.pull(1, true);
  
  
  while(pubsubMessages.length > 0) {
  
    pubsubMessages.forEach(function(pubsubMessage){
      
      var logData = JSON.parse(Utilities.newBlob(Utilities.base64Decode(pubsubMessage.data)).getDataAsString());
      
      var severity = logData.severity;
      
      if(!severity && logData.metadata) {
        severity = logData.metadata.severity;
      }
      if(!severity || CHECK_SEVERITY.indexOf(severity) < 0) {
        Logger.log("not severity message \n" + JSON.stringify(logData));
        return;
      }
      
      if(!logData.httpRequest || logData.httpRequest.status < 500) {
        Logger.log("not httpRequest message \n" + JSON.stringify(logData));
        return;
      }
      
      if(!logData.protoPayload) {
        Logger.log("not protoPayload message \n" + JSON.stringify(logData));
        return;
      }
      
      var headMessage = Utilities.formatString("[%s][%s][%s][Status:%s] `%s` `%s`\n See Detail:https://console.developers.google.com/logs?project=%s&service=appengine.googleapis.com&key1=&key2=&logName=appengine.googleapis.com%2Frequest_log&minLogLevel=0&expandAll=false&timezone=Asia%2FTokyo&filters=request_id:%s\n",
                                               monitorData.projectId, 
                                               moment(logData.protoPayload.endTime).format("YYYY/MM/DD HH:mm:SS"),
                                               severity,
                                               logData.httpRequest.status,
                                               logData.protoPayload.method,
                                               logData.protoPayload.resource,
                                               monitorData.projectId,
                                               logData.protoPayload.requestId
                                              );
      
      var message = headMessage + logData.protoPayload.line.map(function(line){
        return Utilities.formatString("```\n[%s][%s] %s\n```", moment(line.time).format("YYYY/MM/DD HH:mm:SS"), line.severity, line.logMessage);
      }).join("\n");
      
      slackApp.postMessage(monitorData.channelId, message);
    });
    
    
    pubsubMessages = subscription.pull(500, true);
  }
  
}

function getTokenService(){
  
  var jsonKey = JSON.parse(PropertiesService.getScriptProperties().getProperty("jsonKey"));
  var privateKey = jsonKey.private_key;
  var serviceAccountEmail = jsonKey.client_email;
  var sa = GSApp.init(privateKey, ['https://www.googleapis.com/auth/pubsub'], serviceAccountEmail);
  sa.addUser(serviceAccountEmail).requestToken();
  return sa.tokenService(serviceAccountEmail);
}


```

## 4. トリガー登録

そして上の`everyMinutes`メソッドを1分間に1回動くようにトリガー登録します。

## 通知

では実際の通知を見てみましょう

![image](https://qiita-image-store.s3.amazonaws.com/0/2965/67549ab4-502a-9d38-9228-0b9b2f349dbd.png)

見やすいですね
しかもエラーのログだけでなく前後のログもすべて表示され、ほぼこのログだけ見ればOKな状態になりますね。

# まとめ

いかがでしたでしょうか?
今回はGASで作成しましたが、少々問題もあって、あまりにもログ量が多いとエラーを起こすことがあります。
なのでログ量が多いようであればSubscriberをGAEで実施したほうがよいかもしれません。