Skip to content

Commit

Permalink
Auto generate Event Ids in the logging source gen (#87892)
Browse files Browse the repository at this point in the history
  • Loading branch information
@tarekgh
tarekgh authored Jun 24, 2023
1 parent d2e8963 commit 3195fbb
Show file tree
Hide file tree
Showing 4 changed files with 87 additions and 10 deletions.
33 changes: 28 additions & 5 deletions src/libraries/Microsoft.Extensions.Logging.Abstractions/gen/LoggerMessageGenerator.Parser.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -103,6 +103,7 @@ public IReadOnlyList<LoggerClass> GetLogClasses(IEnumerable<ClassDeclarationSynt
IMethodSymbol logMethodSymbol = sm.GetDeclaredSymbol(method, _cancellationToken)!;
Debug.Assert(logMethodSymbol != null, "log method is present.");
(int eventId, int? level, string message, string? eventName, bool skipEnabledCheck) = (-1, null, string.Empty, null, false);
bool suppliedEventId = false;

foreach (AttributeListSyntax mal in method.AttributeLists)
{
Expand Down Expand Up @@ -160,19 +161,21 @@ public IReadOnlyList<LoggerClass> GetLogClasses(IEnumerable<ClassDeclarationSynt
message = string.Empty;
level = items[0].IsNull ? null : (int?)GetItem(items[0]);
}
eventId = -1;
break;

case 2:
// LoggerMessageAttribute(LogLevel level, string message)
eventId = -1;
level = items[0].IsNull ? null : (int?)GetItem(items[0]);
message = items[1].IsNull ? string.Empty : (string)GetItem(items[1]);
break;

case 3:
// LoggerMessageAttribute(int eventId, LogLevel level, string message)
eventId = items[0].IsNull ? -1 : (int)GetItem(items[0]);
if (!items[0].IsNull)
{
suppliedEventId = true;
eventId = (int)GetItem(items[0]);
}
level = items[1].IsNull ? null : (int?)GetItem(items[1]);
message = items[2].IsNull ? string.Empty : (string)GetItem(items[2]);
break;
Expand Down Expand Up @@ -202,6 +205,7 @@ public IReadOnlyList<LoggerClass> GetLogClasses(IEnumerable<ClassDeclarationSynt
{
case "EventId":
eventId = (int)GetItem(value);
suppliedEventId = true;
break;
case "Level":
level = value.IsNull ? null : (int?)GetItem(value);
Expand All @@ -227,6 +231,11 @@ public IReadOnlyList<LoggerClass> GetLogClasses(IEnumerable<ClassDeclarationSynt
break;
}

if (!suppliedEventId)
{
eventId = GetNonRandomizedHashCode(string.IsNullOrWhiteSpace(eventName) ? logMethodSymbol.Name : eventName);
}

var lm = new LoggerMethod
{
Name = logMethodSymbol.Name,
Expand Down Expand Up @@ -298,8 +307,8 @@ public IReadOnlyList<LoggerClass> GetLogClasses(IEnumerable<ClassDeclarationSynt
}

// ensure there are no duplicate event ids.
// LoggerMessageAttribute has constructors that don't take an EventId, we need to exclude the default Id -1 from duplication checks.
if (lm.EventId != -1 && !eventIds.Add(lm.EventId))
// We don't check Id duplication for the auto-generated event id.
if (suppliedEventId && !eventIds.Add(lm.EventId))
{
Diag(DiagnosticDescriptors.ShouldntReuseEventIds, ma.GetLocation(), lm.EventId, classDec.Identifier.Text);
}
Expand Down Expand Up @@ -807,5 +816,19 @@ internal sealed class LoggerParameter
// but instead is supposed to be taken as a parameter for the template.
public bool IsTemplateParameter => !IsLogger && !IsException && !IsLogLevel;
}

/// <summary>
/// Returns a non-randomized hash code for the given string.
/// We always return a positive value.
/// </summary>
internal static int GetNonRandomizedHashCode(string s)
{
uint result = 2166136261u;
foreach (char c in s)
{
result = (c ^ result) * 16777619;
}
return Math.Abs((int)result);
}
}
}
2 changes: 1 addition & 1 deletion ...crosoft.Extensions.Logging.Generators.Tests/Baselines/TestWithDefaultValues.generated.txt
View file
Original file line number Diff line number Diff line change
Expand Up @@ -49,7 +49,7 @@ namespace Microsoft.Extensions.Logging.Generators.Tests.TestClasses
{
logger.Log(
level,
new global::Microsoft.Extensions.Logging.EventId(-1, nameof(M0)),
new global::Microsoft.Extensions.Logging.EventId(316638712, nameof(M0)),
new __M0Struct(),
null,
__M0Struct.Format);
Expand Down
48 changes: 44 additions & 4 deletions ...ns/tests/Microsoft.Extensions.Logging.Generators.Tests/LoggerMessageGeneratedCodeTests.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -209,7 +209,7 @@ public void MessageTests()
Assert.Null(logger.LastException);
Assert.Equal(string.Empty, logger.LastFormattedString);
Assert.Equal(LogLevel.Trace, logger.LastLogLevel);
Assert.Equal(-1, logger.LastEventId.Id);
Assert.Equal(400_526_807, logger.LastEventId.Id);
Assert.Equal(1, logger.CallCount);

logger.Reset();
Expand Down Expand Up @@ -269,40 +269,80 @@ public void InstanceTests()
var logger = new MockLogger();
var o = new TestInstances(logger);

// [LoggerMessage(EventId = 0, Level = LogLevel.Error, Message = "M0")]
logger.Reset();
o.M0();
Assert.Null(logger.LastException);
Assert.Equal("M0", logger.LastFormattedString);
Assert.Equal(LogLevel.Error, logger.LastLogLevel);
Assert.Equal(1, logger.CallCount);

// [LoggerMessage(EventId = 1, Level = LogLevel.Trace, Message = "M1 {p1}")]
logger.Reset();
o.M1("Foo");
Assert.Null(logger.LastException);
Assert.Equal("M1 Foo", logger.LastFormattedString);
Assert.Equal(LogLevel.Trace, logger.LastLogLevel);
Assert.Equal(1, logger.CallCount);

// [LoggerMessage(LogLevel.Information, "M2 {p1}")]
logger.Reset();
o.M2("Bar");
Assert.Null(logger.LastException);
Assert.Equal("M2 Bar", logger.LastFormattedString);
Assert.Equal(LogLevel.Information, logger.LastLogLevel);
Assert.Equal(-1, logger.LastEventId.Id);
Assert.Equal(350_193_950, logger.LastEventId.Id);

// [LoggerMessage("M3 {p1}")]
logger.Reset();
o.M3(LogLevel.Critical, "Foo Bar");
Assert.Null(logger.LastException);
Assert.Equal("M3 Foo Bar", logger.LastFormattedString);
Assert.Equal(LogLevel.Critical, logger.LastLogLevel);
Assert.Equal(-1, logger.LastEventId.Id);
Assert.Equal(366_971_569, logger.LastEventId.Id);

// [LoggerMessage(LogLevel.Debug)]
logger.Reset();
o.M4();
Assert.Null(logger.LastException);
Assert.Equal("", logger.LastFormattedString);
Assert.Equal(LogLevel.Debug, logger.LastLogLevel);
Assert.Equal(-1, logger.LastEventId.Id);
Assert.Equal(383_749_188, logger.LastEventId.Id);

// [LoggerMessage(level: LogLevel.Warning, message: "custom message {v}", eventId: 12341)]
logger.Reset();
o.M5("Hello");
Assert.Null(logger.LastException);
Assert.Equal("custom message Hello", logger.LastFormattedString);
Assert.Equal(LogLevel.Warning, logger.LastLogLevel);
Assert.Equal(12341, logger.LastEventId.Id);

// [LoggerMessage(EventName = "My Event Name", Level = LogLevel.Information, Message = "M6 - {p1}")]
logger.Reset();
o.M6("Generate event Id");
Assert.Null(logger.LastException);
Assert.Equal("M6 - Generate event Id", logger.LastFormattedString);
Assert.Equal(LogLevel.Information, logger.LastLogLevel);
Assert.Equal("My Event Name", logger.LastEventId.Name);
Assert.Equal(26_601_394, logger.LastEventId.Id);

// [LoggerMessage(Level = LogLevel.Warning, Message = "M7 - {p1}")]
logger.Reset();
o.M7("Generate event Id");
Assert.Null(logger.LastException);
Assert.Equal("M7 - Generate event Id", logger.LastFormattedString);
Assert.Equal(LogLevel.Warning, logger.LastLogLevel);
Assert.Equal("M7", logger.LastEventId.Name);
Assert.Equal(434_082_045, logger.LastEventId.Id);

// [LoggerMessage(EventId = 100, Level = LogLevel.Warning, Message = "M8 - {p1}")]
logger.Reset();
o.M8("Generate event Id");
Assert.Null(logger.LastException);
Assert.Equal("M8 - Generate event Id", logger.LastFormattedString);
Assert.Equal(LogLevel.Warning, logger.LastLogLevel);
Assert.Equal("M8", logger.LastEventId.Name);
Assert.Equal(100, logger.LastEventId.Id);
}

[Fact]
Expand Down
14 changes: 14 additions & 0 deletions ...ractions/tests/Microsoft.Extensions.Logging.Generators.Tests/TestClasses/TestInstances.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -28,5 +28,19 @@ public TestInstances(ILogger logger)

[LoggerMessage(LogLevel.Debug)]
public partial void M4();

// Test with named parameters
[LoggerMessage(level: LogLevel.Warning, message: "custom message {v}", eventId: 12341)]
public partial void M5(string v);

// Test auto-generated EventId
[LoggerMessage(EventName = "My Event Name", Level = LogLevel.Information, Message = "M6 - {p1}")]
public partial void M6(string p1);

[LoggerMessage(Level = LogLevel.Warning, Message = "M7 - {p1}")]
public partial void M7(string p1);

[LoggerMessage(EventId = 100, Level = LogLevel.Warning, Message = "M8 - {p1}")]
public partial void M8(string p1);
}
}

0 comments on commit 3195fbb

Please sign in to comment.