[Azure] FunctionAppでログ出力されない場合、context.done()が非同期実行されていないか注意

タイトルがほぼ情報の全てですが、気づくまでに時間がかかったのでメモ。

Azure functionApp (Javascript)でログ出力されない場合、context.done()が非同期実行されてcontext.log()より先になっていないか注意が必要です。

以下サンプルでは、時間のかかる処理をsetTimeout()で代替していますが、functionApp作成時のテンプレートを元にこんなコードを書いてしまうと・・・

module.exports = function (context, myTimer) {
    let timeStamp = new Date().toISOString();
    context.log('JavaScript timer trigger function ran!: ', timeStamp);   

    for (let i = 0; i < 12; i++) {
        setTimeout(function() {
            context.log('[Info] Log output test: ', i);
        }, 1000 * 10 * i);
    }
    context.done();
};

ログが途中で途切れてしまい、悩むことになります。サンプルだと"Function completed"が先に出ているところで気づきそうなものですが、実際のコードで色々ログを出していると気づきにくいですね。

非同期処理の影響であることは、context.done()のところを修正すると確認できます。

module.exports = function (context, myTimer) {
    let timeStamp = new Date().toISOString();
    context.log('JavaScript timer trigger function ran!: ', timeStamp);   

    for (let i = 0; i < 12; i++) {
        setTimeout(function() {
            context.log('[Info] Log output test: ', i);
        }, 1000 * 10 * i);
    }

    setTimeout(function() {
        context.done();
    }, 1000 * 10 * 12);
};

こちらのコードであれば、期待通りにログ出力されることが確認できます。

もちろん実際のコードでは事前に待ち時間が分かることはなく、context.done()の実行タイミングで悩むわけですが、注意事項は以上になります。