Durable Orchestration is scheduled when receiving event instead of taking action

[jwalczakine]

Simplified version of orchestration is just awaiting for an external event and does some job after.

   [FunctionName(nameof(SaleTransactionWorkflow))]
        public async Task<SaleTransactionWorkflowResult> SaleTransactionWorkflow(
            [OrchestrationTrigger] IDurableOrchestrationContext context, ILogger log)
        {
         var saleRegisterInput = await context.WaitForExternalEvent<RegisterSaleTransactionInput>("SaleRegisteredTopic", TimeSpan.FromHours(6));
//does some more job
        }

This SaleTransactionWorkflow orchestration is part of another orchestration:

[FunctionName(nameof(ShoppingSessionWorkflow))]
        public async Task ShoppingSessionWorkflow([OrchestrationTrigger] IDurableOrchestrationContext context, ILogger log)
        {
 var saleTransactionWorkflowResult = await context.CallSubOrchestratorWithRetryAsync<SaleTransactionWorkflowResult>(
                nameof(SaleTransactionWorkflow),
                new RetryOptions(firstRetryInterval: TimeSpan.FromMilliseconds(1), int.MaxValue),
                saleTransactionWorkflowId, input);
         }

The event is called from another function:

[FunctionName(nameof(RegisterSaleTransaction))]
      public async Task<IActionResult> RegisterSaleTransaction(
          [HttpTrigger(AuthorizationLevel.Anonymous, "post", Route = "customer/shoppingSession/{shoppingSessionId}/sale/register")] HttpRequest req,
          [FromUri] Guid shoppingSessionId,
          [DurableClient] IDurableOrchestrationClient orchestrationClient,
          ILogger log)
      {
await orchestrationClient.RaiseEventAsync(ShoppingSessionOrchestration.OrchestrationId(shoppingSessionId),
                  ShoppingSessionOrchestration.SaleRegisteredTopic, registerSaleTransactionInput);
return new NoContentResult();
      }

The problem we experience is that sometimes our orchestraton gets an event but reacts after 15-30 seconds, second call to the same orchestration is usually faster - see the logs screenshot below:

We use consumption plan, we tried to keep functions warm pinging them, but nothing works. Where should we look now to find what causes this issue?

[davidmrdavid]

Thanks for reaching out @jwalczakine.

To summarize your question: you're asking why it takes ~15-30 seconds for your orchestrator to respond to the event that's raised against it?

To investigate further, we would benefit from having your orchestrator instanceID, your app name, and an incident timerange. Thanks!

[jwalczakine]

incident timerange ~ 5/31/2022, 09:34:20 PM - 09:34:51 PM. UTC TIME
Function App name: iXPosGO-Lewiatan-prod-Server-functionApp
orchestrator instanceID: 8c54bba0-458f-4f89-b11e-2a1000a22248

Some more logs from this orchestration instance: