Default logningsniveauer i .NET Core

Default logningsniveauer i .NET Core

For tiden kigger jeg meget de forskellige måder at logge på, da jeg er ved at lave en lille serie omkring loggning i .NET Core. De to fokus områder jeg har er:

  1. Azure Functions v2

  2. ASP.NET Core 2.x og 3.x

Når man snakker logning er der to hovedområder hvorpå disse logs kan inspiceres, som jeg ser det:

  1. den umiddelbare strøm af logs, som foregår enten via

    1. konsollen

    2. en debug viewer (Visual Studio har fx en debug output)

  2. den langtidsholdbare log, som kan være:

    1. en tekst fil

    2. Application Insights

    3. seq

    4. Windows Event Log

    5. eller en helt femte provider

Før man kan logge noget, og før man kan inspicere de logs man laver, skal man dog først beslutte sig for:

  1. hvor vil man logge

  2. hvad vil man logge

  3. på hvilket  niveau vil man logge

Kører man det hele i Azure, bliver alskens ting logget:

  1. CPU

  2. RAM

  3. Requests

  4. Exceptions

  5. Skalering

  6. osv

Meget af det afhænger hvad for resourcer man har provisioneret. Jeg har kun fokus på:

  1. Webapps

  2. Azure Functions

Jeg har kun fokus på applikationslogning her i indlægget, det vil sige logning af kodeudførslen, og hvad Application Insights SDK'et bibringer, jeg har derfor ikke fokus på logning af selve infrastrukturen, det vil sige RAM, skalering, diskplads, CPU osv, som også kan finde vej til Application Insights.

Når man har fundet ud af hvor man vil logge skal man finde ud af på hvilket niveau man vil logge, og her understøtter ILogger de gængse:

  1. Trace

  2. Debug

  3. Information

  4. Warning

  5. Error

  6. Critical

  7. None

Via en LogLevel enum.

Det er faktisk ligefrem og til at forstå. Ikke så mange dikkedarer, men der hvor jeg falder lidt af er på det tidspunkt hvor jeg gerne vil vide hvad der bliver sat som default når man gør brug af loggeren i fx ASP.NET Core eller i Azure Functions, og specielt hvad der defaultes til når man smider Application Insights indover. Det har jeg selvfølgelig gravet lidt i.

Azure Functions

I Azure Functions v2  defaultes der til Information hvis der ikke er defineret nogen logging.loglevel i en konfiguration, fx:

    {
      "version": "2.0",
      "logging": {
        "applicationInsights": {
          "samplingSettings": {
            "isEnabled": false
          }
        }
      }
    }

Det står egentlig godt beskrevet i Microsofts dokumentation, under logLevel property. Følger man linket, ender man her, hvor der står følgende

If you don't explicitly set the minimum level, the default value is Information, which means that Trace and Debug logs are ignored.

Så langt, så godt. Det hele giver mening. Vi kan godt lide når det giver mening OG når dokumentationen beskriver det.

ASP.NET Core 3.1

Tager man og spinner en ASP.NET Core 3.1 site op defaultes der ligeledes til Information, hvis man ikke angiver noget i konfigurations filen:

    {
    }

Som også beskrives via dette link

If you don't explicitly set the minimum level, the default value is Information, which means that Trace and Debug logs are ignored.

Du har helt korrekt forstået min udpensling. Man behøver ikke være den skarpeste scooter på havnen for at se, at både Azure Functions og ASP.NET Core er fuldstændig alligned på logningsfronten. Rent faktisk nævner Azure Functions i dokumentationen at logningsdelen er fuldstændig alligned:

Object that defines the log category filtering for functions in the app. Versions 2.x and later follow the ASP.NET Core layout for log category filtering. This setting lets you filter logging for specific functions. For more information, see Log filtering in the ASP.NET Core documentation.

Det er noget vi som udviklere er meget glade for, og det har ikke altid været således mellem disse to teknologier. Generelt set ser man at disse to teknologier rykker tættere og tættere på hinanden hvad angår

  1. IoC

  2. Logning

  3. runtime inistation af funktioner og controllers

Igen noget vi godt kan lide som udviklere. Det gør selve fremdriften mere slim, da den uniforme tilgang til selve teknologierne læner sig op ad hinanden, og der er et mindre detalje sæt man skal sætte sig ind i for at kunne vælge den bedste teknologi til ens løsningsarkitektur.

