Diagnosticare e risolvere i problemi in Durable Functions

Durable Functions offre diversi strumenti di diagnostica per la risoluzione dei problemi di orchestrazione. Questo articolo illustra come configurare il rilevamento e la registrazione, scrivere codice sicuro per la riproduzione, esaminare le tracce distribuite ed eseguire il debug in locale.

In questo articolo vengono illustrate le operazioni seguenti:

• Configurare il rilevamento di Application Insights per gli eventi del ciclo di vita
• Eseguire query sulle istanze di orchestrazione con Kusto
• Abilitare la registrazione di Durable Task Framework (DTFx) per la diagnostica di basso livello
• Imposta il tracciamento distribuito per visualizzare flussi orchestrativi end-to-end
• Scrivere log sicuri al riavvio nelle funzioni di orchestrazione
• Segnalare lo stato di orchestrazione personalizzato ai client esterni
• Effettuare il debug di orchestrazioni in locale con punti di interruzione

Configurare il rilevamento di Application Insights

Application Insights è il modo consigliato per monitorare Durable Functions. L'estensione Durable genera eventi di rilevamento che consentono di tracciare l'esecuzione end-to-end di un'orchestrazione. È possibile trovare ed eseguire query su questi eventi di rilevamento usando lo strumento Application Insights Analytics nel portale di Azure.

Configurazione a livello di log

Configurare la verbosità dei dati di tracciamento inviati a Application Insights nel file host.json :

{
    "logging": {
        "logLevel": {
            "Host.Triggers.DurableTask": "Information",
        },
    }
}

Per impostazione predefinita vengono generati tutti gli eventi di rilevamento senza riesecuzione. È possibile ridurre il volume di dati impostando su Host.Triggers.DurableTask"Warning" o "Error", il che significa che gli eventi di rilevamento vengono generati solo per situazioni eccezionali. Per abilitare l'emissione degli eventi di riproduzione verbosi dell'orchestrazione, impostare logReplayEvents su true nel file di configurazione host.json.

Registrazione di input e output

Per impostazione predefinita, gli input e gli output delle funzioni orchestratore, attività ed entità non vengono registrati. Questo approccio è consigliato perché la registrazione di input e output potrebbe aumentare i costi di Application Insights. I payload di input e output delle funzioni possono contenere anche informazioni riservate. Vengono invece registrati il numero di byte per gli input e gli output delle funzioni. Se si desidera che l'estensione Durable Functions registri i payload di input e output completi, impostare la proprietà traceInputsAndOutputs su true nel file di configurazione host.json.

Eseguire query su istanze di orchestrazione

Usare le query Kusto seguenti in Application Insights Analytics per esaminare le istanze di orchestrazione.

Query per singola istanza

La query seguente mostra i dati di rilevamento cronologici per una singola istanza di orchestrazione della funzione Hello Sequence. Esclude la riesecuzione in modo da mostrare solo il percorso di esecuzione logico. È possibile ordinare gli eventi ordinando in base timestamp a e sequenceNumber come illustrato nella query seguente:

let targetInstanceId = "ddd1aaa685034059b545eb004b15d4eb";
let start = datetime(2018-03-25T09:20:00);
traces
| where timestamp > start and timestamp < start + 30m
| where customDimensions.Category == "Host.Triggers.DurableTask"
| extend functionName = customDimensions["prop__functionName"]
| extend instanceId = customDimensions["prop__instanceId"]
| extend state = customDimensions["prop__state"]
| extend isReplay = tobool(tolower(customDimensions["prop__isReplay"]))
| extend sequenceNumber = tolong(customDimensions["prop__sequenceNumber"])
| where isReplay != true
| where instanceId == targetInstanceId
| sort by timestamp asc, sequenceNumber asc
| project timestamp, functionName, state, instanceId, sequenceNumber, appName = cloud_RoleName

Il risultato è un elenco di eventi di traccia che mostrano il percorso di esecuzione dell'orchestrazione, incluse eventuali funzioni di attività ordinate per ora di esecuzione in ordine ascendente.

Query di riepilogo dell'istanza

La query seguente mostra lo stato di tutte le istanze di orchestrazione eseguite in un intervallo di tempo specificato.

let start = datetime(2017-09-30T04:30:00);
traces
| where timestamp > start and timestamp < start + 1h
| where customDimensions.Category == "Host.Triggers.DurableTask"
| extend functionName = tostring(customDimensions["prop__functionName"])
| extend instanceId = tostring(customDimensions["prop__instanceId"])
| extend state = tostring(customDimensions["prop__state"])
| extend isReplay = tobool(tolower(customDimensions["prop__isReplay"]))
| extend output = tostring(customDimensions["prop__output"])
| where isReplay != true
| summarize arg_max(timestamp, *) by instanceId
| project timestamp, instanceId, functionName, state, output, appName = cloud_RoleName
| order by timestamp asc

Il risultato è un elenco di ID istanza e dello stato di runtime corrente.

Riferimento ai dati di rilevamento

Ogni istanza di orchestrazione genera eventi di monitoraggio mentre avanza nel suo ciclo di vita. Ogni evento del ciclo di vita contiene un payload customDimensions con diversi campi. Ai nomi dei campi viene anteposta la stringa prop__.

Registrazione di Durable Task Framework (DTFx)

I log delle estensioni permanenti sono utili per comprendere il comportamento della logica di orchestrazione. Tuttavia, questi log non contengono sempre informazioni sufficienti per eseguire il debug di problemi di affidabilità e prestazioni a livello di framework. A partire dalla versione 2.3.0 dell'estensione Durable, per la raccolta sono disponibili anche i log generati da Durable Task Framework (DTFx) sottostante.

Quando si esaminano i log generati da DTFx, è importante comprendere che il motore DTFx ha due componenti: il motore di distribuzione principale (DurableTask.Core) e uno dei molti provider di archiviazione supportati.

È possibile abilitare questi log aggiornando la sezione logging/logLevel del file dell'app per le funzioni host.json. Nell'esempio seguente viene illustrato come abilitare i log degli avvisi e degli errori da DurableTask.Core e DurableTask.AzureStorage:

{
  "version": "2.0",
  "logging": {
    "logLevel": {
      "DurableTask.AzureStorage": "Warning",
      "DurableTask.Core": "Warning"
    }
  }
}

Se Application Insights è abilitato, questi log vengono aggiunti automaticamente alla trace raccolta. È possibile cercarli nello stesso modo in cui si cercano altri trace log usando query Kusto.

La query Kusto seguente illustra come eseguire query per i log DTFx. La parte più importante della query è where customerDimensions.Category startswith "DurableTask" perché filtra i risultati nei log nelle categorie DurableTask.Core e DurableTask.AzureStorage.

traces
| where customDimensions.Category startswith "DurableTask"
| project
    timestamp,
    severityLevel,
    Category = customDimensions.Category,
    EventId = customDimensions.EventId,
    message,
    customDimensions
| order by timestamp asc 

Il risultato è un set di log scritti dai provider di log Durable Task Framework.

Per ulteriori informazioni sugli eventi di log disponibili, consultare la documentazione sulla registrazione strutturata del Durable Task Framework su GitHub.

Tracciamento distribuito

La traccia distribuita tiene traccia delle richieste e mostra in che modo i diversi servizi interagiscono tra loro. In Durable Functions correla le orchestrazioni, le entità e le attività insieme. La traccia distribuita mostra il tempo di esecuzione per ogni passaggio di orchestrazione relativo all'intera orchestrazione e identifica dove si verificano problemi o eccezioni. Questa funzionalità è supportata in Application Insights per tutte le lingue e i provider di archiviazione.

Prerequisiti

Il tracing distribuito richiede specifiche versioni minime dell'estensione.

• Per le app isolate .NET, Microsoft.Azure.Functions.Worker.Extensions.DurableTask>= v1.4.0.
• Per le app non .NET, seguire queste istruzioni per installare manualmente Microsoft.Azure. WebJobs.Extensions.DurableTask>= v3.2.0 per il momento. La tracciabilità distribuita sarà disponibile nei pacchetti di estensioni >v4.24.x.

Configurazione della traccia distribuita

Per configurare il tracciamento distribuito, aggiornare host.json e impostare una risorsa di Application Insights.

host.json

{
   "extensions": {
     "durableTask": {
       "tracing": {
         "distributedTracingEnabled": true,
         "version": "V2"
       }
     }
   }
 }

