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

Convert HealthChecks logging to use new Logging Source Generator #32414

Merged
merged 3 commits into from
Jul 2, 2021

Conversation

eerhardt
Copy link
Member

@eerhardt eerhardt commented May 4, 2021

PR Title
Convert HealthChecks logging to use new Logging Source Generator

PR Description
Simplying the HealthChecks logging code by using the new Logging source generator feature.

See dotnet/runtime#36022

cc @maryamariyan

Copy link
Contributor

@pranavkm pranavkm left a comment

Choose a reason for hiding this comment

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

:shipit:

@davidfowl
Copy link
Member

I would prefer to keep the nested Log class

@eerhardt
Copy link
Member Author

eerhardt commented May 5, 2021

I would prefer to keep the nested Log class

And always pass in _logger?

@davidfowl
Copy link
Member

Yep. I don't like the log methods in the same class as where the logging happens

@eerhardt
Copy link
Member Author

eerhardt commented May 5, 2021

Ok, sounds good. I'll move them back.

Just to be sure, do we think the feature of finding the ILogger _logger instance field is still valuable to certain devs? (Just not ASP.NET library devs?) Or should we remove it and encourage people to use a static nested class?

@eerhardt
Copy link
Member Author

eerhardt commented May 5, 2021

Oh, I remember why I did this now. The source generator doesn't support nested classes.

Severity	Code	Description	Project	File	Line	Suppression State
Error	SYSLIB1004	Logging class cannot be in nested types	Microsoft.Extensions.Diagnostics.HealthChecks	C:\git\aspnetcore\src\HealthChecks\HealthChecks\src\DefaultHealthCheckService.cs	201	

So I would need to move the Log class outside of the Service classes.

@davidfowl
Copy link
Member

So I would need to move the Log class outside of the Service classes.

OR fix issue? Is it possible to mark both as partial and make the current style work?

@eerhardt
Copy link
Member Author

eerhardt commented May 5, 2021

OR fix issue? Is it possible to mark both as partial and make the current style work?

It isn't possible today because this is an explicit limitation in the source generator. I opened dotnet/runtime#52301 to address it.

@mkArtakMSFT mkArtakMSFT added the area-healthchecks Includes: Healthchecks (some bugs also in Extensions repo) label May 5, 2021
@eerhardt
Copy link
Member Author

eerhardt commented May 6, 2021

@davidfowl - do you want me to wait for the source generator support for nested classes? Or should I address the other feedback in this PR to move it forward?

@davidfowl
Copy link
Member

I would do the places that don't need the nested class style change first (I think we have a few of them).

@eerhardt
Copy link
Member Author

eerhardt commented May 6, 2021

I was just going to do 1 place as part of "app building" for preview4. This was the first one that jumped out to me 😄 .

This PR can wait until the support comes in the source generator.

* Keep nested Log class
* Hard-code event names to ensure code refactoring doesn't lead to breaks
@eerhardt eerhardt marked this pull request as ready for review June 29, 2021 17:48
@eerhardt eerhardt requested a review from Pilchie as a code owner June 29, 2021 17:48
@eerhardt
Copy link
Member Author

Thanks for all the feedback. I believe I have addressed it and this is now ready for review. PTAL.

@pranavkm pranavkm self-requested a review June 29, 2021 23:30
@@ -12,6 +12,8 @@ Microsoft.Extensions.Diagnostics.HealthChecks.IHealthChecksBuilder
<PackageTags>diagnostics;healthchecks</PackageTags>
<IsAspNetCoreApp>true</IsAspNetCoreApp>
<Nullable>enable</Nullable>
<!-- workaround https://github.com/dotnet/roslyn/issues/52527 -->
<NoWarn>$(NoWarn);SYSLIB1006</NoWarn>
Copy link
Contributor

Choose a reason for hiding this comment

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

Undo?

Copy link
Member Author

@eerhardt eerhardt Jun 30, 2021

Choose a reason for hiding this comment

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

Even though the underlying roslyn issue is closed, I'm still seeing the warnings in VS without this change

image

Note I am using VS Version 16.11.0 Preview 2.0

Copy link
Member Author

Choose a reason for hiding this comment

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

The reason this is still needed is because we are using an older Roslyn here:

<!-- Packages from dotnet/roslyn -->
<MicrosoftNetCompilersToolsetVersion>3.10.0-1.final</MicrosoftNetCompilersToolsetVersion>

That version didn't have the fix for dotnet/roslyn#52527

@pranavkm pranavkm requested a review from Tratcher June 29, 2021 23:39
@pranavkm
Copy link
Contributor

@Tratcher / @JamesNK / @BrennanConroy could you have a look at this PR and agree on the pattern for specifying event ids? It's the only part of that isn't mechanical.

@JamesNK
Copy link
Member

JamesNK commented Jun 30, 2021

I think specifying them in the attribute is fine. Adding a static class with constants doesn't add anything.

@BrennanConroy
Copy link
Member

I think having the IDs in attributes is fine, but only if there isn't any other code in-between all the attributes like there is currently. As soon as you start putting random gaps in the grouping you make it a lot easier to introduce duplicate IDs.

Clean:

[LoggerMessage(EventIds.HealthCheckProcessingEndId, LogLevel.Debug, "Health check processing with combined status {HealthStatus} completed after {ElapsedMilliseconds}ms", EventName = EventIds.HealthCheckProcessingEndName)]
private static partial void HealthCheckProcessingEnd(ILogger logger, HealthStatus HealthStatus, double ElapsedMilliseconds);
[LoggerMessage(EventIds.HealthCheckBeginId, LogLevel.Debug, "Running health check {HealthCheckName}", EventName = EventIds.HealthCheckBeginName)]
public static partial void HealthCheckBegin(ILogger logger, string HealthCheckName);

Not clean:

[LoggerMessage(EventIds.HealthCheckEndId, LogLevel.Error, HealthCheckEndText, EventName = EventIds.HealthCheckEndName)]
private static partial void HealthCheckEndUnhealthy(ILogger logger, string HealthCheckName, HealthStatus HealthStatus, double ElapsedMilliseconds, string? HealthCheckDescription, Exception? exception);
#pragma warning restore SYSLIB1006
public static void HealthCheckEnd(ILogger logger, HealthCheckRegistration registration, HealthReportEntry entry, TimeSpan duration)
{
switch (entry.Status)
{
case HealthStatus.Healthy:
HealthCheckEndHealthy(logger, registration.Name, entry.Status, duration.TotalMilliseconds, entry.Description);
break;
case HealthStatus.Degraded:
HealthCheckEndDegraded(logger, registration.Name, entry.Status, duration.TotalMilliseconds, entry.Description);
break;
case HealthStatus.Unhealthy:
HealthCheckEndUnhealthy(logger, registration.Name, entry.Status, duration.TotalMilliseconds, entry.Description, entry.Exception);
break;
}
}
[LoggerMessage(EventIds.HealthCheckErrorId, LogLevel.Error, "Health check {HealthCheckName} threw an unhandled exception after {ElapsedMilliseconds}ms", EventName = EventIds.HealthCheckErrorName)]
private static partial void HealthCheckError(ILogger logger, string HealthCheckName, double ElapsedMilliseconds, Exception exception);
public static void HealthCheckError(ILogger logger, HealthCheckRegistration registration, Exception exception, TimeSpan duration) =>
HealthCheckError(logger, registration.Name, duration.TotalMilliseconds, exception);

@Tratcher
Copy link
Member

I think we only need the static class for ids when multiple classes share a log category, then you want a central list to avoid duplicates.

@JamesNK
Copy link
Member

JamesNK commented Jun 30, 2021

Doesn't the new logging generator check for duplicates?

@Tratcher
Copy link
Member

How does that work when the category is defined separately in the ILogger?

@JamesNK
Copy link
Member

JamesNK commented Jun 30, 2021

In the case of KestrelTrace, there would still be one uber logging class, but we're passing in different ILogger instances to the various methods. Same design as today. The difference is just replacing the manually defined KestrelTrace with a mostly code-generated one.

@eerhardt
Copy link
Member Author

eerhardt commented Jul 1, 2021

Is there a recommendation on what to do in this PR? I'm totally fine with making a change to remove the EventIds class.

Personally, I'd lean to keep it as-is because:

  1. It is nice to reuse the constants in the unit tests.
  2. It leads to a nice place to put the comment about using hard coded strings for the EventName so they don't get changed by code refactoring.
    • As a new person to the codebase, I would have never knew about this rule without someone catching it in a code review.

@pranavkm
Copy link
Contributor

pranavkm commented Jul 1, 2021

I guess the consensus seems to be to inline the Ids which we could do in other updates if we need to. In particular because this PR has tests that reference these events, I'm fine with them being in a separate type.

If folks feel super strong about this, please chime in. Otherwise let's get this change in.

@pranavkm pranavkm merged commit 1dd00f4 into dotnet:main Jul 2, 2021
@ghost ghost added this to the 6.0-preview7 milestone Jul 2, 2021
TanayParikh added a commit that referenced this pull request Jul 7, 2021
captainsafia added a commit that referenced this pull request Jul 9, 2021
dotnet-maestro bot added a commit that referenced this pull request Jul 12, 2021
[main] Update dependencies from dotnet/efcore dotnet/runtime


 - Workaround duplicate logging source generator

 - Merge branch 'main' into darc-main-1709b9ed-50a0-4e28-b9b8-0e3759aee720

 - Fix CS8795

https://dev.azure.com/dnceng/public/_build/results?buildId=1222936&view=logs&jobId=b5df7d42-2bda-5dee-96bd-1838a4f7499c&j=b5df7d42-2bda-5dee-96bd-1838a4f7499c&t=c1ffdaa9-e800-5fe8-052c-643f2e9f52ff

 - Update Wasm.Performance.TestApp.csproj

 - Fix skipEnabledCheck

 - Merge branch 'main' into darc-main-1709b9ed-50a0-4e28-b9b8-0e3759aee720

 - Update Workarounds.targets

 - Revert "Fix CS8795"

This reverts commit a2ec9d6.

 - Revert "Convert HealthChecks logging to use new Logging Source Generator (#32414)"

This reverts commit 1dd00f4.

 - Utilize class level SkipEnabledCheckLogOptions

 - React to MvcCoreLoggerExtensions feedback

 - Merge remote-tracking branch 'origin/main' into darc-main-1709b9ed-50a0-4e28-b9b8-0e3759aee720

 - React to nullability changes in TypeConverter

 - Merge branch 'main' into darc-main-1709b9ed-50a0-4e28-b9b8-0e3759aee720

 - React to new analyzer warnings

 - Revert "Revert "Convert HealthChecks logging to use new Logging Source Generator (#32414)""

This reverts commit 5d6e21e.

 - Update src/Http/Routing/src/Matching/DfaMatcher.cs

Co-authored-by: Eric Erhardt <eric.erhardt@microsoft.com>

 - Update exception caught in HTTP2 tests

 - Merge branch 'main' of https://github.com/dotnet/aspnetcore into darc-main-1709b9ed-50a0-4e28-b9b8-0e3759aee720

 - Revert "Remove usings from templates implicitly added by the SDK (#34219)"

This reverts commit d8bba72.

 - Fix up exceptions for HTTP2 tests

 - Revert "Revert "Remove usings from templates implicitly added by the SDK (#34219)""

This reverts commit cce1bd7.

 - Bump up SDK to bring in usings changes

 - Try running template tests on non-Helix

 - Update ci.yml

 - Try disabling template tests on Helix

 - Revert "Stop running template tests on azdo job (already helix-ified) (#32985)"

This reverts commit 7a842b7.

 - Don't build Helix payload for template tests

 - Temporarily skip FrameworkListListsContainsCorrectPaths

 - Use dotnet test for test discovery

 - Revert "Use dotnet test for test discovery"

This reverts commit f5cecb2.

 - Try skipping listing tests list in helix

 - Revert "Try disabling template tests on Helix"

This reverts commit 2136f31.

 - Remove generic type from test method

 - Removed another generic from the test method
@danielcweber
Copy link
Contributor

In the latest 6.0-preview docker image, the logger message arguments are mixed up:
image

This is probably a source generator issue, but I can't figure out whether it has already been fixed.

cc: @maryamariyan

@ghost
Copy link

ghost commented Jul 24, 2021

Hi @danielcweber. It looks like you just commented on a closed PR. The team will most probably miss it. If you'd like to bring something important up to their attention, consider filing a new issue and add enough details to build context.

@eerhardt eerhardt deleted the HealthChecksLogger branch July 26, 2021 14:36
@eerhardt
Copy link
Member Author

Note: I debugged into the repro at #34710. I noticed that this PR isn't in 6.0.0-preview6. It was merged after the preview6 snap.

So the issue existed before my change.

@ghost
Copy link

ghost commented Jul 26, 2021

Hi @eerhardt. It looks like you just commented on a closed PR. The team will most probably miss it. If you'd like to bring something important up to their attention, consider filing a new issue and add enough details to build context.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area-healthchecks Includes: Healthchecks (some bugs also in Extensions repo)
Projects
None yet
Development

Successfully merging this pull request may close these issues.

10 participants