Skip to content

Commit cc33a71

Browse files
PhilBastianjasontaylordev
PhilBastian
and
jasontaylordev
authored
convert SC transports from NServiceBus.Logging to Microsoft.Extensions.Logging (#5009)
* 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 --------- Co-authored-by: JasonTaylorDev <[email protected]>
1 parent dce6435 commit cc33a71

File tree

53 files changed

+387
-357
lines changed

Some content is hidden

Large Commits have some content hidden by default. Use the searchbox below for content that may be hidden.

53 files changed

+387
-357
lines changed

‎src/Directory.Packages.props‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -24,6 +24,7 @@
2424
<PackageVersion Include="Microsoft.Extensions.Hosting" Version="8.0.1" />
2525
<PackageVersion Include="Microsoft.Extensions.Hosting.Abstractions" Version="8.0.1" />
2626
<PackageVersion Include="Microsoft.Extensions.Hosting.WindowsServices" Version="8.0.1" />
27+
<PackageVersion Include="Microsoft.Extensions.Logging.Abstractions" Version="8.0.3" />
2728
<PackageVersion Include="Microsoft.Extensions.TimeProvider.Testing" Version="8.10.0" />
2829
<PackageVersion Include="Microsoft.NET.Test.Sdk" Version="17.13.0" />
2930
<PackageVersion Include="Microsoft-WindowsAPICodePack-Shell" Version="1.1.5" />

‎src/ServiceControl.AcceptanceTests/TestSupport/ServiceControlComponentRunner.cs‎

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -15,8 +15,7 @@
1515
using Microsoft.AspNetCore.TestHost;
1616
using Microsoft.Extensions.DependencyInjection;
1717
using Microsoft.Extensions.Hosting;
18-
using Microsoft.Extensions.Logging.Abstractions;
19-
using NLog;
18+
using Microsoft.Extensions.Logging;
2019
using NServiceBus;
2120
using NServiceBus.AcceptanceTesting;
2221
using NServiceBus.AcceptanceTesting.Support;

‎src/ServiceControl.Audit.AcceptanceTests/TestSupport/ServiceControlComponentRunner.cs‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -44,7 +44,7 @@ async Task InitializeServiceControl(ScenarioContext context)
4444
var logPath = Path.Combine(Path.GetTempPath(), Path.GetRandomFileName());
4545
Directory.CreateDirectory(logPath);
4646

47-
var loggingSettings = new LoggingSettings(Settings.SettingsRootNamespace, defaultLevel: NLog.LogLevel.Debug, logPath: logPath);
47+
var loggingSettings = new LoggingSettings(Settings.SettingsRootNamespace, defaultLevel: LogLevel.Debug, logPath: logPath);
4848

4949
settings = new Settings(transportToUse.TypeName, persistenceToUse.PersistenceType, loggingSettings)
5050
{

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

Lines changed: 6 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -3,26 +3,24 @@ namespace ServiceControl.Audit.Persistence.RavenDB.CustomChecks;
33
using System;
44
using System.Threading;
55
using System.Threading.Tasks;
6+
using Microsoft.Extensions.Logging;
67
using NServiceBus.CustomChecks;
7-
using NServiceBus.Logging;
88

9-
class CheckDirtyMemory(MemoryInformationRetriever memoryInformationRetriever) : CustomCheck("RavenDB dirty memory", "ServiceControl.Audit Health", TimeSpan.FromMinutes(5))
9+
class CheckDirtyMemory(MemoryInformationRetriever memoryInformationRetriever, ILogger<CheckDirtyMemory> logger) : CustomCheck("RavenDB dirty memory", "ServiceControl.Audit Health", TimeSpan.FromMinutes(5))
1010
{
11+
1112
public override async Task<CheckResult> PerformCheck(CancellationToken cancellationToken = default)
1213
{
1314
var (isHighDirty, dirtyMemory) = await memoryInformationRetriever.GetMemoryInformation(cancellationToken);
1415

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

1718
if (isHighDirty)
1819
{
19-
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.";
20-
Log.Warn(message);
21-
return CheckResult.Failed(message);
20+
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);
21+
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.");
2222
}
2323

2424
return CheckResult.Pass;
2525
}
26-
27-
static readonly ILog Log = LogManager.GetLogger<CheckDirtyMemory>();
2826
}

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

Lines changed: 13 additions & 19 deletions
Original file line numberDiff line numberDiff line change
@@ -5,17 +5,17 @@
55
using System.IO;
66
using System.Threading;
77
using System.Threading.Tasks;
8+
using Microsoft.Extensions.Logging;
89
using NServiceBus.CustomChecks;
9-
using NServiceBus.Logging;
1010
using RavenDB;
1111

12-
class CheckFreeDiskSpace(DatabaseConfiguration databaseConfiguration) : CustomCheck("ServiceControl.Audit database", "Storage space", TimeSpan.FromMinutes(5))
12+
class CheckFreeDiskSpace(DatabaseConfiguration databaseConfiguration, ILogger<CheckFreeDiskSpace> logger) : CustomCheck("ServiceControl.Audit database", "Storage space", TimeSpan.FromMinutes(5))
1313
{
1414
public override Task<CheckResult> PerformCheck(CancellationToken cancellationToken = default)
1515
{
16-
if (Logger.IsDebugEnabled)
16+
if (logger.IsEnabled(LogLevel.Debug))
1717
{
18-
Logger.Debug($"Check ServiceControl data drive space remaining custom check starting. Threshold {percentageThreshold:P0}");
18+
logger.LogDebug("Check ServiceControl data drive space remaining custom check starting. Threshold {PercentageThreshold:P0}", percentageThreshold);
1919
}
2020

2121
if (!databaseConfiguration.ServerConfiguration.UseEmbeddedServer)
@@ -34,52 +34,46 @@ public override Task<CheckResult> PerformCheck(CancellationToken cancellationTok
3434

3535
var percentRemaining = (decimal)dataDriveInfo.AvailableFreeSpace / dataDriveInfo.TotalSize;
3636

37-
if (Logger.IsDebugEnabled)
37+
if (logger.IsEnabled(LogLevel.Debug))
3838
{
39-
Logger.Debug($"Free space: {availableFreeSpace:N0}B | Total: {totalSpace:N0}B | Percent remaining {percentRemaining:P1}");
39+
logger.LogDebug("Free space: {AvailableFreeSpace:N0}B | Total: {TotalSpace:N0}B | Percent remaining {PercentRemaining:P1}", availableFreeSpace, totalSpace, percentRemaining);
4040
}
4141

4242
return percentRemaining > percentageThreshold
4343
? CheckResult.Pass
4444
: CheckResult.Failed($"{percentRemaining:P0} disk space remaining on data drive '{dataDriveInfo.VolumeLabel} ({dataDriveInfo.RootDirectory})' on '{Environment.MachineName}'.");
4545
}
4646

47-
public static int Parse(IDictionary<string, string> settings)
47+
public static int Parse(IDictionary<string, string> settings, ILogger logger)
4848
{
4949
if (!settings.TryGetValue(RavenPersistenceConfiguration.DataSpaceRemainingThresholdKey, out var thresholdValue))
5050
{
5151
thresholdValue = $"{DataSpaceRemainingThresholdDefault}";
5252
}
5353

54-
string message;
5554
if (!int.TryParse(thresholdValue, out var threshold))
5655
{
57-
message = $"{RavenPersistenceConfiguration.DataSpaceRemainingThresholdKey} must be an integer.";
58-
Logger.Fatal(message);
59-
throw new Exception(message);
56+
logger.LogCritical("{RavenPersistenceConfigurationDataSpaceRemainingThresholdKey} must be an integer.", RavenPersistenceConfiguration.DataSpaceRemainingThresholdKey);
57+
throw new Exception($"{RavenPersistenceConfiguration.DataSpaceRemainingThresholdKey} must be an integer.");
6058
}
6159

6260
if (threshold < 0)
6361
{
64-
message = $"{RavenPersistenceConfiguration.DataSpaceRemainingThresholdKey} is invalid, minimum value is 0.";
65-
Logger.Fatal(message);
66-
throw new Exception(message);
62+
logger.LogCritical("{RavenPersistenceConfigurationDataSpaceRemainingThresholdKey} is invalid, minimum value is 0.", RavenPersistenceConfiguration.DataSpaceRemainingThresholdKey);
63+
throw new Exception($"{RavenPersistenceConfiguration.DataSpaceRemainingThresholdKey} is invalid, minimum value is 0.");
6764
}
6865

6966
if (threshold > 100)
7067
{
71-
message = $"{RavenPersistenceConfiguration.DataSpaceRemainingThresholdKey} is invalid, maximum value is 100.";
72-
Logger.Fatal(message);
73-
throw new Exception(message);
68+
logger.LogCritical("{RavenPersistenceConfigurationDataSpaceRemainingThresholdKey} is invalid, maximum value is 100.", RavenPersistenceConfiguration.DataSpaceRemainingThresholdKey);
69+
throw new Exception($"{RavenPersistenceConfiguration.DataSpaceRemainingThresholdKey} is invalid, maximum value is 100.");
7470
}
7571

7672
return threshold;
7773
}
7874

7975
readonly string dataPathRoot = Path.GetPathRoot(databaseConfiguration.ServerConfiguration.DbPath);
8076
readonly decimal percentageThreshold = databaseConfiguration.DataSpaceRemainingThreshold / 100m;
81-
8277
public const int DataSpaceRemainingThresholdDefault = 20;
83-
static readonly ILog Logger = LogManager.GetLogger(typeof(CheckFreeDiskSpace));
8478
}
8579
}

‎src/ServiceControl.Audit.Persistence.RavenDB/CustomChecks/CheckMinimumStorageRequiredForIngestion.cs‎

Lines changed: 16 additions & 19 deletions
Original file line numberDiff line numberDiff line change
@@ -5,19 +5,20 @@
55
using System.IO;
66
using System.Threading;
77
using System.Threading.Tasks;
8+
using Microsoft.Extensions.Logging;
89
using NServiceBus.CustomChecks;
9-
using NServiceBus.Logging;
1010
using RavenDB;
11+
using ServiceControl.Infrastructure;
1112

12-
class CheckMinimumStorageRequiredForIngestion(MinimumRequiredStorageState stateHolder, DatabaseConfiguration databaseConfiguration) : CustomCheck("Audit Message Ingestion Process", "ServiceControl.Audit Health", TimeSpan.FromSeconds(5))
13+
class CheckMinimumStorageRequiredForIngestion(MinimumRequiredStorageState stateHolder, DatabaseConfiguration databaseConfiguration, ILogger<CheckMinimumStorageRequiredForIngestion> logger) : CustomCheck("Audit Message Ingestion Process", "ServiceControl.Audit Health", TimeSpan.FromSeconds(5))
1314
{
1415
public override Task<CheckResult> PerformCheck(CancellationToken cancellationToken = default)
1516
{
1617
var percentageThreshold = databaseConfiguration.MinimumStorageLeftRequiredForIngestion / 100m;
1718

18-
if (Logger.IsDebugEnabled)
19+
if (logger.IsEnabled(LogLevel.Debug))
1920
{
20-
Logger.Debug($"Check ServiceControl data drive space starting. Threshold {percentageThreshold:P0}");
21+
logger.LogDebug("Check ServiceControl data drive space starting. Threshold {PercentageThreshold:P0}", percentageThreshold);
2122
}
2223

2324
// Should be checking UseEmbeddedServer but need to check DbPath instead for the ATT hack to work
@@ -35,9 +36,9 @@ public override Task<CheckResult> PerformCheck(CancellationToken cancellationTok
3536

3637
var percentRemaining = (decimal)dataDriveInfo.AvailableFreeSpace / dataDriveInfo.TotalSize;
3738

38-
if (Logger.IsDebugEnabled)
39+
if (logger.IsEnabled(LogLevel.Debug))
3940
{
40-
Logger.Debug($"Free space: {availableFreeSpace} | Total: {totalSpace} | Percent remaining {percentRemaining:P0}");
41+
logger.LogDebug("Free space: {AvailableFreeSpace:N0}B | Total: {TotalSpace:N0}B | Percent remaining {PercentRemaining:P0}", availableFreeSpace, totalSpace, percentRemaining);
4142
}
4243

4344
if (percentRemaining > percentageThreshold)
@@ -46,10 +47,9 @@ public override Task<CheckResult> PerformCheck(CancellationToken cancellationTok
4647
return SuccessResult;
4748
}
4849

49-
var message = $"Audit message ingestion stopped! {percentRemaining:P0} disk space remaining on data drive '{dataDriveInfo.VolumeLabel} ({dataDriveInfo.RootDirectory})' on '{Environment.MachineName}'. This is less than {percentageThreshold}% - the minimal required space configured. The threshold can be set using the {RavenPersistenceConfiguration.MinimumStorageLeftRequiredForIngestionKey} configuration setting.";
50-
Logger.Warn(message);
50+
logger.LogWarning("Audit message ingestion stopped! {PercentRemaining:P0} disk space remaining on data drive '{DataDriveInfoVolumeLabel} ({DataDriveInfoRootDirectory})' on '{EnvironmentMachineName}'. This is less than {PercentageThreshold}% - the minimal required space configured. The threshold can be set using the {RavenPersistenceConfigurationMinimumStorageLeftRequiredForIngestionKey} configuration setting.", percentRemaining, dataDriveInfo.VolumeLabel, dataDriveInfo.RootDirectory, Environment.MachineName, percentageThreshold, RavenPersistenceConfiguration.MinimumStorageLeftRequiredForIngestionKey);
5151
stateHolder.CanIngestMore = false;
52-
return CheckResult.Failed(message);
52+
return CheckResult.Failed($"Audit message ingestion stopped! {percentRemaining:P0} disk space remaining on data drive '{dataDriveInfo.VolumeLabel} ({dataDriveInfo.RootDirectory})' on '{Environment.MachineName}'. This is less than {percentageThreshold}% - the minimal required space configured. The threshold can be set using the {RavenPersistenceConfiguration.MinimumStorageLeftRequiredForIngestionKey} configuration setting.");
5353
}
5454

5555
public static int Parse(IDictionary<string, string> settings)
@@ -61,30 +61,27 @@ public static int Parse(IDictionary<string, string> settings)
6161

6262
if (!int.TryParse(thresholdValue, out var threshold))
6363
{
64-
var message = $"{RavenPersistenceConfiguration.MinimumStorageLeftRequiredForIngestionKey} must be an integer.";
65-
Logger.Fatal(message);
66-
throw new Exception(message);
64+
Logger.LogCritical("{RavenPersistenceConfigurationMinimumStorageLeftRequiredForIngestionKey} must be an integer.", RavenPersistenceConfiguration.MinimumStorageLeftRequiredForIngestionKey);
65+
throw new Exception($"{RavenPersistenceConfiguration.MinimumStorageLeftRequiredForIngestionKey} must be an integer.");
6766
}
6867

6968
if (threshold < 0)
7069
{
71-
var message = $"{RavenPersistenceConfiguration.MinimumStorageLeftRequiredForIngestionKey} is invalid, minimum value is 0.";
72-
Logger.Fatal(message);
73-
throw new Exception(message);
70+
Logger.LogCritical("{RavenPersistenceConfigurationMinimumStorageLeftRequiredForIngestionKey} is invalid, minimum value is 0.", RavenPersistenceConfiguration.MinimumStorageLeftRequiredForIngestionKey);
71+
throw new Exception($"{RavenPersistenceConfiguration.MinimumStorageLeftRequiredForIngestionKey} is invalid, minimum value is 0.");
7472
}
7573

7674
if (threshold > 100)
7775
{
78-
var message = $"{RavenPersistenceConfiguration.MinimumStorageLeftRequiredForIngestionKey} is invalid, maximum value is 100.";
79-
Logger.Fatal(message);
80-
throw new Exception(message);
76+
Logger.LogCritical("{RavenPersistenceConfigurationMinimumStorageLeftRequiredForIngestionKey} is invalid, maximum value is 100.", RavenPersistenceConfiguration.MinimumStorageLeftRequiredForIngestionKey);
77+
throw new Exception($"{RavenPersistenceConfiguration.MinimumStorageLeftRequiredForIngestionKey} is invalid, maximum value is 100.");
8178
}
8279

8380
return threshold;
8481
}
8582

8683
public const int MinimumStorageLeftRequiredForIngestionDefault = 5;
8784
static readonly Task<CheckResult> SuccessResult = Task.FromResult(CheckResult.Pass);
88-
static readonly ILog Logger = LogManager.GetLogger(typeof(CheckMinimumStorageRequiredForIngestion));
85+
static readonly ILogger<CheckMinimumStorageRequiredForIngestion> Logger = LoggerUtil.CreateStaticLogger<CheckMinimumStorageRequiredForIngestion>();
8986
}
9087
}

‎src/ServiceControl.Audit.Persistence.RavenDB/CustomChecks/CheckRavenDBIndexLag.cs‎

Lines changed: 11 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -5,12 +5,13 @@
55
using System.Text;
66
using System.Threading;
77
using System.Threading.Tasks;
8+
using Microsoft.Extensions.Logging;
89
using NServiceBus.CustomChecks;
9-
using NServiceBus.Logging;
1010
using Raven.Client.Documents.Operations;
1111
using ServiceControl.Audit.Persistence.RavenDB;
12+
using ServiceControl.Infrastructure;
1213

13-
class CheckRavenDBIndexLag(IRavenDocumentStoreProvider documentStoreProvider) : CustomCheck("Audit Database Index Lag", "ServiceControl.Audit Health", TimeSpan.FromMinutes(5))
14+
class CheckRavenDBIndexLag(IRavenDocumentStoreProvider documentStoreProvider, ILogger<CheckRavenDBIndexLag> logger) : CustomCheck("Audit Database Index Lag", "ServiceControl.Audit Health", TimeSpan.FromMinutes(5))
1415
{
1516
public override async Task<CheckResult> PerformCheck(CancellationToken cancellationToken = default)
1617
{
@@ -20,7 +21,7 @@ public override async Task<CheckResult> PerformCheck(CancellationToken cancellat
2021

2122
CreateDiagnosticsLogEntry(statistics, indexes);
2223

23-
var indexCountWithTooMuchLag = CheckAndReportIndexesWithTooMuchIndexLag(indexes);
24+
var indexCountWithTooMuchLag = CheckAndReportIndexesWithTooMuchIndexLag(indexes, logger);
2425

2526
if (indexCountWithTooMuchLag > 0)
2627
{
@@ -30,7 +31,7 @@ public override async Task<CheckResult> PerformCheck(CancellationToken cancellat
3031
return CheckResult.Pass;
3132
}
3233

33-
static int CheckAndReportIndexesWithTooMuchIndexLag(IndexInformation[] indexes)
34+
static int CheckAndReportIndexesWithTooMuchIndexLag(IndexInformation[] indexes, ILogger logger)
3435
{
3536
int indexCountWithTooMuchLag = 0;
3637

@@ -43,12 +44,12 @@ static int CheckAndReportIndexesWithTooMuchIndexLag(IndexInformation[] indexes)
4344
if (indexLag > IndexLagThresholdError)
4445
{
4546
indexCountWithTooMuchLag++;
46-
Log.Error($"Index [{indexStats.Name}] IndexingLag {indexLag} is above error threshold ({IndexLagThresholdError}). Launch in maintenance mode to let indexes catch up.");
47+
logger.LogError("Index [{IndexStatsName}] IndexingLag {IndexLag} is above error threshold ({IndexLagThresholdError}). Launch in maintenance mode to let indexes catch up.", indexStats.Name, indexLag, IndexLagThresholdError);
4748
}
4849
else if (indexLag > IndexLagThresholdWarning)
4950
{
5051
indexCountWithTooMuchLag++;
51-
Log.Warn($"Index [{indexStats.Name}] IndexingLag {indexLag} is above warning threshold ({IndexLagThresholdWarning}). Launch in maintenance mode to let indexes catch up.");
52+
logger.LogWarning("Index [{IndexStatsName}] IndexingLag {IndexLag} is above warning threshold ({IndexLagThresholdWarning}). Launch in maintenance mode to let indexes catch up.", indexStats.Name, indexLag, IndexLagThresholdWarning);
5253
}
5354
}
5455
}
@@ -58,7 +59,7 @@ static int CheckAndReportIndexesWithTooMuchIndexLag(IndexInformation[] indexes)
5859

5960
static void CreateDiagnosticsLogEntry(DatabaseStatistics statistics, IndexInformation[] indexes)
6061
{
61-
if (!Log.IsDebugEnabled)
62+
if (!Logger.IsEnabled(LogLevel.Debug))
6263
{
6364
return;
6465
}
@@ -72,11 +73,12 @@ static void CreateDiagnosticsLogEntry(DatabaseStatistics statistics, IndexInform
7273
{
7374
report.AppendLine($"- Index [{indexStats.Name,-44}] State: {indexStats.State}, Stale: {indexStats.IsStale,-5}, Priority: {indexStats.Priority,-6}, LastIndexingTime: {indexStats.LastIndexingTime:u}");
7475
}
75-
Log.Debug(report.ToString());
76+
77+
Logger.LogDebug(report.ToString());
7678
}
7779

7880
static readonly TimeSpan IndexLagThresholdWarning = TimeSpan.FromMinutes(1);
7981
static readonly TimeSpan IndexLagThresholdError = TimeSpan.FromMinutes(10);
80-
static readonly ILog Log = LogManager.GetLogger<CheckRavenDBIndexLag>();
82+
static readonly ILogger<CheckRavenDBIndexLag> Logger = LoggerUtil.CreateStaticLogger<CheckRavenDBIndexLag>();
8183
}
8284
}

0 commit comments

Comments
 (0)