Skip to content

Conversation

@thomhurst
Copy link
Owner

@thomhurst thomhurst commented Jan 17, 2026

Summary

Introduces an extensible log sink architecture for routing test output to multiple destinations. This provides a foundation for custom logging integrations and future streaming capabilities.

Related: #4478 (real-time IDE streaming deferred to #4495)

Key Changes

  • New log sink system - Extensible architecture for routing log output to multiple destinations

    • ILogSink interface for custom log destinations
    • TUnitLoggerFactory for registering sinks at startup
    • LogSinkRouter for dispatching to all registered sinks
  • Built-in sinks

    • TestOutputSink - Accumulates output to TestContext.OutputWriter for test results
    • ConsoleOutputSink - Real-time console output when --output Detailed is enabled
  • Console interceptor integration - OptimizedConsoleInterceptor routes Console.WriteLine calls to registered sinks

  • VerbosityService improvements - Centralized control over output behavior

    • IsDetailedOutput flag for --output Detailed mode

Architecture

Console.WriteLine() / TestContext.OutputWriter
  → OptimizedConsoleInterceptor
    → LogSinkRouter
      → TestOutputSink (always) - buffers for test results
      → ConsoleOutputSink (if --output Detailed) - real-time console
      → Custom sinks (user-registered)

New Public APIs

namespace TUnit.Core.Logging;

// Interface for custom log sinks
public interface ILogSink
{
    bool IsEnabled(LogLevel level);
    void Log(LogLevel level, string message, Exception? exception, TestContext? context);
    ValueTask LogAsync(LogLevel level, string message, Exception? exception, TestContext? context);
}

// Factory for registering sinks
public static class TUnitLoggerFactory
{
    public static void AddSink(ILogSink sink);
    public static void AddSink<TSink>() where TSink : ILogSink, new();
    public static void RemoveSink(ILogSink sink);
    public static void RemoveSink<TSink>() where TSink : ILogSink;
    public static void ClearSinks();
}

Example: Custom Sink

public class MyCustomSink : ILogSink
{
    public bool IsEnabled(LogLevel level) => level >= LogLevel.Warning;
    
    public void Log(LogLevel level, string message, Exception? exception, TestContext? context)
    {
        // Send to external logging service, file, etc.
    }
    
    public ValueTask LogAsync(LogLevel level, string message, Exception? exception, TestContext? context)
    {
        Log(level, message, exception, context);
        return ValueTask.CompletedTask;
    }
}

// Register in test assembly
[assembly: BeforeEvery(Assembly)]
public static class Setup
{
    public static void RegisterSinks() => TUnitLoggerFactory.AddSink(new MyCustomSink());
}

Cleanup Included

  • Fixed critical bug: LogLevelProvider._logLevel was static, causing session pollution
  • Renamed NullLogger<T> to MtpNullLogger<T> for clarity
  • Removed unused AsyncConsoleWriter class
  • Removed dead ProcessFlushQueue() method
  • Improved documentation throughout

Test Plan

  • Unit tests for TUnitLoggerFactory
  • Unit tests for LogSinkRouter
  • Integration tests for log sink system
  • Manual testing with --output Detailed from console
  • Verify console mode with --output Normal still works (buffered)

Future Work

