Log startup exceptions when CaptureStartupErrors is not set

[cwe1ss]

Hi! Right now, if there is a startup exception the process keeps running and prints out the exception. This makes it really hard for orchestration/monitoring tools like Azure Service Fabric to find out whether the startup succeeded or not.

I know that this is a feature ( #370, #486 ) and this is helpful in development scenarios. However, I think that there should be an option that allows us to disable this behavior. In a production environment, these errors must be addressed with proper logging techniques anyway (ETW, ILogger, Windows Event Log, ...) to trigger alerts and so on. Crashing the process would allow Azure Service Fabric to automatically retry a few times.

I would suggest the following behavior:

• It should not be bound to the Environment variable. We might want to have this behavior locally or in our test environment as well.
• It should be a separate parameter (e.g. like --server.urls or a different environment variable). The default could be the current behavior.
• There should be a best-effort to catch the exception and send it to the ILogger pipeline. This way we could send the exception to our logging system - of course, only in case the logger was already initialized. AFAIK this is already the current implementation.
• After the attempt to log the exception, the process should exit with a failure code. If possible, the exception should be sent to the .NET exception EventSource-Provider (but I think this will happen automatically!?)

[davidfowl]

This already exists in rc2 as an option that can be set in the same ways as server.urls.

Hosting/test/Microsoft.AspNetCore.Hosting.Tests/WebHostBuilderTests.cs

Line 141 in cf6d7f9

var hostBuilder = new WebHostBuilder()

It should not be bound to the Environment variable. We might want to have this behavior locally or in our test environment as well.

Its bound like any other setting which means it can come from the environment, or a config switch or a file or it can be set programmatically.

There should be a best-effort to catch the exception and send it to the ILogger pipeline. This way we could send the exception to our logging system - of course, only in case the logger was already initialized. AFAIK this is already the current implementation.

Yep it already does this.

After the attempt to log the exception, the process should exit with a failure code. If possible, the exception should be sent to the .NET exception EventSource-Provider (but I think this will happen automatically!?)

If you've configured this. The hosting pipeline doesn't bake any logger providers into the system.

[cwe1ss]

Hi David, thank you for your response! Looks like a lot has changed since RC1 (which is a good thing!! :-) )

Regarding the logging: Are we talking about this code?

Right now, if CaptureStartupErrors is false, exceptions never enter the catch block and therefore, logger.ApplicationError(ex); is never called. Is there some other location that logs the error?

If not, I think the code should be changed to something like this:

catch (Exception ex) {

  // log and crash the process
  logger.ApplicationError(ex);
  if (!_options.CaptureStartupErrors) {
    throw;

  // keep the server running and output the error
}

[davidfowl]

@Eilon @lodejard @rynowak @Tratcher What did we say about logging and re-throwing? Wasn't that one of the logging no nos?

[cwe1ss]

That's not great, yes. Maybe something like this would be better:

catch (Exception ex) {

  // log and crash the process
  logger.ApplicationError(ex);
  if (!_options.CaptureStartupErrors) {
    Dispose(); // but we should make sure that the process exits with an error code
    return;
  }

  // keep the server running and output the error
}

The important thing is just whether you agree that we should send the exception to the logger in all cases. I'm sure you'll find a smart solution about how to do it! 👍 :)

[cwe1ss]

Not knowing that CaptureStartupErrors exists was my bad. I renamed the issue to better reflect the current discussion. Or do you think that a new issue should have been created for this?

Let me also rephrase the question:

If CaptureStartupErrors is false, do you think that the framework should still log startup errors or is it up to the application developer to catch and log the exception?

I think it would be ok to catch the errors ourselves if we were allowed to pass our own LoggerFactory into the WebHostBuilder (see #661 ). In that case I would change my Program.cs to something like this anyway to get as many exceptions as possible (better safe than sorry). This would also address your concern regarding logging and re-throwing.

public class Program
{
    private static ILogger _logger;

    public static void Main(string[] args)
    {
        var loggerFactory = new LoggerFactory();
        _logger = loggerFactory.CreateLogger<Program>();

        AppDomain.CurrentDomain.UnhandledException += UnhandledException;

        loggerFactory.AddConsole();

        // TODO add remote logger providers (Application Insights, ...)

        var host = new WebHostBuilder(loggerFactory)
            .UseDefaultConfiguration(args)
            .UseServer("Microsoft.AspNetCore.Server.Kestrel")
            .UseStartup<Startup>()
            .Build();

        host.Run();
    }

    private static void UnhandledException(object sender, UnhandledExceptionEventArgs e)
    {
        _logger.LogCritical(0, "Application crashed", (Exception) e.ExceptionObject);
    }
}

If we are not allowed to pass our own LoggerFactory then we don't have many possibilities to catch and log the exception ourselves. There is WebHostBuilder.ConfigureLogging() but this would only allow us to add providers. It would not give us a way to catch and log the exception.

[davidfowl]

Just wrap the build method in a try catch then log

[cwe1ss]

I would do so if I had access to the logger already. If I'm correct, I would have to write something like this at the moment:

public static void Main(string[] args)
{
    ILoggerFactory loggerFactory = null;

    var builder = new WebHostBuilder()
        .ConfigureLogging(factory =>
        {
            factory.AddConsole();
            // TODO initialize remote loggers

            loggerFactory = factory; // "steal" the factory
        })
        .UseDefaultConfiguration(args)
        .UseServer("Microsoft.AspNetCore.Server.Kestrel")
        .UseStartup<Startup>();

    try
    {
        builder.Build().Run();
    }
    catch (Exception ex) when (loggerFactory != null) 
    {
        // out of luck, if the Exception happened before ConfigureLogging was called

        var logger = loggerFactory.CreateLogger<Startup>();
        logger.LogCritical(0, ex, "Startup exception");
    }
}

So I would have to somehow "steal" the loggerFactory from the ConfigureLogging method because there's no way to get it from DI yet. This code is absolutely horrible IMO.

As I said, I think passing an existing LoggerFactory into the WebHostBuilder completely solves this issue.

Thank you again David for taking the time to look at this and for being so responsive! I really appreciate that and I really enjoy working with this framework and with you guys!

[cwe1ss]

As it is now possible to create the LoggerFactory myself and to pass it into the WebHostBuilder (#661), I will solve this by catching the error myself.

I would like to thank you for making this work! 👍