Approfondimenti sulle Applicazioni

Configurare l'app per le funzioni con una risorsa di Application Insights.

Controllo delle tracce

Nella risorsa di Application Insights passare a Ricerca transazioni. Nei risultati, cercare gli eventi Request e Dependency che iniziano con prefissi specifici di Durable (ad esempio, orchestration:, activity:, e così via). Se si seleziona uno di questi eventi, viene aperto un diagramma di Gantt che mostra la traccia distribuita end-to-end. Il grafico visualizza ogni passaggio di orchestrazione come barra orizzontale, con chiamate di attività e orchestrazione secondaria annidate sotto l'orchestrazione padre. La lunghezza della barra rappresenta la durata dell'orologio a parete di ogni passaggio, rendendo più semplice individuare colli di bottiglia o attività inaspettatamente lente.

Registrazione sicura contro i replay nelle funzioni di orchestrator

Le funzioni dell'agente di orchestrazione vengono riprodotte ogni volta che viene ricevuto un nuovo input, ovvero qualsiasi istruzione di log in un agente di orchestrazione viene eseguita più volte per una singola esecuzione logica. Ad esempio, una funzione con tre chiamate di attività produce un output del log simile al seguente durante la riproduzione:

Calling F1.
Calling F1.
Calling F2.
Calling F1.
Calling F2.
Calling F3.
Calling F1.
Calling F2.
Calling F3.
Done!

Per evitare righe di log duplicate, controllare il flag "sta riproducendo" in modo che i log vengano eseguiti solo al primo passaggio (non di riproduzione). Gli esempi seguenti mostrano la registrazione sicura per la riproduzione in ogni lingua.

[FunctionName("FunctionChain")]
public static async Task Run(
    [OrchestrationTrigger] IDurableOrchestrationContext context,
    ILogger log)
{
    log = context.CreateReplaySafeLogger(log);
    log.LogInformation("Calling F1.");
    await context.CallActivityAsync("F1");
    log.LogInformation("Calling F2.");
    await context.CallActivityAsync("F2");
    log.LogInformation("Calling F3");
    await context.CallActivityAsync("F3");
    log.LogInformation("Done!");
}

[Function("FunctionChain")]
public static async Task Run([OrchestrationTrigger] TaskOrchestrationContext context)
{
    ILogger log = context.CreateReplaySafeLogger("FunctionChain");
    log.LogInformation("Calling F1.");
    await context.CallActivityAsync("F1");
    log.LogInformation("Calling F2.");
    await context.CallActivityAsync("F2");
    log.LogInformation("Calling F3");
    await context.CallActivityAsync("F3");
    log.LogInformation("Done!");
}

const df = require("durable-functions");

module.exports = df.orchestrator(function*(context){
    if (!context.df.isReplaying) context.log("Calling F1.");
    yield context.df.callActivity("F1");
    if (!context.df.isReplaying) context.log("Calling F2.");
    yield context.df.callActivity("F2");
    if (!context.df.isReplaying) context.log("Calling F3.");
    yield context.df.callActivity("F3");
    context.log("Done!");
});

import * as df from "durable-functions";

df.app.orchestration("FunctionChain", function* (context) {
    if (!context.df.isReplaying) context.log("Calling F1.");
    yield context.df.callActivity("F1");
    if (!context.df.isReplaying) context.log("Calling F2.");
    yield context.df.callActivity("F2");
    if (!context.df.isReplaying) context.log("Calling F3.");
    yield context.df.callActivity("F3");
    context.log("Done!");
});

import logging
import azure.functions as func
import azure.durable_functions as df

def orchestrator_function(context: df.DurableOrchestrationContext):
    if not context.is_replaying:
        logging.info("Calling F1.")
    yield context.call_activity("F1")
    if not context.is_replaying:
        logging.info("Calling F2.")
    yield context.call_activity("F2")
    if not context.is_replaying:
        logging.info("Calling F3.")
    yield context.call_activity("F3")
    logging.info("Done!")
    return None

main = df.Orchestrator.create(orchestrator_function)

