serilog-aspnetcore: .NET 6 WebApplicationFactory test throws System.InvalidOperationException : The entry point exited without ever building an IHost.

Description When I have Serilog configured on my Program.cs and if I run more than one test that uses WebApplicationFactory I get an exception thrown System.InvalidOperationException : The entry point exited without ever building an IHost. accessing the application factory services.

Reproduction Program.cs

using System.Text.Json.Serialization;
using Serilog;

Log.Logger = new LoggerConfiguration()
    .WriteTo.Console()
    .CreateBootstrapLogger();

Log.Information("Starting up...");

try
{
    var builder = WebApplication.CreateBuilder(args);
    builder.Host.UseSerilog((ctx, lc) => lc.ReadFrom.Configuration(ctx.Configuration));

    var configuration = builder.Configuration;
    var services = builder.Services;
    // Add services to the container.

    services.AddControllers()
         .AddJsonOptions(options =>
         {
             options.JsonSerializerOptions.Converters.Add(new JsonStringEnumConverter());
         })
         .AddControllersAsServices();
    services.AddEndpointsApiExplorer();

    services.AddSwaggerGen();

    var app = builder.Build();

    app.UseSerilogRequestLogging();

    app.UseCors(builder =>
        builder
            .WithOrigins(configuration.GetSection("AllowedOrigins")
                .AsEnumerable()
                .Select(kvp => kvp.Value)
                .Where(origin => !string.IsNullOrEmpty(origin))
                .ToArray()
            )
            .SetIsOriginAllowedToAllowWildcardSubdomains()
            .AllowAnyMethod()
            .AllowAnyHeader()
            .AllowCredentials());

    // Configure the HTTP request pipeline.
    if (app.Environment.IsDevelopment())
    {
        app.UseSwagger();
        app.UseSwaggerUI();
    }

    app.UseHttpsRedirection();

    app.UseAuthentication();
    app.UseAuthorization();

    app.MapControllers();

    app.Run();
    return 0;
}
catch (Exception ex)
{
    Log.Fatal(ex, "Host terminated unexpectedly.");
    return 1;
}
finally
{
    Log.CloseAndFlush();
}

#pragma warning disable CA1050 // Declare types in namespaces
public partial class Program { } // so you can reference it in tests
#pragma warning restore CA1050 // Declare types in namespaces

appsettings.json:

{
  "AllowedHosts": "*",
  "Serilog": {
    "AllowedHosts": "*",
    "MinimumLevel": {
      "Default": "Information",
      "Override": {
        "Microsoft": "Warning",
        "Microsoft.Hosting.Lifetime": "Information"
      }
    },
    "Enrich": [
      "FromLogContext"
    ],
    "Filter": [
      {
        "Name": "ByExcluding",
        "Args": {
          "expression": "@mt = 'An unhandled exception has occurred while executing the request.'"
        }
      }
    ],
    "WriteTo": [
      {
        "Name": "Console",
        "Args": {
          "outputTemplate": "[{Timestamp:HH:mm:ss} [{Level}]: {Message:l}{NewLine}{Exception}"
        }
      }
    ]
  }
}

TestApplication.cs:

using Microsoft.AspNetCore.Mvc.Testing;
using Microsoft.Extensions.Hosting;

namespace Api.Tests;

internal class TestApplication : WebApplicationFactory<Program>
{
    private readonly string environment;

    public TestApplication(string environment = "Development")
    {
        this.environment = environment;
    }

    protected override IHost CreateHost(IHostBuilder builder)
    {
        builder.UseEnvironment(environment);
        return base.CreateHost(builder);
    }
}

SwaggerTest.cs:

using System.Linq;
using System.Threading.Tasks;
using FluentAssertions;
using Microsoft.Extensions.DependencyInjection;
using Swashbuckle.AspNetCore.Swagger;
using Xunit;

namespace Api.Tests.Swagger;

public class SwaggerTest
{
    [Fact]
    public async Task OperationIds_Should_Be_Unique()
    {
        await using var application = new TestApplication();
        var swaggerProvider = application.Services.GetRequiredService<ISwaggerProvider>();
        var swagger = swaggerProvider.GetSwagger("v1");
        var operationIds = swagger.Paths.Values.SelectMany(path => path.Operations.Values.Select(operation => operation.OperationId)).ToList();

        operationIds.Should().OnlyHaveUniqueItems();
    }

    [Fact]
    public async Task OperationIds_Should_Be_Unique2()
    {
        await using var application = new TestApplication();
        var swaggerProvider = application.Services.GetRequiredService<ISwaggerProvider>();
        var swagger = swaggerProvider.GetSwagger("v1");
        var operationIds = swagger.Paths.Values.SelectMany(path => path.Operations.Values.Select(operation => operation.OperationId)).ToList();

        operationIds.Should().OnlyHaveUniqueItems();
    }
}

Expected behavior Tests pass, and does not throw calling application.Services

Relevant package, tooling and runtime versions

<PackageReference Include="Serilog.AspNetCore" Version="4.1.0" />
<PackageReference Include="Serilog.Expressions" Version="3.2.1" />

dotnet --version:

6.0.102

Additional context The tests pass if I comment out the line builder.Host.UseSerilog((ctx, lc) => lc.ReadFrom.Configuration(ctx.Configuration)); from Program.cs.

About this issue

  • Original URL
  • State: open
  • Created 2 years ago
  • Reactions: 10
  • Comments: 28 (7 by maintainers)

Commits related to this issue

Most upvoted comments

Same issue here.

This is an ugly issue IMO because if you try and do everything right by following the Serilog docs and use CreateBootstrapLogger() and you follow the official Microsoft Integration Testing Docs which recommend creating test classes with ITestFixture<CustomWebAppFactory<Program>> by default everything will run in parallel and you will hit this bug and then spend maybe hours fighting it before you land here on this issue from Google.

Maybe the Serilog docs could be improved to warn of this? IE:

If you use CreateBootstrapLogger() along with XUnit parallel tests, an exception may get thrown in your startup/program as the freezing of the ReloadableLogger is a stateful operation.

Or maybe there is a way for someone much smarter than me to maker a change in CreateBootstrapLogger() to circumvent this issue?

+7
VictorioBerra on Mar 2, 2023

Changing Serilog initialization in Program.cs from:

Log.Logger = new LoggerConfiguration()
    .WriteTo.Console()
    .CreateBootstrapLogger();

to:

Log.Logger = new LoggerConfiguration()
    .WriteTo.Console()
    .CreateLogger();

solved the problem. @nblumhardt could you explain why is that?

+6
pikoscielniak on Mar 7, 2022

I ran into this today and settled on the following workaround.

Step 1 : inject a setting during the test server bootstrap

