Diagnostiquer et résoudre les problèmes dans Durable Functions

Durable Functions fournit plusieurs outils de diagnostic pour résoudre les problèmes d’orchestration. Cet article explique comment configurer le suivi et la journalisation, écrire du code sécurisé en relecture, inspecter les traces distribuées et déboguer localement.

Dans cet article, vous allez apprendre à :

Configurer le suivi d’Application Insights

Application Insights est la méthode recommandée pour surveiller Durable Functions. L’extension Durable émet des événements de suivi qui vous permettent de suivre l’exécution de bout en bout d’une orchestration. Vous pouvez rechercher et interroger ces événements de suivi à l’aide de l’outil Application Insights Analytics dans le portail Azure.

Configuration du niveau de journalisation

Configurez le niveau de détail des données de suivi émises vers Application Insights dans votre fichier host.json :

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

Par défaut, tous les événements de suivi non rejoués sont transmis. Vous pouvez réduire le volume de données en définissant Host.Triggers.DurableTask"Warning" ou "Error", ce qui signifie que le suivi des événements n’est émis que dans des situations exceptionnelles. Pour activer l’émission d’événements de relecture d’orchestration détaillés, définissez logReplayEvents sur true dans le fichier de configuration host.json.

Journalisation d’entrée et de sortie

Par défaut, les entrées et sorties des fonctions d’orchestrateur, d’activité et d’entité ne sont pas journalisées. Cette approche est recommandée, car la journalisation des entrées et des sorties peut augmenter les coûts d’Application Insights. Les charges utiles d’entrée et de sortie de fonction peuvent également contenir des informations sensibles. Au lieu de cela, le nombre d’octets pour les entrées et sorties de fonction est journalisé. Si vous souhaitez que l’extension Durable Functions journalise les charges utiles d’entrée et de sortie complètes, définissez la propriété traceInputsAndOutputs sur true dans le fichier de configuration host.json.

Interroger l’instance d’orchestration

Utilisez les requêtes Kusto suivantes dans Application Insights Analytics pour inspecter les instances d’orchestration.

Requête d’instance unique

La requête suivante affiche les données de suivi historiques d’une seule instance de la fonction d’orchestration Séquence Hello. Elle exclut la réexécution afin que seul le chemin d’exécution logique s’affiche. Vous pouvez commander des événements en triant par timestamp et sequenceNumber comme indiqué dans la requête suivante :

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

Le résultat est une liste d’événements de suivi indiquant le chemin d’exécution de l’orchestration, y compris toutes les fonctions d’activité triées par durée d’exécution par ordre ascendant.

Requête de résumé de l’instance

La requête suivante affiche l’état de toutes les instances d’orchestration qui ont été exécutées dans un intervalle de temps spécifié.

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

Le résultat est une liste d’ID d’instances et leur actuel état d’exécution.

Références de suivi de données

Chaque instance d’orchestration génère des événements de suivi au fur et à mesure qu’elle progresse dans son cycle de vie. Chaque événement de cycle de vie contient une charge utile customDimensions avec plusieurs champs. Les noms de champs contiennent tous le préfixe prop__.

La journalisation du framework Durable Task (DTFx)

Les journaux d’extension Durable sont utiles pour comprendre le comportement de votre logique d’orchestration. Toutefois, ces journaux ne contiennent pas toujours assez d’informations pour déboguer les problèmes de performances et de fiabilité au niveau de l’infrastructure. À partir de la version 2.3.0 de l’extension Durable, les journaux émis par l’infrastructure Durable Task Framework (DTFx) sous-jacentes sont également disponibles pour la collecte.

Lorsque vous examinez les journaux d'activité émis par DTFx, il est important de comprendre que le moteur DTFx a deux composants : le moteur de répartition principal (DurableTask.Core) et l’un des nombreux fournisseurs de stockage pris en charge.

Vous pouvez activer ces journaux en mettant à jour la section logging/logLevel du fichierhost.json de votre application de fonction. l’exemple suivant montre comment activer les journaux d’avertissement et d’erreur depuis DurableTask.Core et DurableTask.AzureStorage :

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

si application insights est activé, ces journaux d’activité sont automatiquement ajoutés à la collection trace. Vous pouvez les rechercher de la même manière que vous recherchez d'autres trace logs à l'aide de requêtes Kusto.

