dotnet / runtime

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

LoggerMessageAttribute doesn't support parameters with dots #82172

Open JWilh opened 1 year ago

JWilh commented 1 year ago

Description

Hi,

first of all, I really like the LoggerMessageAttribute šŸ‘, but I have a "small" problem why I can't use it: In order to align with our custom tags from our OpenTelemetry traces we want to use parameters with dots in the name. Something like this "messaging.id" or "messaging.type".

It's not possible to do that with the LoggerMessageAttribute as it's not possible to include a "dot" in the c# parameter or did I missed something?

My issue is similar to https://github.com/dotnet/runtime/issues/60968, but it's not the same as my example is about a dot and not a @.

Reproduction Steps

This doesn't compile:

[LoggerMessage(Level = LogLevel.Information, EventName = "LogMessage",
        Message = "The event {messaging.id} of type {messaging.type} did something")]
public static partial void LogMyMessage(this ILogger logger, string messaging.id, string messaging.type);

If I try to use something do it like this the code generated from the code generator is not compiling:

[LoggerMessage(Level = LogLevel.Information, EventName = "LogMessage",
        Message = "The event {messaging.id} of type {messaging.type} did something")]
public static partial void LogMyMessage(this ILogger logger, string messaging_id, string messaging_type);

Expected behavior

Be able to use it with a parameter that has a "dot" šŸ˜€

Actual behavior

Code is not compiling.

Regression?

No response

Known Workarounds

No response

Configuration

.Net 6.0

Other information

No response

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
### Description Hi, first of all, I really like the LoggerMessageAttribute šŸ‘, but I have a "small" problem why I can't use it: In order to align with our custom tags from our OpenTelemetry traces we want to use parameters with dots in the name. Something like this "messaging.id" or "messaging.type". It's not possible to do that with the LoggerMessageAttribute as it's not possible to include a "dot" in the c# parameter or did I missed something? ### Reproduction Steps This doesn't compile: ``` [LoggerMessage(Level = LogLevel.Information, EventName = "LogMessage", Message = "The event {messaging.id} of type {messaging.type} did something")] public static partial void LogMyMessage(this ILogger logger, string messaging.id, string messaging.type); ``` If I try to use something do it like this the code generated from the code generator is not compiling: ``` [LoggerMessage(Level = LogLevel.Information, EventName = "LogMessage", Message = "The event {messaging.id} of type {messaging.type} did something")] public static partial void LogMyMessage(this ILogger logger, string messaging_id, string messaging_type); ``` ### Expected behavior Be able to use it with a parameter that has a "dot" šŸ˜€ ### Actual behavior Code is not compiling. ### Regression? _No response_ ### Known Workarounds _No response_ ### Configuration _No response_ ### Other information _No response_
Author: JWilh
Assignees: -
Labels: `area-Extensions-Logging`
Milestone: -
tarekgh commented 1 year ago

@JWilh can't you sanitize the parameter names and use something different than .? The issue is the source generator can generate structs with the fields named the same as the parameters. Using . is not going to work. Also, C# doesn't allow using . in the parameter's names. The names inside the message templates and the parameter names must match. Any reason you cannot use underscores in the message template too? support that inside the source generator can add untrivial complexity.

Why can't you sanitize the parameter names in your code? like using underscore for example.

ghost commented 1 year ago

This issue has been marked needs-author-action and may be missing some important information.

pinkfloydx33 commented 1 year ago

Not the author, but when using structured logging such names are supported. The underlying logging provider (and consumer, ie. otel, appinsights) might be expecting the parameters to have specific names--like those in op--and be outside of user control.

tarekgh commented 1 year ago

@pinkfloydx33 could you please elaborate more about your scenario when using the source generator? examples will be good :-)

pinkfloydx33 commented 1 year ago

My specific examples are that I can't currently use the source generator with its lack of @ destructuring support; but that's another issue.

I was just commenting on what OP said; otel for example relies on well-known log properties with dots in their names. That could be achieved with a Serilog log provider/sink sending "normal" logs out, but not with source-gen.

tarekgh commented 1 year ago

I can't currently use the source generator with its lack of @ destructuring support;

Just FYI, https://github.com/dotnet/runtime/pull/79038

