Skip to content

Commit 15b7a58

Browse files
teta2kteta2k
authored
Log transient API failures as warnings instead of errors (#333)
* Log transient API failures as warnings * Cover warning log paths
1 parent 10cddee commit 15b7a58

6 files changed

Lines changed: 121 additions & 8 deletions

File tree

‎Aikido.Zen.Core/Agent.cs‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -140,7 +140,7 @@ public void Start()
140140
}
141141
else
142142
{
143-
LogHelper.ErrorLog(Logger, $"Heartbeat was not sent successfully: {response.Error}");
143+
LogHelper.WarningLog(Logger, $"Heartbeat was not sent successfully: {response.Error}");
144144
}
145145
}
146146
};

‎Aikido.Zen.Core/Api/Reporting.cs‎

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -29,12 +29,12 @@ public async Task<ReportingAPIResponse> ReportAsync(string token, object @event)
2929
}
3030
catch (TaskCanceledException ex)
3131
{
32-
LogHelper.ErrorLog(Agent.Logger, $"Error reporting event (possible timeout): {ex.Message}");
32+
LogHelper.WarningLog(Agent.Logger, $"Failed to report event (possible timeout): {ex.Message}");
3333
return new ReportingAPIResponse { Success = false, Error = "timeout" };
3434
}
3535
catch (Exception ex)
3636
{
37-
LogHelper.ErrorLog(Agent.Logger, $"Error reporting event: {ex.Message}");
37+
LogHelper.WarningLog(Agent.Logger, $"Failed to report event: {ex.Message}");
3838
return new ReportingAPIResponse { Success = false, Error = "unknown_error" };
3939
}
4040
}
@@ -54,7 +54,7 @@ public async Task<FirewallListsAPIResponse> GetFirewallLists(string token)
5454
}
5555
catch (Exception ex)
5656
{
57-
LogHelper.ErrorLog(Agent.Logger, $"Error retrieving Firewall Lists: {ex.Message}");
57+
LogHelper.WarningLog(Agent.Logger, $"Failed to retrieve Firewall Lists: {ex.Message}");
5858
return new FirewallListsAPIResponse { Success = false, Error = "unknown_error" };
5959
}
6060
}

‎Aikido.Zen.Core/Api/Runtime.cs‎

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -25,12 +25,12 @@ public async Task<ConfigLastUpdatedAPIResponse> GetConfigLastUpdated(string toke
2525
}
2626
catch (TaskCanceledException ex)
2727
{
28-
LogHelper.ErrorLog(Agent.Logger, $"Error retrieving config last updated (possible timeout): {ex.Message}");
28+
LogHelper.WarningLog(Agent.Logger, $"Failed to retrieve config last updated (possible timeout): {ex.Message}");
2929
return new ConfigLastUpdatedAPIResponse { Success = false, Error = "timeout" };
3030
}
3131
catch (Exception ex)
3232
{
33-
LogHelper.ErrorLog(Agent.Logger, $"Error retrieving config last updated: {ex.Message}");
33+
LogHelper.WarningLog(Agent.Logger, $"Failed to retrieve config last updated: {ex.Message}");
3434
return new ConfigLastUpdatedAPIResponse { Success = false, Error = "unknown_error" };
3535
}
3636
}
@@ -45,12 +45,12 @@ public async Task<ReportingAPIResponse> GetConfig(string token)
4545
}
4646
catch (TaskCanceledException ex)
4747
{
48-
LogHelper.ErrorLog(Agent.Logger, $"Error retrieving config (possible timeout): {ex.Message}");
48+
LogHelper.WarningLog(Agent.Logger, $"Failed to retrieve config (possible timeout): {ex.Message}");
4949
return new ReportingAPIResponse { Success = false, Error = "timeout" };
5050
}
5151
catch (Exception ex)
5252
{
53-
LogHelper.ErrorLog(Agent.Logger, $"Error retrieving config: {ex.Message}");
53+
LogHelper.WarningLog(Agent.Logger, $"Failed to retrieve config: {ex.Message}");
5454
return new ReportingAPIResponse { Success = false, Error = "unknown_error" };
5555
}
5656
}

‎Aikido.Zen.Core/Helpers/LogHelper.cs‎

Lines changed: 30 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -84,6 +84,36 @@ public static void ErrorLog(ILogger logger, Exception exception, string message)
8484
}
8585
}
8686

87+
/// <summary>
88+
/// Logs a warning message, after sanitizing the message.
89+
/// </summary>
90+
/// <param name="logger">The logger instance to use.</param>
91+
/// <param name="message">The message to log.</param>
92+
public static void WarningLog(ILogger logger, string message) => WarningLog(logger, null, message);
93+
94+
/// <summary>
95+
/// Logs a warning message, after sanitizing the message.
96+
/// </summary>
97+
/// <param name="logger">The logger instance to use.</param>
98+
/// <param name="exception">The exception associated with the warning, if any.</param>
99+
/// <param name="message">The message to log.</param>
100+
public static void WarningLog(ILogger logger, Exception exception, string message)
101+
{
102+
// Sanitize the message to prevent log injection
103+
string sanitizedMessage = SanitizeMessage(message);
104+
105+
if (exception == null)
106+
{
107+
// we log the message to the outputs defined by the application
108+
logger.LogWarning(sanitizedMessage);
109+
}
110+
else
111+
{
112+
// we log the message to the outputs defined by the application
113+
logger.LogWarning(exception, sanitizedMessage);
114+
}
115+
}
116+
87117
/// <summary>
88118
/// Logs an information message, after sanitizing the message and applying rate limiting.
89119
/// </summary>

