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.

Sign up for GitHub

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

Add SkipEnabledCheck on LoggerMessageAttribute #54305

Merged
merged 7 commits into from
Jun 22, 2021
Merged

Add SkipEnabledCheck on LoggerMessageAttribute #54305

Show file tree
Hide file tree
Changes from 6 commits
Commits
Show all changes
7 commits
Select commit Hold shift + click to select a range
46af543
Add SkipEnabledCheck on LoggerMessageAttribute
maryamariyan Jun 17, 2021
221f272
Apply suggestions from code review
maryamariyan Jun 17, 2021
1fa1344
Make logging generator more robust with null input
maryamariyan Jun 17, 2021
fe5181c
PR feedback
maryamariyan Jun 17, 2021
82271d1
Adds LoggerMessageAttribute ctor overload
maryamariyan Jun 18, 2021
58e1a75
properly identify misconfigured input
maryamariyan Jun 22, 2021
73fd442
Address PR feedback
maryamariyan Jun 22, 2021
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
35 changes: 23 additions & 12 deletions ...libraries/Microsoft.Extensions.Logging.Abstractions/gen/LoggerMessageGenerator.Emitter.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -381,34 +381,45 @@ private void GenLogMethod(LoggerMethod lm, string nestedIndentation)
GenParameters(lm);

