Diagnostik i Durable Functions i Azure
Det finns flera alternativ för att diagnostisera problem med Durable Functions. Vissa av dessa alternativ är desamma för vanliga funktioner medan andra är unika för Durable Functions.
Programinsikter
Application Insights är det rekommenderade sättet att utföra diagnostik och övervakning i Azure Functions. Samma sak gäller för Durable Functions. En översikt över hur du använder Application Insights i funktionsappen finns i Övervaka Azure Functions.
Azure Functions Durable Extension genererar även spårningshändelser som gör att du kan spåra körningen från slutpunkt till slutpunkt för en orkestrering. Dessa spårningshändelser kan hittas och frågas med hjälp av verktyget Application Insights Analytics i Azure Portal.
Spåra data
Varje livscykelhändelse för en orkestreringsinstans gör att en spårningshändelse skrivs till spårningssamlingen i Application Insights. Den här händelsen innehåller en customDimensions-nyttolast med flera fält. Fältnamn är alla förberedda med prop__
.
- hubName: Namnet på aktivitetshubben där orkestreringarna körs.
- appName: Namnet på funktionsappen. Det här fältet är användbart när du har flera funktionsappar som delar samma Application Insights-instans.
- slotName: Distributionsplatsen där den aktuella funktionsappen körs. Det här fältet är användbart när du använder distributionsplatser för att versionshantera orkestreringarna.
- functionName: Namnet på orkestrerings- eller aktivitetsfunktionen.
- functionType: Funktionens typ, till exempel Orchestrator eller Activity.
- instanceId: Det unika ID:t för orkestreringsinstansen.
- tillstånd: Körningstillståndet för instansens livscykel. Giltiga värden är:
- Schemalagd: Funktionen har schemalagts för körning men har inte börjat köras än.
- Startad: Funktionen har börjat köras men har ännu inte väntat eller slutförts.
- Väntar: Orkestratorn har schemalagt en del arbete och väntar på att det ska slutföras.
- Lyssnar: Orchestrator lyssnar efter ett externt händelsemeddelande.
- Slutförd: Funktionen har slutförts.
- Misslyckades: Funktionen misslyckades med ett fel.
- orsak: Ytterligare data som är associerade med spårningshändelsen. Om en instans till exempel väntar på ett externt händelsemeddelande anger det här fältet namnet på den händelse som den väntar på. Om en funktion har misslyckats innehåller det här fältet felinformationen.
- isReplay: Booleskt värde som anger om spårningshändelsen ska köras igen.
- extensionVersion: Versionen av tillägget Durable Task. Versionsinformationen är särskilt viktig när du rapporterar eventuella buggar i tillägget. Långvariga instanser kan rapportera flera versioner om en uppdatering sker medan den körs.
- sequenceNumber: Körningssekvensnummer för en händelse. Kombinerat med tidsstämpeln hjälper till att beställa händelserna efter körningstid. Observera att det här talet återställs till noll om värden startas om medan instansen körs, så det är viktigt att alltid sortera efter tidsstämpel först och sedan sekvensNummer.
Utförligheten i spårning av data som skickas till Application Insights kan konfigureras i logger
avsnittet (Functions 1.x) eller logging
(Functions 2.0) i host.json
filen.
Funktioner 1.0
{
"logger": {
"categoryFilter": {
"categoryLevels": {
"Host.Triggers.DurableTask": "Information"
}
}
}
}
Funktioner 2.0
{
"logging": {
"logLevel": {
"Host.Triggers.DurableTask": "Information",
},
}
}
Som standard genereras alla spårningshändelser som inte spelas upp. Datavolymen kan minskas genom att ange Host.Triggers.DurableTask
till "Warning"
eller "Error"
i vilket fall spårningshändelser endast genereras för exceptionella situationer. Om du vill aktivera sändning av utförliga orkestreringsreprishändelser anger du logReplayEvents
till true
i konfigurationsfilen host.json .
Kommentar
Som standard samplas Application Insights-telemetri av Azure Functions-körningen för att undvika att data genereras för ofta. Detta kan leda till att spårningsinformation går förlorad när många livscykelhändelser inträffar på kort tid. I artikeln Azure Functions Monitoring beskrivs hur du konfigurerar det här beteendet.
Indata och utdata från orkestrerings-, aktivitets- och entitetsfunktioner loggas inte som standard. Det här standardbeteendet rekommenderas eftersom loggning av indata och utdata kan öka Application Insights-kostnaderna. Funktionsindata och utdatanyttolaster kan också innehålla känslig information. I stället loggas antalet byte för funktionsindata och utdata i stället för de faktiska nyttolasterna som standard. Om du vill att Durable Functions-tillägget ska logga de fullständiga in- och utdatanyttolasterna anger du traceInputsAndOutputs
egenskapen till true
i konfigurationsfilen host.json .
Enskild instansfråga
Följande fråga visar historiska spårningsdata för en enda instans av Hello Sequence-funktionsorkestreringen . Den skrivs med hjälp av Kusto-frågespråk. Den filtrerar bort omspelningskörning så att endast den logiska körningssökvägen visas. Händelser kan ordnas genom sortering efter timestamp
och sequenceNumber
som visas i frågan nedan:
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
Resultatet är en lista över spårningshändelser som visar orkestreringens körningssökväg, inklusive alla aktivitetsfunktioner som ordnas efter körningstiden i stigande ordning.
Instanssammanfattningsfråga
Följande fråga visar status för alla orkestreringsinstanser som kördes inom ett angivet tidsintervall.
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
Resultatet är en lista över instans-ID:n och deras aktuella körningsstatus.
Durable Task Framework-loggning
Durable-tilläggsloggarna är användbara för att förstå hur orkestreringslogik fungerar. De här loggarna innehåller dock inte alltid tillräckligt med information för att felsöka prestanda- och tillförlitlighetsproblem på ramverksnivå. Från och med v2.3.0 i Durable-tillägget är loggar som genereras av det underliggande Durable Task Framework (DTFx) också tillgängliga för insamling.
När du tittar på loggar som genereras av DTFx är det viktigt att förstå att DTFx-motorn består av två komponenter: kärnmotorn för sändning (DurableTask.Core
) och en av många lagringsproviders som stöds (Durable Functions använder DurableTask.AzureStorage
som standard, men andra alternativ är tillgängliga).
- DurableTask.Core: Grundläggande orkestreringskörning och schemaläggningsloggar på låg nivå och telemetri.
- DurableTask.AzureStorage: Serverdelsloggar som är specifika för Azure Storage-tillståndsprovidern. Dessa loggar omfattar detaljerade interaktioner med interna köer, blobbar och lagringstabeller som används för att lagra och hämta internt orkestreringstillstånd.
- DurableTask.Netherite: Serverdelsloggar som är specifika för Netherite-lagringsprovidern, om de är aktiverade.
- DurableTask.SqlServer: Serverdelsloggar som är specifika för Microsoft SQL-lagringsprovidern (MSSQL) om de är aktiverade.
Du kan aktivera loggarna genom att uppdatera logging/logLevel
avsnittet i funktionsappens host.json fil. I följande exempel visas hur du aktiverar varnings- och felloggar från både DurableTask.Core
och DurableTask.AzureStorage
:
{
"version": "2.0",
"logging": {
"logLevel": {
"DurableTask.AzureStorage": "Warning",
"DurableTask.Core": "Warning"
}
}
}
Om du har Application Insights aktiverat läggs dessa loggar automatiskt till i trace
samlingen. Du kan söka efter dem på samma sätt som du söker efter andra trace
loggar med hjälp av Kusto-frågor.
Kommentar
För produktionsprogram rekommenderar vi att du aktiverar DurableTask.Core
och lämpliga lagringsproviderloggar (t.ex. DurableTask.AzureStorage
) med hjälp av "Warning"
filtret. Högre verbositetsfilter som "Information"
är mycket användbara för felsökning av prestandaproblem. Dessa logghändelser kan dock vara stora och kan avsevärt öka kostnaderna för Application Insights-datalagring.
Följande Kusto-fråga visar hur du frågar efter DTFx-loggar. Den viktigaste delen av frågan är where customerDimensions.Category startswith "DurableTask"
eftersom det filtrerar resultatet till loggar i DurableTask.Core
kategorierna och DurableTask.AzureStorage
.
traces
| where customDimensions.Category startswith "DurableTask"
| project
timestamp,
severityLevel,
Category = customDimensions.Category,
EventId = customDimensions.EventId,
message,
customDimensions
| order by timestamp asc
Resultatet är en uppsättning loggar skrivna av Durable Task Framework-loggprovidrar.
Mer information om vilka logghändelser som är tillgängliga finns i den strukturerade loggningsdokumentationen för Durable Task Framework på GitHub.
Apploggning
Det är viktigt att ha orkestreringsuppspelningsbeteendet i åtanke när du skriver loggar direkt från en orchestrator-funktion. Tänk till exempel på följande orchestrator-funktion:
[FunctionName("FunctionChain")]
public static async Task Run(
[OrchestrationTrigger] IDurableOrchestrationContext context,
ILogger 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!");
}
De resulterande loggdata kommer att se ut ungefär som i följande exempelutdata:
Calling F1.
Calling F1.
Calling F2.
Calling F1.
Calling F2.
Calling F3.
Calling F1.
Calling F2.
Calling F3.
Done!
Kommentar
Kom ihåg att även om loggarna påstår sig anropa F1, F2 och F3 kallas dessa funktioner bara första gången de påträffas. Efterföljande anrop som inträffar under reprisen hoppas över och utdata spelas upp på orkestreringslogik.
Om du bara vill skriva loggar på icke-repriskörningar kan du skriva ett villkorsuttryck för att logga endast om flaggan "spelas upp" är false
. Tänk på exemplet ovan, men den här gången med repriskontroller.
[FunctionName("FunctionChain")]
public static async Task Run(
[OrchestrationTrigger] IDurableOrchestrationContext context,
ILogger log)
{
if (!context.IsReplaying) log.LogInformation("Calling F1.");
await context.CallActivityAsync("F1");
if (!context.IsReplaying) log.LogInformation("Calling F2.");
await context.CallActivityAsync("F2");
if (!context.IsReplaying) log.LogInformation("Calling F3");
await context.CallActivityAsync("F3");
log.LogInformation("Done!");
}
Från och med Durable Functions 2.0 har .NET-orkestreringsfunktioner också möjlighet att skapa en ILogger
som automatiskt filtrerar bort logginstruktioner under uppspelningen. Den här automatiska filtreringen görs med api:et IDurableOrchestrationContext.CreateReplaySafeLogger(ILogger).
[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!");
}
Kommentar
De tidigare C#-exemplen är för Durable Functions 2.x. För Durable Functions 1.x måste du använda DurableOrchestrationContext
i stället för IDurableOrchestrationContext
. Mer information om skillnaderna mellan versioner finns i artikeln Durable Functions-versioner .
Med de tidigare nämnda ändringarna är loggutdata följande:
Calling F1.
Calling F2.
Calling F3.
Done!
Anpassad status
Med anpassad orkestreringsstatus kan du ange ett anpassat statusvärde för orkestreringsfunktionen. Den här anpassade statusen visas sedan för externa klienter via HTTP-statusfrågans API eller via språkspecifika API-anrop. Den anpassade orkestreringsstatusen möjliggör bättre övervakning av orkestreringsfunktioner. Till exempel kan orchestrator-funktionskoden anropa API:et "set custom status" för att uppdatera förloppet för en långvarig åtgärd. En klient, till exempel en webbsida eller ett annat externt system, kan sedan regelbundet fråga HTTP-statusfrågans API:er för mer detaljerad förloppsinformation. Exempelkod för att ange ett anpassat statusvärde i en orchestrator-funktion finns nedan:
[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...
}
Kommentar
Det tidigare C#-exemplet är för Durable Functions 2.x. För Durable Functions 1.x måste du använda DurableOrchestrationContext
i stället för IDurableOrchestrationContext
. Mer information om skillnaderna mellan versioner finns i artikeln Durable Functions-versioner .
Medan orkestreringen körs kan externa klienter hämta den här anpassade statusen:
GET /runtime/webhooks/durabletask/instances/instance123?code=XYZ
Klienterna får följande svar:
{
"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"
}
Varning
Nyttolasten för anpassad status är begränsad till 16 KB UTF-16 JSON-text eftersom den måste få plats i en Azure Table Storage-kolumn. Du kan använda extern lagring om du behöver större nyttolast.
Distribuerad spårning
Distribuerad spårning spårar begäranden och visar hur olika tjänster interagerar med varandra. I Durable Functions korrelerar den också orkestreringar och aktiviteter tillsammans. Det här är användbart för att förstå hur lång tid orkestreringen tar i förhållande till hela orkestreringen. Det är också användbart att förstå var ett program har ett problem eller var ett undantag utlöstes. Den här funktionen stöds för alla språk och lagringsleverantörer.
Kommentar
Distribuerad spårning V2 kräver Durable Functions v2.12.0 eller senare. Dessutom är distribuerad spårning V2 i ett förhandsversionstillstånd och därför instrumenteras inte vissa Durable Functions-mönster. Till exempel instrumenteras inte durable entitetsåtgärder och spårningar visas inte i Application Insights.
Konfigurera distribuerad spårning
Om du vill konfigurera distribuerad spårning uppdaterar du host.json och konfigurerar en Application Insights-resurs.
host.json
"durableTask": {
"tracing": {
"distributedTracingEnabled": true,
"Version": "V2"
}
}
Programinsikter
Om funktionsappen inte har konfigurerats med en Application Insights-resurs konfigurerar du den enligt anvisningarna här.
Inspektera spårningarna
I Application Insights-resursen går du till Transaktionssökning. I resultatet söker du efter Request
och Dependency
händelser som börjar med Durable Functions-specifika prefix (t.ex. orchestration:
, activity:
osv.). Om du väljer en av dessa händelser öppnas ett Gantt-schema som visar distribuerad spårning från slutpunkt till slutpunkt.
Felsökning
Om du inte ser spårningarna i Application Insights måste du vänta ungefär fem minuter efter att programmet har körts för att säkerställa att alla data sprids till Application Insights-resursen.
Felsökning
Azure Functions stöder felsökning av funktionskod direkt, och samma stöd vidarebefordras till Durable Functions, oavsett om det körs i Azure eller lokalt. Det finns dock några beteenden att känna till vid felsökning:
- Repris: Orchestrator-funktioner spelas regelbundet upp när nya indata tas emot. Det här beteendet innebär att en enda logisk körning av en orkestreringsfunktion kan resultera i att samma brytpunkt uppnås flera gånger, särskilt om den anges tidigt i funktionskoden.
- Väntar: När en
await
påträffas i en orkestreringsfunktion ger den kontroll tillbaka till Durable Task Framework-avsändare. Om det är första gången en viss uppgiftawait
påträffas återupptas aldrig den associerade aktiviteten. Eftersom uppgiften aldrig återupptas är det inte möjligt att kliva över väntan (F10 i Visual Studio). Att kliva över fungerar bara när en uppgift spelas upp igen. - Tidsgränser för meddelanden: Durable Functions använder internt kömeddelanden för att köra orkestrerings-, aktivitets- och entitetsfunktioner. Om du bryter dig in i felsökningen under längre tidsperioder i en miljö med flera virtuella datorer kan det leda till att en annan virtuell dator hämtar meddelandet, vilket resulterar i duplicerad körning. Det här beteendet finns även för vanliga köutlösarfunktioner, men är viktigt att påpeka i den här kontexten eftersom köerna är en implementeringsinformation.
- Stoppa och starta: Meddelanden i durable functions sparas mellan felsökningssessioner. Om du slutar felsöka och avslutar den lokala värdprocessen medan en varaktig funktion körs kan den funktionen köras igen automatiskt i en framtida felsökningssession. Det här beteendet kan vara förvirrande när det inte förväntas. Att använda en ny aktivitetshubb eller rensa innehållet i aktivitetshubben mellan felsökningssessioner är en teknik för att undvika det här beteendet.
Dricks
Om du anger brytpunkter i orkestreringsfunktioner kan du ange en villkorlig brytpunkt som bara bryts om värdet "spelar upp" är false
.
Storage
Durable Functions lagrar som standard tillståndet i Azure Storage. Det här beteendet innebär att du kan kontrollera orkestreringarnas tillstånd med hjälp av verktyg som Microsoft Azure Storage Explorer.
Detta är användbart för felsökning eftersom du ser exakt vilket tillstånd en orkestrering kan vara i. Meddelanden i köerna kan också undersökas för att lära sig vilket arbete som väntar (eller fastnar i vissa fall).
Varning
Även om det är praktiskt att se körningshistorik i tabelllagring bör du undvika att använda något beroende av den här tabellen. Det kan ändras i takt med att Durable Functions-tillägget utvecklas.
Kommentar
Andra lagringsproviders kan konfigureras i stället för standardleverantören för Azure Storage. Beroende på vilken lagringsprovider som har konfigurerats för din app kan du behöva använda olika verktyg för att inspektera det underliggande tillståndet. Mer information finns i dokumentationen om Durable Functions Storage Providers .
Durable Functions Monitor
Durable Functions Monitor är ett grafiskt verktyg för övervakning, hantering och felsökning av orkestrering och entitetsinstanser. Det är tillgängligt som ett Visual Studio Code-tillägg eller en fristående app. Information om konfiguration och en lista över funktioner finns i den här wikin.
Felsökningsguide för Durable Functions
Information om hur du felsöker vanliga problem, till exempel orkestreringar som fastnar, misslyckas med att starta, köra långsamt osv. finns i den här felsökningsguiden.