Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Malformed message template string should throw warning or compiler error as a preference over runtime exceptions #7285

Open
Kritner opened this issue Apr 9, 2024 · 10 comments · May be fixed by #7286
Labels
Area-Microsoft.CodeAnalysis.NetAnalyzers Enhancement help wanted The issue is up-for-grabs, and can be claimed by commenting

Comments

@Kritner
Copy link

Kritner commented Apr 9, 2024

          I am closing the issue but feel free to respond if you still have any questions.

Originally posted by @tarekgh in dotnet/runtime#97852 (comment)


Couldn't respond since locked, but we ran into this and is exceedingly frustrating. Will add additional information momentarily


Issue:

malformed message template strings for at a minimum logged messages should be throwing compiler errors IMO, rather than the current runtime errors seen with .net8.

Repro:
https://github.com/Kritner/MessageTemplateNet8

using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Hosting;
using Microsoft.Extensions.Logging;

HostApplicationBuilder builder = Host.CreateApplicationBuilder(args);
builder.Services.AddLogging(loggingBuilder => loggingBuilder.AddConsole());

var host = builder.Build();

var logger = host.Services.GetRequiredService<ILogger<Program>>();

logger.LogInformation("Hello world");

var i = 5;
logger.LogInformation("My value {i}}", i);

image

This same code does not encounter a run time error in .net7. When updating to .net8 in a large code base, there is no indication that the badly message template will fail at run time, but it can and does (see above screenshot).

I feel like this needs to be a compiler error, lest you run into the same run time errors I've encountered.

@tarekgh
Copy link
Member

tarekgh commented Apr 9, 2024

In C#, only the interpolated strings in the form of $"..." is get validated. In general "My value {i}} is a valid C# string but its usage in logging messages will be invalid which is detected at runtime. Maybe having C# analyzer can help in such scenario but considering the high priority work we are doing this will be addressed in the future. Meanwhile, if you interested, you can write your analyzer and use it in your codebase. https://learn.microsoft.com/en-us/visualstudio/code-quality/roslyn-analyzers-overview?view=vs-2022.

@buyaa-n
Copy link
Member

buyaa-n commented Apr 9, 2024

I feel like this needs to be a compiler error, lest you run into the same run time errors I've encountered.

It seems this scenario is already covered with https://learn.microsoft.com/en-us/dotnet/fundamentals/code-analysis/quality-rules/ca2017 @Kritner could you enable that analyzer in your repo (it is enabled and warns by default, but the rule might disabled for your project) and check the diagnostics?

@buyaa-n buyaa-n transferred this issue from dotnet/runtime Apr 9, 2024
@Kritner
Copy link
Author

Kritner commented Apr 9, 2024

I feel like this needs to be a compiler error, lest you run into the same run time errors I've encountered.

It seems this scenario is already covered with https://learn.microsoft.com/en-us/dotnet/fundamentals/code-analysis/quality-rules/ca2017 @Kritner could you enable that analyzer in your repo (it is enabled and warns by default, but the rule might disabled for your project) and check the diagnostics?

Yeah so it's weird... we're not NoWarning against this particular "CA2017", but we don't get the string template being flagged as a CA2017... I can easily make the CA2017 appear (and get a compiler error yay) if I change...

logger.LogInformation("My value {i}}", i);

to

logger.LogInformation("My value {i}", i, i+1);

image

@buyaa-n
Copy link
Member

buyaa-n commented Apr 9, 2024

Yeah, looks it is not covered with CA2017 when it should

@buyaa-n buyaa-n added Bug The product is not behaving according to its current intended design Area-Microsoft.CodeAnalysis.NetAnalyzers help wanted The issue is up-for-grabs, and can be claimed by commenting Enhancement and removed untriaged Bug The product is not behaving according to its current intended design labels Apr 9, 2024
Kritner added a commit to Kritner/roslyn-analyzers that referenced this issue Apr 10, 2024
@Kritner
Copy link
Author

Kritner commented Apr 10, 2024

I added a potential fix in #7286, but i'm not sure that the current CA2017 wording really fits with the new trigger for failure.

image

When you have unmatched/unclosed brackets that doesn't quite jive with the above error message. Does that warrant updating the message, or it being its own new CA____?

@buyaa-n
Copy link
Member

buyaa-n commented Apr 10, 2024

When you have unmatched/unclosed brackets that doesn't quite jive with the above error message. Does that warrant updating the message, or it being its own new CA____?

