RE:NODE

App hosting13 min read

ASP.NET Core logging and health checks in production

ILogger and log levels, structured messages, Serilog with sane sinks, request logging, and health check endpoints that tell the truth about your app.

0 readers

An ASP.NET Core app in production needs two things from you before it needs anything clever: logs that say what happened, at a level you chose on purpose, and an endpoint that says whether the app can do its job right now. The built-in ILogger covers the first if you set Logging:LogLevel deliberately and write structured messages instead of interpolated strings. AddHealthChecks() plus MapHealthChecks("/healthz") covers the second in two lines. Serilog is worth adding when you want files, enrichment or a log server; it is not required to log well. This post goes through both halves in the order you will meet them, with the defaults, the configuration keys, and the mistakes that turn logging into a disk-full incident.

How logging works in ASP.NET Core#

Logging is part of the generic host. When you call WebApplication.CreateBuilder(args), the builder registers the console, debug and event source providers (plus the Windows event log on Windows) and reads the Logging section of configuration. Anything that asks for an ILogger<T> through dependency injection receives a logger whose category is the full name of T, and every log call is filtered by that category before it reaches a provider.

csharp
public class OrderService(ILogger<OrderService> logger, AppDbContext db){    public async Task PlaceAsync(Order order)    {        db.Orders.Add(order);        await db.SaveChangesAsync();        logger.LogInformation("Order {OrderId} placed for {CustomerId}",            order.Id, order.CustomerId);    }}

The category matters because it is what the filter matches against. Microsoft.EntityFrameworkCore.Database.Command is the category that logs every SQL statement, Microsoft.AspNetCore.Hosting.Diagnostics logs request start and finish, and MyApp.OrderService is the one above. Filters match by prefix, so a rule for Microsoft.AspNetCore covers everything beneath it.

There are seven levels, and they are an ordered scale rather than a set of labels:

LevelValueUse it for
Trace0Step-by-step detail, possibly containing sensitive data. Never on in production
Debug1Developer diagnostics. Off in production unless you are hunting something
Information2Normal events worth a line: started, order placed, job finished
Warning3Something odd that the app recovered from
Error4An operation failed; the app keeps running
Critical5The app or a core dependency is down
None6Used only in filters, to switch a category off

A filter set to Warning passes Warning, Error and Critical and drops the rest. The cost of a dropped message is very small - the logger checks the level before formatting anything - which is why you can leave LogDebug calls in code without paying for them.

Setting log levels in appsettings and environment variables#

The template's appsettings.json is close to right for production:

appsettings.json
{  "Logging": {    "LogLevel": {      "Default": "Information",      "Microsoft.AspNetCore": "Warning",      "Microsoft.EntityFrameworkCore.Database.Command": "Warning"    }  }}

Default applies to every category without a more specific rule. Microsoft.AspNetCore at Warning silences the framework's per-request chatter, which otherwise produces two or more lines for every request, including every static file. The Entity Framework line is the one people forget: at Information, EF Core logs each SQL command it executes with its duration, which is useful on your laptop and a flood under load.

Configuration is layered, so you rarely need to edit the file to change a level on a running deployment. Environment variables override JSON, and the separator for nested keys is a double underscore:

env
Logging__LogLevel__Default=WarningLogging__LogLevel__Microsoft.EntityFrameworkCore.Database.Command=Information

A category name with dots works as an environment variable key on Linux. appsettings.Production.json is loaded on top of appsettings.json when ASPNETCORE_ENVIRONMENT (or DOTNET_ENVIRONMENT) is Production, which is also the default when neither is set. ASP.NET Core configuration and secrets explains the whole layering order, and it is worth reading before you put a connection string anywhere.

Changes to appsettings.json on disk are picked up while the app runs, because the default JSON source has reloadOnChange set. Environment variables are read once at start, so changing one means a restart.

Writing log messages that are worth reading#

The single most common logging mistake in .NET is string interpolation:

csharp
// Wrong: formatted every time, and the values are lost as fieldslogger.LogInformation($"Order {order.Id} placed for {order.CustomerId}");// Right: a message template with named placeholderslogger.LogInformation("Order {OrderId} placed for {CustomerId}",    order.Id, order.CustomerId);

The second form is a message template. The placeholders are matched to the arguments by position, not by name, and the names become properties on the log event. With the plain console logger you see the same sentence either way. With a structured provider - the JSON console formatter, Serilog, or anything that ships to a log server - you get OrderId and CustomerId as fields you can filter on, and the template itself stays constant, so "how many times did this message happen" becomes a simple count. The interpolated version is also formatted even when the level is filtered out, because the string is built before the method is called.

For hot paths, the source-generated LoggerMessage attribute removes the remaining cost: no boxing of value types, no parsing of the template at runtime, and a check of the level before anything is evaluated.

csharp
public static partial class Log{    [LoggerMessage(Level = LogLevel.Warning,        Message = "Payment provider slow: {ElapsedMs} ms for order {OrderId}")]    public static partial void PaymentSlow(ILogger logger, long elapsedMs, int orderId);}

Three habits are worth more than any provider choice:

  • Log exceptions as exceptions. logger.LogError(ex, "Charging order {OrderId} failed", id) keeps the stack trace as a structured field. Putting ex.Message into the template throws away the part you need.
  • One line per event, not per step. A request that logs ten Information lines on the happy path will bury the one Warning that matters.
  • Never log secrets or whole request bodies. Passwords, tokens, connection strings and card numbers end up in log files that are copied, downloaded and kept far longer than the data they describe.

Scopes attach context to every message written inside them, which is how you get an order number onto lines logged by code that does not know about orders. using (logger.BeginScope("Order {OrderId}", id)) { ... } does it; the console provider shows scopes only if IncludeScopes is enabled on its formatter, while structured providers record them as properties.

Console output in a container#

On a container host, the console is the log. Whatever the process writes to standard output is what the panel shows you, and what is kept between restarts depends on the host, so treat the console as a live view rather than an archive. The default simple formatter writes two lines per message (the category on one, the text on the next), which reads badly in a live console. Two changes help:

csharp
builder.Logging.ClearProviders();builder.Logging.AddSimpleConsole(options =>{    options.SingleLine = true;    options.TimestampFormat = "yyyy-MM-dd HH:mm:ss ";    options.UseUtcTimestamp = true;});

If something downstream parses your logs, use builder.Logging.AddJsonConsole() instead, which writes one JSON object per line with the template, the rendered message, and every named property.

On RE:NODE the console tab shows the process's output unfiltered and live, alongside graphs for memory, CPU and disk against the plan's limits, so a single-line, timestamped console is what you will actually be reading when something goes wrong. It is not a log archive: if you need last Tuesday's errors next month, write them somewhere that keeps them.

Serilog: when it is worth adding#

Serilog earns its place when you want one of three things the built-in providers do not do well: rolling log files with retention, enrichment (machine name, request ID, user ID on every event), or shipping to a log server such as Seq, Elasticsearch or Grafana Loki through a sink. The setup is a package and a few lines:

bash
$ dotnet add package Serilog.AspNetCore$ dotnet add package Serilog.Sinks.File
csharp
Log.Logger = new LoggerConfiguration()    .WriteTo.Console()    .CreateBootstrapLogger();try{    var builder = WebApplication.CreateBuilder(args);    builder.Services.AddSerilog((services, lc) => lc        .ReadFrom.Configuration(builder.Configuration)        .ReadFrom.Services(services)        .Enrich.FromLogContext());    var app = builder.Build();    app.UseSerilogRequestLogging();    // ... endpoints    app.Run();}catch (Exception ex){    Log.Fatal(ex, "Host terminated unexpectedly");}finally{    Log.CloseAndFlush();}

The bootstrap logger catches failures during startup, before configuration is loaded - which is exactly when a missing environment variable crashes the app and the default setup prints very little. Log.CloseAndFlush() matters for asynchronous and batching sinks: without it, the last messages before a crash are still in a buffer when the process exits.

UseSerilogRequestLogging() replaces the framework's several lines per request with one line carrying method, path, status code and elapsed time, which is the request log most people actually want. Combine it with a Microsoft.AspNetCore override at Warning so the framework's own lines are not written as well.

The configuration lives in its own section, which replaces Logging once Serilog is in charge:

appsettings.json
{  "Serilog": {    "MinimumLevel": {      "Default": "Information",      "Override": {        "Microsoft.AspNetCore": "Warning",        "Microsoft.EntityFrameworkCore": "Warning"      }    },    "WriteTo": [      { "Name": "Console" },      {        "Name": "File",        "Args": {          "path": "logs/app-.log",          "rollingInterval": "Day",          "retainedFileCountLimit": 14,          "fileSizeLimitBytes": 52428800,          "rollOnFileSizeLimit": true        }      }    ]  }}

If you do not need files, do not write them. A console-only app that ships to a log server through a sink has nothing to fill the disk with. Logs worth keeping goes through what to retain and for how long.

Health checks: liveness, readiness and dependencies#

A health check endpoint answers one question for a machine: can this instance serve requests right now? ASP.NET Core ships the plumbing in the box.

csharp
builder.Services.AddHealthChecks()    .AddCheck("self", () => HealthCheckResult.Healthy(), tags: ["live"])    .AddDbContextCheck<AppDbContext>(tags: ["ready"]);var app = builder.Build();app.MapHealthChecks("/healthz/live", new HealthCheckOptions{    Predicate = check => check.Tags.Contains("live")});app.MapHealthChecks("/healthz/ready", new HealthCheckOptions{    Predicate = check => check.Tags.Contains("ready")});

AddDbContextCheck comes from the Microsoft.Extensions.Diagnostics.HealthChecks.EntityFrameworkCore package and simply asks EF Core whether it can connect. For checks against a database without EF Core, the community AspNetCore.HealthChecks.* packages provide AddSqlServer, AddNpgSql, AddMySql, AddRedis and many others; they are widely used but not part of the framework, so pin their versions like any other dependency.

The response is plain text - Healthy, Degraded or Unhealthy - with status codes mapped like this by default:

ResultHTTP statusMeaning
Healthy200Everything checked is fine
Degraded200Working, but something is slow or partly failing
Unhealthy503Do not send traffic here

The split between liveness and readiness is the part that prevents outages instead of causing them. Liveness asks "is the process alive and not wedged" and should check nothing external. Readiness asks "can it serve real requests", and is where the database belongs. If your only endpoint checks the database and something restarts the app whenever that endpoint fails, a five-second database hiccup restarts every instance at once, and they all reconnect together. A liveness check that touches no dependency cannot cause that.

A custom check is a class implementing IHealthCheck:

csharp
public class QueueDepthCheck(IJobQueue queue) : IHealthCheck{    public async Task<HealthCheckResult> CheckHealthAsync(        HealthCheckContext context, CancellationToken cancellationToken = default)    {        var depth = await queue.CountAsync(cancellationToken);        return depth switch        {            < 1_000 => HealthCheckResult.Healthy($"{depth} jobs queued"),            < 10_000 => HealthCheckResult.Degraded($"{depth} jobs queued"),            _ => HealthCheckResult.Unhealthy($"{depth} jobs queued")        };    }}builder.Services.AddHealthChecks()    .AddCheck<QueueDepthCheck>("queue", timeout: TimeSpan.FromSeconds(3), tags: ["ready"]);

Give every check that touches the network a timeout. A health endpoint that hangs for thirty seconds is worse than one that returns 503, because whatever polls it may hold connections open and pile up.

Securing and exposing the health endpoint#

The default response is a single word, which is safe to expose. The moment you add a detailed writer - the popular UIResponseWriter.WriteHealthCheckUIResponse from AspNetCore.HealthChecks.UI.Client, or your own JSON with each check's description and exception - you are publishing the names of your dependencies and sometimes their error messages. Keep the public endpoint terse and put the detailed one behind authorisation or a host restriction:

csharp
app.MapHealthChecks("/healthz/ready");                 // public, one wordapp.MapHealthChecks("/healthz/detail", new HealthCheckOptions{    ResponseWriter = UIResponseWriter.WriteHealthCheckUIResponse}).RequireAuthorization("Ops");

Exclude health endpoints from request logging, or a monitor polling every thirty seconds writes nearly three thousand lines a day of nothing. With Serilog, the GetLevel option of UseSerilogRequestLogging can drop them to Verbose.

Know what will actually call the endpoint. On RE:NODE the platform's crash watcher polls every two minutes for a server whose uptime went backwards or that went offline, and opens a ticket after three unexpected restarts in an hour. It watches the process; it does not call your /healthz. A wedged app whose process is still alive and returning 503 will not be restarted by it, so point an external uptime monitor at the readiness URL through your domain. Monitoring that tells you something covers what to alert on, and graceful shutdown and health checks covers the other half - flipping readiness to unhealthy when the app is stopping, so a proxy stops sending it traffic before it exits.

Request logging, HTTP logging and correlation#

Three request-level tools exist, and they are not interchangeable:

  • Serilog request logging - one summary line per request. The right default.
  • `AddHttpLogging` / `UseHttpLogging` - the framework's HTTP logging middleware, which can include headers and bodies. It logs at Information under the Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware category, so it shows nothing until that category is allowed through the filter. Useful for a short debugging session; dangerous left on, because headers include cookies and authorisation tokens unless you restrict RequestHeaders and ResponseHeaders.
  • `AddW3CLogging` - an access log in the W3C extended format, written to files. Handy if you already have tools that read IIS-style logs.

For correlation, every request already has HttpContext.TraceIdentifier, and with the default Activity tracking each log event inside a request carries a TraceId and SpanId when the provider records them (the JSON console formatter and Serilog both can). Return the trace ID in error responses - ProblemDetails includes a traceId extension by default when you use AddProblemDetails() - and a user's screenshot of an error page becomes a direct search in your logs.

Behind a reverse proxy, the client address in your request logs is the proxy's until you enable forwarded headers. The real client IP arrives in X-Forwarded-For, and ASP.NET Core behind a reverse proxy shows the ForwardedHeadersOptions that make HttpContext.Connection.RemoteIpAddress correct, which is what both your logs and any rate limiter read.

Troubleshooting#

Nothing is logged at all. Usually ClearProviders() was called and nothing was added back, or Serilog was configured but its WriteTo section is empty or misspelt. Serilog's SelfLog.Enable(Console.Error) prints its own configuration errors.

The console is flooded with SQL. Microsoft.EntityFrameworkCore.Database.Command is at Information, either explicitly or through Default. Add the override at Warning.

Startup crashes with no useful output. The exception happened before logging was configured. Use a bootstrap logger (Serilog) or wrap builder.Build() and app.Run() in a try/catch that writes to Console.Error, then read the console from the top.

Health endpoint returns 503 but the app works. One check tagged into that endpoint is failing or timing out. Temporarily map a detailed writer behind authorisation and read which one; it is usually a dependency the endpoint should not have been checking.

The disk filled up. Find the log directory first. Rolling file sinks with default retention, Debug left on, and HTTP logging with bodies are the three usual causes, in that order.

Log lines show the proxy's address for every client. Forwarded headers are not configured, or KnownProxies does not include the proxy's address, so the middleware ignores the header.

FAQ#

Do I need Serilog, or is the built-in logging enough?

The built-in ILogger with the JSON console formatter is enough for an app whose logs are read from the console or collected from standard output. Serilog is worth adding for rolling files with retention, enrichment on every event, or a sink to a log server. Your code keeps calling ILogger either way, so switching later costs one setup change.

What log level should production run at?

Information for your own categories, Warning for Microsoft.AspNetCore and EF Core. Raise one category to Debug temporarily through an environment variable when you are chasing a problem, then put it back.

Should the health check test the database?

The readiness check should, because an app that cannot reach its database cannot serve most requests. The liveness check should not, because restarting the app does not fix the database and restarting every instance at once makes recovery slower.

Why are my structured properties missing from the output?

Either the message was built with string interpolation, so there are no placeholders to capture, or the provider is the plain simple console formatter, which renders the sentence and discards the fields. Use a message template and a structured formatter or sink.

How often should a monitor call the health endpoint?

Every 30 to 60 seconds is enough for a small app. More often adds load and log noise without telling you much sooner, and alerting after two consecutive failures avoids paging yourself over a single slow response.


Comments

Completely anonymous: no account, no email, no cookie. We store the name you type, the text and the time - nothing else. Links are limited and markup is not rendered.

0/2000