Azure Functions のログを見てみる

Azure Functions で吐かれるログはポータルからリアルタイムに見ることが出来ますね。 これはこれで開発時に嬉しいのですが、じゃぁ運用時に障害発生したときに見るログとかはどうすればいいの？と思ってみてみました。

最初はApp Serviceのログの仕組みが使えるのかと思ってたのですが…

docs.microsoft.com

なんだか、これを有効化してもBlobにログが出てないように見えました。ということで、結局Functionsのログはどこに出てるの！？と探してみるとStorageアカウントのTableに吐き出されてました。

ドキュメントの何処に書いてあるんだろう… まだ、WebJobのドキュメントとかちゃんと見てないんだけど、そこらへんかしら？まぁ後で確認しないとだな…。

ということで、こんな感じのテーブルが出来ます。

名前的に月単位で作られるのかな？ 中身を見てみるとこんな感じになってます。

ログレベル

error, warn, info, verboseがあります。 それぞれのレベルのログを出すには、以下のようにnode.jsだとcontext.logを呼び出します。

module.exports = function (context, req) {
    context.log.verbose(context.invocationId, ': verbose');
    context.log.info(context.invocationId, ': info');
    context.log.warn(context.invocationId, ': warn');
    context.log.error(context.invocationId, ': error');
    context.res = {
        status: 200,
        body: "invoked"
    };
    context.done();
};

ログ系メソッドは、引数を複数渡すと連結して出してくれるので便利ですね。あとinvocationIdは、関数の呼び出しごとに割り当てられる一位なIDがとれるっぽいので参考に出してます。

この関数をたたくとこんな感じにポータルのログ出力に出てきました。

2017-08-20T08:04:42.298 Function started (Id=c10fdebd-0c7f-4514-a39a-e7420edece7e)
2017-08-20T08:04:42.313 c10fdebd-0c7f-4514-a39a-e7420edece7e : verbose
2017-08-20T08:04:42.313 c10fdebd-0c7f-4514-a39a-e7420edece7e : info
2017-08-20T08:04:42.313 c10fdebd-0c7f-4514-a39a-e7420edece7e : warn
2017-08-20T08:04:42.345 c10fdebd-0c7f-4514-a39a-e7420edece7e : error
2017-08-20T08:04:42.345 Function completed (Success, Id=c10fdebd-0c7f-4514-a39a-e7420edece7e, Duration=43ms)

テーブルのほうにはPartitionKeyがIでRowKeyが、context.invocationIdの値みたいな感じで出るみたいです。

これのLogOutputプロパティを見ると結果が格納されていました。

bd949c0d-f32b-4fad-99af-32e8c096df00 : verbose
bd949c0d-f32b-4fad-99af-32e8c096df00 : info
bd949c0d-f32b-4fad-99af-32e8c096df00 : warn
bd949c0d-f32b-4fad-99af-32e8c096df00 : error

ここで気になるのはエンテティの最大サイズが1MBだという点です。

エンティティ:エンティティは、プロパティのセットで、データベースの行に似ています。 エンティティの最大サイズは 1 MB です。

docs.microsoft.com

まぁ1MBを超えるようなログを出すほど大きな関数は無いだろうということなんでしょうね？

ということで、こんな関数を作ってみました。

module.exports = function (context, req) {
    for (var i = 0; i < 1024 * 1024; i++) {
        context.log('index: ', i,' - 01234567890');
    }
    context.res = {
        status: 200,
        body: "OK"
    };
    context.done();
};

多分、1MB超えると思います！

実行するとポータル上はこんな感じになりました。私もそう思います。

実行が終わったのでテーブルストレージを見てみます。

あ…割と早々に切り捨てられてますね。ログの出しすぎには注意しましょう。

ログのフィルタリング

そうはいっても開発中は詳細ログを出してて運用に入るとエラーログだけ出したいですよね。 ということで、ログの出力をフィルタリングできます。

host.jsonのtracingのconsoleLevelで指定します。verbose, info, warning, error及びoffが指定できます。 waring以上しか出さないようにするには以下のようにします。

{ 
    "tracing": {
        "consoleLevel": "waring"
    }
}

こうするとポータル上のログにはこう出ます。

ただ、テーブルストレージのほうには関係なくはかれちゃうみたいですね。

モニターから見る

まぁこれが正攻法なんでしょうが、Functionsのポータルにミニターというのがあります。これを選ぶと、関数の呼び出し単位のログを見たりできます。

これもconsoleLevelは関係ないみたいというか、テーブルストレージを見やすく出してくれてるだけにも見えます。

まとめ

色々やってみましたがモニターで見るのがよさそうですね。 あとログの出力量はほどほどに。

あと、モニターのページに書かれてましたがApplication Insightsの使用をお勧めされているので、今度はそちらも見てみたいと思います。ではでは。