概要
備忘録。
アクティビティ関数が同期的な関数のときの挙動を確認。
オーケストラ関数でawaitするときとawaitしないときの挙動を比較する。
結果
- クライアント関数では
StartNewAsync
の挙動は変わらず、すぐにインスタンスIDを返して終了する - オーケストラ関数でawaitするとき
- アクティビティ関数を順番に処理する
- for文の中でアクティビティ関数を呼び出す部分のtry-catchの挙動が怪しい(エラーが起きた後の関数でもcatchしている)
- オーケストラ関数でawaitしないとき
- 2020/11/19 追記: awaitしない場合、Durable Functionsとして正しく動作しない
- 最初にアクティビティ関数をすべて呼び出す
- すべてのアクティビティ関数の処理が終わったらオーケストラ関数は終了する
- for文の中でアクティビティ関数を呼び出す部分のtry-catchは機能しない
プログラム概要
- クライアント関数
- httpトリガー
- オーケストラ関数を呼び出しIDを返す
- オーケストラ関数
- 5回アクティビティ関数を呼び出す
- アクティビティ関数
- 開始時と終了時にログを出す
- 1秒待つ
- 4回目(i==3)のときに例外を投げる
オーケストラ関数でawaitするとき
using System;
using System.Collections.Generic;
using System.Net.Http;
using System.Threading.Tasks;
using Microsoft.Azure.WebJobs;
using Microsoft.Azure.WebJobs.Extensions.DurableTask;
using Microsoft.Azure.WebJobs.Extensions.Http;
using Microsoft.Extensions.Logging;
namespace FunctionApp1
{
public static class Function1
{
[FunctionName("Function1")]
public static async Task RunOrchestrator(
[OrchestrationTrigger] IDurableOrchestrationContext context, ILogger log)
{
var outputs = new List<string>();
for(var i = 0; i<5; i++)
{
try
{
await context.CallActivityAsync<string>("WaitTest", i);
}catch(Exception e)
{
log.LogError($"error orcestration: {i}", e);
}
}
}
[FunctionName("Function1_Hello")]
public static string SayHello([ActivityTrigger] string name, ILogger log)
{
log.LogInformation($"Saying hello to {name}.");
return $"Hello {name}!";
}
[FunctionName("Function1_HttpStart")]
public static async Task<HttpResponseMessage> HttpStart(
[HttpTrigger(AuthorizationLevel.Anonymous, "get", "post")] HttpRequestMessage req,
[DurableClient] IDurableOrchestrationClient starter,
ILogger log)
{
string instanceId = await starter.StartNewAsync("Function1", null);
log.LogInformation($"Started orchestration with ID = '{instanceId}'.");
return starter.CreateCheckStatusResponse(req, instanceId);
}
[FunctionName("WaitTest")]
public static void WaitTest([ActivityTrigger] int num, ILogger log)
{
log.LogInformation($"Wait start {num}.");
if (num == 3) throw new Exception($"wait test {num}");
System.Threading.Thread.Sleep(1000);
log.LogInformation($"Wait end {num}.");
}
}
}
awaitするときの実行結果
- 同期的な処理となっている
- errorがi=4のときにも
error 3
が出力されている
[2020-11-17T22:45:08.861Z] Started orchestration with ID = '10e0901243534d1f99e0641cd08d77e9'.
[2020-11-17T22:45:09.148Z] Wait start 0.
[2020-11-17T22:45:10.169Z] Wait end 0.
[2020-11-17T22:45:10.328Z] Wait start 1.
[2020-11-17T22:45:11.355Z] Wait end 1.
[2020-11-17T22:45:11.470Z] Wait start 2.
[2020-11-17T22:45:12.494Z] Wait end 2.
[2020-11-17T22:45:12.641Z] Wait start 3.
[2020-11-17T22:45:18.021Z] error orcestration: 3
[2020-11-17T22:45:18.069Z] Wait start 4.
[2020-11-17T22:45:19.106Z] Wait end 4.
[2020-11-17T22:45:19.280Z] error orcestration: 3
全文
For detailed output, run func with --verbose flag.
[2020-11-17T22:45:08.717Z] Executing 'Function1_HttpStart' (Reason='This function was programmatically called via the host APIs.', Id=ce826db7-2cb4-45cf-974a-3de4e391bda3)
[2020-11-17T22:45:08.861Z] Started orchestration with ID = '10e0901243534d1f99e0641cd08d77e9'.
[2020-11-17T22:45:08.922Z] Executed 'Function1_HttpStart' (Succeeded, Id=ce826db7-2cb4-45cf-974a-3de4e391bda3, Duration=228ms)
[2020-11-17T22:45:09.035Z] Executing 'Function1' (Reason='(null)', Id=75b89d74-1272-464a-9137-76adb266953c)
[2020-11-17T22:45:09.070Z] Executed 'Function1' (Succeeded, Id=75b89d74-1272-464a-9137-76adb266953c, Duration=37ms)
[2020-11-17T22:45:09.145Z] Executing 'WaitTest' (Reason='(null)', Id=ac67fc92-c1a3-4869-86a9-75a81a926258)
[2020-11-17T22:45:09.148Z] Wait start 0.
[2020-11-17T22:45:10.169Z] Wait end 0.
[2020-11-17T22:45:10.173Z] Executed 'WaitTest' (Succeeded, Id=ac67fc92-c1a3-4869-86a9-75a81a926258, Duration=1032ms)
[2020-11-17T22:45:10.276Z] Executing 'Function1' (Reason='(null)', Id=547e0ec9-7897-4871-986d-6b9719cd3ffd)
[2020-11-17T22:45:10.285Z] Executed 'Function1' (Succeeded, Id=547e0ec9-7897-4871-986d-6b9719cd3ffd, Duration=9ms)
[2020-11-17T22:45:10.324Z] Executing 'WaitTest' (Reason='(null)', Id=f065f601-30b1-48e8-89a6-ad5872727eef)
[2020-11-17T22:45:10.328Z] Wait start 1.
[2020-11-17T22:45:11.355Z] Wait end 1.
[2020-11-17T22:45:11.359Z] Executed 'WaitTest' (Succeeded, Id=f065f601-30b1-48e8-89a6-ad5872727eef, Duration=1036ms)
[2020-11-17T22:45:11.422Z] Executing 'Function1' (Reason='(null)', Id=90973633-b082-4049-87f1-e2707ab0d548)
[2020-11-17T22:45:11.428Z] Executed 'Function1' (Succeeded, Id=90973633-b082-4049-87f1-e2707ab0d548, Duration=6ms)
[2020-11-17T22:45:11.465Z] Executing 'WaitTest' (Reason='(null)', Id=de67afa0-bcd7-4576-a00e-82c13a273c81)
[2020-11-17T22:45:11.470Z] Wait start 2.
[2020-11-17T22:45:12.494Z] Wait end 2.
[2020-11-17T22:45:12.499Z] Executed 'WaitTest' (Succeeded, Id=de67afa0-bcd7-4576-a00e-82c13a273c81, Duration=1034ms)
[2020-11-17T22:45:12.594Z] Executing 'Function1' (Reason='(null)', Id=a5f60633-299e-4f21-b8b0-c99a1954c648)
[2020-11-17T22:45:12.600Z] Executed 'Function1' (Succeeded, Id=a5f60633-299e-4f21-b8b0-c99a1954c648, Duration=6ms)
[2020-11-17T22:45:12.636Z] Executing 'WaitTest' (Reason='(null)', Id=badcfeda-6f4c-4234-a363-73cbb6f69358)
[2020-11-17T22:45:12.641Z] Wait start 3.
[2020-11-17T22:45:17.759Z] Executed 'WaitTest' (Failed, Id=badcfeda-6f4c-4234-a363-73cbb6f69358, Duration=5122ms)
[2020-11-17T22:45:17.761Z] System.Private.CoreLib: Exception while executing function: WaitTest. FunctionApp1: wait test 3.
[2020-11-17T22:45:17.768Z] 10e0901243534d1f99e0641cd08d77e9: Function 'WaitTest (Activity)' failed with an error. Reason: System.Exception: wait test 3
[2020-11-17T22:45:17.772Z] at FunctionApp1.Function1.WaitTest(Int32 num, ILogger log) in D:\develop\develop\tutorial\lesson\ms-functions\durable-functions\FunctionApp1\FunctionApp1\Function1.cs:line 68
[2020-11-17T22:45:17.775Z] at lambda_method(Closure , Function1 , Object[] )
[2020-11-17T22:45:17.776Z] at Microsoft.Azure.WebJobs.Host.Executors.VoidMethodInvoker`2.InvokeAsync(TReflected instance, Object[] arguments) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\VoidMethodInvoker.cs:line 21
[2020-11-17T22:45:17.777Z] Host lock lease acquired by instance ID '00000000000000000000000089F91BFB'.
[2020-11-17T22:45:17.780Z] at Microsoft.Azure.WebJobs.Host.Executors.FunctionInvoker`2.InvokeAsync(Object instance, Object[] arguments) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionInvoker.cs:line 52
[2020-11-17T22:45:17.783Z] at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.InvokeAsync(IFunctionInvoker invoker, ParameterHelper parameterHelper, CancellationTokenSource timeoutTokenSource, CancellationTokenSource functionCancellationTokenSource, Boolean throwOnTimeout, TimeSpan timerInterval, IFunctionInstance instance) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:line 547
[2020-11-17T22:45:17.785Z] at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.ExecuteWithWatchersAsync(IFunctionInstanceEx instance, ParameterHelper parameterHelper, ILogger logger, CancellationTokenSource functionCancellationTokenSource) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:line 492
[2020-11-17T22:45:17.787Z] at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.ExecuteWithLoggingAsync(IFunctionInstanceEx instance, ParameterHelper parameterHelper, IFunctionOutputDefinition outputDefinition, ILogger logger, CancellationTokenSource functionCancellationTokenSource) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:line 438
[2020-11-17T22:45:17.789Z] at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.ExecuteWithLoggingAsync(IFunctionInstanceEx instance, FunctionStartedMessage message, FunctionInstanceLogEntry instanceLogEntry, ParameterHelper parameterHelper, ILogger logger, CancellationToken cancellationToken) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:line 245. IsReplay: False. State: Failed. HubName: TestHubName. AppName: . SlotName: . ExtensionVersion: 2.1.1. SequenceNumber: 19.
[2020-11-17T22:45:17.882Z] Executing 'Function1' (Reason='(null)', Id=7c939f14-4fec-4467-996d-5f1076176ea8)
[2020-11-17T22:45:18.021Z] error orcestration: 3
[2020-11-17T22:45:18.026Z] Executed 'Function1' (Succeeded, Id=7c939f14-4fec-4467-996d-5f1076176ea8, Duration=144ms)
[2020-11-17T22:45:18.062Z] Executing 'WaitTest' (Reason='(null)', Id=976ca6d2-3aa9-4ef8-a94e-8fb2a6e10b80)
[2020-11-17T22:45:18.069Z] Wait start 4.
[2020-11-17T22:45:19.106Z] Wait end 4.
[2020-11-17T22:45:19.110Z] Executed 'WaitTest' (Succeeded, Id=976ca6d2-3aa9-4ef8-a94e-8fb2a6e10b80, Duration=1048ms)
[2020-11-17T22:45:19.209Z] Executing 'Function1' (Reason='(null)', Id=25851548-8da8-40fb-9a38-a7658fdac60a)
[2020-11-17T22:45:19.280Z] error orcestration: 3
[2020-11-17T22:45:19.288Z] Executed 'Function1' (Succeeded, Id=25851548-8da8-40fb-9a38-a7658fdac60a, Duration=78ms)
awaitしない場合
[FunctionName("Function1")]
- public static async Task RunOrchestrator(
+ public static void RunOrchestrator(
[OrchestrationTrigger] IDurableOrchestrationContext context, ILogger log)
{
var outputs = new List<string>();
for(var i = 0; i<5; i++)
{
try
{
- await context.CallActivityAsync<string>("WaitTest", i);
+ context.CallActivityAsync<string>("WaitTest", i);
}catch(Exception e)
{
log.LogError($"error orcestration: {i}", e);
}
}
}
非同期でない場合実行結果
- 最初に一気に呼んで終わるのを待つ形になった
- オーケストラ関数ではerrorはキャッチできない
[2020-11-17T22:58:26.814Z] Started orchestration with ID = '7efeb6a870a2495391ca35b2f9632b07'.
[2020-11-17T22:58:27.094Z] Wait start 0.
[2020-11-17T22:58:27.101Z] Wait start 3.
[2020-11-17T22:58:29.292Z] Wait end 0.
[2020-11-17T22:58:29.317Z] Wait start 2.
[2020-11-17T22:58:29.343Z] Wait start 1.
[2020-11-17T22:58:29.365Z] Wait start 4.
[2020-11-17T22:58:29.378Z] Executed 'WaitTest' (Failed, Id=7039f7ae-4190-4ad5-9354-3ac191953465, Duration=2278ms)
[2020-11-17T22:58:29.382Z] System.Private.CoreLib: Exception while executing function: WaitTest. FunctionApp1: wait test 3.
[2020-11-17T22:58:30.345Z] Wait end 2.
[2020-11-17T22:58:30.375Z] Wait end 1.
[2020-11-17T22:58:30.391Z] Wait end 4.
[2020-11-17T22:58:30.461Z] Executing 'Function1' (Reason='(null)', Id=0cd7581d-3e7a-4393-a4c8-df32c9584be2)
[2020-11-17T22:58:30.469Z] Executed 'Function1' (Succeeded, Id=0cd7581d-3e7a-4393-a4c8-df32c9584be2, Duration=8ms)
全文
For detailed output, run func with --verbose flag.
[2020-11-17T22:58:26.685Z] Executing 'Function1_HttpStart' (Reason='This function was programmatically called via the host APIs.', Id=92b02247-1f19-44b1-bb65-6e8874464f00)
[2020-11-17T22:58:26.814Z] Started orchestration with ID = '7efeb6a870a2495391ca35b2f9632b07'.
[2020-11-17T22:58:26.864Z] Executed 'Function1_HttpStart' (Succeeded, Id=92b02247-1f19-44b1-bb65-6e8874464f00, Duration=199ms)
[2020-11-17T22:58:26.982Z] Executing 'Function1' (Reason='(null)', Id=3111f811-f08c-403a-8eb6-bffbfe30f622)
[2020-11-17T22:58:27.009Z] Executed 'Function1' (Succeeded, Id=3111f811-f08c-403a-8eb6-bffbfe30f622, Duration=29ms)
[2020-11-17T22:58:27.091Z] Executing 'WaitTest' (Reason='(null)', Id=fd9a0891-3d3f-4d09-9c95-97e69f3d29e9)
[2020-11-17T22:58:27.094Z] Wait start 0.
[2020-11-17T22:58:27.098Z] Executing 'WaitTest' (Reason='(null)', Id=7039f7ae-4190-4ad5-9354-3ac191953465)
[2020-11-17T22:58:27.101Z] Wait start 3.
[2020-11-17T22:58:29.292Z] Wait end 0.
[2020-11-17T22:58:29.296Z] Executing 'WaitTest' (Reason='(null)', Id=743ef8a2-861c-4ae4-871e-48fc24f6ff16)
[2020-11-17T22:58:29.315Z] Executed 'WaitTest' (Succeeded, Id=fd9a0891-3d3f-4d09-9c95-97e69f3d29e9, Duration=2226ms)
[2020-11-17T22:58:29.317Z] Wait start 2.
[2020-11-17T22:58:29.338Z] Executing 'WaitTest' (Reason='(null)', Id=eecc50ae-44eb-4281-81a7-f5445c820e40)
[2020-11-17T22:58:29.343Z] Wait start 1.
[2020-11-17T22:58:29.360Z] Executing 'WaitTest' (Reason='(null)', Id=62a79e09-f82f-4216-933c-c51b07c87623)
[2020-11-17T22:58:29.365Z] Wait start 4.
[2020-11-17T22:58:29.378Z] Executed 'WaitTest' (Failed, Id=7039f7ae-4190-4ad5-9354-3ac191953465, Duration=2278ms)
[2020-11-17T22:58:29.382Z] System.Private.CoreLib: Exception while executing function: WaitTest. FunctionApp1: wait test 3.
[2020-11-17T22:58:29.382Z] Host lock lease acquired by instance ID '00000000000000000000000089F91BFB'.
[2020-11-17T22:58:29.400Z] 7efeb6a870a2495391ca35b2f9632b07: Function 'WaitTest (Activity)' failed with an error. Reason: System.Exception: wait test 3
[2020-11-17T22:58:29.403Z] at FunctionApp1.Function1.WaitTest(Int32 num, ILogger log) in D:\develop\develop\tutorial\lesson\ms-functions\durable-functions\FunctionApp1\FunctionApp1\Function1.cs:line 67
[2020-11-17T22:58:29.406Z] at lambda_method(Closure , Function1 , Object[] )
[2020-11-17T22:58:29.408Z] at Microsoft.Azure.WebJobs.Host.Executors.VoidMethodInvoker`2.InvokeAsync(TReflected instance, Object[] arguments) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\VoidMethodInvoker.cs:line 21
[2020-11-17T22:58:29.410Z] at Microsoft.Azure.WebJobs.Host.Executors.FunctionInvoker`2.InvokeAsync(Object instance, Object[] arguments) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionInvoker.cs:line 52
[2020-11-17T22:58:29.413Z] at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.InvokeAsync(IFunctionInvoker invoker, ParameterHelper parameterHelper, CancellationTokenSource timeoutTokenSource, CancellationTokenSource functionCancellationTokenSource, Boolean throwOnTimeout, TimeSpan timerInterval, IFunctionInstance instance) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:line 547
[2020-11-17T22:58:29.415Z] at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.ExecuteWithWatchersAsync(IFunctionInstanceEx instance, ParameterHelper parameterHelper, ILogger logger, CancellationTokenSource functionCancellationTokenSource) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:line 492
[2020-11-17T22:58:29.417Z] at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.ExecuteWithLoggingAsync(IFunctionInstanceEx instance, ParameterHelper parameterHelper, IFunctionOutputDefinition outputDefinition, ILogger logger, CancellationTokenSource functionCancellationTokenSource) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:line 438
[2020-11-17T22:58:29.422Z] at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.ExecuteWithLoggingAsync(IFunctionInstanceEx instance, FunctionStartedMessage message, FunctionInstanceLogEntry instanceLogEntry, ParameterHelper parameterHelper, ILogger logger, CancellationToken cancellationToken) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:line 245. IsReplay: False. State: Failed. HubName: TestHubName. AppName: . SlotName: . ExtensionVersion: 2.1.1. SequenceNumber: 16.
[2020-11-17T22:58:29.481Z] Executing 'Function1' (Reason='(null)', Id=d194f00f-b4f4-4f95-9a4a-2d925867c237)
[2020-11-17T22:58:29.501Z] Executed 'Function1' (Succeeded, Id=d194f00f-b4f4-4f95-9a4a-2d925867c237, Duration=19ms)
[2020-11-17T22:58:30.345Z] Wait end 2.
[2020-11-17T22:58:30.350Z] Executed 'WaitTest' (Succeeded, Id=743ef8a2-861c-4ae4-871e-48fc24f6ff16, Duration=1054ms)
[2020-11-17T22:58:30.375Z] Wait end 1.
[2020-11-17T22:58:30.381Z] Executed 'WaitTest' (Succeeded, Id=eecc50ae-44eb-4281-81a7-f5445c820e40, Duration=1044ms)
[2020-11-17T22:58:30.391Z] Wait end 4.
[2020-11-17T22:58:30.395Z] Executed 'WaitTest' (Succeeded, Id=62a79e09-f82f-4216-933c-c51b07c87623, Duration=1035ms)
[2020-11-17T22:58:30.461Z] Executing 'Function1' (Reason='(null)', Id=0cd7581d-3e7a-4393-a4c8-df32c9584be2)
[2020-11-17T22:58:30.469Z] Executed 'Function1' (Succeeded, Id=0cd7581d-3e7a-4393-a4c8-df32c9584be2, Duration=8ms)
For分の先頭にログを追加
- コメントでアドバイスいただいたので、試してみる。
For分の先頭にログを追加した結果
- for文を繰り返し呼んでいることがわかる。
- 最後の4つ目の関数を呼んだ後も、もう一度呼んでいる
[2020-11-19T14:05:48.697Z] Started orchestration with ID = 'c17bd4ab817344dda9be1e2682dcea3f'.
[2020-11-19T14:05:48.895Z] Calling F0.
[2020-11-19T14:05:48.986Z] Wait start 0.
[2020-11-19T14:05:50.001Z] Wait end 0.
[2020-11-19T14:05:50.113Z] Calling F0.
[2020-11-19T14:05:50.119Z] Calling F1.
[2020-11-19T14:05:50.164Z] Wait start 1.
[2020-11-19T14:05:51.191Z] Wait end 1.
[2020-11-19T14:05:51.269Z] Calling F0.
[2020-11-19T14:05:51.274Z] Calling F1.
[2020-11-19T14:05:51.277Z] Calling F2.
[2020-11-19T14:05:51.331Z] Wait start 2.
[2020-11-19T14:05:52.352Z] Wait end 2.
[2020-11-19T14:05:52.423Z] Calling F0.
[2020-11-19T14:05:52.427Z] Calling F1.
[2020-11-19T14:05:52.433Z] Calling F2.
[2020-11-19T14:05:52.435Z] Calling F3.
[2020-11-19T14:05:52.486Z] Wait start 3.
[2020-11-19T14:05:58.539Z] Calling F0.
[2020-11-19T14:05:58.542Z] Calling F1.
[2020-11-19T14:05:58.544Z] Calling F2.
[2020-11-19T14:05:58.546Z] Calling F3.
[2020-11-19T14:05:58.680Z] error orcestration: 3
[2020-11-19T14:05:58.684Z] Calling F4.
[2020-11-19T14:05:58.731Z] Wait start 4.
[2020-11-19T14:05:59.742Z] Wait end 4.
[2020-11-19T14:05:59.817Z] Calling F0.
[2020-11-19T14:05:59.820Z] Calling F1.
[2020-11-19T14:05:59.822Z] Calling F2.
[2020-11-19T14:05:59.824Z] Calling F3.
[2020-11-19T14:05:59.889Z] error orcestration: 3
[2020-11-19T14:05:59.894Z] Calling F4.
実行するときだけログを出す。
if (!context.IsReplaying)
を追加する。
for (var i = 0; i < 5; i++)
{
if (!context.IsReplaying) log.LogInformation($"Calling F{i}.");
try
{
await context.CallActivityAsync<string>("WaitTest", i);
}
catch (Exception e)
{
if (!context.IsReplaying) log.LogError($"error orcestration: {i}", e);
}
}
実行するときだけログを出す結果
- errorが3の時だけ出力され、期待する結果となっている。
[2020-11-19T14:13:45.582Z] Wait start 0.
[2020-11-19T14:13:46.604Z] Wait end 0.
[2020-11-19T14:13:46.707Z] Calling F1.
[2020-11-19T14:13:46.759Z] Wait start 1.
[2020-11-19T14:13:47.776Z] Wait end 1.
[2020-11-19T14:13:47.855Z] Calling F2.
[2020-11-19T14:13:47.858Z] Executed 'Function1' (Succeeded, Id=bab7f475-549c-494e-ac25-5248a08e1e6c, Duration=9ms)
[2020-11-19T14:13:47.899Z] Executing 'WaitTest' (Reason='(null)', Id=b2717391-6010-4286-9fac-7bd0a0323282)
[2020-11-19T14:13:47.904Z] Wait start 2.
[2020-11-19T14:13:48.936Z] Wait end 2.
[2020-11-19T14:13:49.008Z] Calling F3.
[2020-11-19T14:13:49.052Z] Wait start 3.
[2020-11-19T14:13:51.638Z] error orcestration: 3
[2020-11-19T14:13:51.646Z] Calling F4.
[2020-11-19T14:13:51.690Z] Wait start 4.
[2020-11-19T14:13:52.705Z] Wait end 4.
[2020-11-19T14:13:52.709Z] Executed 'WaitTest' (Succeeded, Id=2610c850-123d-4f49-9290-0ccd9de8e9df, Duration=1024ms)
[2020-11-19T14:13:52.798Z] Executing 'Function1' (Reason='(null)', Id=fdb78d86-de88-4dca-9c87-722315dabef4)
[2020-11-19T14:13:52.874Z] Executed 'Function1' (Succeeded, Id=fdb78d86-de88-4dca-9c87-722315dabef4, Duration=76ms)
実行するときだけログを出す(パターン2)
log = context.CreateReplaySafeLogger(log);
でもいける。
実行結果は同じなので割愛。
log = context.CreateReplaySafeLogger(log);
for (var i = 0; i < 5; i++)
{
log.LogInformation($"Calling F{i}.");
try
{
await context.CallActivityAsync<string>("WaitTest", i);
}
catch (Exception e)
{
log.LogError($"error orcestration: {i}", e);
}
}
まとめてawaitするとき
[FunctionName("Function1")]
public static async Task RunOrchestrator(
[OrchestrationTrigger] IDurableOrchestrationContext context, ILogger log)
{
log = context.CreateReplaySafeLogger(log);
var tasks = new List<Task>();
for (var i = 0; i < 5; i++)
{
log.LogInformation($"Calling F{i}.");
try
{
tasks.Add(context.CallActivityAsync<string>("WaitTest", i));
}
catch (Exception e)
{
log.LogError($"error orcestration: {i}", e);
}
}
try
{
await Task.WhenAll(tasks);
}
catch(Exception e)
{
log.LogError($"when all error", e);
}
}
まとめてawaitした実行結果
- 最初に全部呼んで、ばらばらにアクティビティは動くパターンとなった。
- catchはWhenAllのほうで行われる
[2020-11-19T14:25:59.938Z] Calling F0.
[2020-11-19T14:25:59.952Z] Calling F1.
[2020-11-19T14:25:59.955Z] Calling F2.
[2020-11-19T14:25:59.958Z] Calling F3.
[2020-11-19T14:25:59.959Z] Calling F4.
[2020-11-19T14:26:00.051Z] Wait start 0.
[2020-11-19T14:26:00.058Z] Wait start 1.
[2020-11-19T14:26:00.075Z] Wait start 3.
[2020-11-19T14:26:02.636Z] Wait end 0.
[2020-11-19T14:26:02.644Z] Wait end 1.
[2020-11-19T14:26:02.659Z] Wait start 2.
[2020-11-19T14:26:02.676Z] Wait start 4.
[2020-11-19T14:26:03.703Z] Wait end 2.
[2020-11-19T14:26:03.712Z] Wait end 4.
[2020-11-19T14:32:15.312Z] when all error
全文
For detailed output, run func with --verbose flag.
[2020-11-19T14:32:06.804Z] Host lock lease acquired by instance ID '00000000000000000000000089F91BFB'.[2020-11-19T14:32:08.546Z] Executing 'Function1_HttpStart' (Reason='This function was programmatically called via the host APIs.', Id=7630dc7b-565e-4305-8b13-64a18f0e3761)
[2020-11-19T14:32:12.068Z] Started orchestration with ID = '0bd466ef3f0148279a04c2dfe76d86fb'.
[2020-11-19T14:32:12.118Z] Executed 'Function1_HttpStart' (Succeeded, Id=7630dc7b-565e-4305-8b13-64a18f0e3761, Duration=3597ms)
[2020-11-19T14:32:12.207Z] Executing 'Function1' (Reason='(null)', Id=c69648c0-c355-4c4f-957d-1e79b9f2e6e6)
[2020-11-19T14:32:12.220Z] Calling F0.
[2020-11-19T14:32:12.232Z] Calling F1.
[2020-11-19T14:32:12.234Z] Calling F2.
[2020-11-19T14:32:12.236Z] Calling F3.
[2020-11-19T14:32:12.238Z] Calling F4.
[2020-11-19T14:32:12.244Z] Executed 'Function1' (Succeeded, Id=c69648c0-c355-4c4f-957d-1e79b9f2e6e6, Duration=40ms)
[2020-11-19T14:32:12.312Z] Executing 'WaitTest' (Reason='(null)', Id=4a059f44-9e92-4c27-9d41-d7782bcafe0d)
[2020-11-19T14:32:12.316Z] Wait start 0.
[2020-11-19T14:32:12.320Z] Executing 'WaitTest' (Reason='(null)', Id=98aae882-8adc-4ea2-917b-41026a1d663e)
[2020-11-19T14:32:12.323Z] Wait start 1.
[2020-11-19T14:32:12.337Z] Executing 'WaitTest' (Reason='(null)', Id=3f8ec10e-0760-49b0-984c-62ae56d5fa6d)
[2020-11-19T14:32:12.339Z] Wait start 2.
[2020-11-19T14:32:12.349Z] Executing 'WaitTest' (Reason='(null)', Id=d85f4681-bef5-4d6b-b33b-25e00a1ea332)
[2020-11-19T14:32:12.352Z] Wait start 3.
[2020-11-19T14:32:14.046Z] Wait end 1.
[2020-11-19T14:32:14.046Z] Wait end 0.
[2020-11-19T14:32:14.046Z] Wait end 2.
[2020-11-19T14:32:14.048Z] Executing 'WaitTest' (Reason='(null)', Id=b464b72c-eb76-4bc7-99b3-7fa1e2805360)
[2020-11-19T14:32:14.053Z] Executed 'WaitTest' (Succeeded, Id=98aae882-8adc-4ea2-917b-41026a1d663e, Duration=1733ms)
[2020-11-19T14:32:14.056Z] Executed 'WaitTest' (Succeeded, Id=4a059f44-9e92-4c27-9d41-d7782bcafe0d, Duration=1746ms)
[2020-11-19T14:32:14.058Z] Executed 'WaitTest' (Succeeded, Id=3f8ec10e-0760-49b0-984c-62ae56d5fa6d, Duration=1722ms)
[2020-11-19T14:32:14.063Z] Wait start 4.
[2020-11-19T14:32:14.123Z] Executed 'WaitTest' (Failed, Id=d85f4681-bef5-4d6b-b33b-25e00a1ea332, Duration=1772ms)
[2020-11-19T14:32:14.126Z] System.Private.CoreLib: Exception while executing function: WaitTest. FunctionApp1: wait test 3.
[2020-11-19T14:32:14.135Z] 0bd466ef3f0148279a04c2dfe76d86fb: Function 'WaitTest (Activity)' failed with an error. Reason: System.Exception: wait test 3
[2020-11-19T14:32:14.140Z] at FunctionApp1.Function1.WaitTest(Int32 num, ILogger log) in D:\develop\develop\tutorial\lesson\ms-functions\durable-functions\FunctionApp1\FunctionApp1\Function1.cs:line 81
[2020-11-19T14:32:14.143Z] at lambda_method(Closure , Function1 , Object[] )
[2020-11-19T14:32:14.145Z] at Microsoft.Azure.WebJobs.Host.Executors.VoidMethodInvoker`2.InvokeAsync(TReflected instance, Object[] arguments) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\VoidMethodInvoker.cs:line 21
[2020-11-19T14:32:14.149Z] at Microsoft.Azure.WebJobs.Host.Executors.FunctionInvoker`2.InvokeAsync(Object instance, Object[] arguments) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionInvoker.cs:line 52
[2020-11-19T14:32:14.160Z] at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.InvokeAsync(IFunctionInvoker invoker, ParameterHelper parameterHelper, CancellationTokenSource timeoutTokenSource, CancellationTokenSource functionCancellationTokenSource, Boolean throwOnTimeout, TimeSpan timerInterval, IFunctionInstance instance) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:line 547
[2020-11-19T14:32:14.164Z] at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.ExecuteWithWatchersAsync(IFunctionInstanceEx instance, ParameterHelper parameterHelper, ILogger logger, CancellationTokenSource functionCancellationTokenSource) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:line 492
[2020-11-19T14:32:14.167Z] at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.ExecuteWithLoggingAsync(IFunctionInstanceEx instance, ParameterHelper parameterHelper, IFunctionOutputDefinition outputDefinition, ILogger logger, CancellationTokenSource functionCancellationTokenSource) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:line 438
[2020-11-19T14:32:14.172Z] at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.ExecuteWithLoggingAsync(IFunctionInstanceEx instance, FunctionStartedMessage message, FunctionInstanceLogEntry instanceLogEntry, ParameterHelper parameterHelper, ILogger logger, CancellationToken cancellationToken) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:line 245. IsReplay: False. State: Failed. HubName: TestHubName. AppName: . SlotName: . ExtensionVersion: 2.1.1. SequenceNumber: 18.
[2020-11-19T14:32:14.239Z] Executing 'Function1' (Reason='(null)', Id=3faf90b2-300a-44ff-b772-70da77ab00bb)
[2020-11-19T14:32:14.250Z] Executed 'Function1' (Succeeded, Id=3faf90b2-300a-44ff-b772-70da77ab00bb, Duration=10ms)
[2020-11-19T14:32:14.376Z] Executing 'Function1' (Reason='(null)', Id=c3a58494-b865-4a33-867f-0f71eba0585e)
[2020-11-19T14:32:14.396Z] Executed 'Function1' (Succeeded, Id=c3a58494-b865-4a33-867f-0f71eba0585e, Duration=20ms)
[2020-11-19T14:32:15.080Z] Wait end 4.
[2020-11-19T14:32:15.085Z] Executed 'WaitTest' (Succeeded, Id=b464b72c-eb76-4bc7-99b3-7fa1e2805360, Duration=1036ms)
[2020-11-19T14:32:15.172Z] Executing 'Function1' (Reason='(null)', Id=185d3a9b-4cbc-4354-9667-b8bb9f8d2cb4)
[2020-11-19T14:32:15.312Z] when all error
[2020-11-19T14:32:15.320Z] Executed 'Function1' (Succeeded, Id=185d3a9b-4cbc-4354-9667-b8bb9f8d2cb4, Duration=149ms)
オーケストレータを複数呼んでみる
- 引数を渡すために、NugetからMicrosoft.Azure.Extensions.DurableTaskのバージョンを
2.1.1
から2.3.1
、Microsoft.NET.Sdk.Functionsを3.0.11に上げた。-
Task<string> StartNewAsync<T>(string orchestratorFunctionName, string instanceId, T input);
しかなかった
-
[FunctionName("Function1_HttpStart")]
public static async Task<HttpResponseMessage> HttpStart(
[HttpTrigger(AuthorizationLevel.Anonymous, "get", "post")] HttpRequestMessage req,
[DurableClient] IDurableOrchestrationClient starter,
ILogger log)
{
// Function input comes from the request content.
var list = new List<string>();
for(var i=0; i < 5; i++)
{
string instanceId = await starter.StartNewAsync<string>("Function1", i.ToString());
log.LogInformation($"Started orchestration with ID = '{instanceId}'.");
list.Add(instanceId);
}
return starter.CreateCheckStatusResponse(req, string.Join(',', list));
}
[FunctionName("Function1")]
public static async Task RunOrchestrator(
[OrchestrationTrigger] IDurableOrchestrationContext context, ILogger log)
{
log = context.CreateReplaySafeLogger(log);
var i = context.GetInput<int>();
try
{
await context.CallActivityAsync("WaitTest", i);
}
catch (Exception e)
{
log.LogError($"error orcestration: {i}", e);
}
}
オーケストレータを複数呼んだときの実行結果
- 結果はあまり変わらない。若干、こちらのほうが負荷がかかっているように感じた。
[2020-11-19T14:55:29.943Z] Started orchestration with ID = '1e7957a7c9c34db1a91a03902a05ca37'.
[2020-11-19T14:55:30.018Z] Started orchestration with ID = '9897b34ea1cc4ca5b8c33f86361499d2'.
[2020-11-19T14:55:30.079Z] Started orchestration with ID = '84f3b2ea0c884df486aad5d9442c4171'.
[2020-11-19T14:55:30.145Z] Started orchestration with ID = 'ce604295b19f462eafcac8936af10d4c'.
[2020-11-19T14:55:30.200Z] Started orchestration with ID = '1303791230e547ada8fed167ab3e2e35'.
[2020-11-19T14:55:30.331Z] Wait start 0.
[2020-11-19T14:55:30.338Z] Wait start 1.
[2020-11-19T14:55:30.394Z] Wait start 4.
[2020-11-19T14:55:30.407Z] Wait start 2.
[2020-11-19T14:55:30.426Z] Wait start 3.
[2020-11-19T14:55:35.317Z] Wait end 1.
[2020-11-19T14:55:35.317Z] Wait end 2.
[2020-11-19T14:55:35.318Z] Wait end 0.
[2020-11-19T14:55:35.317Z] Wait end 4.
[2020-11-19T14:55:35.788Z] error orcestration: 3
全文
For detailed output, run func with --verbose flag.
[2020-11-19T14:55:29.806Z] Executing 'Function1_HttpStart' (Reason='This function was programmatically called via the host APIs.', Id=d7836646-1daf-4935-801a-4195a0de0702)
[2020-11-19T14:55:29.943Z] Started orchestration with ID = '1e7957a7c9c34db1a91a03902a05ca37'.
[2020-11-19T14:55:30.018Z] Started orchestration with ID = '9897b34ea1cc4ca5b8c33f86361499d2'.
[2020-11-19T14:55:30.079Z] Started orchestration with ID = '84f3b2ea0c884df486aad5d9442c4171'.
[2020-11-19T14:55:30.131Z] Executing 'Function1' (Reason='(null)', Id=cba6690f-0c95-41da-8ce1-52e30c39db06)
[2020-11-19T14:55:30.131Z] Executing 'Function1' (Reason='(null)', Id=0bd50b15-542e-44fa-9111-9141200867ed)
[2020-11-19T14:55:30.131Z] Executing 'Function1' (Reason='(null)', Id=f7e9eaa8-b512-4b96-b0aa-26f10620d6a2)
[2020-11-19T14:55:30.136Z] Executing 'Function1' (Reason='(null)', Id=a9678e18-aba0-40f2-8d5e-0b4bcfc5ee76)
[2020-11-19T14:55:30.145Z] Started orchestration with ID = 'ce604295b19f462eafcac8936af10d4c'.
[2020-11-19T14:55:30.198Z] Executed 'Function1' (Succeeded, Id=cba6690f-0c95-41da-8ce1-52e30c39db06, Duration=57ms)
[2020-11-19T14:55:30.198Z] Executed 'Function1' (Succeeded, Id=f7e9eaa8-b512-4b96-b0aa-26f10620d6a2, Duration=57ms)
[2020-11-19T14:55:30.198Z] Executed 'Function1' (Succeeded, Id=0bd50b15-542e-44fa-9111-9141200867ed, Duration=57ms)
[2020-11-19T14:55:30.198Z] Executed 'Function1' (Succeeded, Id=a9678e18-aba0-40f2-8d5e-0b4bcfc5ee76, Duration=48ms)
[2020-11-19T14:55:30.200Z] Started orchestration with ID = '1303791230e547ada8fed167ab3e2e35'.
[2020-11-19T14:55:30.213Z] Executing 'Function1' (Reason='(null)', Id=426d46dc-0d7f-4e1e-b42e-19ad66261598)
[2020-11-19T14:55:30.218Z] Executed 'Function1' (Succeeded, Id=426d46dc-0d7f-4e1e-b42e-19ad66261598, Duration=5ms)
[2020-11-19T14:55:30.226Z] Executed 'Function1_HttpStart' (Succeeded, Id=d7836646-1daf-4935-801a-4195a0de0702, Duration=452ms)
[2020-11-19T14:55:30.319Z] Executing 'WaitTest' (Reason='(null)', Id=329996d7-a4d8-48da-89e8-a211f7d2f8a6)
[2020-11-19T14:55:30.331Z] Executing 'WaitTest' (Reason='(null)', Id=43ab802c-1622-426f-b68c-9be79d3b9bf1)
[2020-11-19T14:55:30.331Z] Wait start 0.
[2020-11-19T14:55:30.338Z] Wait start 1.
[2020-11-19T14:55:30.368Z] Executing 'WaitTest' (Reason='(null)', Id=29aaacea-6941-4d09-a9be-9a76572bc1c3)
[2020-11-19T14:55:30.394Z] Wait start 4.
[2020-11-19T14:55:30.402Z] Executing 'WaitTest' (Reason='(null)', Id=47a061b1-f185-45df-9fd8-229d362ce3e9)
[2020-11-19T14:55:30.407Z] Wait start 2.
[2020-11-19T14:55:30.422Z] Executing 'WaitTest' (Reason='(null)', Id=48b51618-b7fc-4010-a85a-9375bdaa4fff)
[2020-11-19T14:55:30.426Z] Wait start 3.
[2020-11-19T14:55:35.317Z] Wait end 1.
[2020-11-19T14:55:35.317Z] Wait end 2.
[2020-11-19T14:55:35.336Z] Executed 'WaitTest' (Succeeded, Id=43ab802c-1622-426f-b68c-9be79d3b9bf1, Duration=5008ms)
[2020-11-19T14:55:35.318Z] Wait end 0.
[2020-11-19T14:55:35.317Z] Wait end 4.
[2020-11-19T14:55:35.345Z] Executed 'WaitTest' (Succeeded, Id=329996d7-a4d8-48da-89e8-a211f7d2f8a6, Duration=5032ms)
[2020-11-19T14:55:35.341Z] Executed 'WaitTest' (Succeeded, Id=47a061b1-f185-45df-9fd8-229d362ce3e9, Duration=4938ms)
[2020-11-19T14:55:35.352Z] Executed 'WaitTest' (Succeeded, Id=29aaacea-6941-4d09-a9be-9a76572bc1c3, Duration=4984ms)
[2020-11-19T14:55:35.430Z] Executed 'WaitTest' (Failed, Id=48b51618-b7fc-4010-a85a-9375bdaa4fff, Duration=5006ms)
[2020-11-19T14:55:35.436Z] System.Private.CoreLib: Exception while executing function: WaitTest. FunctionApp1: wait test 3.
[2020-11-19T14:55:35.458Z] ce604295b19f462eafcac8936af10d4c: Function 'WaitTest (Activity)' failed with an error. Reason: System.Exception: wait test 3
[2020-11-19T14:55:35.461Z] at FunctionApp1.Function1.WaitTest(Int32 num, ILogger log) in D:\develop\develop\tutorial\lesson\ms-functions\durable-functions\FunctionApp1\FunctionApp1\Function1.cs:line 72
[2020-11-19T14:55:35.463Z] at lambda_method(Closure , Function1 , Object[] )
[2020-11-19T14:55:35.465Z] at Microsoft.Azure.WebJobs.Host.Executors.VoidMethodInvoker`2.InvokeAsync(TReflected instance, Object[] arguments) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\VoidMethodInvoker.cs:line 21
[2020-11-19T14:55:35.468Z] at Microsoft.Azure.WebJobs.Host.Executors.FunctionInvoker`2.InvokeAsync(Object instance, Object[] arguments) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionInvoker.cs:line 52
[2020-11-19T14:55:35.471Z] at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.InvokeAsync(IFunctionInvoker invoker, ParameterHelper parameterHelper, CancellationTokenSource timeoutTokenSource, CancellationTokenSource functionCancellationTokenSource, Boolean throwOnTimeout, TimeSpan timerInterval, IFunctionInstance instance) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:line 547
[2020-11-19T14:55:35.474Z] at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.ExecuteWithWatchersAsync(IFunctionInstanceEx instance, ParameterHelper parameterHelper, ILogger logger, CancellationTokenSource functionCancellationTokenSource) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:line 492
[2020-11-19T14:55:35.475Z] Host lock lease acquired by instance ID '00000000000000000000000089F91BFB'.
[2020-11-19T14:55:35.476Z] at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.ExecuteWithLoggingAsync(IFunctionInstanceEx instance, ParameterHelper parameterHelper, IFunctionOutputDefinition outputDefinition, ILogger logger, CancellationTokenSource functionCancellationTokenSource) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:line 438
[2020-11-19T14:55:35.480Z] at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.ExecuteWithLoggingAsync(IFunctionInstanceEx instance, FunctionStartedMessage message, FunctionInstanceLogEntry instanceLogEntry, ParameterHelper parameterHelper, ILogger logger, CancellationToken cancellationToken) in C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:line 245. IsReplay: False. State: Failed. HubName: TestHubName. AppName: . SlotName: . ExtensionVersion: 2.3.1. SequenceNumber: 31. TaskEventId: 0
[2020-11-19T14:55:35.628Z] Executing 'Function1' (Reason='(null)', Id=dca3fa6f-30f6-4ad7-a814-e3eaeb980b86)
[2020-11-19T14:55:35.629Z] Executing 'Function1' (Reason='(null)', Id=a0b174b2-87f1-48ac-adcf-65d9bc2af27b)
[2020-11-19T14:55:35.629Z] Executing 'Function1' (Reason='(null)', Id=f5fe360c-c3fa-4347-9b1d-4646d4715cde)
[2020-11-19T14:55:35.629Z] Executing 'Function1' (Reason='(null)', Id=b89674e7-eb2c-414c-a93a-85ea799b3f5e)
[2020-11-19T14:55:35.628Z] Executing 'Function1' (Reason='(null)', Id=7cb6d125-fa37-4206-8065-e315d6f8838b)
[2020-11-19T14:55:35.646Z] Executed 'Function1' (Succeeded, Id=b89674e7-eb2c-414c-a93a-85ea799b3f5e, Duration=17ms)
[2020-11-19T14:55:35.646Z] Executed 'Function1' (Succeeded, Id=a0b174b2-87f1-48ac-adcf-65d9bc2af27b, Duration=17ms)
[2020-11-19T14:55:35.646Z] Executed 'Function1' (Succeeded, Id=7cb6d125-fa37-4206-8065-e315d6f8838b, Duration=17ms)
[2020-11-19T14:55:35.646Z] Executed 'Function1' (Succeeded, Id=dca3fa6f-30f6-4ad7-a814-e3eaeb980b86, Duration=17ms)
[2020-11-19T14:55:35.788Z] error orcestration: 3
[2020-11-19T14:55:35.792Z] Executed 'Function1' (Succeeded, Id=f5fe360c-c3fa-4347-9b1d-4646d4715cde, Duration=163ms)