@FunctionName("FunctionChain")
public void functionChain(
        @DurableOrchestrationTrigger(name = "ctx") TaskOrchestrationContext ctx,
        ExecutionContext functionContext) {
    Logger log = functionContext.getLogger();
    if (!ctx.getIsReplaying()) log.info("Calling F1.");
    ctx.callActivity("F1").await();
    if (!ctx.getIsReplaying()) log.info("Calling F2.");
    ctx.callActivity("F2").await();
    if (!ctx.getIsReplaying()) log.info("Calling F3.");
    ctx.callActivity("F3").await();
    log.info("Done!");
}

Con la registrazione sicura per la riproduzione, l'output del log è:

Calling F1.
Calling F2.
Calling F3.
Done!

Stato di orchestrazione personalizzato

Usare lo stato di orchestrazione personalizzato per segnalare lo stato del flusso di lavoro ai client esterni. I modelli comuni includono percentuali di completamento, descrizioni dei passaggi e riepiloghi degli errori. I client esterni possono visualizzare lo stato personalizzato tramite l'API di query sullo stato HTTP o le chiamate API specifiche del linguaggio.

Il codice seguente illustra come impostare un valore di stato personalizzato in una funzione dell'agente di orchestrazione:

[FunctionName("SetStatusTest")]
public static async Task SetStatusTest([OrchestrationTrigger] IDurableOrchestrationContext context)
{
    // ...do work...

    // update the status of the orchestration with some arbitrary data
    var customStatus = new { completionPercentage = 90.0, status = "Updating database records" };
    context.SetCustomStatus(customStatus);

    // ...do more work...
}

[Function("SetStatusTest")]
public static async Task SetStatusTest([OrchestrationTrigger] TaskOrchestrationContext context)
{
    // ...do work...

    // update the status of the orchestration with some arbitrary data
    var customStatus = new { completionPercentage = 90.0, status = "Updating database records" };
    context.SetCustomStatus(customStatus);

    // ...do more work...
}

const df = require("durable-functions");

module.exports = df.orchestrator(function*(context) {
    // ...do work...

    // update the status of the orchestration with some arbitrary data
    const customStatus = { completionPercentage: 90.0, status: "Updating database records", };
    context.df.setCustomStatus(customStatus);

    // ...do more work...
});

import * as df from "durable-functions";

df.app.orchestration("SetStatusTest", function* (context) {
    // ...do work...

    // update the status of the orchestration with some arbitrary data
    const customStatus = { completionPercentage: 90.0, status: "Updating database records" };
    context.df.setCustomStatus(customStatus);

    // ...do more work...
});

import logging
import azure.functions as func
import azure.durable_functions as df

def orchestrator_function(context: df.DurableOrchestrationContext):
    # ...do work...

    # update the status of the orchestration with some arbitrary data
    custom_status = {'completionPercentage': 90.0, 'status': 'Updating database records'}
    context.set_custom_status(custom_status)
    # ...do more work...

    return None

main = df.Orchestrator.create(orchestrator_function)

@FunctionName("SetStatusTest")
public void setStatusTest(
        @DurableOrchestrationTrigger(name = "ctx") TaskOrchestrationContext ctx) {
    // ...do work...

    // update the status of the orchestration with some arbitrary data
    ctx.setCustomStatus(new Object() {
        public final double completionPercentage = 90.0;
        public final String status = "Updating database records";
    });

    // ...do more work...
}

Mentre l'orchestrazione è in esecuzione, i client esterni possono recuperare questo stato personalizzato:

GET /runtime/webhooks/durabletask/instances/instance123?code=XYZ

I client ricevono la risposta seguente:

{
  "runtimeStatus": "Running",
  "input": null,
  "customStatus": { "completionPercentage": 90.0, "status": "Updating database records" },
  "output": null,
  "createdTime": "2017-10-06T18:30:24Z",
  "lastUpdatedTime": "2017-10-06T19:40:30Z"
}

Risoluzione dei problemi

Azure Functions supporta direttamente il debug del codice della funzione e lo stesso supporto viene inoltrato a Durable Functions, sia in esecuzione in Azure che in locale. Usare il flusso di lavoro seguente per un'esperienza di debug ottimale:

1. Avviare una nuova sessione di debug con un nuovo hub attività o cancellare il contenuto dell'hub attività tra le sessioni. I messaggi residui dalle esecuzioni precedenti possono causare una ri-esecuzione imprevista.