pinkfloydx33 commented 1 year ago

Ok cool, thanks... I knew it was in the works. That didn't make it for 7 though, right?

tarekgh commented 1 year ago

That didn't make it for 7 though, right?

Yes, the fix is not included in .NET 7.0 but you can use our .NET 8.0 preview packages to try it.

JWilh commented 1 year ago

Hi @tarekgh,

@JWilh can't you sanitize the parameter names and use something different than .? The issue is the source generator can generate structs with the fields named the same as the parameters. Using . is not going to work. Also, C# doesn't allow using . in the parameter's names. The names inside the message templates and the parameter names must match. Any reason you cannot use underscores in the message template too? support that inside the source generator can add untrivial complexity.

Why can't you sanitize the parameter names in your code? like using underscore for example.

We use the OpenTelemetry library to send our logs to NewRelic. The OpenTelemetry library and also other 3 party libraries like MassTransit submits traces with the properties organized like this: http.method http.status_code, ... (or for masstransit messaging.masstransit.destination_address and so on)

That is the reason we also adapted this for our own logs and traces and because we already have a large set of properties defined that we use for our traces and logs we don't want to change that.

Yes, I'm aware that C# doesn't support parameter names with dots, but maybe it's possible to think about supporting it like by just ignoring the dots when matching the parameters:

[LoggerMessage(Level = LogLevel.Information, EventName = "LogMessage",
        Message = "The event {messaging.id} of type {messaging.type} did something")]
public static partial void LogMyMessage(this ILogger logger, string messagingid, string messagingtype);

Or as another solution that would than support basically everything maybe an additional attribute?

[LoggerMessage(Level = LogLevel.Information, EventName = "LogMessage",
        Message = "The event {messaging.id} of type {messaging.type} did something")]
public static partial void LogMyMessage(this ILogger logger, 
        [LoggerArgument("messaging.id")] string id, 
        [LoggerArgument("messaging.type")] string type);

With that people are always free to do what they want and the feature would support everything and people would always have a workaround :-)

What are you thoughts about this :-)? Thanks in advance

tarekgh commented 1 year ago

@JWilh thanks for the reply. I am wondering who writes the code for the source generator which declares the LoggerMessage attribute? Why can't just use in the message template names match the parameters? Why we need to have the source generator workaround such cases which can be handled by who write the source generationg calling code? sorry if I am missing something here :-)

JWilh commented 1 year ago

@tarekgh We have a list of constants defined like this:

public static class Tags
{
    public static class User
    {
        public const string Id = "user.id";

Our tags follow the standard for OpenTelemetry and we use the "const User.Id" tag in activities/traces and in logs either directly or in a logger scope. And it's working fine with LoggerMessage.Define, it just don't work with LoggerMessageAttribute. In case we would now switch, we would break all of our already created queries and dashboards or we would get a mismatch between our traces and logs, which would create not required confusion for our operations guys.

We don't want that, so we are not able to use the LoggerMessageAttribute, but need to stick with LoggerMessage.Define, which is from my point of view a drawback of the LoggerMessageAttribute, that shouldn't be required, as it's way more convenient than LoggerMessage.Define.

tarekgh commented 1 year ago

@JWilh to be clear I am not pushing back on any idea. I am just trying to understand the whole picture. I am not suggesting switching or changing the tags format or breaking anything. I encourage using LoggerMessageAttribute too. I am trying to understand how you are planning to use LoggerMessageAttribute. Don't you need to provide the template message anyway and you have control over that?

Let's take an example:

Today, you can do the following:

[LoggerMessage(Level = LogLevel.Information, EventName = "LogMessage", Message = "The event {MessageId} of type {MessageType} did something")]
public static partial void LogMyMessage(this ILogger logger, string messagingid, string messagingtype);

Your ask is to support the message like Message = "The event {Message.Id} of type {Message.Type} did something" and make it work with the parameters of the method. Who is constructing this message template in your code? I guess it has to be hardcoded because this is used during the code compilation and source generation. At runtime, your code will just call LogMyMessage and pass the parameter values of messagingid and messagingtype. My question, why can't you define the Message with template not using . like Message = "The event {MessageId} of type {MessageType} did something". How will this break the current behavior? If you can provide an example of how you are going to use the LoggerMessageAttribute with the tag constants, that will be helpful.

JWilh commented 1 year ago

Hi @tarekgh, oh sorry, I misunderstood your question :-).

Yes, the logmessage itself could be changed to "The event {MessageId} of type {MessageType} did something", it's just the individual developer who decides what he want's to log.

The problem is mainly: We talk about already existing log messages, that are already written either using LogX directly or using LoggerMessage.Define using this "dot" format. And these properties are currently also the same for all our telemetry.

Our goal now was just to move these already existing logs to LoggerMessageAttribute.

In case we decide to change the logger attribute format we would either get different names like: If you query for all logs associated with a specific message id, you would then need to query for messageId, if you query for traces you would need to query for message.id. (That is not that convenient, which was the reason we decided to move our log parameter names to use the same format)

The other point is: Of cause not all every logmessage and not every trace tag, but some of those log messages formats and trace tags are already used by our operations guys for alerting rules and dashboards in New Relic. They would then need to adapt for the changed names as well.

This is all possible and not that big of a deal, but from my point of view it shouldn't be required :-) (and in our case we will most likely then just not use LoggerMessageAttribute, which would be a pity as it's so much nicer than LoggerMessage.Define).

