From f71521f2540311e97d13646ff6d6524dfcc3965f Mon Sep 17 00:00:00 2001 From: Marty Tippin <120425148+tippmar-nr@users.noreply.github.com> Date: Fri, 23 Jun 2023 13:12:35 -0500 Subject: [PATCH] fix: Format and log audit-level messages only when audit logging is enabled. (#1734) --- .../Core/DataTransport/HttpCollectorWire.cs | 10 ++- .../NewRelic/Agent/Core/Logging/AuditLog.cs | 30 ++++++-- .../DataTransport/HttpCollectorWireTests.cs | 39 +++++++++++ .../Core.UnitTest/Logging/AuditLogTests.cs | 70 +++++++++++++++++++ 4 files changed, 139 insertions(+), 10 deletions(-) create mode 100644 tests/Agent/UnitTests/Core.UnitTest/Logging/AuditLogTests.cs diff --git a/src/Agent/NewRelic/Agent/Core/DataTransport/HttpCollectorWire.cs b/src/Agent/NewRelic/Agent/Core/DataTransport/HttpCollectorWire.cs index 93f9ac210..e83401b2f 100644 --- a/src/Agent/NewRelic/Agent/Core/DataTransport/HttpCollectorWire.cs +++ b/src/Agent/NewRelic/Agent/Core/DataTransport/HttpCollectorWire.cs @@ -156,10 +156,14 @@ public string SendData(string method, ConnectionInfo connectionInfo, string seri } } - private static void AuditLog(Direction direction, Source source, string uri) + private void AuditLog(Direction direction, Source source, string uri) { - var message = string.Format(AuditLogFormat, direction, source, Strings.ObfuscateLicenseKeyInAuditLog(uri, LicenseKeyParameterName)); - Logging.AuditLog.Log(message); + if (Logging.AuditLog.IsAuditLogEnabled) + { + var message = string.Format(AuditLogFormat, direction, source, + Strings.ObfuscateLicenseKeyInAuditLog(uri, LicenseKeyParameterName)); + Logging.AuditLog.Log(message); + } } private Uri GetUri(string method, ConnectionInfo connectionInfo) diff --git a/src/Agent/NewRelic/Agent/Core/Logging/AuditLog.cs b/src/Agent/NewRelic/Agent/Core/Logging/AuditLog.cs index fae125001..67319423b 100644 --- a/src/Agent/NewRelic/Agent/Core/Logging/AuditLog.cs +++ b/src/Agent/NewRelic/Agent/Core/Logging/AuditLog.cs @@ -10,27 +10,43 @@ namespace NewRelic.Agent.Core.Logging public static class AuditLog { // a lazy ILogger instance that injects an "Audit" property - private static Lazy _lazyAuditLogger = new Lazy(() => - Serilog.Log.Logger.ForContext(LogLevelExtensions.AuditLevel, LogLevelExtensions.AuditLevel)); + private static Lazy _lazyAuditLogger = LazyAuditLogger(); + + public static bool IsAuditLogEnabled { get; set; } //setter is public only for unit tests, not expected to be use anywhere else + + // for unit tests only + public static void ResetLazyLogger() + { + _lazyAuditLogger = LazyAuditLogger(); + } + + private static Lazy LazyAuditLogger() + { + return new Lazy(() => + Serilog.Log.Logger.ForContext(LogLevelExtensions.AuditLevel, LogLevelExtensions.AuditLevel)); + } /// /// Logs at the AUDIT level. This log level should be used only as dictated by the security team to satisfy auditing requirements. /// public static void Log(string message) { + if (IsAuditLogEnabled) // use Fatal log level to ensure audit log messages never get filtered due to level restrictions _lazyAuditLogger.Value.Fatal(message); } - internal static LoggerConfiguration IncludeOnlyAuditLog(this LoggerConfiguration loggerConfiguration) + public static LoggerConfiguration IncludeOnlyAuditLog(this LoggerConfiguration loggerConfiguration) { - return loggerConfiguration.Filter.ByIncludingOnly($"{LogLevelExtensions.AuditLevel} is not null"); + IsAuditLogEnabled = true; // set a flag so Log() can short-circuit when audit log is not enabled - //return loggerConfiguration.Filter.ByIncludingOnly(logEvent => - // logEvent.Properties.ContainsKey(LogLevelExtensions.AuditLevel)); + return loggerConfiguration.Filter.ByIncludingOnly($"{LogLevelExtensions.AuditLevel} is not null"); } - internal static LoggerConfiguration ExcludeAuditLog(this LoggerConfiguration loggerConfiguration) + + public static LoggerConfiguration ExcludeAuditLog(this LoggerConfiguration loggerConfiguration) { + IsAuditLogEnabled = false; // set a flag so Log() can short-circuit when audit log is not enabled + return loggerConfiguration.Filter.ByIncludingOnly($"{LogLevelExtensions.AuditLevel} is null"); } } diff --git a/tests/Agent/UnitTests/Core.UnitTest/DataTransport/HttpCollectorWireTests.cs b/tests/Agent/UnitTests/Core.UnitTest/DataTransport/HttpCollectorWireTests.cs index 434878d1d..396c8d559 100644 --- a/tests/Agent/UnitTests/Core.UnitTest/DataTransport/HttpCollectorWireTests.cs +++ b/tests/Agent/UnitTests/Core.UnitTest/DataTransport/HttpCollectorWireTests.cs @@ -15,6 +15,8 @@ using System.Threading.Tasks; using System.Threading; using NewRelic.Agent.Core.Exceptions; +using NewRelic.Agent.Core.Logging; +using Serilog; using Telerik.JustMock; namespace NewRelic.Agent.Core.DataTransport @@ -26,6 +28,7 @@ public class HttpCollectorWireTests private IAgentHealthReporter _agentHealthReporter; private IHttpClientFactory _httpClientFactory; private MockHttpMessageHandler _mockHttpMessageHandler; + private ILogger _mockILogger; [SetUp] public void SetUp() @@ -33,6 +36,9 @@ public void SetUp() _configuration = Mock.Create(); _agentHealthReporter = Mock.Create(); _httpClientFactory = Mock.Create(); + + _mockILogger = Mock.Create(); + Log.Logger = _mockILogger; } private HttpCollectorWire CreateHttpCollectorWire(Dictionary requestHeadersMap = null) @@ -306,6 +312,39 @@ public void SendData_ShouldDropPayload_WhenPayloadSizeExceedsMaxSize() Mock.Assert(() => _httpClientFactory.CreateClient(Arg.IsAny()), Occurs.Never()); Assert.AreEqual(false, _mockHttpMessageHandler.SendAsyncInvoked); } + + [TestCase(false)] + [TestCase(true)] + public void SendData_ShouldNotCallAuditLog_UnlessAuditLogIsEnabled(bool isEnabled) + { + // Arrange + AuditLog.ResetLazyLogger(); + Mock.Arrange(() => _configuration.AgentLicenseKey).Returns("license_key"); + Mock.Arrange(() => _configuration.CollectorMaxPayloadSizeInBytes).Returns(1024); + + var connectionInfo = new ConnectionInfo(_configuration); + var serializedData = "{ \"key\": \"value\" }"; + var httpResponse = new HttpResponseMessage(HttpStatusCode.OK) + { + Content = new StringContent("{}") + }; + + CreateMockHttpClient(httpResponse, false); + + var collectorWire = CreateHttpCollectorWire(); + + var mockForContextLogger = Mock.Create(); + Mock.Arrange(() => _mockILogger.ForContext(Arg.AnyString, Arg.AnyObject, false)) + .Returns(() => mockForContextLogger); + + AuditLog.IsAuditLogEnabled = isEnabled; + + // Act + var _ = collectorWire.SendData("test_method", connectionInfo, serializedData, Guid.NewGuid()); + + // Assert + Mock.Assert(() => mockForContextLogger.Fatal(Arg.AnyString), isEnabled ? Occurs.Exactly(3) : Occurs.Never()); + } } public class MockHttpMessageHandler : HttpMessageHandler diff --git a/tests/Agent/UnitTests/Core.UnitTest/Logging/AuditLogTests.cs b/tests/Agent/UnitTests/Core.UnitTest/Logging/AuditLogTests.cs new file mode 100644 index 000000000..1a72e8345 --- /dev/null +++ b/tests/Agent/UnitTests/Core.UnitTest/Logging/AuditLogTests.cs @@ -0,0 +1,70 @@ +// Copyright 2020 New Relic, Inc. All rights reserved. +// SPDX-License-Identifier: Apache-2.0 + +using NUnit.Framework; +using Serilog; +using Serilog.Configuration; +using Telerik.JustMock; + +namespace NewRelic.Agent.Core.Logging.Tests +{ + [TestFixture] + public class AuditLogTests + { + private ILogger _mockILogger; + + [SetUp] + public void SetUp() + { + _mockILogger = Mock.Create(); + Log.Logger = _mockILogger; + + // reset state for each test + AuditLog.ResetLazyLogger(); + AuditLog.IsAuditLogEnabled = false; + } + + [TearDown] + public void TearDown() + { + AuditLog.ResetLazyLogger(); + } + + [Test] + public void IncludeOnlyAuditLog_EnablesAuditLog() + { + Assert.False(AuditLog.IsAuditLogEnabled); + + var _ = new LoggerConfiguration().IncludeOnlyAuditLog(); + + Assert.True(AuditLog.IsAuditLogEnabled); + } + + [Test] + public void ExcludeAuditLog_DisablesAuditLog() + { + AuditLog.IsAuditLogEnabled = true; + + var _ = new LoggerConfiguration().ExcludeAuditLog(); + + Assert.False(AuditLog.IsAuditLogEnabled); + } + + [TestCase(true)] + [TestCase(false)] + public void Log_OnlyLogsWhenAuditLogEnabled(bool logEnabled) + { + var mockForContextLogger = Mock.Create(); + Mock.Arrange(() => _mockILogger.ForContext(Arg.AnyString, Arg.AnyObject, false)) + .Returns(() => mockForContextLogger); + + AuditLog.IsAuditLogEnabled = logEnabled; + + var message = "This is an audit message"; + + AuditLog.Log(message); + + Mock.Assert(() => mockForContextLogger.Fatal(message), logEnabled ? Occurs.Once() : Occurs.Never()); + } + } +}