public class CustomWebAppFactory
    : WebApplicationFactory<Your.Program>
{

    protected override void ConfigureWebHost(IWebHostBuilder builder)
    {
        builder.UseSetting("integrationTest", "true");
        ...
    }

Step 2: pull out the arg and conditionally build your loggers

    public static Serilog.ILogger CreateIntegrationTestLogger()
        => new LoggerConfiguration()
             .WriteTo.Console()
             .CreateLogger();

    public static Serilog.ILogger CreateBootstrapLogger()
        => new LoggerConfiguration()
            .WriteTo.Console()
            .CreateBootstrapLogger();

    public static void Main(string[] args)
    {
        var isIntegrationTest = args.Contains("--integrationTest=true");
        Log.Logger = isIntegrationTest ? CreateIntegrationTestLogger() : CreateBootstrapLogger();
        ...
    }

Another option would be to use Debug/Release pragma to define the logger behaviour or the --environment="Development" flag which is also available in the args array. That choice depends on what env + build config you choose to run your tests.

+3
tmakin on Mar 13, 2023

I can confirm that the problem happens only when tests are run in parallel. When I run test with the config:

{
  "$schema": "https://xunit.net/schema/current/xunit.runner.schema.json",
  "parallelizeTestCollections": false
}

they all pass, but unfortunately it’s not a solution at my case. I strongly need run tests parallelly.

+3
pikoscielniak on Mar 4, 2022

@nblumhardt Coming in as another mildly annoyed person who followed both Serilog and MSFT’s documentation for appropriately using Serilog and E2E testing w/ WebApplicationFactory, and after a couple days of trial and error, stumbled across parallelization as the culprit and thus this issue. It would be great to either see a resolution or perhaps an edit to the documentation for CreateBootstrapLogger that it can cause issues in these scenarios.

+2
svengeance on Jul 21, 2023

Are we obligated to use Log.Logger? I’ve solved this problem like that:

using Serilog;
using var log = new LoggerConfiguration()
    .WriteTo.Console()
    .CreateLogger();
try
{
    var builder = WebApplication.CreateBuilder(args);
    builder.Host.UseSerilog((ctx, sp, conf) => conf.ReadFrom.Configuration(ctx.Configuration)));
    // builder configuration omitted
    var app = builder.Build();
    // app configuration omitted
    app.Run();
}
catch (Exception ex)
{
    log.Fatal(ex, "An unhandled exception occurred during bootstrapping");
}
public partial class Program { }
+2
gritcsenko on May 31, 2023

Does anyone have a solution please?

+2
Brawns on Oct 12, 2022

Workaround with logger set did not work for me.

Log.Logger = new LoggerConfiguration()
    .WriteTo.Console()
    .CreateLogger();
+2
span on Apr 17, 2022

@pikoscielniak thanks for helping to track it down. CreateBootstrapLogger() creates a ReloadableLogger, which the UseSerilog() callback reconfigures and then freezes.

Freezing is a stateful operation:

https://github.com/serilog/serilog-extensions-hosting/blob/dev/src/Serilog.Extensions.Hosting/Extensions/Hosting/ReloadableLogger.cs#L80

Not sure how best to avoid this in testing… 🤔

+2
nblumhardt on Mar 7, 2022

It’s really strange. When I run tests in debug all tests pass.

+2
pikoscielniak on Mar 4, 2022

Also LGTM, @gritcsenko, if you’re not using Log.Logger 👍

+1
nblumhardt on May 31, 2023

@span @MichaelDeutschCoding sounds like you’re hitting something else; if you’re sure it’s Serilog-related, could you please post a new issue and include as much detail as possible? Thanks!

I can confirm my issues were not only Serilog related and they are now resolved. I had two issues. I did feel the need to post here though, since Google search result were sparse on the error message.

  1. The same as mentioned, where the bootstrap logger was causing the problem and the suggested fix works fine. I do get another error message when using the bootstrap logger though. System.InvalidOperationException: The logger is already frozen..

  2. I also had to remove a try/catch statement that I had around my app code in Program.cs. I was using the try/catch for some debugging but it seems it actually caused this same IHost error. Not sure if it is a bug or feature, but it is .net core related rather than serilog.

+1
span on Apr 18, 2022

Just adding another voice here that we’re also seeing this exception in parallel unit tests when using WebApplicationFactory and CreateBootstrapLogger().

+1
wokket on Mar 10, 2022

https://nblumhardt.com/2020/10/bootstrap-logger/#why-cant-we-just-do-both has some info on the problems CreateBootstrapLogger() resolves; if those issues don’t apply to you then it’s fine to just use CreateLogger() instead.

+1
nblumhardt on Mar 8, 2022
Read more comments on GitHub
← serilog-aspnetcore: Could not load file or assembly Microsoft.Extensions.DependencyModel
serilog-aspnetcore: RequestLoggingMiddleware does not include RequestId →