‎Aikido.Zen.Test/AgentTests.cs‎

Lines changed: 36 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,9 @@
33
using Aikido.Zen.Core.Models;
44
using Aikido.Zen.Core.Models.Events;
55
using Aikido.Zen.Tests.Mocks;
6+
using Microsoft.Extensions.Logging;
67
using Moq;
8+
using System.Collections.Concurrent;
79
using System.Reflection;
810

911
namespace Aikido.Zen.Test
@@ -262,6 +264,40 @@ public async Task Start_QueuesStartedEventAndSchedulesHeartbeat()
262264
);
263265
}
264266

267+
[Test]
268+
public void Start_HeartbeatFailureCallback_LogsWarning()
269+
{
270+
var loggerMock = new Mock<ILogger>();
271+
Agent.ConfigureLogger(loggerMock.Object);
272+
273+
try
274+
{
275+
_agent.Start();
276+
277+
var scheduledEventsField = typeof(Agent).GetField("_scheduledEvents", BindingFlags.NonPublic | BindingFlags.Instance);
278+
Assert.That(scheduledEventsField, Is.Not.Null);
279+
280+
var scheduledEvents = scheduledEventsField!.GetValue(_agent) as ConcurrentDictionary<string, Agent.ScheduledItem>;
281+
Assert.That(scheduledEvents, Is.Not.Null);
282+
Assert.That(scheduledEvents!.TryGetValue(Heartbeat.ScheduleId, out var scheduledItem), Is.True);
283+
var callback = scheduledItem!.Callback;
284+
Assert.That(callback, Is.Not.Null);
285+
286+
callback!(new Heartbeat(), new ReportingAPIResponse { Success = false, Error = "timeout" });
287+
288+
loggerMock.Verify(logger => logger.Log(
289+
It.Is<LogLevel>(level => level == LogLevel.Warning),
290+
It.IsAny<EventId>(),
291+
It.Is<It.IsAnyType>((v, t) => v.ToString()!.Contains("Heartbeat was not sent successfully: timeout")),
292+
It.IsAny<Exception?>(),
293+
It.IsAny<Func<It.IsAnyType, Exception?, string>>()), Times.Once);
294+
}
295+
finally
296+
{
297+
Agent.ConfigureLogger(null);
298+
}
299+
}
300+
265301
[Test]
266302
public void QueueEvent_WithNullToken_ThrowsArgumentNullException()
267303
{

‎Aikido.Zen.Test/Helpers/LogHelperTests.cs‎

Lines changed: 47 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -102,6 +102,53 @@ public void AttackLog_ShouldLogMessageAsInformation()
102102
It.IsAny<Func<It.IsAnyType, Exception?, string>>()), Times.Once);
103103
}
104104

105+
[Test]
106+
public void WarningLog_ShouldLogMessageAsWarning()
107+
{
108+
var message = "Test warning message";
109+
110+
LogHelper.WarningLog(_loggerMock.Object, message);
111+
112+
_loggerMock.Verify(logger => logger.Log(
113+
It.Is<LogLevel>(level => level == LogLevel.Warning),
114+
It.IsAny<EventId>(),
115+
It.Is<It.IsAnyType>((v, t) => v.ToString().EndsWith(message)),
116+
It.IsAny<Exception?>(),
117+
It.IsAny<Func<It.IsAnyType, Exception?, string>>()), Times.Once);
118+
}
119+
120+
[Test]
121+
public void WarningLog_ShouldSanitizeMessage_WhenMessageContainsDangerousCharacters()
122+
{
123+
var message = "Warning\nmessage\rwith\tdetails";
124+
var expectedSanitizedContent = "Warningmessagewithdetails";
125+
126+
LogHelper.WarningLog(_loggerMock.Object, message);
127+
128+
_loggerMock.Verify(logger => logger.Log(
129+
It.Is<LogLevel>(level => level == LogLevel.Warning),
130+
It.IsAny<EventId>(),
131+
It.Is<It.IsAnyType>((v, t) => v.ToString().Contains(expectedSanitizedContent)),
132+
It.IsAny<Exception?>(),
133+
It.IsAny<Func<It.IsAnyType, Exception?, string>>()), Times.Once);
134+
}
135+
136+
[Test]
137+
public void WarningLog_WithException_ShouldLogExceptionAsWarning()
138+
{
139+
var message = "Test warning with exception";
140+
var exception = new InvalidOperationException("test exception");
141+
142+
LogHelper.WarningLog(_loggerMock.Object, exception, message);
143+
144+
_loggerMock.Verify(logger => logger.Log(
145+
It.Is<LogLevel>(level => level == LogLevel.Warning),
146+
It.IsAny<EventId>(),
147+
It.Is<It.IsAnyType>((v, t) => v.ToString()!.EndsWith(message)),
148+
exception,
149+
It.IsAny<Func<It.IsAnyType, Exception?, string>>()), Times.Once);
150+
}
151+
105152
[Test]
106153
public void AttackLog_ShouldSanitizeMessage_WhenMessageContainsDangerousCharacters()
107154
{

0 commit comments

Comments
 (0)