What to Log and What Never to Log
Log decisions and failures, never secrets or personal data, and treat log volume as the running cost it is.
logger.LogError(ex, "charge failed for customer {CustomerId}", customerId);Logs are read when something is wrong, by someone who was not there. That is the standard to write to.
What to log
Log decisions and the identifiers that explain them: this payment was declined, this request was rejected as invalid, this retry was the third. Log the boundaries: a call to another service failed, a message was taken off a queue. Log failures with their exception object, so the stack trace comes too. Every line should include at least one id you can search on.
Do not log a line that only says a method was entered. The useful version says what the method decided.
What never to log
Passwords, password hashes, API keys, tokens, Authorization headers, cookies, card numbers, full request and response bodies. Also personal data you have no reason to keep: names, email addresses, postal addresses, dates of birth. A log store is copied, backed up, shipped to a third party and read by people who are not allowed to see any of that. Log an id instead, and mask what has to appear, such as the last four digits of a card.
Volume is money
Log systems bill by the gigabyte ingested and stored. One Information line inside a loop over ten thousand rows is ten thousand lines. Keep per-item detail at Debug, raise chatty framework categories to Warning, and do not log the same failure at every level of the call stack as it is rethrown.
Example
// dotnet add package Microsoft.Extensions.Logging.Console
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Logging.Console;
using ILoggerFactory factory = LoggerFactory.Create(builder =>
{
builder.SetMinimumLevel(LogLevel.Information);
builder.AddSimpleConsole(options =>
{
options.ColorBehavior = LoggerColorBehavior.Disabled;
});
});
ILogger logger = factory.CreateLogger("Payments");
string cardNumber = "4111111111111111";
// The decision, the id that finds the record, and a masked card.
logger.LogInformation(
"payment declined: customer {CustomerId} card {CardSuffix} reason {Reason}",
4821, Redact.Last4(cardNumber), "insufficient_funds");
// Never this. The card number and the email would sit in the log store
// for as long as it is kept, which is longer than you think:
// logger.LogInformation("declined card {Card} for {Email}",
// cardNumber, "[email protected]");
static class Redact
{
public static string Last4(string cardNumber)
{
return cardNumber.Length <= 4 ? "****" : "****" + cardNumber[^4..];
}
}
// Output:
// info: Payments[0]
// payment declined: customer 4821 card ****1111 reason insufficient_fundsWhen to use it
- Record why a payment was refused without storing the card number.
- Cut a log bill by raising the level of the two categories producing most of the volume.
- Make a production failure diagnosable from the log line alone, without reproducing it.
More examples
Log the exception once, where you handle it
This prints a fail: line with the message, then the exception type, its message and the stack trace. The rule that matters is once: log where you decide what to do about the failure, and let the exception travel untouched everywhere else. A catch that logs and rethrows gives you the same failure three times with three stack traces.
using Microsoft.Extensions.Logging;
public class CheckoutService
{
private readonly ILogger<CheckoutService> _logger;
public CheckoutService(ILogger<CheckoutService> logger)
{
_logger = logger;
}
public bool Charge(int customerId)
{
try
{
CallGateway(customerId);
return true;
}
catch (TimeoutException ex)
{
// The exception is the first argument, so the stack trace is
// kept. Logging ex.Message alone would lose it.
_logger.LogError(ex, "charge failed for customer {CustomerId}", customerId);
return false;
}
}
private static void CallGateway(int customerId)
{
throw new TimeoutException("the payment gateway did not answer");
}
}Never log a whole object
Passing an object as a log value calls ToString on it, and for a record that prints the lot. The same trap applies to serialising a request body "so we have it". Choose the fields deliberately, one at a time, and the day someone adds a Password property to that type you are still safe.
using Microsoft.Extensions.Logging;
public record SignUpRequest(string Email, string Password, string Country);
public static class SignUpLogging
{
public static void LogAccepted(ILogger logger, SignUpRequest request, int userId)
{
// Wrong. A record's generated ToString prints every property,
// so this writes the password into the log:
// logger.LogInformation("sign-up accepted {Request}", request);
// Right. An id to find the row, and one field that is not personal.
logger.LogInformation("sign-up accepted: user {UserId} country {Country}",
userId, request.Country);
}
}Turning down the two loudest categories
The first category writes a request-starting and a request-finished line for every request, including health probes; the second writes every SQL statement EF Core executes, at Information. Together they are often most of a log bill. Raising them to Warning keeps your own Information lines and drops theirs. Put this in production configuration only, so local debugging still shows the SQL.
{
"Logging": {
"LogLevel": {
"Default": "Information",
"Microsoft.AspNetCore.Hosting.Diagnostics": "Warning",
"Microsoft.EntityFrameworkCore.Database.Command": "Warning"
}
}
}
Discussion