Application Insights SDK'et

ASP.NET Core 3

Hvis man kobler Application Insights på vil man gerne være helt sikker på at man ikke smider alt for meget data over, da det koster 18 kr pr GB. Jeg har set løsninger som har spist flere tusinde kroner om dagen. Det at bruge de korrekte logningsniveauer og logge de korrekte steder er uden for scope af dette indlæg (og noget jeg behandler i en serie af indlæg senere på året). Jeg vil rigtig gerne være helt skarp på hvad der bliver sendt over, og måden jeg bliver det på, er ved åbne for dokumentationen, hvor der står følgende:

Only Warning or higher ILogger logs (from all categories) are sent to Application Insights by default. But you can apply filters to modify this behavior.

Umiddelbart skulle man tro, hvis man ikke explicit konfigurerede Application Insights provideren i ens konfiguration, så vil den defaulte til Information, da Information er den sane default for næsten alt, men ikke for alle providers, da Application Insights er lidt speciel, da det i sidste ende kan koste penge, så Microsoft har været meget konservative i deres tilgang her, hvilket er en hel fin strategi.

Man kan let afprøve det ved kun at defaulte til Information i ens default logning level

    {
      "Logging": {
        "LogLevel": {
          "Default": "Information"
        }
      },
      "AllowedHosts": "*"
    }

Og derefter skrive nogle log events:

    Logger.LogInformation("Information");
    Logger.LogWarning("Warning");
    Logger.LogTrace("Trace");
    Logger.LogDebug("Debug");
    Logger.LogError("Error");
    Logger.LogCritical("Critical");

og tjekker traces i Application Insights. Her vil man stadig kun se

  1. Warning

  2. Error

  3. Critical

Mens konsollen vil indeholde alle overstående samt Information

/images/levels.png

Hvilket er lidt specielt, da den defaulte logging level for console provideren er Information. En sjov lille detalje, som divergerer lidt fra den ellers generelle Information fallback, som nok højest sandsynlig er lavet, som en sikker fallback, da man helst ikke vil flyde for mange log traces i Application Insights, hvis brugeren ikke explicit har angivet et default niveau.

Hvis du vil have Application Insights til at defaulte til Warning, og du vil have console provideren til at defaulte til Information, så kan du blot lade helt være med at angive noget:

    {
    }

Det er lettere at læse, men det er meget indforstået.

Azure Functions

MEN: Husker I hvad jeg skrev omkring den defaulte lognings niveau i Azure Functions?

If you don't explicitly set the minimum level, the default value is Information, which means that Trace and Debug logs are ignored.

Hvis man I Azure Functions ikke definere en default logLevel i host.json

    {
      "version": "2.0",
      "functionTimeout": "00:10:00",
      "logging": {
        "applicationInsights": {
          "samplingSettings": {
            "isEnabled": false
          }
        }
      }
    }

Så defaulter den til Information, og dette gælder OGSÅ for Application Insights, for Application Insights provideren, selvom dette ikke er gældende for ASP.NET Core delen, hvor den defaulter til Warning, hvis ikke andet er angivet.

Jeg tror dog Azure Functions laver denne defaulting, da man som sådan ikke kan angive nogen logLevel for application insights settings delen. På den måde kommer logLevel for Azure Functions til at gælde for både

  1. Konsollen

  2. Application Insights

selvom dokumentationen siger at der defaultes til Warning for Application Insights hvis ikke andet er angivet.

TLDR

loglevel for Application Insights defaulter til

  1. Warning hvis ikke andet er defineret i ASP.NET Core

  2. Information hvis ikke andet er defineret i Azure Functions

Kunne man beskrive dette noget bedre i dokumentationen? Det synes jeg godt man kunne., derfor har jeg også åbnet en case ved Microsoft.

Wrapping up

Jeg er stadig imponeret over hvor god dokumentationen er, og hvor meget information man kan grave frem. Man kan diskutere om alle default niveauer fortjente en samlet side for sig, så det gav noget overblik, men er i petitesse afdelingen. Jeg er glad for at arbejde med serier af produkter, og teknologier, hvor adgangen til dokumentationen er let, hvor det tekniske niveau er højt, og hvor man kan mærke at der altid med tiden bliver tilføjet, opdateret og tilrettet ting, når noget fornyer i sig.

Man lærer noget nyt hver dag. Selv med en så gammel traver, som logning.

comments powered by Disqus