serilog-extensions-hosting icon indicating copy to clipboard operation
serilog-extensions-hosting copied to clipboard

Two-stage initialization with exception during `UseSerilog` is not logged to files

Open cremor opened this issue 1 year ago • 5 comments

Example:

Log.Logger = new LoggerConfiguration()
    .WriteTo.Debug()
    .WriteTo.Console()
    .WriteTo.File(BootstrapLogFilePath, LogEventLevel.Error)
    .CreateBootstrapLogger();
	
var builder = WebApplication.CreateBuilder(args);
	
builder.Host.UseSerilog((context, services, loggerConfiguration) => loggerConfiguration
    .ReadFrom.Configuration(context.Configuration)
    .ReadFrom.Services(services));

If an exception happens in the configureLogger action passed to UseSerilog (e.g. because the configuration in appsettings.json is invalid) then the resulting exception will be logged in the console and debug output, but it will not be logged in the file.

The Serilog SelfLog logs a related exception: "Caught exception while emitting to sink Serilog.Core.Sinks.RestrictedSink: System.ObjectDisposedException: Cannot write to a closed TextWriter." It looks like the bootstrap logger is already disposed, but the new logger doesn't exist yet. So the exception can't be logged to any file.

Would it be possible to only dispose the bootstrap logger once the new logger is fully loaded? Then the exception would be logged to the file sink from the bootstrap logger.

In any case, exceptions that happen during the configureLogger action passed to UseSerilog should be written to the SelfLog.

cremor avatar Aug 04 '23 13:08 cremor

It's not possible to wait for the new logger to be fully constructed before disposing the bootstrap logger, as this prevents reopening the same log file in both configurations, for example. Logging to SelfLog seems like a good first step to improving this, though.

nblumhardt avatar Aug 05 '23 00:08 nblumhardt

It's not possible to wait for the new logger to be fully constructed before disposing the bootstrap logger, as this prevents reopening the same log file in both configurations, for example.

I see. Would it be possible to recreate the bootstrap logger configuration when an exception happens?

Logging to SelfLog seems like a good first step to improving this, though.

Thanks!

One additional idea: Depending on what exactly fails during logging configuration the exception message could be not helpful at all and the stack trace could be complicated. Maybe it would be a good idea to wrap those exceptions with something like "Serilog logger configuration failed, see inner exception for details."?

cremor avatar Aug 05 '23 07:08 cremor

Unfortunately the bootstrap logger is configured outside of the code callable by this package, so it can't be re-created (otherwise it'd be a reasonable way to go).

SelfLog supports arbitrary string arguments, so the message could include the text you mention, e.g.:

SelfLog.Write($"Logger reconfiguration failed: {ex}");

(It's not necessary to mention that the message is from Serilog, since it's Serilog's internal log - nothing else writes to it.)

nblumhardt avatar Aug 09 '23 05:08 nblumhardt

The wrapper exception idea was for the exception that is actually thrown - not for the self log.

cremor avatar Aug 09 '23 05:08 cremor

Ah, sorry, now I understand what you mean :+1:

nblumhardt avatar Aug 09 '23 05:08 nblumhardt