dotnet / runtime

.NET is a cross-platform runtime for cloud, mobile, desktop, and IoT apps.
https://docs.microsoft.com/dotnet/core/
MIT License
14.91k stars 4.63k forks source link

Control how LogValuesFormatter formats structured data, or: opt-out of enumerating structured data #77253

Open Bouke opened 1 year ago

Bouke commented 1 year ago

I want to pass structured data to ILogger.Log and have this represented in a human-readable format in the message string, and store the structured data deconstructed. The structured data I'm passing in can be anything, amongst which types that implement IEnumerable.

However this collides with LogValuesFormatter which performs ToString() on the elements produced by IEnumerable. For highly-structured data this often provides non-human readable output, e.g.[SomeType, System.Collections.Generic.List`1[SomeOtherType]]. Calling ToString() on the enumerated values is not ideal, as it doesn't pass any log format specifiers.

There is currently no way to opt-out of this undesired behaviour. The runtime does have an interface available to control how objects are represented as strings, namely IFormattable. As a user I would expect that implementing this interface for my structured data would use that instead of trying to be "smart" about my data by enumerating it.

So what I propose is the ability to control how structured data is formatted in the message. The runtime already has an interface to do opt-in to this behaviour: IFormattable. LogValuesFormatter would check for this interface and skip enumerating:

// don't enumerate values that are formattable
if (value is IFormattable)
{
    return value;
}
dotnet-issue-labeler[bot] commented 1 year ago

I couldn't figure out the best area label to add to this issue. If you have write-permissions please help me learn by adding exactly one area label.

ghost commented 1 year ago

Tagging subscribers to this area: @dotnet/area-extensions-logging See info in area-owners.md if you want to be subscribed.

Issue Details
I want to pass structured data to `ILogger.Log` and have this represented in a human-readable format in the message string, and store the structured data deconstructed. The structured data I'm passing in can be anything, amongst which types that implement `IEnumerable`. However this collides with `LogValuesFormatter` which performs [`ToString()` on the elements produced by `IEnumerable`][0]. For highly-structured data this often provides non-human readable output, e.g.```[SomeType, System.Collections.Generic.List`1[SomeOtherType]]```. Calling `ToString()` on the enumerated values is not ideal, as it doesn't pass any log format specifiers. There is currently no way to opt-out of this undesired behaviour. The runtime does have an interface available to control how objects are represented as strings, namely `IFormattable`. As a user I would expect that implementing this interface for my structured data would use that instead of trying to be "smart" about my data by enumerating it. So what I propose is the ability to control how structured data is formatted in the message. The runtime already has an interface to do opt-in to this behaviour: `IFormattable`. `LogValuesFormatter` would check for this interface and skip enumerating: ```cs // don't enumerate values that are formattable if (value is IFormattable) { return value; } ``` [0]: https://github.com/dotnet/runtime/blob/12f9f91031224a45c146812a7f4a41e8cdb87e1c/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LogValuesFormatter.cs#L215-L247
Author: Bouke
Assignees: -
Labels: `untriaged`, `area-Extensions-Logging`
Milestone: -
maryamariyan commented 1 year ago

Related to https://github.com/dotnet/runtime/issues/35995

maryamariyan commented 1 year ago

@Bouke what do you think about the suggestion provided by @wekempf in https://github.com/dotnet/runtime/issues/35995#issuecomment-857297900 for this case?

So what I propose is the ability to control how structured data is formatted in the message. The runtime already has an interface to do opt-in to this behaviour: IFormattable. LogValuesFormatter would check for this interface and skip enumerating:

Are you suggesting to add an opt out flag? what would the runtime do otherwise when the opt out flag is set?

maryamariyan commented 1 year ago

cc @JakenVeina who added this comment https://github.com/dotnet/runtime/issues/35995#issuecomment-864356753 in the other issue.

Bouke commented 1 year ago

@Bouke what do you think about the suggestion provided by @wekempf in #35995 (comment) for this case?

That's something different, that issue is about adding structured data that shouldn't affect the formatted message, and discussing whether additional APIs are needed to support that.

This is about LogValuesFormatter trying to be smart when creating log messages. It enumerates IEnumerables and calls their ToString(), which is ok for simple arrays (int[], string[] etc), but not so when the value is structured data. My proposal is to honour IFormattable:

Provides functionality to format the value of an object into a string representation.

.

Are you suggesting to add an opt out flag? what would the runtime do otherwise when the opt out flag is set?

Yes. When opting out, the value will be passed as-is into the string formatter and thus use the IFormattable implementation of that value.

maryamariyan commented 1 year ago

@Bouke would you like to recommend an API suggestion and sample usages to go with a small repro code?

Please check out our API review process and the suggested format

KalleOlaviNiemitalo commented 1 month ago

Another way to implement this would be to make LogValuesFormatter check for a colon in the format item.

internal sealed class LoggableDurationList : List<TimeSpan>
{
    public override string ToString()
    {
        TimeSpan total = TimeSpan.Zero;
        foreach (TimeSpan duration in this)
        {
            total += duration;
        }
        return $"Total {total}";
    }
}
ILogger logger;
var durations = new LoggableDurationList() { TimeSpan.FromSeconds(42), TimeSpan.FromSeconds(69) };

// No change in behavior.
// Does not call LoggableDurationList.ToString().
// Formats as a comma-delimited list of TimeSpan.ToString().
// As in: string.Format(Processing duration: {0}", string.Join(", ", durations));
logger.LogInformation("Processing duration: {Durations}", durations)

// No change in behavior.
// Formats the list as above, and then pads it to 30 characters.
// As in: string.Format(Processing duration: {0,-30}", string.Join(", ", durations));
logger.LogInformation("Processing duration: {Durations,-30}", durations)

// NEW: Ignores IEnumerable and calls LoggableDurationList.ToString().
// Discards the format string "" because LoggableDurationList does not implement IFormattable.
// As in: string.Format(Processing duration: {0:}", durations)
logger.LogInformation("Processing duration: {Durations:}", durations);