Logico_jp

Azure Functionsのトリガー再試行ポリシー

このエントリは2020/11/09現在の情報に基づいています。将来の機能追加や変更に伴い記載内容と乖離する可能性があります。

日本語ドキュメントにはまだ反映されていないが、Azure Functions の Trigger Retry Policy が Preview として追加されている。

Trigger Retry Policyとは

Functionの呼び出しに失敗した場合に再試行する仕組みをポリシーとして定義できる、というもの。任意のトリガー、任意のFunctionに対して定義できる。ドキュメントには以下のような記述がある。

A retry policy can be defined on any function for any trigger type in your function app. The retry policy re-executes a function until either successful execution or until the maximum number of retries occur. Retry policies can be defined for all functions in an app or for individual functions. By default, a function app won’t retry messages (aside from the specific triggers that have a retry policy on the trigger source). A retry policy is evaluated whenever an execution results in an uncaught exception. As a best practice, you should catch all exceptions in your code and rethrow any errors that should result in a retry. Event Hubs and Azure Cosmos DB checkpoints won’t be written until the retry policy for the execution has completed, meaning progressing on that partition is paused until the current batch has completed.

Retry policies (preview) （2020/11/09現在英語のみ）
https://docs.microsoft.com/azure/azure-functions/functions-bindings-error-pages#retry-policies-preview

捕捉されない例外が送出されたときに、リトライポリシーによりトリガーの再試行が発生するので、発生しうる例外はすべて拾い、再試行が望ましい場合は例外をrethrowするべきである。

定義

再試行間隔は一定間隔もしくは指数関数的に増えるリトライ間隔（Exponential Backoff）を選択できる。定義対象はFunction Application全体、もしくはFunctionごと。両方に定義した場合、Function Applicationに対する定義を個々のFunctionに対する定義でオーバーライドする（ま、そりゃそうだ）。

Functions App全体に対して定義する場合

定義先は host.json。以下はその例。固定間隔、最大再試行回数2回、間隔は3秒。

{
    "retry": {
        "strategy": "fixedDelay",
        "maxRetryCount": 2,
        "delayInterval": "00:00:03"  
    }
}

retry （2020/11/09現在英語のみ）
https://docs.microsoft.com/azure/azure-functions/functions-host-json#retry

Function個々に対して定義する場合

定義先はfunction.json。以下はその例。Exponential Backoff、最大再試行回数5回、最小間隔10秒、最大間隔15分。

{
    "disabled": false,
    "bindings": [
        {
            ....
        }
    ],
    "retry": {
        "strategy": "exponentialBackoff",
        "maxRetryCount": 5,
        "minimumInterval": "00:00:10",
        "maximumInterval": "00:15:00"
    }
}

注意点

このリトライポリシーは、サービスが持つデフォルトの再試行回数と掛け合わされる点に注意が必要。ドキュメントにもあるが、例えばService Busの場合、デフォルトで10回配信試行するが、Trigger retry policyとして上記の例のように定義していた場合、Service Busからの配信で5×10回の計50回の再試行が発生する。再試行の流れを図示すると以下のような感じ。

Preview期間中の制限

以下に記載があるが、（GA後の話ではなく）Preview時の制約として、Consumption planの場合、Queueの最終メッセージがを再試行している間や再試行の間、アプリケーションは0にまでスケールインする可能性があるので注意が必要。

Retry limitations during preview
https://docs.microsoft.com/azure/azure-functions/functions-bindings-error-pages#retry-limitations-during-preview

実際に試してみる

例によってJavaで。。今回はHTTP Triggerでどうなるかを試してみる。Trigger Retry Policyを指定しないと1回目で50xのエラーが出るはずだが、果たして。

Mavenを使ってFunctionアプリケーションを作成。

mvn archetype:generate \
-DarchetypeGroupId=com.microsoft.azure \
-DarchetypeArtifactId=azure-functions-archetype \
-DappName=logico11 \
-DappRegion=japaneast \
-DresourceGroup=logico-rg \
-DgroupId=com.logico11.group \
-DartifactId=logico11-functions-trigger-retry-policy \
-Dpackage=com.logico11 \
-DinteractiveMode=false

pom.xmlを編集しておく。今回はJava 11、App ServiceプランのPricing TierとしてB1を指定したが、ここは全くのお好みでOK。なお、この設定は以下のエントリと同じ。

Azure Functions v3 で Java 11 をサポート
https://wordpress.com/post/logico-jp.io/4561

コードは37行目あたりの名前を指定しない場合にHTTP 400を返す箇所があるので、それを書き換えておく。以下のような感じ。当然メソッドシグネチャにもthrow Exceptionを追加しておく。