2. Impostare punti di interruzione nelle funzioni dell'agente di orchestrazione o dell'attività. Per le funzioni di orchestrazione, utilizzate un punto di interruzione condizionale che si attiva solo quando il valore "is replaying" è false, per evitare di attivare lo stesso punto di interruzione più volte durante la riproduzione.

3. Eseguire passo passo il codice come di consueto. Tenere presente i comportamenti seguenti:

   • Replay:
     Le funzioni di orchestrazione vengono rieseguite regolarmente quando vengono ricevuti nuovi dati di input. Una singola esecuzione logica di una funzione dell'agente di orchestrazione può comportare il raggiungimento dello stesso punto di interruzione più volte, soprattutto se viene impostato all'inizio del codice della funzione.

   • Attendono:
     Ogni volta che viene rilevato un await in una funzione dell'agente di orchestrazione, la funzione cede il controllo al dispatcher Durable Task Framework. Se è la prima volta che viene rilevato un particolare await , l'attività associata non viene mai ripresa. Poiché l'attività non viene mai ripresa, passare sopra l'await (F10 in Visual Studio) non è possibile. Questa operazione funziona solo se un'attività è in corso di riesecuzione.

   • Timeout della messaggistica:
     Durable Functions usa internamente i messaggi della coda per guidare l'esecuzione di funzioni di orchestrazione, attività ed entità. In un ambiente con più macchine virtuali, le sessioni di debug estese potrebbero causare l'elaborazione del messaggio da parte di un'altra macchina virtuale, con conseguente esecuzione duplicata. Sebbene questo comportamento esista anche per le normali funzioni di trigger della coda, è importante sottolineare questo contesto perché le code sono un dettaglio dell'implementazione.

   • Arresto e avvio:
     I messaggi in Durable Functions vengono mantenuti tra le sessioni di debug. Se si arresta il debug e si termina il processo host locale durante l'esecuzione di una funzione durevole, tale funzione potrebbe essere eseguita di nuovo automaticamente in una sessione di debug futura.

Strumenti aggiuntivi

Esaminare lo stato di archiviazione

Per impostazione predefinita, Durable Functions archivia lo stato in Azure Storage. È possibile esaminare lo stato e i messaggi di orchestrazione usando strumenti come Microsoft Azure Storage Explorer.

Screenshot che mostra Azure Storage Explorer con lo stato di orchestrazione di Durable Functions in tabelle e code.

Monitoraggio delle funzioni durevoli

Durable Functions Monitor è uno strumento grafico per monitorare, gestire e eseguire il debug delle istanze di orchestrazione ed entità. È disponibile come estensione Visual Studio Code o come app autonoma. Per istruzioni sull'installazione e un elenco delle funzionalità, vedere il wiki Durable Functions Monitor Wiki.

Diagnostica del portale Azure

Il portale Azure offre strumenti di diagnostica predefiniti per le app per le funzioni.

Diagnosticare e risolvere i problemi: Diagnostica app per le funzioni di Azure è una risorsa utile per il monitoraggio e la diagnosi di potenziali problemi nell'applicazione. Fornisce anche suggerimenti per risolvere i problemi in base alla diagnosi. Per altre informazioni, vedere Diagnostica app di Azure Functions.

Tracce di orchestrazione: Il portale di Azure fornisce informazioni dettagliate sulla traccia dell'orchestrazione per comprendere lo stato di ogni istanza di orchestrazione e di tracciare l'esecuzione end-to-end. Quando si visualizza l'elenco delle funzioni all'interno dell'app Azure Functions, viene visualizzata una colonna Monitor che contiene collegamenti alle tracce. Per accedere a queste informazioni, è necessario che Application Insights sia abilitato per l'app.

Analizzatore Roslyn

L'analizzatore Durable Functions Roslyn è un analizzatore di codice live che guida gli sviluppatori C# a seguire i vincoli specifici di codice delle Durable Functions . Per istruzioni su come abilitarlo in Visual Studio e Visual Studio Code, vedere Durable Functions Roslyn Analyzer.

Risoluzione dei problemi

Per risolvere problemi comuni, ad esempio orchestrazioni bloccate, mancata avvio o esecuzione lenta, vedere la guida alla risoluzione dei problemi Durable Functions guida alla risoluzione dei problemi.

Passaggi successivi