Azure Functions for Java でリトライを実装する

# Azure Functions for Java でリトライを実装する

未だプレビューなのですが、Azure Functions にはリトライが実装されています。

[Azure Functions のエラー処理と再試行のガイダンス | Microsoft Docs](https://docs.microsoft.com/ja-jp/azure/azure-functions/functions-bindings-error-pages?tabs=java&WT.mc_id=AZ-MVP-5001265)

上記を参照するとC#は属性ベースでリトライが指定できるのですが、Java等のその他の言語は、`function.json`に指定しろと書いてあります。とはいえ、`function.json` は、自動生成されたりするものですから、使い勝手がよくありません。

調べてみると、GitHubにIsssueが立っていて動きがなかったので、質問してみると既に実装済でした。以下のタグに説明があります（SNAPSHOTですが既にリリース済です）

https://github.com/Azure/azure-functions-java-library/releases/tag/1.4.2-SNAPSHOT

リトライには、固定秒（FixedDelayRetry）でのものと、指数関数的バックオフ（ExponentialBackoffRetry）­‐ リトライ毎に間隔が増加していくものの、よくある2つが用意されています。

## FixedDelayRetry

サンプルを引用しますが、`FixedDelayRetry` アノテーションで、回数とインターバルを指定します。インターバルが文字列なのが行けてませんが、単に `function.json` への定義用かと思えばそんなものなのでしょうか。

```java
    @FunctionName("HttpExampleRetry")
    @FixedDelayRetry(maxRetryCount = 3, delayInterval = "00:00:05")  // ★
    public HttpResponseMessage runRetry(
            @HttpTrigger(
                    name = "req",
                    methods = {HttpMethod.GET, HttpMethod.POST},
                    authLevel = AuthorizationLevel.ANONYMOUS)
                    HttpRequestMessage<Optional<String>> request,
            final ExecutionContext context) throws Exception {
        context.getLogger().info("Java HTTP trigger processed a request.");

        // Parse query parameter
        final String query = request.getQueryParameters().get("name");
        final String name = request.getBody().orElse(query);

        if (name == null) {
            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(name).build();
        }
    }
```

## ExponentialBackoffRetry

こちらのサンプルからの引用。 `ExponentialBackoffRetry` アノテーションで、回数、最小インターバル、最大インターバルを指定します。あとは適当にフレームワーク側がリトライしてくれるでしょう。

```java
    @FunctionName("HttpExampleExponentialBackoffRetry")
    @ExponentialBackoffRetry(maxRetryCount = 3, minimumInterval = "00:00:01", maximumInterval = "00:00:03") // ★
    public HttpResponseMessage runRetryExponentialBackoffRetry(
            @HttpTrigger(
                    name = "req",
                    methods = {HttpMethod.GET, HttpMethod.POST},
                    authLevel = AuthorizationLevel.ANONYMOUS)
                    HttpRequestMessage<Optional<String>> request,
            final ExecutionContext context) throws Exception {
        context.getLogger().info("Java HTTP trigger processed a request.");

        // Parse query parameter
        final String query = request.getQueryParameters().get("name");
        final String name = request.getBody().orElse(query);

        if (name == null) {
            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(name).build();
        }
    }
```


# 試してみる

開発環境で試してみましょう。各種ログをTraceレベルにして、適当にスタックトレースをはしょってあります。

以下は、リトライなしの場合。例外が出ると、そおまま終わってしまします。

```log
[2021-04-26T08:51:37.318Z] Request successfully matched the route with name 'noretry' and template 'api/noretry'
[2021-04-26T08:51:37.320Z] Executing 'Functions.noretry' (Reason='This function was programmatically called via the host APIs.', Id=f0d01936-4b9a-42e8-a7fc-2bc075e11420)
[2021-04-26T08:51:37.321Z] Sending invocation id:f0d01936-4b9a-42e8-a7fc-2bc075e11420
[2021-04-26T08:51:37.323Z] Posting invocation id:f0d01936-4b9a-42e8-a7fc-2bc075e11420 on workerId:760295b9-ab89-4fbf-84bc-b9e1ac57e8ae
[2021-04-26T08:51:37.325Z] HttpContext has ClaimsPrincipal; parsing to gRPC.
[2021-04-26T08:51:37.327Z] Writing invocation request invocationId: f0d01936-4b9a-42e8-a7fc-2bc075e11420 to workerId: 760295b9-ab89-4fbf-84bc-b9e1ac57e8ae
[2021-04-26T08:51:37.331Z] Java HTTP trigger processed a request.
[2021-04-26T08:51:37.333Z] Received invocation response for invocationId: f0d01936-4b9a-42e8-a7fc-2bc075e11420 from workerId: 760295b9-ab89-4fbf-84bc-b9e1ac57e8ae
[2021-04-26T08:51:37.334Z] InvocationResponse received for invocation id: f0d01936-4b9a-42e8-a7fc-2bc075e11420
[2021-04-26T08:51:37.337Z] Executed 'Functions.noretry' (Failed, Id=f0d01936-4b9a-42e8-a7fc-2bc075e11420, Duration=17ms)
[2021-04-26T08:51:37.338Z] System.Private.CoreLib: Exception while executing function: Functions.noretry. System.Private.CoreLib: Result: Failure
Exception: InvalidParameterException:
Stack: java.lang.reflect.InvocationTargetException
[2021-04-26T08:51:37.339Z]      at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
...
[2021-04-26T08:51:37.353Z]      at java.base/java.lang.Thread.run(Thread.java:834)
[2021-04-26T08:51:37.354Z] Caused by: java.security.InvalidParameterException
[2021-04-26T08:51:37.355Z]      at com.example.moris.Function.run2(Function.java:45)
[2021-04-26T08:51:37.357Z]      ... 16 more
[2021-04-26T08:51:37.358Z] .
[2021-04-26T08:51:37.360Z] Executed HTTP request: {
[2021-04-26T08:51:37.361Z]   requestId: "39285172-f05f-4312-902c-e00094813005",
[2021-04-26T08:51:37.362Z]   identities: "",
[2021-04-26T08:51:37.363Z]   status: "500",
[2021-04-26T08:51:37.364Z]   duration: "51"
[2021-04-26T08:51:37.365Z] }
```

リトライを設定した場合は、以下の通り。リトライを3回に指定してあるのですが、Traceレベルですと、` Waiting for ``00:00:02`` before retrying function execution. Next attempt: '1'. Max retry count: '3'` が 確認できまました。適切に設定すれば、このログだけうまく出力させておけて、リトライがかかったことを後から確認出来る気がします。

```log
[2021-04-26T08:53:39.116Z] Request successfully matched the route with name 'fixeddelayretry' and template 'api/fixeddelayretry'
[2021-04-26T08:53:39.120Z] Executing 'Functions.fixeddelayretry' (Reason='This function was programmatically called via the host APIs.', Id=d8ef45ce-9669-4eab-9810-0b2c499217ba)
[2021-04-26T08:53:39.122Z] Sending invocation id:d8ef45ce-9669-4eab-9810-0b2c499217ba
[2021-04-26T08:53:39.123Z] Posting invocation id:d8ef45ce-9669-4eab-9810-0b2c499217ba on workerId:760295b9-ab89-4fbf-84bc-b9e1ac57e8ae
[2021-04-26T08:53:39.125Z] HttpContext has ClaimsPrincipal; parsing to gRPC.
[2021-04-26T08:53:39.127Z] Writing invocation request invocationId: d8ef45ce-9669-4eab-9810-0b2c499217ba to workerId: 760295b9-ab89-4fbf-84bc-b9e1ac57e8ae
[2021-04-26T08:53:39.131Z] Java HTTP trigger processed a request.
[2021-04-26T08:53:39.133Z] Received invocation response for invocationId: d8ef45ce-9669-4eab-9810-0b2c499217ba from workerId: 760295b9-ab89-4fbf-84bc-b9e1ac57e8ae
[2021-04-26T08:53:39.135Z] InvocationResponse received for invocation id: d8ef45ce-9669-4eab-9810-0b2c499217ba
[2021-04-26T08:53:39.138Z] Executed 'Functions.fixeddelayretry' (Failed, Id=d8ef45ce-9669-4eab-9810-0b2c499217ba, Duration=19ms)
[2021-04-26T08:53:39.139Z] System.Private.CoreLib: Exception while executing function: Functions.fixeddelayretry. System.Private.CoreLib: Result: Failure
Exception: InvalidParameterException:
Stack: java.lang.reflect.InvocationTargetException
[2021-04-26T08:53:39.141Z]      at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
...
[2021-04-26T08:53:39.157Z] Caused by: java.security.InvalidParameterException
[2021-04-26T08:53:39.158Z]      at com.example.moris.Function.run(Function.java:30)
[2021-04-26T08:53:39.159Z]      ... 16 more
[2021-04-26T08:53:39.160Z] .
[2021-04-26T08:53:39.169Z] Waiting for `00:00:02` before retrying function execution. Next attempt: '1'. Max retry count: '3'
[2021-04-26T08:53:41.200Z] Executing 'Functions.fixeddelayretry' (Reason='This function was programmatically called via the host APIs.', Id=b8ba3618-ed2b-4931-ba05-6454aa5da158)
[2021-04-26T08:53:41.203Z] Sending invocation id:b8ba3618-ed2b-4931-ba05-6454aa5da158
[2021-04-26T08:53:41.205Z] Posting invocation id:b8ba3618-ed2b-4931-ba05-6454aa5da158 on workerId:760295b9-ab89-4fbf-84bc-b9e1ac57e8ae
[2021-04-26T08:53:41.207Z] HttpContext has ClaimsPrincipal; parsing to gRPC.
[2021-04-26T08:53:41.209Z] Writing invocation request invocationId: b8ba3618-ed2b-4931-ba05-6454aa5da158 to workerId: 760295b9-ab89-4fbf-84bc-b9e1ac57e8ae
[2021-04-26T08:53:41.215Z] Java HTTP trigger processed a request.
[2021-04-26T08:53:41.219Z] Received invocation response for invocationId: b8ba3618-ed2b-4931-ba05-6454aa5da158 from workerId: 760295b9-ab89-4fbf-84bc-b9e1ac57e8ae
[2021-04-26T08:53:41.221Z] InvocationResponse received for invocation id: b8ba3618-ed2b-4931-ba05-6454aa5da158
[2021-04-26T08:53:41.226Z] Executed 'Functions.fixeddelayretry' (Failed, Id=b8ba3618-ed2b-4931-ba05-6454aa5da158, Duration=25ms)
[2021-04-26T08:53:41.228Z] System.Private.CoreLib: Exception while executing function: Functions.fixeddelayretry. System.Private.CoreLib: Result: Failure
Exception: InvalidParameterException:
Stack: java.lang.reflect.InvocationTargetException
[2021-04-26T08:53:41.230Z]      at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
...
[2021-04-26T08:53:41.249Z] Caused by: java.security.InvalidParameterException
[2021-04-26T08:53:41.250Z]      at com.example.moris.Function.run(Function.java:30)
[2021-04-26T08:53:41.251Z]      ... 16 more
[2021-04-26T08:53:41.252Z] .
[2021-04-26T08:53:41.256Z] Waiting for `00:00:02` before retrying function execution. Next attempt: '2'. Max retry count: '3'
[2021-04-26T08:53:43.263Z] Executing 'Functions.fixeddelayretry' (Reason='This function was programmatically called via the host APIs.', Id=68731e8d-015f-4ca9-8689-6e6953700296)
[2021-04-26T08:53:43.266Z] Sending invocation id:68731e8d-015f-4ca9-8689-6e6953700296
[2021-04-26T08:53:43.268Z] Posting invocation id:68731e8d-015f-4ca9-8689-6e6953700296 on workerId:760295b9-ab89-4fbf-84bc-b9e1ac57e8ae
[2021-04-26T08:53:43.269Z] HttpContext has ClaimsPrincipal; parsing to gRPC.
[2021-04-26T08:53:43.271Z] Writing invocation request invocationId: 68731e8d-015f-4ca9-8689-6e6953700296 to workerId: 760295b9-ab89-4fbf-84bc-b9e1ac57e8ae
[2021-04-26T08:53:43.275Z] Java HTTP trigger processed a request.
[2021-04-26T08:53:43.278Z] Received invocation response for invocationId: 68731e8d-015f-4ca9-8689-6e6953700296 from workerId: 760295b9-ab89-4fbf-84bc-b9e1ac57e8ae
[2021-04-26T08:53:43.280Z] InvocationResponse received for invocation id: 68731e8d-015f-4ca9-8689-6e6953700296
[2021-04-26T08:53:43.284Z] Executed 'Functions.fixeddelayretry' (Failed, Id=68731e8d-015f-4ca9-8689-6e6953700296, Duration=20ms)
[2021-04-26T08:53:43.285Z] System.Private.CoreLib: Exception while executing function: Functions.fixeddelayretry. System.Private.CoreLib: Result: Failure
Exception: InvalidParameterException:
Stack: java.lang.reflect.InvocationTargetException
[2021-04-26T08:53:43.287Z]      at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
...
[2021-04-26T08:53:43.306Z] Caused by: java.security.InvalidParameterException
[2021-04-26T08:53:43.308Z]      at com.example.moris.Function.run(Function.java:30)
[2021-04-26T08:53:43.310Z]      ... 16 more
[2021-04-26T08:53:43.311Z] .
[2021-04-26T08:53:43.313Z] Waiting for `00:00:00` before retrying function execution. Next attempt: '3'. Max retry count: '3'
[2021-04-26T08:53:43.314Z] Executing 'Functions.fixeddelayretry' (Reason='This function was programmatically called via the host APIs.', Id=9a499277-61d0-4d2e-b68c-24210b3172a6)
[2021-04-26T08:53:43.316Z] Sending invocation id:9a499277-61d0-4d2e-b68c-24210b3172a6
[2021-04-26T08:53:43.317Z] Posting invocation id:9a499277-61d0-4d2e-b68c-24210b3172a6 on workerId:760295b9-ab89-4fbf-84bc-b9e1ac57e8ae
[2021-04-26T08:53:43.318Z] HttpContext has ClaimsPrincipal; parsing to gRPC.
[2021-04-26T08:53:43.319Z] Writing invocation request invocationId: 9a499277-61d0-4d2e-b68c-24210b3172a6 to workerId: 760295b9-ab89-4fbf-84bc-b9e1ac57e8ae
[2021-04-26T08:53:43.326Z] Java HTTP trigger processed a request.
[2021-04-26T08:53:43.329Z] Received invocation response for invocationId: 9a499277-61d0-4d2e-b68c-24210b3172a6 from workerId: 760295b9-ab89-4fbf-84bc-b9e1ac57e8ae
[2021-04-26T08:53:43.332Z] InvocationResponse received for invocation id: 9a499277-61d0-4d2e-b68c-24210b3172a6
[2021-04-26T08:53:43.354Z] Executed 'Functions.fixeddelayretry' (Failed, Id=9a499277-61d0-4d2e-b68c-24210b3172a6, Duration=21ms)
[2021-04-26T08:53:43.357Z] System.Private.CoreLib: Exception while executing function: Functions.fixeddelayretry. System.Private.CoreLib: Result: Failure
Exception: InvalidParameterException:
Stack: java.lang.reflect.InvocationTargetException
[2021-04-26T08:53:43.359Z]      at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
...
[2021-04-26T08:53:43.382Z] Caused by: java.security.InvalidParameterException
[2021-04-26T08:53:43.383Z]      at com.example.moris.Function.run(Function.java:30)
[2021-04-26T08:53:43.384Z]      ... 16 more
[2021-04-26T08:53:43.385Z] .
[2021-04-26T08:53:43.389Z] Executed HTTP request: {
[2021-04-26T08:53:43.391Z]   requestId: "31cc7ed4-4f9b-4a9e-a5d8-abb0f94d8eb3",
[2021-04-26T08:53:43.393Z]   identities: "",
[2021-04-26T08:53:43.393Z]   status: "500",
[2021-04-26T08:53:43.394Z]   duration: "4284"
[2021-04-26T08:53:43.395Z] }
```


# まとめ

現在のところ関数側で、リトライの回数とかは取得できなさそうでした。いずれ `context` インスタンス経由で取得できれば回数把握とかできていいんですけど。とはいえ、アノテーションで指定できるようになったので、積極的に使っていきたいですね。