You can have a same rule id with different message, look https://github.com/dotnet/roslyn-analyzers/blob/main/src/NetAnalyzers/Core/Microsoft.NetCore.Analyzers/Runtime/AttributeStringLiteralsShouldParseCorrectly.cs#L43 for example, it has 2 diagnostics with different message but same id

@Kritner
Copy link
Author

Kritner commented Apr 10, 2024

I've not worked w/ localization before, what's the expectation around providing strings for other languages? just... don't and they'll get filled in over time in additional PRs or something else?

@buyaa-n
Copy link
Member

buyaa-n commented Apr 10, 2024

You just need to add the new message to the https://github.com/dotnet/roslyn-analyzers/blob/main/src/NetAnalyzers/Core/Microsoft.NetCore.Analyzers/MicrosoftNetCoreAnalyzersResources.resx in English, then build, the build will generate resources for other languages which will be translated later with other professionals, you don't need to worry about that

@stephentoub
Copy link
Member

This same code does not encounter a run time error in .net7.

FWIW, it does for me. On .NET 7:

info: Program[0]
      Hello world
Unhandled exception. System.AggregateException: An error occurred while writing to logger(s). (Input string was not in a correct format.)
 ---> System.FormatException: Input string was not in a correct format.
   at System.Text.ValueStringBuilder.ThrowFormatInvalidString()
   at System.Text.ValueStringBuilder.AppendFormatHelper(IFormatProvider provider, String format, ReadOnlySpan`1 args)
   at System.String.FormatHelper(IFormatProvider provider, String format, ReadOnlySpan`1 args)
   at System.String.Format(IFormatProvider provider, String format, Object[] args)
   at Microsoft.Extensions.Logging.LogValuesFormatter.Format(Object[] values)
   at Microsoft.Extensions.Logging.FormattedLogValues.ToString()
   at Microsoft.Extensions.Logging.LoggerExtensions.MessageFormatter(FormattedLogValues state, Exception error)
   at Microsoft.Extensions.Logging.Console.SimpleConsoleFormatter.Write[TState](LogEntry`1& logEntry, IExternalScopeProvider scopeProvider, TextWriter textWriter)
   at Microsoft.Extensions.Logging.Console.ConsoleLogger.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
   at Microsoft.Extensions.Logging.Logger.<Log>g__LoggerLog|13_0[TState](LogLevel logLevel, EventId eventId, ILogger logger, Exception exception, Func`3 formatter, List`1& exceptions, TState& state)
   --- End of inner exception stack trace ---
   at Microsoft.Extensions.Logging.Logger.ThrowLoggingError(List`1 exceptions)
   at Microsoft.Extensions.Logging.Logger.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
   at Microsoft.Extensions.Logging.Logger`1.Microsoft.Extensions.Logging.ILogger.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
   at Microsoft.Extensions.Logging.LoggerExtensions.Log(ILogger logger, LogLevel logLevel, EventId eventId, Exception exception, String message, Object[] args)
   at Microsoft.Extensions.Logging.LoggerExtensions.Log(ILogger logger, LogLevel logLevel, String message, Object[] args)
   at Microsoft.Extensions.Logging.LoggerExtensions.LogInformation(ILogger logger, String message, Object[] args)
   at Program.<Main>$(String[] args)

@Kritner
Copy link
Author

Kritner commented Apr 30, 2024

This same code does not encounter a run time error in .net7.

FWIW, it does for me. On .NET 7:

yeah i'm not sure what exactly happened here - i can confirm i see the behavior on .net7 as well now.
Could this have been a change to one of the minor/patch revs of logging or something else?

Cuz it's the weirdest thing, this is seemingly a pretty hot path of code for us, but we didn't start seeing exceptions here until the .net8 update. But yeah, rolling back to .net7 now and still seeing the issue

EDIT:

in our codebase where we actually encountered the issue we're using serilog, i'm wondering if we also updated that package version in our update to .net8, and maybe it was masking the issue? It's certainly bothering me now that we didn't see it before updating to .net8, but then going back to .net7 didn't fix it 😓

either way though, i don't think the idea of a new analyzer looking for these issues is a bad thing yeah?

@Kritner Kritner changed the title Malformed message template string should throw error (difference in behavior .net7 vs .net8) Malformed message template string should throw warning or compiler error as a preference over runtime exceptions May 2, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Area-Microsoft.CodeAnalysis.NetAnalyzers Enhancement help wanted The issue is up-for-grabs, and can be claimed by commenting
Projects
None yet
4 participants