La requête Kusto suivante montre comment interroger les journaux DTFx. La partie la plus importante de la requête est where customerDimensions.Category startswith "DurableTask" car elle filtre les résultats vers les logs dans les catégories DurableTask.Core et DurableTask.AzureStorage.

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

Le résultat est un ensemble de journaux écrits par les fournisseurs de journaux Durable Task Framework.

Pour plus d’informations sur les événements de journal disponibles, consultez la documentation de journalisation structurée Durable Task Framework sur GitHub.

Traçage distribué

Le suivi distribué effectue le suivi des requêtes et montre comment les différents services interagissent entre eux. Dans Durable Functions, il met en corrélation les orchestrations, les entités et les activités. Le suivi distribué affiche le temps d’exécution de chaque étape d’orchestration par rapport à l’intégralité de l’orchestration et identifie l’endroit où des problèmes ou des exceptions se produisent. Cette fonctionnalité est prise en charge dans Application Insights pour tous les langages et fournisseurs de stockage.

Prerequisites

Le suivi distribué nécessite des versions d’extension minimales spécifiques :

• Pour les applications isolées .NET, Microsoft.Azure.Functions.Worker.Extensions.DurableTask>= v1.4.0.
• Pour non-.NET applications, suivez ces instructions pour installer manuellement Microsoft.Azure.WebJobs.Extensions.DurableTask>= v3.2.0 pour l’instant. Le suivi distribué sera disponible dans les bundles d’extensions >v4.24.x.

Configuration du suivi distribué

Pour configurer le suivi distribué, mettez à jour le host.json et configurez la ressource Application Insights.

host.json

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

Application Insights

Configurez votre application de fonction avec une ressource Application Insights.

Inspection des traces

Dans votre ressource Application Insights, accédez à Recherche de transactions. Dans les résultats, recherchez les événements Request et Dependency qui commencent par des préfixes spécifiques à Durable (par exemple, orchestration:, activity:, etc.). La sélection de l’un de ces événements ouvre un diagramme de Gantt qui affiche la trace distribuée de bout en bout. Le graphique affiche chaque étape d’orchestration sous forme de barre horizontale, avec des appels d'activité et des appels de sous-orchestration intégrés sous l'orchestration principale. La longueur de la barre représente la durée en temps réel de chaque étape, ce qui permet de repérer facilement les goulots d’étranglement ou les activités inhabituellement lentes.

Journalisation en relecture sécurisée dans les fonctions d’orchestrateur

Les fonctions Orchestrator réexécutent chaque fois que de nouvelles entrées sont reçues, ce qui signifie que toute instruction de journal dans un orchestrateur s’exécute plusieurs fois lors d'une seule exécution logique. Par exemple, une fonction avec trois appels d’activité produit une sortie de log comme celle-ci lors de la relecture :

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

Pour empêcher les lignes de journal en double, vérifiez l’indicateur « relecture » afin que les journaux d’activité s’exécutent uniquement sur la première passe (sans relecture). Les exemples suivants montrent la journalisation sécurisée contre la réexécution dans chaque langue.

[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!");
}

Avec la journalisation protégée contre les relectures, la sortie du journal est la suivante :

Calling F1.
Calling F2.
Calling F3.
Done!

État de l’orchestration personnalisée

Utilisez l’état d’orchestration personnalisé pour signaler la progression du flux de travail aux clients externes. Les modèles courants incluent des pourcentages d’achèvement, des descriptions d’étapes et des résumés d’erreurs. Les clients externes peuvent afficher l’état personnalisé via l’API de requête d’état HTTP ou les appels d’API spécifiques à la langue.

Le code suivant montre comment définir une valeur d’état personnalisée dans une fonction d’orchestrateur :

[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...
}

Pendant l’exécution de l’orchestration, les clients externes peuvent récupérer cet état personnalisé :

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

Les clients obtiennent la réponse suivante :

{
  "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"
}

Débogage

Azure Functions prend en charge le débogage du code de fonction directement, et cette même prise en charge est transmise à Durable Functions, qu’elle s’exécute dans Azure ou localement. Utilisez le flux de travail suivant pour optimiser l’expérience de débogage :

