trbenning / serilog-sinks-xunit

The xunit test output sink for Serilog
MIT License
83 stars 8 forks source link

logging with LogEventLevel.Debug does not log anything #1

Closed Driedas closed 6 years ago

Driedas commented 6 years ago

hey, as per the title, the sink doesn't log anything when the system under test logs with the log level of Debug

unit test to reproduce:

[Fact]
public void Emit_ShouldWriteDebugEventWhenMinimumLevelSetToDebug()
{
    var outputHelper = Substitute.For<ITestOutputHelper>();
    var formatter = Substitute.For<ITextFormatter>();

    var logger = new LoggerConfiguration()
        .WriteTo.TestOutput(outputHelper, formatter, restrictedToMinimumLevel: LogEventLevel.Debug)
        .CreateLogger();

    const string message = "Hello";
    logger.Debug(message);

    outputHelper.Received(1).WriteLine(Arg.Any<string>());

    formatter.Received(1).Format(
        Arg.Is<LogEvent>(ev => ev.Level == LogEventLevel.Debug && ev.MessageTemplate.Text == message),
        Arg.Any<StringWriter>());
}

would try my hand on a fix as well but not sure where to begin, the correct parameters are being passed in...

trbenning commented 6 years ago

Thanks for reporting this. I'll take a look today.

trbenning commented 6 years ago

It looks like the default minimum level set by LoggerConfiguration is Information. The restrictedToMinimumLevel parameter only affects that particular sink, and is typically used to set the sink's minimum level higher than the logger's minimum level. Setting the sink's minimum level lower than the logger's minimum level will have no effect, since the lower level messages are never sent to the sink at all.

To have it output Verbose & Debug messages, you need to set the logger's minimum level to Verbose like this:

var logger = new LoggerConfiguration()
    .MinimumLevel.Verbose()
    .WriteTo.TestOutput(outputHelper, formatter, restrictedToMinimumLevel: LogEventLevel.Verbose)
    .CreateLogger();

I hope this helps, but let me know if it doesn't.

Driedas commented 6 years ago

Thanks, have tried setting the minimum level in the test to Verbose, but it still fails, nothing gets logged.

Super fast response time by the way 👍

trbenning commented 6 years ago

I'm having a little trouble reproducing the failure. That being said, I had to update some nuget packages just to run the tests at all on my system. I've pushed a change to the dev branch that includes the updated packages, and adds your test and a couple of integration tests that can be verified by looking at the test output.

Could you reference the prerelease package 1.0.5-dev-00013, and see if you still have any issues? If you want to see the latest code just run git checkout -b dev origin/dev.

For the sake of clarity, I can run this test successfully, which is the same test you posted earlier with the addition of .MinimumLevel.Verbose().:

[Fact]
public void Emit_ShouldWriteDebugEventWhenMinimumLevelSetToDebug()
{
    var outputHelper = Substitute.For<ITestOutputHelper>();
    var formatter = Substitute.For<ITextFormatter>();

    var logger = new LoggerConfiguration()
        .MinimumLevel.Verbose()
        .WriteTo.TestOutput(outputHelper, formatter, restrictedToMinimumLevel: LogEventLevel.Debug)
        .CreateLogger();

    const string message = "Hello";
    logger.Debug(message);

    outputHelper.Received(1).WriteLine(Arg.Any<string>());

    formatter.Received(1).Format(
        Arg.Is<LogEvent>(ev => ev.Level == LogEventLevel.Debug && ev.MessageTemplate.Text == message),
        Arg.Any<StringWriter>());
}

You won't see any output for this test, since ITestOutputHelper & ITextFormatter are being stubbed. You can run the integration tests to see test output.

Driedas commented 6 years ago

Yay, the addition of .MinimumLevel.Verbose() fixed it on my end as well, so apparently this was just a case of lack-of-knowledge on my part and nothing to do with your library. Cheers mate and apologies for wasting your time!

trbenning commented 6 years ago

No worries. You made me realize I needed to update the packages at least, so thanks!

ngnam commented 1 year ago

thanks you! n