Thanks in advance :-)

pinkfloydx33 commented 1 year ago

FWIW, according to messagetemplates.org property names in structured logging are supposed to match the regex [A-Za-z0-9_]+

I did a little checking this morning using our current stack which includes Serilog (via MS.E.L) and Datalust Seq as the log aggregator.

I did a quick Google of some other platforms, specifically Elastic/Kibana and it was unclear to me whether or not they support properties with a period in the name as they use the syntax explicitly for querying by/for nested properties.

I guess my point is that support likely depends on the third-party libs being used to transmit and consume such data. While I agree that it's important to have the log properties/data points consistent throughout one's stack (querying for either "abcXyz" or "abc.xyz" depending on context is no fun) I am not sure it makes sense to include explicit support for it--at least without knowing what's actually supported throughout the ecosystem.

Note that this differs from my previous stance, from which I was swayed after this experiment. That said, the fact that normal MS.E.L usage (either via ILogger.Log or LoggerMessage.Define) supports it is possibly an indicator that source-gen should as well.

julealgon commented 3 months ago

We have the exact same concern as OP and just hit this problem today when investigating adding our first source-generated logs to an application: we wanted to have identifiers in the logs match the same identifiers we already use in traces so we can cross query and correlate the data in Datadog, but the [LoggerMessage] generator does not allow us to use the same notation.

Reading this thread here, I'm actually very surprised that so many people seemed to be unaware of the standard naming convention defined by OpenTelemetry which uses dots for nested properties and underscores for spaces. We are stuck with using mismatching identifiers right now.

This suggestion from @JWilh is what makes the most sense to me as well:

Or as another solution that would than support basically everything maybe an additional attribute?

[LoggerMessage(Level = LogLevel.Information, EventName = "LogMessage",
    Message = "The event {messaging.id} of type {messaging.type} did something")]
public static partial void LogMyMessage(this ILogger logger, 
    [LoggerArgument("messaging.id")] string id, 
    [LoggerArgument("messaging.type")] string type);

This would also be similar to how model binding works in the Web API space. Take for example the [FromHeader] binding attribute, and this example:

public IActionResult Get([FromHeader(Name = "X-Custom-Header")] string customHeader)
{
    ...
}

Here we have the same type of limitation, where the characters allowed for C# identifiers are not sufficient to map against characters allowed in the http header, so an explicit override is provided.

Using an attribute and constant interpolation support would also permit this, which is a bit convoluted but would still work:


[LoggerMessage(Level = LogLevel.Information, EventName = "LogMessage",
    Message = $"The event {{{OpenTelemetryAttributes.Messagging.Id}}} of type {{{OpenTelemetryAttributes.Messagging.Type}}} did something")]
public static partial void LogMyMessage(this ILogger logger, 
    [LoggerArgument(OpenTelemetryAttributes.Messagging.Id)] string id, 
    [LoggerArgument(OpenTelemetryAttributes.Messagging.Type)] string type);