Azure Functions の新機能!関数のリトライを試してみた(普通に便利)


追記

2020/11/11
Microsoft.NET.Sdk.Functions の 3.0.11 で確認したところ Microsoft.Azure.WebJobs が最新になっていたので、ここで書いている手動での NuGet パッケージの追加は不要になっていました。

本文

新機能出たら試したくなりますよね。先日 xin9le さんのツイートで見つけたこのツイート

今まで組み込みでリトライ機能を提供しているトリガー(Queue など)を覗いて、関数が例外で終わったときにリトライをしたいときには自前で書くか、Polly とか使ってリトライするように書くかしないといけませんでした。

今回追加された機能を使うと関数に属性でリトライの設定をするだけで、Azure Functions 内部でリトライをやってくれるようになります。

ドキュメントは上記ツイートにも書いてありますが、この URL になります。

試してみよう

新機能あるあるなのかもしれませんが、今回追加された FixedDelayRetryAttributeExponentialBackoffRetryAttribute が定義されているライブラリは、まだプロジェクトテンプレートから新規作成した状態では使えません。GitHub の Azure Functions 関連のリポジトリで地道に検索して回ったところ Microsoft.Azure.WebJobs パッケージで定義されている属性ということがわかったので、NuGet パッケージマネージャーから最新の Microsoft.Azure.WebJobs を手動で追加します。

今日時点では 3.0.23 が最新でした。
Microsoft.Azure.WebJobs パッケージは Microsoft.NET.Sdk.Functions の依存先なので普通は何もしなくていいのですが Microsoft.NET.Sdk.Functions の今日時点での最新のパッケージは、ちょっと古い Microsoft.Azure.WebJobs を参照しているので、この作業が必要になります。多分、少ししたら Microsoft.NET.Sdk.Functions パッケージが更新されると思うので、この手順は不要になると思います。

NuGet のパッケージを追加したらソリューションエクスプローラーは以下のような感じになります。

パッケージが更新されたので上記内容は不要になりました。
Microsoft.NET.Sdk.Functions を 3.0.11 に更新してください。

では、5 回に 1 回しか正常終了しない関数を作ってリトライの属性をつけて動きを確認してみます。

using System;
using System.Threading.Tasks;
using Microsoft.AspNetCore.Mvc;
using Microsoft.Azure.WebJobs;
using Microsoft.Azure.WebJobs.Extensions.Http;
using Microsoft.AspNetCore.Http;
using Microsoft.Extensions.Logging;

namespace FunctionApp7
{
    public static class Function1
    {
        private static int _counter = 0;

        [FixedDelayRetry(maxRetryCount: 4, delayInterval: "00:00:03")]
        [FunctionName("Function1")]
        public static async Task<IActionResult> Run(
            [HttpTrigger(AuthorizationLevel.Function, "get", "post", Route = null)] HttpRequest req,
            ILogger log)
        {
            log.LogInformation("実行してるよ!");
            if (++_counter % 5 != 0)
            {
                log.LogInformation($"5回に1回しか成功しません。 {_counter}");
                throw new Exception("エラー!!");
            }

            log.LogInformation("成功!!");
            return new OkResult();
        }
    }
}

static 変数を使って手抜き実装ですが、今回の用途には十分でしょう。maxRetryCount が 4 なのでエラーが出続けると最初の 1 回 + リトライ 4 回で合計 5 回実行されます。この関数は 5 回実行すると 1 回成功するので最後のリトライで正常終了するはずです。では実行してみましょう。

実行ログはこんな感じになりました。

[2020-11-05T00:29:30.933Z] Executing 'Function1' (Reason='This function was programmatically called via the host APIs.', Id=09d3a94f-7eae-4247-97c3-fcd8fdaf3838)
[2020-11-05T00:29:30.941Z] 実行してるよ!
[2020-11-05T00:29:30.942Z] 5回に1回しか成功しません。 1
[2020-11-05T00:29:31.009Z] Executed 'Function1' (Failed, Id=09d3a94f-7eae-4247-97c3-fcd8fdaf3838, Duration=97ms)
[2020-11-05T00:29:31.010Z] System.Private.CoreLib: Exception while executing function: Function1. FunctionApp7: エラー!!.
[2020-11-05T00:29:34.033Z] Executing 'Function1' (Reason='This function was programmatically called via the host APIs.', Id=7ca7ee75-ed60-403c-914b-5e21bb700249)
[2020-11-05T00:29:34.035Z] 実行してるよ!
[2020-11-05T00:29:34.035Z] 5回に1回しか成功しません。 2
[2020-11-05T00:29:34.051Z] Executed 'Function1' (Failed, Id=7ca7ee75-ed60-403c-914b-5e21bb700249, Duration=18ms)
[2020-11-05T00:29:34.052Z] System.Private.CoreLib: Exception while executing function: Function1. FunctionApp7: エラー!!.
[2020-11-05T00:29:37.065Z] Executing 'Function1' (Reason='This function was programmatically called via the host APIs.', Id=b036c50c-eb1d-4247-8122-d1088751fdbf)
[2020-11-05T00:29:37.067Z] 実行してるよ!
[2020-11-05T00:29:37.069Z] 5回に1回しか成功しません。 3
[2020-11-05T00:29:37.085Z] Executed 'Function1' (Failed, Id=b036c50c-eb1d-4247-8122-d1088751fdbf, Duration=20ms)
[2020-11-05T00:29:37.086Z] System.Private.CoreLib: Exception while executing function: Function1. FunctionApp7: エラー!!.
[2020-11-05T00:29:40.118Z] Executing 'Function1' (Reason='This function was programmatically called via the host APIs.', Id=58219d68-2bba-44f0-ad9e-28fa6a51d99a)
[2020-11-05T00:29:40.120Z] 実行してるよ!
[2020-11-05T00:29:40.122Z] 5回に1回しか成功しません。 4
[2020-11-05T00:29:40.139Z] Executed 'Function1' (Failed, Id=58219d68-2bba-44f0-ad9e-28fa6a51d99a, Duration=21ms)
[2020-11-05T00:29:40.141Z] System.Private.CoreLib: Exception while executing function: Function1. FunctionApp7: エラー!!.
[2020-11-05T00:29:40.144Z] Executing 'Function1' (Reason='This function was programmatically called via the host APIs.', Id=c704a877-2e21-4216-b7c3-429215fe91f5)
[2020-11-05T00:29:40.145Z] 実行してるよ!
[2020-11-05T00:29:40.147Z] 成功!!
[2020-11-05T00:29:40.150Z] Executed 'Function1' (Succeeded, Id=c704a877-2e21-4216-b7c3-429215fe91f5, Duration=6ms)

3 秒待ってリトライしているのがわかりますね。

指数バックオフのリトライもやってみましょう。単純に FixedRetry から ExponentialBackoffRetry に置き換えます。

using System;
using System.Threading.Tasks;
using Microsoft.AspNetCore.Mvc;
using Microsoft.Azure.WebJobs;
using Microsoft.Azure.WebJobs.Extensions.Http;
using Microsoft.AspNetCore.Http;
using Microsoft.Extensions.Logging;

namespace FunctionApp7
{
    public static class Function1
    {
        private static int _counter = 0;

        [ExponentialBackoffRetry(maxRetryCount: 4, minimumInterval: "00:00:03", maximumInterval: "00:00:15")]
        [FunctionName("Function1")]
        public static async Task<IActionResult> Run(
            [HttpTrigger(AuthorizationLevel.Function, "get", "post", Route = null)] HttpRequest req,
            ILogger log)
        {
            log.LogInformation("実行してるよ!");
            if (++_counter % 5 != 0)
            {
                log.LogInformation($"5回に1回しか成功しません。 {_counter}");
                throw new Exception("エラー!!");
            }

            log.LogInformation("成功!!");
            return new OkResult();
        }
    }
}

実行してみます。一定間隔ではなくなってリトライ回数が増えるほど間隔が長くなってますね。

実際のログも貼っておきます。

[2020-11-05T00:35:54.188Z] Executing 'Function1' (Reason='This function was programmatically called via the host APIs.', Id=00cee606-3bf1-4ce2-99db-c7a4692c827f)
[2020-11-05T00:35:54.194Z] 実行してるよ!
[2020-11-05T00:35:54.195Z] 5回に1回しか成功しません。 1
[2020-11-05T00:35:54.275Z] Executed 'Function1' (Failed, Id=00cee606-3bf1-4ce2-99db-c7a4692c827f, Duration=105ms)
[2020-11-05T00:35:54.276Z] System.Private.CoreLib: Exception while executing function: Function1. FunctionApp7: エラー!!.
[2020-11-05T00:35:57.294Z] Executing 'Function1' (Reason='This function was programmatically called via the host APIs.', Id=5f801559-201e-4c29-a3ce-8bad5343c097)
[2020-11-05T00:35:57.295Z] 実行してるよ!
[2020-11-05T00:35:57.297Z] 5回に1回しか成功しません。 2
[2020-11-05T00:35:57.313Z] Executed 'Function1' (Failed, Id=5f801559-201e-4c29-a3ce-8bad5343c097, Duration=19ms)
[2020-11-05T00:35:57.314Z] System.Private.CoreLib: Exception while executing function: Function1. FunctionApp7: エラー!!.
[2020-11-05T00:36:03.537Z] Executing 'Function1' (Reason='This function was programmatically called via the host APIs.', Id=928fdfba-7a41-4f20-be08-30059614b61d)
[2020-11-05T00:36:03.540Z] 実行してるよ!
[2020-11-05T00:36:03.541Z] 5回に1回しか成功しません。 3
[2020-11-05T00:36:03.559Z] Executed 'Function1' (Failed, Id=928fdfba-7a41-4f20-be08-30059614b61d, Duration=22ms)
[2020-11-05T00:36:03.561Z] System.Private.CoreLib: Exception while executing function: Function1. FunctionApp7: エラー!!.
[2020-11-05T00:36:12.354Z] Executing 'Function1' (Reason='This function was programmatically called via the host APIs.', Id=061aa130-b70e-4351-aff2-72924d98814b)
[2020-11-05T00:36:12.357Z] 実行してるよ!
[2020-11-05T00:36:12.359Z] 5回に1回しか成功しません。 4
[2020-11-05T00:36:12.376Z] Executed 'Function1' (Failed, Id=061aa130-b70e-4351-aff2-72924d98814b, Duration=21ms)
[2020-11-05T00:36:12.377Z] System.Private.CoreLib: Exception while executing function: Function1. FunctionApp7: エラー!!.
[2020-11-05T00:36:12.381Z] Executing 'Function1' (Reason='This function was programmatically called via the host APIs.', Id=754c00c3-f591-4d0c-931c-289b4907f67d)
[2020-11-05T00:36:12.383Z] 実行してるよ!
[2020-11-05T00:36:12.384Z] 成功!!
[2020-11-05T00:36:12.388Z] Executed 'Function1' (Succeeded, Id=754c00c3-f591-4d0c-931c-289b4907f67d, Duration=7ms)

まとめ

HttpTrigger や TimerTrigger など、今までエラーで終わると終わりっぱなしだった(まぁ例外処理してないので、それが普通なんですが)トリガーに対してリトライを設定できるようになったので、今まで手動で書いてたリトライ処理が、この属性指定の方法で賄える仕様ならコードがすっきりしていいですね。