if (name == null) {
    throw new Exception("Trigger Retry Policy Test!!!");
//            return request.createResponseBuilder(HttpStatus.BAD_REQUEST).body("Please pass a name on the query string or in the request body").build();
} else {
    return request.createResponseBuilder(HttpStatus.OK).body("Hello, " + name).build();
}

続いてTrigger Retry Policyの設定。今回はTrigger Retry Policyをhost.jsonとfunction.jsonで異なるものを指定し、どちらが優先するか（function.jsonへの指定が優先することはわかっているが）を確認する。まずはhost.jsonに指定。

{
  "version": "2.0",
  "extensionBundle": {
    "id": "Microsoft.Azure.Functions.ExtensionBundle",
    "version": "[1.*, 2.0.0)"
  },
  "retry": {
    "strategy": "fixedDelay",
    "maxRetryCount": 2,
    "delayInterval": "00:00:03"
  }
}

ビルドしてデプロイ、そしてテスト。最初はQuery parameterを指定して実行。

https://{Function AppのURL}/api/HttpExample?name=Taro

結果は以下の通り (HTTP 200)。

Hello, Taro

ログストリームの出力は以下の通り。Succeededということで成功していることがわかる。

2020-11-09T04:14:24.599548480Z: [INFO]  [40m[32minfo[39m[22m[49m: Function.HttpExample[1]
2020-11-09T04:14:24.599596781Z: [INFO]        Executing 'Functions.HttpExample' (Reason='This function was programmatically called via the host APIs.', Id=ef333314-027d-4d0f-a172-8a333b544e9b)
2020-11-09T04:14:24.630822680Z: [INFO]  [40m[32minfo[39m[22m[49m: Function.HttpExample.User[0]
2020-11-09T04:14:24.630866681Z: [INFO]        Java HTTP trigger processed a request.
2020-11-09T04:14:24.632579825Z: [INFO]  [40m[32minfo[39m[22m[49m: Function.HttpExample.User[0]
2020-11-09T04:14:24.632600525Z: [INFO]        Function "HttpExample" (Id: ef333314-027d-4d0f-a172-8a333b544e9b) invoked by Java Worker
2020-11-09T04:14:24.671165712Z: [INFO]  [40m[32minfo[39m[22m[49m: Function.HttpExample[2]
2020-11-09T04:14:24.671261315Z: [INFO]        Executed 'Functions.HttpExample' (Succeeded, Id=ef333314-027d-4d0f-a172-8a333b544e9b, Duration=56ms)

続いて、Query Parameterを指定しない場合。これはHTTP 500が返るはず。

https://{Function AppのURL}/api/HttpExample

結果は想定通り HTTP 500。ログストリームの出力を見ると（長くなるので関連箇所のみ抜粋）、最初の試行（青字）で失敗し、2回再試行している（赤字）ことがわかる。

2020-11-09T04:19:20.629762305Z: [INFO]  [40m[32minfo[39m[22m[49m: Function.HttpExample[1]
2020-11-09T04:19:20.629837607Z: [INFO]        Executing 'Functions.HttpExample' (Reason='This function was programmatically called via the host APIs.', Id=8a79cab5-1c52-48c9-abcc-b09c53363ab0)
2020-11-09T04:19:20.653004795Z: [INFO]  [40m[32minfo[39m[22m[49m: Function.HttpExample.User[0]
2020-11-09T04:19:20.653075897Z: [INFO]        Java HTTP trigger processed a request.
2020-11-09T04:19:20.707347976Z: [INFO]  [41m[30mfail[39m[22m[49m: Function.HttpExample.User[0]
2020-11-09T04:19:20.707387177Z: [INFO]        The query parameter of 'name' is not specified!
2020-11-09T04:19:20.725721842Z: [INFO]  [41m[30mfail[39m[22m[49m: Function.HttpExample[3]
2020-11-09T04:19:20.725795044Z: [INFO]        Executed 'Functions.HttpExample' (Failed, Id=8a79cab5-1c52-48c9-abcc-b09c53363ab0, Duration=82ms)
2020-11-09T04:19:20.726320457Z: [INFO]  Microsoft.Azure.WebJobs.Host.FunctionInvocationException: Exception while executing function: Functions.HttpExample
2020-11-09T04:19:20.726339558Z: [INFO]   ---> Microsoft.Azure.WebJobs.Script.Workers.Rpc.RpcException: Result: Failure
2020-11-09T04:19:20.726349458Z: [INFO]  Exception: Exception: Trigger Retry Policy Test!!!
2020-11-09T04:19:20.726357458Z: [INFO]  Stack: java.lang.reflect.InvocationTargetException
...
...
2020-11-09T04:19:23.779146953Z: [INFO]        Executing 'Functions.HttpExample' (Reason='This function was programmatically called via the host APIs.', Id=be991d60-20c0-4178-9a4d-1bb2d5d71329)
2020-11-09T04:19:23.865230116Z: [INFO]  [40m[32minfo[39m[22m[49m: Function.HttpExample.User[0]
2020-11-09T04:19:23.865275317Z: [INFO]        Java HTTP trigger processed a request.
2020-11-09T04:19:23.977196529Z: [INFO]  [41m[30mfail[39m[22m[49m: Function.HttpExample.User[0]
2020-11-09T04:19:23.977240230Z: [INFO]        The query parameter of 'name' is not specified!
2020-11-09T04:19:24.012749422Z: [INFO]  [41m[30mfail[39m[22m[49m: Function.HttpExample[3]
2020-11-09T04:19:24.012786023Z: [INFO]        Executed 'Functions.HttpExample' (Failed, Id=be991d60-20c0-4178-9a4d-1bb2d5d71329, Duration=226ms)
2020-11-09T04:19:24.014207759Z: [INFO]  Microsoft.Azure.WebJobs.Host.FunctionInvocationException: Exception while executing function: Functions.HttpExample
2020-11-09T04:19:24.014229560Z: [INFO]   ---> Microsoft.Azure.WebJobs.Script.Workers.Rpc.RpcException: Result: Failure
2020-11-09T04:19:24.014253860Z: [INFO]  Exception: Exception: Trigger Retry Policy Test!!!
2020-11-09T04:19:24.014263060Z: [INFO]  Stack: java.lang.reflect.InvocationTargetException
...
...
2020-11-09T04:19:24.068444522Z: [INFO]        Executing 'Functions.HttpExample' (Reason='This function was programmatically called via the host APIs.', Id=7c5a47f7-4367-49b1-ba49-039d8d653823)
2020-11-09T04:19:24.086060364Z: [INFO]  [40m[32minfo[39m[22m[49m: Function.HttpExample.User[0]
2020-11-09T04:19:24.086152067Z: [INFO]        Java HTTP trigger processed a request.
2020-11-09T04:19:24.105254847Z: [INFO]  [41m[30mfail[39m[22m[49m: Function.HttpExample.User[0]
2020-11-09T04:19:24.105320248Z: [INFO]        The query parameter of 'name' is not specified!
2020-11-09T04:19:24.129726561Z: [INFO]  [41m[30mfail[39m[22m[49m: Function.HttpExample[3]
2020-11-09T04:19:24.129765362Z: [INFO]        Executed 'Functions.HttpExample' (Failed, Id=7c5a47f7-4367-49b1-ba49-039d8d653823, Duration=51ms)
2020-11-09T04:19:24.130836489Z: [INFO]  Microsoft.Azure.WebJobs.Host.FunctionInvocationException: Exception while executing function: Functions.HttpExample
2020-11-09T04:19:24.130856290Z: [INFO]   ---> Microsoft.Azure.WebJobs.Script.Workers.Rpc.RpcException: Result: Failure
2020-11-09T04:19:24.130879190Z: [INFO]  Exception: Exception: Trigger Retry Policy Test!!!
2020-11-09T04:19:24.130890191Z: [INFO]  Stack: java.lang.reflect.InvocationTargetException
...

続いて、function.jsonに指定してみる。今回はintervalは同じながらも、retry countを1回にする。host.jsonは変更していないので、function.jsonと両方に設定がある状態。

{
  "scriptFile" : "../logico11-functions-trigger-retry-policy-1.0-SNAPSHOT.jar",
  "entryPoint" : "com.logico11.Function.run",
  "bindings" : [...],
  "retry": {
    "strategy": "fixedDelay",
    "maxRetryCount": 1,
    "delayInterval": "00:00:03"
  }
}

function.jsonはtarget側に生成されるので、デプロイだけ実行する。Portalからfunction.jsonの内容を確認して問題ないことを確認。

それではテスト。最初はQuery parameterを指定して実行。

https://{Function AppのURL}/api/HttpExample?name=Taro

当然 HTTP 200 で期待したレスポンスが返る。

Hello, Taro

ログストリームの出力は以下のような感じ。

 2020-11-09T04:29:24.599548480Z: [INFO]  [40m[32minfo[39m[22m[49m: Function.HttpExample[1]
 2020-11-09T04:29:24.599596781Z: [INFO]        Executing 'Functions.HttpExample' (Reason='This function was programmatically called via the host APIs.', Id=ef333314-027d-4d0f-a172-8a333b544e9b)
 2020-11-09T04:29:24.630822680Z: [INFO]  [40m[32minfo[39m[22m[49m: Function.HttpExample.User[0]
 2020-11-09T04:29:24.630866681Z: [INFO]        Java HTTP trigger processed a request.
 2020-11-09T04:29:24.632579825Z: [INFO]  [40m[32minfo[39m[22m[49m: Function.HttpExample.User[0]
 2020-11-09T04:29:24.632600525Z: [INFO]        Function "HttpExample" (Id: ef333314-027d-4d0f-a172-8a333b544e9b) invoked by Java Worker
 2020-11-09T04:29:24.671165712Z: [INFO]  [40m[32minfo[39m[22m[49m: Function.HttpExample[2]
 2020-11-09T04:29:24.671261315Z: [INFO]        Executed 'Functions.HttpExample' (Succeeded, Id=ef333314-027d-4d0f-a172-8a333b544e9b, Duration=56ms)

で、Query Parameterを指定しない場合は、HTTP 500が返るが、ログストリームの出力を見ると以下のような感じで、最初の試行＋1回の再試行、つまりfunction.jsonで定義したTrigger Retry Policyが使われていることを確認できる。

 2020-11-09T05:01:50.144365231Z: [INFO]  [40m[32minfo[39m[22m[49m: Function.HttpExample[1]
 2020-11-09T05:01:50.144414432Z: [INFO]        Executing 'Functions.HttpExample' (Reason='This function was programmatically called via the host APIs.', Id=d726e163-46b8-4efd-8efd-24cc0d77dcf4)
 2020-11-09T05:01:50.168028150Z: [INFO]  [40m[32minfo[39m[22m[49m: Function.HttpExample.User[0]
 2020-11-09T05:01:50.168097752Z: [INFO]        Java HTTP trigger processed a request.
 2020-11-09T05:01:50.215530893Z: [INFO]  [41m[30mfail[39m[22m[49m: Function.HttpExample.User[0]
 2020-11-09T05:01:50.215588694Z: [INFO]        The query parameter of 'name' is not specified!
 2020-11-09T05:01:50.230846329Z: [INFO]  [41m[30mfail[39m[22m[49m: Function.HttpExample[3]
 2020-11-09T05:01:50.230914030Z: [INFO]        Executed 'Functions.HttpExample' (Failed, Id=d726e163-46b8-4efd-8efd-24cc0d77dcf4, Duration=81ms)
 2020-11-09T05:01:50.231974254Z: [INFO]  Microsoft.Azure.WebJobs.Host.FunctionInvocationException: Exception while executing function: Functions.HttpExample
 2020-11-09T05:01:50.231994754Z: [INFO]   ---> Microsoft.Azure.WebJobs.Script.Workers.Rpc.RpcException: Result: Failure
 2020-11-09T05:01:50.232019255Z: [INFO]  Exception: Exception: Trigger Retry Policy Test!!!
 2020-11-09T05:01:50.232028955Z: [INFO]  Stack: java.lang.reflect.InvocationTargetException
 …
 …
 2020-11-09T05:01:50.297374389Z: [INFO]  [40m[32minfo[39m[22m[49m: Function.HttpExample[1]
 2020-11-09T05:01:50.297383490Z: [INFO]        Executing 'Functions.HttpExample' (Reason='This function was programmatically called via the host APIs.', Id=b26467cd-2bf0-4b58-8d5e-6052f6a1a562)
 2020-11-09T05:01:50.297391490Z: [INFO]  [40m[32minfo[39m[22m[49m: Function.HttpExample.User[0]
 2020-11-09T05:01:50.297399190Z: [INFO]        Java HTTP trigger processed a request.
 2020-11-09T05:01:50.310296973Z: [INFO]  [41m[30mfail[39m[22m[49m: Function.HttpExample.User[0]
 2020-11-09T05:01:50.310325474Z: [INFO]        The query parameter of 'name' is not specified!
 2020-11-09T05:01:50.337753076Z: [INFO]  [41m[30mfail[39m[22m[49m: Function.HttpExample[3]
 2020-11-09T05:01:50.337793477Z: [INFO]        Executed 'Functions.HttpExample' (Failed, Id=b26467cd-2bf0-4b58-8d5e-6052f6a1a562, Duration=46ms)
 2020-11-09T05:01:50.338603695Z: [INFO]  Microsoft.Azure.WebJobs.Host.FunctionInvocationException: Exception while executing function: Functions.HttpExample
 2020-11-09T05:01:50.338623495Z: [INFO]   ---> Microsoft.Azure.WebJobs.Script.Workers.Rpc.RpcException: Result: Failure
 2020-11-09T05:01:50.338632595Z: [INFO]  Exception: Exception: Trigger Retry Policy Test!!!
 2020-11-09T05:01:50.338653396Z: [INFO]  Stack: java.lang.reflect.InvocationTargetException
 …
 …
カテゴリー: Azure、Event Hubs、Functions、Java、Technologyタグ: 、、、コメントする

コメントを残す

以下に詳細を記入するか、アイコンをクリックしてログインしてください。

Gravatar
WordPress.com ロゴ

WordPress.com アカウントを使ってコメントしています。 ( ログアウト /  変更 )

Facebook の写真

Facebook アカウントを使ってコメントしています。 ( ログアウト /  変更 )

キャンセル

%s と連携中