alefranz / MELT

MELT is a free, open source, testing library for the .NET Standard Microsoft Extensions Logging library. It is a solution to easily test logs.
Apache License 2.0
72 stars 5 forks source link

A log entry produced within a scope should contain the properties defined on the scope #27

Open penenkel opened 3 years ago

penenkel commented 3 years ago

When producing a log entry from within a scope, as in this sample

            var loggerFactory = TestLoggerFactory.Create();
            var logger = loggerFactory.CreateLogger<Sample>();
            using (logger.BeginScope(new Dictionary<string, object>() { { "property0", "value0" } }))
            {
                logger.LogInformation("message {property2}", "value2");
            }

I expected loggerFactory .Sink.LogEntries[0].Properties to contain both properties, but found only propertiy2. Whereas property0 only seems to be captured in loggerFactory.Sink.Scopes[0].Properties. Is this intentional?

This article seems to indicate that this is not the behavior of the "real" implementation.

alefranz commented 3 years ago

Hello!

Thanks for reaching out!

This behaviour is by design as the scope and the log entry are two separate concepts. The logging abstraction defined by Microsoft.Extensions.Logging only provide the ability to capture the current scopes when a log entry is emitted, but doesn't define the behaviour. Attaching the scope properties to the log entry is an implementation choice of some logging providers.

As this library works at the abstraction level, that particular behaviour is not reproduced, as for example when authoring a library, you would have no knowledge of the particular logging provided used by the consumer. You also have to consider the rules on how to handle duplicates and so on which are implementation specific: for example the default Microsoft provider allow for duplicated properties while Serilog override the values.

What do you think? Would you like to see this behaviour included in the library? in which context would this be useful?

Thank you, Alessio

penenkel commented 3 years ago

Ah, yes, in hindsight it makes total sense that such an aggregation lies in the purview of the logging providers. As I am using Serilog underneath I never noticed that this might not be true for all providers.

For my use case I don`t particularly care if a property was added via a scope or a message, I just want to check if it is there (as Serilog will aggregate them anyway). If something like this were to be added to the library, it should probably be done on the assertion/check level. On that note: How can I find out in which scopes a particular log event participated?

alefranz commented 3 years ago

Apologies for the delay.

The library is designed for Microsoft.Extensions.Logging, so it replicates the "standard" behaviour, not the particular choicies of different loggers. However, to support writing integration tests, there is some special support for Serilog in the library. Have a look at the section Serilog compatibility using Serilog.AspNetCore (and corresponding examples) which relies on Serilog under the hood so you can test the Serilog behaviour.

Let me know if that is what you are looking for and if it works for you or you would need something different, like being able to do that in lighter unit tests.

You can otherwise test the scope properties, which you can retrieve from the log property (please update to 0.7.0 first has the scope support has been improved)