Real-time IDE streaming (#4495) will build on this sink architecture in a future PR.

Design for #4478 - enables real-time log streaming to IDEs during test
execution via a plugin-based ILogSink system inspired by ASP.NET Core.
Add sink routing to the console interceptors so that Console.WriteLine
calls stream in real-time to registered log sinks.

- Add abstract SinkLogLevel property to OptimizedConsoleInterceptor
- StandardOutConsoleInterceptor uses LogLevel.Information
- StandardErrorConsoleInterceptor uses LogLevel.Error
- Route all WriteLine methods (sync and async) to LogSinkRouter
- Use both sync RouteToSinks and async RouteToSinksAsync as appropriate
Add built-in log sink that streams log messages to IDEs (Rider, VS, etc.)
via Microsoft Testing Platform's IOutputDevice.DisplayAsync().

Features:
- Implements ILogSink interface from TUnit.Core.Logging
- Implements IOutputDeviceDataProducer for MTP integration
- Color-coded output by log level (Red=Error, Yellow=Warning, Gray=Debug)
- Configurable minimum log level (default: Information)
- Fire-and-forget sync logging with async implementation
- Exception message formatting appended to log message
Add comprehensive tests covering:
- AddSink registers sink and makes it available via GetSinks
- AddSink<T> instantiates and registers generic sink types
- GetSinks returns empty list when no sinks registered
- GetSinks returns snapshot (not live reference)
- Clear removes all sinks without disposing them
- DisposeAllAsync disposes IAsyncDisposable sinks
- DisposeAllAsync disposes IDisposable sinks
- DisposeAllAsync prefers IAsyncDisposable over IDisposable
- DisposeAllAsync clears sinks list after disposal
- DisposeAllAsync continues disposing remaining sinks on error

Tests use [NotInParallel] to ensure isolation since
TUnitLoggerFactory has static state.
Add end-to-end tests verifying that messages logged through
DefaultLogger are properly routed to registered sinks via
LogSinkRouter. Tests cover:

- Basic message routing to registered sink
- Multiple message routing
- Correct log level propagation
- Log level prefixes in messages
- Context passing to sinks
- Async logging support
- Multiple sinks receiving broadcast messages
- Disabled sink filtering
- Level-filtered sink behavior
@thomhurst
Copy link
Owner Author

Summary

Adds a plugin-based log sink system for real-time IDE streaming during test execution.

Critical Issues

1. Performance Regression in OptimizedConsoleInterceptor (BLOCKING)

Location: TUnit.Engine/Logging/OptimizedConsoleInterceptor.cs:499-547

The PR replaces optimized WriteLineFormatted calls with string.Format, which defeats the purpose of the BufferedTextWriter optimization.

Before: _originalOutBuffer?.WriteLineFormatted(format, arg0, arg1);
After: var str = string.Format(format, arg0, arg1); _originalOutBuffer?.WriteLine(str);

Problem: WriteLineFormatted uses StringBuilder.AppendFormat to avoid allocating intermediate strings. The new code calls string.Format upfront, creating an allocation on every formatted console write. This is a hot path during test execution.

Fix: Either keep using WriteLineFormatted and route the format string directly to sinks, OR if you need the formatted string, cache it once and reuse it for both destinations.

2. Lock Type Not Available in netstandard2.0 (BLOCKING)

Location: TUnit.Core/Logging/TUnitLoggerFactory.cs:177

The Lock type was introduced in .NET 9. TUnit targets netstandard2.0;net8.0;net9.0;net10.0. This will fail to compile on netstandard2.0 and net8.0.

Fix: Replace with object _lock or use conditional compilation.

3. Breaking Change - Removal of OriginalConsole Writes (BLOCKING)

Location: TUnit.Core/Logging/DefaultLogger.cs:25-31, 48-54

The PR removes writes to GlobalContext.Current.OriginalConsoleOut/Error from DefaultLogger. Was this intentional? If users relied on this for debugging, this is a breaking change. Verify that OutputDeviceLogSink provides equivalent coverage.

Suggestions

  1. Consider Thread-Safety of Sink Iteration (Low Priority)

Location: TUnit.Core/Logging/LogSinkRouter.cs:108, 136

GetSinks() creates a new array on every log call. If log volume is high, consider caching the sink array and invalidating on changes.

Verdict

REQUEST CHANGES - Critical issues 1, 2, and 3 must be addressed.

Skip IDE streaming when running in console environment since console
output is already visible. Uses IClientInfo to detect console clients.
@thomhurst
Copy link
Owner Author

Summary

Implements a plugin-based log sink system for real-time log streaming to IDEs.

Critical Issues

Performance concern in hot path: LogSinkRouter.RouteToSinks() allocates a new array on EVERY console write via TUnitLoggerFactory.GetSinks().ToArray(). This executes on every WriteLine() in OptimizedConsoleInterceptor.

Impact: Tests that write frequently to console will cause significant GC pressure.

Recommendation: Cache the sinks array and invalidate on Add/Clear to avoid hot path allocations.

This violates TUnit Performance First rule (CLAUDE.md rule 4).

Suggestions

  1. Consider lazy init for OutputDeviceLogSink in TUnitServiceProvider.cs:281
  2. Fire-and-forget in OutputDeviceLogSink.Log() may lose logs on early test completion
  3. Lock contention lessens if caching implemented

Verdict

REQUEST CHANGES - Critical perf issue needs fixing before merge

IDEs display test output from StandardOutputProperty on TestNodeUpdateMessage,
not from IOutputDevice.DisplayAsync. Changed approach to:

- Add OutputUpdate method to ITUnitMessageBus for real-time output updates
- Create IdeOutputLogSink that sends TestNodeUpdateMessage with current output
- Modify TestExtensions.ToTestNode to support output during InProgress state
- Remove unused OutputDeviceLogSink (IOutputDevice approach didn't work for IDEs)

This sends TestNodeUpdateMessage updates with InProgressTestNodeStateProperty
AND StandardOutputProperty, which IDEs pick up for real-time test output display.
@thomhurst
Copy link
Owner Author

Summary

Implements a plugin-based log sink system that enables real-time log streaming to IDEs during test execution.

Critical Issues

1. CRITICAL: Breaking behavioral change in DefaultLogger (TUnit.Core/Logging/DefaultLogger.cs:125-158)

The removal of GlobalContext.Current.OriginalConsoleOut/Error.WriteLine() calls changes existing behavior. Previously, DefaultLogger output went to:

  1. Historical capture (context.OutputWriter)
  2. Console output (GlobalContext.Current.OriginalConsoleOut) ← REMOVED

Now it only goes to:

  1. Historical capture (context.OutputWriter)
  2. Registered sinks (via LogSinkRouter)

Impact: Users who rely on seeing logger output in the console when running tests from the command line will see nothing unless a sink is registered. The IdeOutputLogSink is only registered for IDE clients, not console clients.

Fix: Restore the OriginalConsoleOut/Error writes OR ensure a console sink is registered for console clients in TUnitServiceProvider.cs.


2. CRITICAL: Performance - Hot path allocations (TUnit.Engine/Logging/OptimizedConsoleInterceptor.cs)

From the diff, every WriteLine call now routes to sinks via LogSinkRouter.RouteToSinks(). This violates Rule 4: Performance First:

  • Each console write triggers a GetSinks() call which does lock + ToArray() (allocation)
  • Console interception is a hot path (every Console.WriteLine in user test code)
  • For tests with heavy console output, this creates significant overhead

Fix: Consider caching the sink list or using a lock-free approach. The current implementation in LogSinkRouter:

var sinks = TUnitLoggerFactory.GetSinks(); // lock + ToArray() every call

Should either:

  • Cache the array and invalidate on registration changes
  • Use a lock-free collection like ImmutableArray with atomic swap

Suggestions

1. ILogSink.Log() fire-and-forget pattern (TUnit.Engine/Logging/IdeOutputLogSink.cs:23-25)

public void Log(LogLevel level, string message, Exception? exception, Context? context)
{
    // Fire and forget - the async call will complete in background
    _ = LogAsync(level, message, exception, context);
}

This is dangerous - exceptions in the async continuation will be swallowed and not logged anywhere. The LogSinkRouter already catches and logs exceptions, but only for the awaited path.

Suggestion: Document this behavior in ILogSink interface comments, or consider making Log() fully synchronous for sinks that need it (and have IdeOutputLogSink use a background queue instead).


2. Missing ConfigureAwait(false) in one location

TUnit.Engine/Logging/IdeOutputLogSink.cs:41 calls await _messageBus.OutputUpdate(testContext).ConfigureAwait(false);

But should verify all async paths in the routing use ConfigureAwait(false) consistently to avoid context capture overhead.


3. Lock type compatibility (TUnit.Core/Logging/TUnitLoggerFactory.cs:9)

private static readonly Lock _lock = new();

This uses the new .NET 9 System.Threading.Lock type. Verify this builds on net472 (one of the target frameworks based on public API snapshot files). If targeting .NET Framework 4.7.2, you may need object _lock = new() instead.


Verdict

⚠️ REQUEST CHANGES - Critical issues found

Blocking:

  1. Behavioral regression in console output
  2. Performance regression in hot path violates mandatory rules

Non-blocking but recommended:
3. Document fire-and-forget risks
4. Verify Lock compatibility with net472

This was referenced Jan 19, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants