Skip to content

Commit

Permalink
fix: Console logging is inconsistent between Agent and Profiler (#2955)
Browse files Browse the repository at this point in the history
  • Loading branch information
@tippmar-nr
tippmar-nr authored Jan 17, 2025
1 parent ee0dd2b commit 7c42b33
Show file tree
Hide file tree
Showing 9 changed files with 61 additions and 52 deletions.
86 changes: 45 additions & 41 deletions src/Agent/NewRelic/Agent/Core/Logging/LoggerBootstrapper.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -20,10 +20,6 @@ namespace NewRelic.Agent.Core
public static class LoggerBootstrapper
{

// Watch out! If you change the time format that the agent puts into its log files, other log parsers may fail.
//private static ILayout AuditLogLayout = new PatternLayout("%utcdate{yyyy-MM-dd HH:mm:ss,fff} NewRelic %level: %message\r\n");
//private static ILayout FileLogLayout = new PatternLayout("%utcdate{yyyy-MM-dd HH:mm:ss,fff} NewRelic %6level: [pid: %property{pid}, tid: %property{threadid}] %message\r\n");

private const string AuditLogLayout = "{UTCTimestamp} NewRelic Audit: {Message:l}\n";

private const string FileLogLayout = "{UTCTimestamp} NewRelic {NRLogLevel,6}: [pid: {pid}, tid: {tid}] {Message:l}\n{Exception:l}";
Expand All @@ -34,8 +30,16 @@ public static class LoggerBootstrapper

public static void SetLoggingLevel(string newLogLevel) => _loggingLevelSwitch.MinimumLevel = newLogLevel.MapToSerilogLogLevel();

private static bool _isWindows;

public static void Initialize()
{
#if NETSTANDARD2_0
_isWindows = RuntimeInformation.IsOSPlatform(OSPlatform.Windows);
#else
_isWindows = true;
#endif

var startupLoggerConfig = new LoggerConfiguration()
.Enrich.With(new ThreadIdEnricher(), new ProcessIdEnricher(), new NrLogLevelEnricher(), new UTCTimestampEnricher())
.MinimumLevel.Information()
Expand All @@ -52,22 +56,26 @@ public static void Initialize()
/// <remarks>This should only be called once, as soon as you have a valid config.</remarks>
public static void ConfigureLogger(ILogConfig config)
{
// if logging is disabled, we don't log anywhere
if (!config.Enabled)
{
SetLoggingLevel("off"); // to short-circuit logging calls
Log.Logger = Serilog.Core.Logger.None; // a logger that does nothing
return;
}

SetLoggingLevel(config.LogLevel);

AuditLog.IsAuditLogEnabled = config.IsAuditLogEnabled;
AuditLog.IsAuditLogEnabled = config.IsAuditLogEnabled && !config.Console;

var loggerConfig = new LoggerConfiguration()
.MinimumLevel.ControlledBy(_loggingLevelSwitch)
.Enrich.With(new ThreadIdEnricher(), new ProcessIdEnricher(), new NrLogLevelEnricher(), new UTCTimestampEnricher())
.ConfigureConsoleSink(config)
.ConfigureAuditLogSink(config)
.ConfigureFileSink(config)
.ConfigureDebugSink();

if (config.Console)
{
loggerConfig = loggerConfig.ConfigureConsoleSink();
}

// configure the global singleton logger instance (which remains specific to the Agent by way of ILRepack)
var configuredLogger = loggerConfig.CreateLogger();

Expand All @@ -90,6 +98,9 @@ private static void EchoInMemoryLogsToConfiguredLogger(ILogger configuredLogger)
_inMemorySink.Dispose();
}

/// <summary>
/// Configures the in-memory log sink used during bootstrapping.
/// </summary>
private static LoggerConfiguration ConfigureInMemoryLogSink(this LoggerConfiguration loggerConfiguration)
{
// formatter not needed since this will be pushed to other sinks for output.
Expand All @@ -116,12 +127,7 @@ private static LoggerConfiguration ConfigureInMemoryLogSink(this LoggerConfigura
/// <param name="loggerConfiguration"></param>
private static LoggerConfiguration ConfigureEventLogSink(this LoggerConfiguration loggerConfiguration)
{
#if NETSTANDARD2_0
var isWindows = RuntimeInformation.IsOSPlatform(OSPlatform.Windows);
#else
var isWindows = true;
#endif
if (isWindows)
if (_isWindows)
{
const string eventLogName = "Application";
const string eventLogSourceName = "New Relic .NET Agent";
Expand Down Expand Up @@ -169,8 +175,10 @@ private static LoggerConfiguration ConfigureDebugSink(this LoggerConfiguration l
/// <summary>
/// Configure the console sink
/// </summary>
private static LoggerConfiguration ConfigureConsoleSink(this LoggerConfiguration loggerConfiguration)
private static LoggerConfiguration ConfigureConsoleSink(this LoggerConfiguration loggerConfiguration, ILogConfig config)
{
if (!config.Console) return loggerConfiguration;

return loggerConfiguration
.WriteTo.Async(a =>
a.Logger(configuration =>
Expand All @@ -185,14 +193,11 @@ private static LoggerConfiguration ConfigureConsoleSink(this LoggerConfiguration
/// <summary>
/// Configure the file log sink
/// </summary>
/// <param name="loggerConfiguration"></param>
/// <param name="config">The configuration for the appender.</param>
private static LoggerConfiguration ConfigureFileSink(this LoggerConfiguration loggerConfiguration, ILogConfig config)
{
if (!config.Enabled)
{
return loggerConfiguration;
}
// console logging disables all file logging output.
if (config.Console) return loggerConfiguration;

string logFileName = config.GetFullLogFileName();

try
Expand All @@ -201,32 +206,36 @@ private static LoggerConfiguration ConfigureFileSink(this LoggerConfiguration lo
.WriteTo
.Async(a =>
a.Logger(configuration =>
{
configuration
.ExcludeAuditLog()
.ConfigureRollingLogSink(logFileName, FileLogLayout, config);
})
);
{
configuration
.ExcludeAuditLog()
.ConfigureRollingLogSink(logFileName, FileLogLayout, config);
})
);
}
catch (Exception ex)
{
Log.Logger.Warning(ex, "Unexpected exception when configuring file sink.");

// Fallback to the event log sink if we cannot setup a file logger.
Extensions.Logging.Log.FileLoggingHasFailed = true;
Log.Logger.Warning("Falling back to EventLog sink.");
loggerConfiguration.ConfigureEventLogSink();
if (_isWindows)
{
// Fallback to the event log sink if we cannot setup a file logger.
Extensions.Logging.Log.FileLoggingHasFailed = true;
Log.Logger.Warning("Falling back to EventLog sink.");
loggerConfiguration.ConfigureEventLogSink();
}
}

return loggerConfiguration;
}

/// <summary>
/// Setup the audit log file appender and attach it to a logger.
/// Configure the audit log sink
/// </summary>
private static LoggerConfiguration ConfigureAuditLogSink(this LoggerConfiguration loggerConfiguration, ILogConfig config)
{
if (!config.IsAuditLogEnabled || !config.Enabled) return loggerConfiguration;
// console logging disables all file logging output, including audit logs
if (!config.IsAuditLogEnabled || config.Console) return loggerConfiguration;

string logFileName = config.GetFullLogFileName().Replace(".log", "_audit.log");

Expand All @@ -242,13 +251,8 @@ private static LoggerConfiguration ConfigureAuditLogSink(this LoggerConfiguratio
}

/// <summary>
/// Sets up a rolling file appender using defaults shared for all our rolling file appenders.
/// Configure the rolling log sink
/// </summary>
/// <param name="loggerConfiguration"></param>
/// <param name="fileName">The name of the file this appender will write to.</param>
/// <param name="outputFormat"></param>
/// <param name="config"></param>
/// <remarks>This does not call appender.ActivateOptions or add the appender to the logger.</remarks>
private static LoggerConfiguration ConfigureRollingLogSink(this LoggerConfiguration loggerConfiguration, string fileName, string outputFormat, ILogConfig config)
{
// check that the log file is accessible
Expand Down
2 changes: 0 additions & 2 deletions tests/Agent/IntegrationTests/ContainerIntegrationTests/Tests/AwsSdk/AwsSdkDynamoDBTest.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -35,8 +35,6 @@ public AwsSdkDynamoDBTest(AwsSdkContainerDynamoDBTestFixture fixture, ITestOutpu
configModifier.ConfigureFasterMetricsHarvestCycle(15);
configModifier.ConfigureFasterSpanEventsHarvestCycle(15);
configModifier.ConfigureFasterTransactionTracesHarvestCycle(15);
configModifier.LogToConsole();

},
exerciseApplication: () =>
{
Expand Down
2 changes: 0 additions & 2 deletions ...s/Agent/IntegrationTests/ContainerIntegrationTests/Tests/AwsSdk/AwsSdkMultiServiceTest.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -36,8 +36,6 @@ public AwsSdkMultiServiceTest(AwsSdkContainerMultiServiceTestFixture fixture, IT
configModifier.ConfigureFasterMetricsHarvestCycle(15);
configModifier.ConfigureFasterSpanEventsHarvestCycle(15);
configModifier.ConfigureFasterTransactionTracesHarvestCycle(15);
configModifier.LogToConsole();

},
exerciseApplication: () =>
{
Expand Down
2 changes: 0 additions & 2 deletions tests/Agent/IntegrationTests/ContainerIntegrationTests/Tests/AwsSdk/AwsSdkSQSTest.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -41,8 +41,6 @@ protected AwsSdkSQSTestBase(AwsSdkContainerSQSTestFixture fixture, ITestOutputHe
configModifier.ConfigureFasterMetricsHarvestCycle(15);
configModifier.ConfigureFasterSpanEventsHarvestCycle(15);
configModifier.ConfigureFasterTransactionTracesHarvestCycle(15);
configModifier.LogToConsole();

},
exerciseApplication: () =>
{
Expand Down
1 change: 0 additions & 1 deletion ...s/Agent/IntegrationTests/ContainerIntegrationTests/Tests/InfiniteTracingContainerTests.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -33,7 +33,6 @@ protected InfiniteTracingContainerTest(T fixture, ITestOutputHelper output) : ba
configModifier.ConfigureFasterMetricsHarvestCycle(10);
configModifier.ConfigureFasterTransactionTracesHarvestCycle(10);
configModifier.SetLogLevel("Finest");
configModifier.LogToConsole();
},
exerciseApplication: () =>
{
Expand Down
1 change: 0 additions & 1 deletion tests/Agent/IntegrationTests/ContainerIntegrationTests/Tests/KafkaTests.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -34,7 +34,6 @@ protected LinuxKafkaTest(T fixture, ITestOutputHelper output) : base(fixture)
var configModifier = new NewRelicConfigModifier(_fixture.DestinationNewRelicConfigFilePath);
configModifier.SetLogLevel("debug");
configModifier.ConfigureFasterMetricsHarvestCycle(10);
configModifier.LogToConsole();

_fixture.RemoteApplication.SetAdditionalEnvironmentVariable("NEW_RELIC_KAFKA_TOPIC", _topicName);
},
Expand Down
1 change: 0 additions & 1 deletion tests/Agent/IntegrationTests/ContainerIntegrationTests/Tests/LinuxContainerTests.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,6 @@ protected LinuxContainerTest(T fixture, ITestOutputHelper output) : base(fixture
{
var configModifier = new NewRelicConfigModifier(_fixture.DestinationNewRelicConfigFilePath);
configModifier.ConfigureFasterMetricsHarvestCycle(10);
configModifier.LogToConsole();
},
exerciseApplication: () =>
{
Expand Down
1 change: 0 additions & 1 deletion tests/Agent/IntegrationTests/ContainerIntegrationTests/Tests/MemcachedTests.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -26,7 +26,6 @@ protected LinuxMemcachedTest(T fixture, ITestOutputHelper output) : base(fixture
var configModifier = new NewRelicConfigModifier(_fixture.DestinationNewRelicConfigFilePath);
configModifier.SetLogLevel("debug");
configModifier.ConfigureFasterMetricsHarvestCycle(10);
configModifier.LogToConsole();
},
exerciseApplication: () =>
{
Expand Down
17 changes: 16 additions & 1 deletion tests/Agent/UnitTests/Core.UnitTest/NewRelic.Agent.Core.FromLegacy/LoggerBootstrapperTest.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -29,6 +29,21 @@ public static void No_log_levels_are_enabled_when_config_log_is_off()
);
}

[Test]
public void NoLogLevelsAreEnabled_WhenLogIsDisabled()
{
ILogConfig config = LogConfigFixtureWithLogEnabled(false);
LoggerBootstrapper.Initialize();
LoggerBootstrapper.ConfigureLogger(config);
NrAssert.Multiple(
() => Assert.That(Log.IsFinestEnabled, Is.False),
() => Assert.That(Log.IsDebugEnabled, Is.False),
() => Assert.That(Log.IsInfoEnabled, Is.False),
() => Assert.That(Log.IsWarnEnabled, Is.False),
() => Assert.That(Log.IsErrorEnabled, Is.False)
);
}

[Test]
public static void All_log_levels_are_enabled_when_config_log_is_all()
{
Expand Down Expand Up @@ -210,7 +225,7 @@ private static ILogConfig LogConfigFixtureWithLogEnabled(bool enabled)
" <application>" +
" <name>Test</name>" +
" </application>" +
" <log level=\"debug\" console=\"true\" enabled=\"{0}\" />" +
" <log level=\"all\" console=\"false\" enabled=\"{0}\" />" +
"</configuration>",
enabled.ToString().ToLower());

Expand Down

0 comments on commit 7c42b33

Please sign in to comment.