1. Démarrez une nouvelle session de débogage avec un hub de tâches nouveau ou effacez le contenu du hub de tâches entre les sessions. Les messages restants des exécutions précédentes peuvent entraîner une réexécution inattendue.

2. Définissez des points d’arrêt dans vos fonctions d’orchestrateur ou d’activité. Dans le cadre des fonctions d’orchestrateur, utilisez un point d’arrêt conditionnel qui ne s’arrête que lorsque la valeur de « est en train de rejouer » est false, afin d’éviter d’atteindre le même point d’arrêt plusieurs fois pendant la relecture.

3. Parcourez votre code normalement. Gardez à l’esprit les comportements suivants :

   • Replay:
     Les fonctions Orchestrator rejouent régulièrement lorsque de nouvelles entrées sont reçues. Une seule exécution logique d’une fonction d’orchestrateur peut entraîner l’atteinte du même point d’arrêt plusieurs fois, en particulier si elle est définie tôt dans le code de la fonction.

   • En attente:
     Chaque fois qu’un élément await est rencontré dans une fonction d’orchestrateur, le contrôle repasse au répartiteur de l’infrastructure Durable Task Framework. S’il s’agit de la première rencontre d'un await, la tâche associée n’est jamais reprise. Puisque la tâche ne reprend jamais, vous ne pouvez pas exécuter un pas à pas principal sur l’instruction await (F10 dans Visual Studio). Parcourez uniquement des travaux lorsqu’une tâche est réexécutée.

   • Délais d’expiration de messagerie :
     Durable Functions utilise en interne les messages de file d’attente pour piloter l’exécution des fonctions d’orchestrateur, d’activité et d’entité. Dans un environnement à plusieurs machines virtuelles, les sessions de débogage étendues peuvent entraîner le traitement d’une autre machine virtuelle par le message, ce qui entraîne une exécution en double. Bien que ce comportement existe également pour les fonctions de déclencheur de file d’attente standard, ce contexte est important de mettre en évidence, car les files d’attente sont un détail d’implémentation.

   • Arrêt et démarrage :
     Les messages dans Durable Functions persistent entre les sessions de débogage. Si vous arrêtez le débogage et arrêtez le processus hôte local pendant l’exécution d’une fonction durable, cette fonction peut s’exécuter automatiquement dans une prochaine session de débogage.

Outils supplémentaires

Inspecter l’état du stockage

Par défaut, Durable Functions stocke l’état dans stockage Azure. Vous pouvez inspecter l’état et les messages d’orchestration à l’aide d’outils tels que l’Explorateur Stockage Microsoft Azure.

Moniteur de Fonctions Durables

Durable Functions Monitor est un outil graphique permettant de surveiller, de gérer et de déboguer des instances d’orchestration et d’entité. Il est disponible en tant qu'extension Visual Studio Code ou une application autonome. Pour obtenir des instructions de configuration et une liste de fonctionnalités, consultez le wiki Durable Functions Monitor Wiki.

diagnostics du portail Azure

Le portail Azure fournit des outils de diagnostic intégrés pour vos applications de fonction.

Diagnostiquer et résoudre les problèmes : Diagnostics d’application de fonction Azure est une ressource utile pour surveiller et diagnostiquer les problèmes potentiels dans votre application. Il fournit également des suggestions pour aider à résoudre les problèmes en fonction du diagnostic. Pour plus d’informations, consultez Azure Function App Diagnostics.

Traces d’orchestration : Le portail Azure fournit des détails de trace d’orchestration pour vous aider à comprendre l’état de chaque instance d’orchestration et à suivre l’exécution de bout en bout. Lorsque vous affichez la liste des fonctions dans votre application Azure Functions, vous voyez une colonne Monitor qui contient des liens vers les traces. Vous devez activer Application Insights pour que votre application accède à ces informations.

Analyseur Roslyn

L'analyseur Roslyn de Durable Functions est un analyseur de code en temps réel qui guide les développeurs C# pour suivre les contraintes de code spécifiques à Durable Functions. Pour obtenir des instructions sur l’activation dans Visual Studio et Visual Studio Code, consultez Durable Functions Roslyn Analyzer.

Résolution des problèmes

Pour résoudre les problèmes courants tels que les orchestrations bloquées, l’échec du démarrage ou l’exécution lente, consultez le guide de résolution des problèmes Durable Functions.

Étapes suivantes