_builder.Append($@")
{nestedIndentation}{{
{nestedIndentation}{{");

string enabledCheckIndentation = lm.SkipEnabledCheck ? "" : " ";
if (!lm.SkipEnabledCheck)
{
_builder.Append($@"
{nestedIndentation}if ({logger}.IsEnabled({level}))
{nestedIndentation}{{");
}

if (UseLoggerMessageDefine(lm))
{
_builder.Append($@"
{nestedIndentation}__{lm.Name}Callback({logger}, ");
{nestedIndentation}{enabledCheckIndentation}__{lm.Name}Callback({logger}, ");

GenCallbackArguments(lm);

_builder.Append(@$"{exceptionArg});");
_builder.Append($"{exceptionArg});");
}
else
{
_builder.Append($@"
{nestedIndentation}{logger}.Log(
{level},
new global::Microsoft.Extensions.Logging.EventId({lm.EventId}, {eventName}),
");
GenHolder(lm);
_builder.Append($@",
{exceptionArg},
__{lm.Name}Struct.Format);");
{nestedIndentation}{enabledCheckIndentation}{logger}.Log(
{nestedIndentation}{enabledCheckIndentation}{level},
{nestedIndentation}{enabledCheckIndentation}new global::Microsoft.Extensions.Logging.EventId({lm.EventId}, {eventName}),
{nestedIndentation}{enabledCheckIndentation}");
GenHolder(lm);
_builder.Append($@",
{nestedIndentation}{enabledCheckIndentation}{exceptionArg},
{nestedIndentation}{enabledCheckIndentation}__{lm.Name}Struct.Format);");
}

if (!lm.SkipEnabledCheck)
{
_builder.Append($@"
{nestedIndentation}}}");
}

_builder.Append($@"
{nestedIndentation}}}
{nestedIndentation}}}");

static string GetException(LoggerMethod lm)
Expand Down
114 changes: 82 additions & 32 deletions src/libraries/Microsoft.Extensions.Logging.Abstractions/gen/LoggerMessageGenerator.Parser.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@
using Microsoft.CodeAnalysis;
using Microsoft.CodeAnalysis.CSharp;
using Microsoft.CodeAnalysis.CSharp.Syntax;
using System.Collections.Immutable;

namespace Microsoft.Extensions.Logging.Generators
{
Expand All @@ -28,7 +29,7 @@ public Parser(Compilation compilation, Action<Diagnostic> reportDiagnostic, Canc
}

/// <summary>
/// Gets the set of logging classes or structs containing methods to output.
/// Gets the set of logging classes containing methods to output.
/// </summary>
public IReadOnlyList<LoggerClass> GetLogClasses(IEnumerable<ClassDeclarationSyntax> classes)
{
Expand Down Expand Up @@ -83,7 +84,7 @@ public IReadOnlyList<LoggerClass> GetLogClasses(IEnumerable<ClassDeclarationSynt
bool multipleLoggerFields = false;

ids.Clear();
foreach (var member in classDec.Members)
foreach (MemberDeclarationSyntax member in classDec.Members)
{
var method = member as MethodDeclarationSyntax;
if (method == null)
Expand All @@ -93,6 +94,9 @@ public IReadOnlyList<LoggerClass> GetLogClasses(IEnumerable<ClassDeclarationSynt
}

sm ??= _compilation.GetSemanticModel(classDec.SyntaxTree);
IMethodSymbol logMethodSymbol = sm.GetDeclaredSymbol(method, _cancellationToken) as IMethodSymbol;
Debug.Assert(logMethodSymbol != null, "log method is present.");
(int eventId, int? level, string message, string? eventName, bool skipEnabledCheck) = (-1, null, string.Empty, null, false);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Does this need to use a tuple anymore? Can this just be regular variables?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

no but I thought it would be neater this way, all defined in one line.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not crazy about it... Especially because I need to match up the variable with the value on the right-hand side to see what its default value is.


foreach (AttributeListSyntax mal in method.AttributeLists)
{
Expand All @@ -105,7 +109,78 @@ public IReadOnlyList<LoggerClass> GetLogClasses(IEnumerable<ClassDeclarationSynt
continue;
}

(int eventId, int? level, string message, string? eventName) = ExtractAttributeValues(ma.ArgumentList!, sm);
bool hasMisconfiguredInput = false;
ImmutableArray<AttributeData>? boundAttrbutes = logMethodSymbol?.GetAttributes();

if (boundAttrbutes == null)
{
continue;
}

foreach (AttributeData attributeData in boundAttrbutes)
{
// argument syntax takes parameters. e.g. EventId = 0
// supports: e.g. [LoggerMessage(EventId = 0, Level = LogLevel.Warning, Message = "custom message")]
if (attributeData.NamedArguments.Any())
{
foreach (KeyValuePair<string, TypedConstant> namedArgument in attributeData.NamedArguments)
{
TypedConstant typedConstant = namedArgument.Value;
if (typedConstant.Kind == TypedConstantKind.Error)
{
hasMisconfiguredInput = true;
}
else
{
TypedConstant value = namedArgument.Value;
switch (namedArgument.Key)
{
case "EventId":
eventId = (int)GetItem(value);
break;
case "Level":
level = value.IsNull ? null : (int?)GetItem(value);
break;
case "SkipEnabledCheck":
skipEnabledCheck = (bool)GetItem(value);
break;
case "EventName":
eventName = (string?)GetItem(value);
break;
case "Message":
message = value.IsNull ? "" : (string)GetItem(value);
break;
}
}
}
}

// supports: [LoggerMessage(0, LogLevel.Warning, "custom message")]
// supports: [LoggerMessage(eventId: 0, level: LogLevel.Warning, message: "custom message")]
if (attributeData.ConstructorArguments.Any())
{
foreach (TypedConstant typedConstant in attributeData.ConstructorArguments)
{
if (typedConstant.Kind == TypedConstantKind.Error)
{
hasMisconfiguredInput = true;
}
}

ImmutableArray<TypedConstant> items = attributeData.ConstructorArguments;
Debug.Assert(items.Length == 3);

eventId = items[0].IsNull ? -1 : (int)GetItem(items[0]);
level = items[1].IsNull ? null : (int?)GetItem(items[1]);
message = items[2].IsNull ? "" : (string)GetItem(items[2]);
}
}

if (hasMisconfiguredInput)
{
// skip further generator execution and let compiler generate the errors
break;
}

IMethodSymbol? methodSymbol = sm.GetDeclaredSymbol(method, _cancellationToken);
if (methodSymbol != null)
Expand All @@ -119,6 +194,7 @@ public IReadOnlyList<LoggerClass> GetLogClasses(IEnumerable<ClassDeclarationSynt
EventName = eventName,
IsExtensionMethod = methodSymbol.IsExtensionMethod,
Modifiers = method.Modifiers.ToString(),
SkipEnabledCheck = skipEnabledCheck
};

ExtractTemplates(message, lm.TemplateMap, lm.TemplateList);
Expand Down Expand Up @@ -435,35 +511,6 @@ bool IsAllowedKind(SyntaxKind kind) =>
return (loggerField, false);
}

private (int eventId, int? level, string message, string? eventName) ExtractAttributeValues(AttributeArgumentListSyntax args, SemanticModel sm)
{
int eventId = 0;
int? level = null;
string? eventName = null;
string message = string.Empty;
foreach (AttributeArgumentSyntax a in args.Arguments)
{
// argument syntax takes parameters. e.g. EventId = 0
Debug.Assert(a.NameEquals != null);
switch (a.NameEquals.Name.ToString())
{
case "EventId":
eventId = (int)sm.GetConstantValue(a.Expression, _cancellationToken).Value!;
break;
case "EventName":
eventName = sm.GetConstantValue(a.Expression, _cancellationToken).ToString();
break;
case "Level":
level = (int)sm.GetConstantValue(a.Expression, _cancellationToken).Value!;
break;
case "Message":
message = sm.GetConstantValue(a.Expression, _cancellationToken).ToString();
break;
}
}
return (eventId, level, message, eventName);
}

private void Diag(DiagnosticDescriptor desc, Location? location, params object?[]? messageArgs)
{
_reportDiagnostic(Diagnostic.Create(desc, location, messageArgs));
Expand Down Expand Up @@ -580,6 +627,8 @@ private string GetStringExpression(SemanticModel sm, SyntaxNode expr)

return string.Empty;
}

private static object GetItem(TypedConstant arg) => arg.Kind == TypedConstantKind.Array ? arg.Values : arg.Value;
}

/// <summary>
Expand Down Expand Up @@ -612,6 +661,7 @@ internal class LoggerMethod
public bool IsExtensionMethod;
public string Modifiers = string.Empty;
public string LoggerField = string.Empty;
public bool SkipEnabledCheck;
}

/// <summary>
Expand Down
2 changes: 2 additions & 0 deletions ...icrosoft.Extensions.Logging.Abstractions/ref/Microsoft.Extensions.Logging.Abstractions.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -119,10 +119,12 @@ public static partial class LoggerMessage
public sealed partial class LoggerMessageAttribute : System.Attribute
{
public LoggerMessageAttribute() { }
public LoggerMessageAttribute(int eventId, Microsoft.Extensions.Logging.LogLevel level, string message) { }
public int EventId { get { throw null; } set { } }
public string? EventName { get { throw null; } set { } }
public Microsoft.Extensions.Logging.LogLevel Level { get { throw null; } set { } }
public string Message { get { throw null; } set { } }
public bool SkipEnabledCheck { get { throw null; } set { } }
}
public partial class Logger<T> : Microsoft.Extensions.Logging.ILogger, Microsoft.Extensions.Logging.ILogger<T>
{
Expand Down
19 changes: 19 additions & 0 deletions src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LoggerMessageAttribute.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -37,6 +37,20 @@ public sealed class LoggerMessageAttribute : Attribute
/// </summary>
public LoggerMessageAttribute() { }

/// <summary>
/// Initializes a new instance of the <see cref="LoggerMessageAttribute"/> class
/// which is used to guide the production of a strongly-typed logging method.
/// </summary>
/// <param name="eventId">The log event Id.</param>
/// <param name="level">The log level.</param>
/// <param name="message">Format string of the log message.</param>
public LoggerMessageAttribute(int eventId, LogLevel level, string message)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Any reason not to have EventName here?

Copy link
Member Author

@maryamariyan maryamariyan Jun 22, 2021 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This was the only ctor approved since we assumed it to be the most commonly used. If we think there is value in adding another ctor with EventName included (4 args) then we can take it to API review.

{
EventId = eventId;
Level = level;
Message = message;
}

/// <summary>
/// Gets the logging event id for the logging method.
/// </summary>
Expand All @@ -59,5 +73,10 @@ public LoggerMessageAttribute() { }
/// Gets the message text for the logging method.
/// </summary>
public string Message { get; set; } = "";

/// <summary>
/// Gets the flag to skip IsEnabled check for the logging method.
/// </summary>
public bool SkipEnabledCheck { get; set; }
}
}
57 changes: 57 additions & 0 deletions ...crosoft.Extensions.Logging.Generators.Tests/Baselines/TestWithDefaultValues.generated.txt
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,57 @@
// <auto-generated/>
#nullable enable

namespace Microsoft.Extensions.Logging.Generators.Tests.TestClasses
{
partial class TestWithDefaultValues
{
[global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "6.0.0.0")]
private readonly struct __M0Struct : global::System.Collections.Generic.IReadOnlyList<global::System.Collections.Generic.KeyValuePair<string, object?>>
{

public override string ToString()
{

return $"";
}

public static string Format(__M0Struct state, global::System.Exception? ex) => state.ToString();

public int Count => 1;

public global::System.Collections.Generic.KeyValuePair<string, object?> this[int index]
{
get => index switch
{
0 => new global::System.Collections.Generic.KeyValuePair<string, object?>("{OriginalFormat}", ""),

_ => throw new global::System.IndexOutOfRangeException(nameof(index)), // return the same exception LoggerMessage.Define returns in this case
};
}

public global::System.Collections.Generic.IEnumerator<global::System.Collections.Generic.KeyValuePair<string, object?>> GetEnumerator()
{
for (int i = 0; i < 1; i++)
{
yield return this[i];
}
}

global::System.Collections.IEnumerator global::System.Collections.IEnumerable.GetEnumerator() => GetEnumerator();
}

[global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "6.0.0.0")]
public static partial void M0(global::Microsoft.Extensions.Logging.ILogger logger, global::Microsoft.Extensions.Logging.LogLevel level)
{
if (logger.IsEnabled(level))
{
logger.Log(
level,
new global::Microsoft.Extensions.Logging.EventId(-1, nameof(M0)),
new __M0Struct(),
null,
__M0Struct.Format);
}
}
}
}
18 changes: 18 additions & 0 deletions ...soft.Extensions.Logging.Generators.Tests/Baselines/TestWithSkipEnabledCheck.generated.txt
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,18 @@
// <auto-generated/>
#nullable enable

namespace Microsoft.Extensions.Logging.Generators.Tests.TestClasses
{
partial class TestWithSkipEnabledCheck
{
[global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "6.0.0.0")]
private static readonly global::System.Action<global::Microsoft.Extensions.Logging.ILogger, global::System.Exception?> __M0Callback =
global::Microsoft.Extensions.Logging.LoggerMessage.Define(global::Microsoft.Extensions.Logging.LogLevel.Information, new global::Microsoft.Extensions.Logging.EventId(0, nameof(M0)), "Message: When using SkipEnabledCheck, the generated code skips logger.IsEnabled(logLevel) check before calling log. To be used when consumer has already guarded logger method in an IsEnabled check.", true);

[global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "6.0.0.0")]
public static partial void M0(global::Microsoft.Extensions.Logging.ILogger logger)
{
__M0Callback(logger, null);
}
}
}
Loading