Skip to content

Per-ActorSystem ILoggerFactory — global Proto.Log static causes test instability under parallel xUnit runs #2427

Description

@adbre

Summary

Proto.Log._loggerFactory is a process-global mutable static (Proto.Actor/Logging/Log.cs:22). AddProtoCluster overwrites it on every cluster bootstrap (Proto.Cluster/ServiceCollectionExtensions.cs:36-39):

var loggerFactory = p.GetRequiredService<ILoggerFactory>();
Log.SetLoggerFactory(loggerFactory);

This is the only piece of cluster framework state that is shared across ActorSystem instances. Every other piece (mailboxes, identity registry, gossip, IRemote, IClusterProvider, TestProvider + InMemAgent) is correctly per-instance.

Impact

In an xUnit test suite where each test creates its own ActorSystem via AddProtoCluster:

  • Every test's ILoggerFactory is wired to that test's own ITestOutputHelper.
  • Last-write-wins: tests running concurrently overwrite each other's Log._loggerFactory.
  • When test A finishes, xUnit deactivates its ITestOutputHelper. If A's cluster shutdown is still draining actors in the background, those actors call Log.CreateLogger<T>() → log → throw InvalidOperationException("There is no currently active test"). Uncaught background exception → testhost crash.
  • The actual symptom is "Test host process crashed", not a test-method failure, which makes diagnosis painful.

This forces test suites to run sequentially even when each test has its own ActorSystem.

Reproduction

Minimal xUnit project. Each test class creates its own ActorSystem + Cluster and routes Proto.Actor's logging through that test's ITestOutputHelper. xUnit runs different test collections in parallel by default, so classes A and B run concurrently.

TestSystem.cs — shared bootstrap:

using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;
using Proto;
using Proto.Cluster;
using Proto.Cluster.Testing;
using Xunit.Abstractions;

public sealed class TestSystem : IAsyncDisposable
{
    private readonly ServiceProvider _services;
    public Cluster Cluster { get; }

    public TestSystem(ITestOutputHelper output)
    {
        var services = new ServiceCollection();
        services.AddLogging(b => b.AddProvider(new XUnitLoggerProvider(output)));
        services.AddProtoCluster((_, c) =>
        {
            c.ClusterName = "Repro";
            c.ClusterProvider = new TestProvider(new TestProviderOptions(), new InMemAgent());
        });
        _services = services.BuildServiceProvider();
        Cluster = _services.GetRequiredService<Cluster>();
        Cluster.StartMemberAsync().GetAwaiter().GetResult();
    }

    public async Task PingAsync()
    {
        // Any cluster activation that spawns an actor and produces log writes is enough.
        // TopologyConsensus ensures the system is fully bootstrapped.
        await Cluster.MemberList.TopologyConsensus(default);
    }

    public async ValueTask DisposeAsync()
    {
        await Cluster.ShutdownAsync(graceful: true);
        await _services.DisposeAsync();
    }
}

XUnitLoggerProvider.cs — the smallest possible bridge from ILoggerFactory to ITestOutputHelper (this is what every Proto.Actor + xUnit setup ends up writing in some form):

public sealed class XUnitLoggerProvider(ITestOutputHelper output) : ILoggerProvider
{
    public ILogger CreateLogger(string categoryName) => new XUnitLogger(output, categoryName);
    public void Dispose() { }
    private sealed class XUnitLogger(ITestOutputHelper output, string category) : ILogger
    {
        public IDisposable? BeginScope<TState>(TState state) where TState : notnull => null;
        public bool IsEnabled(LogLevel level) => true;
        public void Log<TState>(LogLevel level, EventId id, TState state, Exception? ex, Func<TState, Exception?, string> fmt)
            => output.WriteLine($"[{level}] {category}: {fmt(state, ex)}");
    }
}

Test classes — at least two, in different collections (xUnit default: every class is its own collection):

public class ReproATests : IAsyncDisposable
{
    private readonly TestSystem _system;
    public ReproATests(ITestOutputHelper output) => _system = new(output);
    [Fact] public Task Run() => _system.PingAsync();
    public ValueTask DisposeAsync() => _system.DisposeAsync();
}

public class ReproBTests : IAsyncDisposable
{
    private readonly TestSystem _system;
    public ReproBTests(ITestOutputHelper output) => _system = new(output);
    [Fact] public Task Run() => _system.PingAsync();
    public ValueTask DisposeAsync() => _system.DisposeAsync();
}

xunit.runner.json (xUnit defaults are equivalent — included for explicitness):

{
  "parallelizeAssembly": false,
  "parallelizeTestCollections": true
}

Run dotnet test repeatedly. With ~4–8 such test classes you'll see intermittent runs where one or more tests show "The active test run was aborted. Reason: Test host process crashed". The dump shows an unhandled InvalidOperationException("There is no currently active test") originating from ITestOutputHelper.WriteLine, called from XUnitLogger.Log, called from a Proto.Actor internal type via Log.CreateLogger<T>() during another test's cluster shutdown.

Setting "parallelizeTestCollections": false makes the failure go away — confirming the race is across concurrent tests, not within one.

Root cause

Proto.Log provides no ActorSystem-scoped logger access. Internal Proto.Actor types call Log.CreateLogger<T>() without an ActorSystem context, so the framework can't route a log call to "the right" factory even if one were available.

Suggested fix

Make ActorSystem own its ILoggerFactory:

  • Add ActorSystem.LoggerFactory (resolved via Config or DI).
  • Internal types that currently use Log.CreateLogger<T>() should accept an ActorSystem (or Context.System) and call system.LoggerFactory.CreateLogger<T>().
  • Keep the static Log as a fallback for non-system-scoped code paths to preserve backward compatibility.

This was already on the V2 wishlist — "Remove static Logging factory — make better use of DI" — in #1683, but that issue was closed when V2 plans (PR #1979) were shelved. The DI-based logger is, in my view, valuable independently of the V2 effort and could ship as a focused, non-breaking change.

Workarounds

For test code today, wrapping the per-test ILoggerFactory so WriteLine swallows InvalidOperationException("There is no currently active test") keeps the host alive at the cost of dropping late log lines. Disabling parallelizeTestCollections in xunit.runner.json also avoids the crash but serializes the entire suite.

Environment

  • Proto.Actor 1.7.0 / 1.8.0 (both affected — Log.cs is identical)
  • xUnit 2.x with Xunit.Abstractions.ITestOutputHelper
  • Proto.Cluster.Testing.TestProvider + InMemAgent

Related

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions