convert SC loggers to ILogger #5000

PhilBastian · 2025-06-09T23:39:05Z

No description provided.

src/ServiceControl.Audit/Auditing/AuditIngestion.cs

src/ServiceControl.Audit/Auditing/AuditPersister.cs

src/ServiceControl.Infrastructure/Watchdog.cs

src/ServiceControl/App.config

src/ServiceControl.Infrastructure/Watchdog.cs

src/ServiceControl/ServiceControl.csproj

…xtensions.logging_spike

…or creation

…sions.Logging

…s.Logging

…ontrol.infrastructure

…nder

…nder # Conflicts: # src/ServiceControl.Infrastructure/LoggingSettings.cs

* convert SC transports from NServiceBus.Logging to Microsoft.Extensions.Logging * remove signedassembly requirement so that infrastructure can be imported * revert previous change and instead propogate signing back to servicecontrol.infrastructure * fix signature of customisation classes that are dynamically created * add ilogger to test services and remove direct construction with logger * get tests to use ilogger * Switch to .NET logging * Work in progress * Remove test code * Improve logging format for storage space details * Properly shutdown NLog in Program.cs * Remove Seq logging and prepare for .NET logging migration * Update LogLevel format * Update LogLevel format in logging settings * enable adding test logging provider as part of loggerutils and create framework for settings driven logger selection * add ability to select logging provider from config * handle setting not existing * change logmanager logger factory to the standard one now used by the rest of SC * ensure logger for transport tests * domain events and persister loggers * set default to nlog and pass loglevel to test context * replace logmanager usage in persistence * cleanup remaining references to LogManager * missing files from last checkin * fix different dependency version test failure * move loggerutil setup before first static logger usage * fix different dependency version test failure --------- Co-authored-by: JasonTaylorDev <hello@jasontaylor.dev>

ramonsmits

Great job!

Some questions:

Why not OpenTelemetry OLTP exporter? I think this is even supported by Seq.
Ensure all loggers/providers are always flushed in finally
I think a bootstrap logger that is based on logging extensions would make sense.
As a lot of init is done only in "commands" where a hostbuilder is created any logger lifetimes there could be ended when that host instance gets disposed. If Seq/NLog its initialized and passed this can't result in lifetime issues
Seems that some log statements can benefit from logger scopes like OnMessagein the ingestioners, custom checks, etc. but maybe that that should not be part of this PR as its already HUGE
Do a search on ." as I saw many messages ending in .

ramonsmits · 2025-06-23T12:17:03Z

src/ServiceControl.AcceptanceTesting/DiscardMessagesBehavior.cs

@@ -44,15 +45,20 @@ public Task Invoke(ITransportReceiveContext context, Func<ITransportReceiveConte
            {
                context.Message.Headers.TryGetValue(Headers.MessageId, out var originalMessageId);
                context.Message.Headers.TryGetValue(Headers.EnclosedMessageTypes, out var enclosedMessageTypes);
-                log.Debug($"Discarding message '{context.Message.MessageId}'({originalMessageId ?? string.Empty}) because it's session id is '{session}' instead of '{currentSession}' Message Types: {enclosedMessageTypes}.");
+                var logger = LoggerUtil.CreateStaticLogger<DiscardMessagesBehavior>();


Why not use the serviceprovider to resolve a logger?

this class is only used by tests and is always newed up, not resolved from the container

ramonsmits · 2025-06-23T12:20:50Z

src/ServiceControl.Audit.Persistence.RavenDB/CustomChecks/CheckDirtyMemory.cs

    public override async Task<CheckResult> PerformCheck(CancellationToken cancellationToken = default)
    {
        var (isHighDirty, dirtyMemory) = await memoryInformationRetriever.GetMemoryInformation(cancellationToken);

-        Log.Debug($"RavenDB dirty memory value: {dirtyMemory}.");
+        logger.LogDebug("RavenDB dirty memory value: {DirtyMemory}.", dirtyMemory);


This is I think a timer/schedule based task. Likely better to have a IServiceProvider injected that will create a logger scope per iteration

ramonsmits · 2025-06-23T12:21:40Z

src/ServiceControl.Audit.Persistence.RavenDB/CustomChecks/CheckDirtyMemory.cs

-            var message = $"There is a high level of RavenDB dirty memory ({dirtyMemory}). See https://docs.particular.net/servicecontrol/troubleshooting#ravendb-dirty-memory for guidance on how to mitigate the issue.";
-            Log.Warn(message);
-            return CheckResult.Failed(message);
+            logger.LogWarning("There is a high level of RavenDB dirty memory ({DirtyMemory}). See https://docs.particular.net/servicecontrol/troubleshooting#ravendb-dirty-memory for guidance on how to mitigate the issue.", dirtyMemory);


Suggested change

logger.LogWarning("There is a high level of RavenDB dirty memory ({DirtyMemory}). See https://docs.particular.net/servicecontrol/troubleshooting#ravendb-dirty-memory for guidance on how to mitigate the issue.", dirtyMemory);

logger.LogWarning("There is a high level of RavenDB dirty memory ({DirtyMemory}). See https://docs.particular.net/servicecontrol/troubleshooting#ravendb-dirty-memory for guidance on how to mitigate the issue", dirtyMemory);

ramonsmits · 2025-06-23T12:21:49Z

src/ServiceControl.Audit.Persistence.RavenDB/CustomChecks/CheckDirtyMemory.cs

-            Log.Warn(message);
-            return CheckResult.Failed(message);
+            logger.LogWarning("There is a high level of RavenDB dirty memory ({DirtyMemory}). See https://docs.particular.net/servicecontrol/troubleshooting#ravendb-dirty-memory for guidance on how to mitigate the issue.", dirtyMemory);
+            return CheckResult.Failed($"There is a high level of RavenDB dirty memory ({dirtyMemory}). See https://docs.particular.net/servicecontrol/troubleshooting#ravendb-dirty-memory for guidance on how to mitigate the issue.");


Suggested change

return CheckResult.Failed($"There is a high level of RavenDB dirty memory ({dirtyMemory}). See https://docs.particular.net/servicecontrol/troubleshooting#ravendb-dirty-memory for guidance on how to mitigate the issue.");

return CheckResult.Failed($"There is a high level of RavenDB dirty memory ({dirtyMemory}). See https://docs.particular.net/servicecontrol/troubleshooting#ravendb-dirty-memory for guidance on how to mitigate the issue");

ramonsmits · 2025-06-23T12:24:05Z

src/ServiceControl.Audit.Persistence.RavenDB/CustomChecks/CheckFreeDiskSpace.cs

    {
        public override Task<CheckResult> PerformCheck(CancellationToken cancellationToken = default)
        {
-            if (Logger.IsDebugEnabled)
+            if (logger.IsEnabled(LogLevel.Debug))


Same here, this is a scheduled job. Consider a logger scope identifying an iteration

src/ServiceControl/Monitoring/HeartbeatEndpointSettingsSyncHostedService.cs

ramonsmits · 2025-06-24T08:17:23Z

src/ServiceControl/Operations/ErrorIngestion.cs

            }
            catch (Exception e)
            {
-                Logger.Error("Failed to stop infrastructure", e);
+                logger.LogError(e, "Failed to stop infrastructure");


Comment for the OnMessage method below: Add logging scope :-)

ramonsmits · 2025-06-24T08:20:14Z

src/ServiceControl/Program.cs

+    logger.LogInformation("Shutdown complete");
    NLog.LogManager.Shutdown();


Same as before, ensure any loggers used are properly flushing

ramonsmits · 2025-06-24T08:24:37Z

src/ServiceControl/Recoverability/Retrying/Infrastructure/ReturnToSender.cs

@@ -32,16 +30,14 @@ public virtual async Task HandleMessage(MessageContext message, IMessageDispatch
            }
            else
            {
-                Log.WarnFormat("{0}: Can't find message body. Missing header ServiceControl.Retry.Attempt.MessageId", messageId);
+                logger.LogWarning("{MessageId}: Can't find message body. Missing header ServiceControl.Retry.Attempt.MessageId", messageId);


So... lets use a Logger scope instead of prefixing these with the message id?

logger scope doesn't print to file unless specified in the nlog layout string, which we don't want for the vast majority of log entries

…ions

…tedService.cs Co-authored-by: Ramon Smits <ramon.smits@gmail.com>

…xtensions.logging_spike

PhilBastian added 2 commits June 9, 2025 14:53

convert audit loggers to ILogger

a47d8ec

revert app.config checkins

047420b

PhilBastian requested review from jasontaylordev and abparticular June 9, 2025 23:39

PhilBastian self-assigned this Jun 9, 2025

PhilBastian commented Jun 9, 2025

View reviewed changes

use pascal case for structured logging

ad7cc4a

jasontaylordev reviewed Jun 10, 2025

View reviewed changes

src/ServiceControl.Infrastructure/Watchdog.cs Outdated Show resolved Hide resolved

src/ServiceControl/ServiceControl.csproj Outdated Show resolved Hide resolved

PhilBastian and others added 22 commits June 10, 2025 12:07

revert accidental checkin for primary instance

3534fd2

Merge remote-tracking branch 'origin/extensions.logging_spike' into e…

aec0e48

…xtensions.logging_spike

Apply suggestions from code review

b6505e6

fix build error

2a0db48

Merge remote-tracking branch 'origin/extensions.logging_spike' into e…

573d9a2

…xtensions.logging_spike

revert setupcommand to having a parameterless constructor for activat…

1041b4e

…or creation

replace NServiceBus.logging in Audit.Persistence with Microsoft.Exten…

4f25d49

…sions.Logging

convert SC transports from NServiceBus.Logging to Microsoft.Extension…

a8c746f

…s.Logging

remove signedassembly requirement so that infrastructure can be imported

42d01e7

revert previous change and instead propogate signing back to servicec…

96ec124

…ontrol.infrastructure

fix signature of customisation classes that are dynamically created

5aaabe6

add ilogger to test services and remove direct construction with logger

67920ff

get tests to use ilogger

b3c690a

Switch to .NET logging

66aaa02

Work in progress

e2196e6

Remove test code

e9f287e

Improve logging format for storage space details

9b97c92

Properly shutdown NLog in Program.cs

005968d

Remove Seq logging and prepare for .NET logging migration

49ba86c

Update LogLevel format

938c963

Update LogLevel format in logging settings

fb7f77e

Merge branch 'master' into extensions.logging_transports

6c713bb

Merge branch 'extensions.logging_spike' into extensions.logging_remai…

416258d

…nder

PhilBastian changed the title ~~convert audit loggers to ILogger~~ convert SC loggers to ILogger Jun 18, 2025

PhilBastian and others added 15 commits June 19, 2025 09:24

set default to nlog and pass loglevel to test context

479d409

default to nLog

c3c3de4

replace logmanager usage in persistence

316516e

cleanup remaining references to LogManager

6df6fd2

missing files from last checkin

e37e282

fix different dependency version test failure

4485d7b

move loggerutil setup before first static logger usage

4b80ba3

Merge branch 'extensions.logging_spike' into extensions.logging_remai…

1200d13

…nder # Conflicts: # src/ServiceControl.Infrastructure/LoggingSettings.cs

fix different dependency version test failure

92b99b0

add logging config to all services

39039ed

enable seq url to be configured

56a4635

allow seq url to be configured

ddb7568

fix logger not being available in program.cs

b825edc

make nlog level based on configuration again

7edf38f

PhilBastian requested a review from ramonsmits June 24, 2025 07:12

ramonsmits reviewed Jun 24, 2025

View reviewed changes

PhilBastian and others added 11 commits June 25, 2025 12:52

fix logging not being available during logging setup

ec9c21f

remove '.' from the end of log messages

912ef81

remove unnecessary static logger

e7bf499

remove unnecessary checks since it's not around intensive log convers…

f0be16f

…ions

remove unnecessary checks

061ba55

add opentelemetry as a logging provider option

22bcf4b

missing package reference

ca52fa1

Update src/ServiceControl/Monitoring/HeartbeatEndpointSettingsSyncHos…

8b55728

…tedService.cs Co-authored-by: Ramon Smits <ramon.smits@gmail.com>

Update src/ServiceControl/Monitoring/HeartbeatEndpointSettingsSyncHos…

43cc46c

…tedService.cs Co-authored-by: Ramon Smits <ramon.smits@gmail.com>

log text changes suggested in review

ff85749

Merge remote-tracking branch 'origin/extensions.logging_spike' into e…

2fb0180

…xtensions.logging_spike

	logger.LogWarning("There is a high level of RavenDB dirty memory ({DirtyMemory}). See https://docs.particular.net/servicecontrol/troubleshooting#ravendb-dirty-memory for guidance on how to mitigate the issue.", dirtyMemory);
	logger.LogWarning("There is a high level of RavenDB dirty memory ({DirtyMemory}). See https://docs.particular.net/servicecontrol/troubleshooting#ravendb-dirty-memory for guidance on how to mitigate the issue", dirtyMemory);

	return CheckResult.Failed($"There is a high level of RavenDB dirty memory ({dirtyMemory}). See https://docs.particular.net/servicecontrol/troubleshooting#ravendb-dirty-memory for guidance on how to mitigate the issue.");
	return CheckResult.Failed($"There is a high level of RavenDB dirty memory ({dirtyMemory}). See https://docs.particular.net/servicecontrol/troubleshooting#ravendb-dirty-memory for guidance on how to mitigate the issue");

		logger.LogInformation("Shutdown complete");
		NLog.LogManager.Shutdown();

convert SC loggers to ILogger #5000

Are you sure you want to change the base?

convert SC loggers to ILogger #5000

Uh oh!

Conversation

PhilBastian commented Jun 9, 2025

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

ramonsmits left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!