From febaf6e057aa8e14d8fdea5edb9590175458e00b Mon Sep 17 00:00:00 2001 From: Stas Date: Tue, 12 Apr 2022 11:24:48 -0700 Subject: [PATCH] make logger immutable (#1783) Co-authored-by: stas --- src/ApiService/ApiService/Log.cs | 135 ++++++++++++------ .../ApiService/QueueProxyHeartbeat.cs | 5 +- .../ApiService/onefuzzlib/Events.cs | 4 +- .../onefuzzlib/WebhookOperations.cs | 9 +- 4 files changed, 101 insertions(+), 52 deletions(-) diff --git a/src/ApiService/ApiService/Log.cs b/src/ApiService/ApiService/Log.cs index 2f1d54ba40..acd26f3540 100644 --- a/src/ApiService/ApiService/Log.cs +++ b/src/ApiService/ApiService/Log.cs @@ -10,9 +10,9 @@ namespace Microsoft.OneFuzz.Service; public interface ILog { - void Log(Guid correlationId, String message, SeverityLevel level, IDictionary tags, string? caller); - void LogEvent(Guid correlationId, String evt, IDictionary tags, IDictionary? metrics, string? caller); - void LogException(Guid correlationId, Exception ex, IDictionary tags, IDictionary? metrics, string? caller); + void Log(Guid correlationId, String message, SeverityLevel level, IReadOnlyDictionary tags, string? caller); + void LogEvent(Guid correlationId, String evt, IReadOnlyDictionary tags, IReadOnlyDictionary? metrics, string? caller); + void LogException(Guid correlationId, Exception ex, IReadOnlyDictionary tags, IReadOnlyDictionary? metrics, string? caller); void Flush(); } @@ -22,24 +22,39 @@ class AppInsights : ILog new TelemetryClient( new TelemetryConfiguration(EnvironmentVariables.AppInsights.InstrumentationKey)); - public void Log(Guid correlationId, String message, SeverityLevel level, IDictionary tags, string? caller) + public void Log(Guid correlationId, String message, SeverityLevel level, IReadOnlyDictionary tags, string? caller) { - tags["Correlation ID"] = correlationId.ToString(); - if (caller is not null) tags["CalledBy"] = caller; - telemetryClient.TrackTrace(message, level, tags); + Dictionary copyTags = new(tags); + copyTags["Correlation ID"] = correlationId.ToString(); + if (caller is not null) copyTags["CalledBy"] = caller; + telemetryClient.TrackTrace(message, level, copyTags); } - public void LogEvent(Guid correlationId, String evt, IDictionary tags, IDictionary? metrics, string? caller) + public void LogEvent(Guid correlationId, String evt, IReadOnlyDictionary tags, IReadOnlyDictionary? metrics, string? caller) { - tags["Correlation ID"] = correlationId.ToString(); - if (caller is not null) tags["CalledBy"] = caller; - telemetryClient.TrackEvent(evt, properties: tags, metrics: metrics); + Dictionary copyTags = new(tags); + copyTags["Correlation ID"] = correlationId.ToString(); + if (caller is not null) copyTags["CalledBy"] = caller; + + Dictionary? copyMetrics = null; + if (metrics is not null) + { + copyMetrics = new(metrics); + } + + telemetryClient.TrackEvent(evt, properties: copyTags, metrics: copyMetrics); } - public void LogException(Guid correlationId, Exception ex, IDictionary tags, IDictionary? metrics, string? caller) + public void LogException(Guid correlationId, Exception ex, IReadOnlyDictionary tags, IReadOnlyDictionary? metrics, string? caller) { - tags["Correlation ID"] = correlationId.ToString(); + Dictionary copyTags = new(tags); + copyTags["Correlation ID"] = correlationId.ToString(); + if (caller is not null) copyTags["CalledBy"] = caller; - if (caller is not null) tags["CalledBy"] = caller; - telemetryClient.TrackException(ex, tags, metrics); + Dictionary? copyMetrics = null; + if (metrics is not null) + { + copyMetrics = new(metrics); + } + telemetryClient.TrackException(ex, copyTags, copyMetrics); } public void Flush() @@ -52,7 +67,7 @@ public void Flush() class Console : ILog { - private string DictToString(IDictionary? d) + private string DictToString(IReadOnlyDictionary? d) { if (d is null) { @@ -64,41 +79,41 @@ private string DictToString(IDictionary? d) } } - private void LogTags(Guid correlationId, string? caller, IDictionary tags) + private void LogTags(Guid correlationId, IReadOnlyDictionary tags) { var ts = DictToString(tags); if (!string.IsNullOrEmpty(ts)) { - System.Console.WriteLine($"[{correlationId}:{caller}] Tags:{ts}"); + System.Console.WriteLine($"[{correlationId}] Tags:{ts}"); } } - private void LogMetrics(Guid correlationId, string? caller, IDictionary? metrics) + private void LogMetrics(Guid correlationId, IReadOnlyDictionary? metrics) { var ms = DictToString(metrics); if (!string.IsNullOrEmpty(ms)) { - System.Console.Out.WriteLine($"[{correlationId}:{caller}] Metrics:{DictToString(metrics)}"); + System.Console.Out.WriteLine($"[{correlationId}] Metrics:{DictToString(metrics)}"); } } - public void Log(Guid correlationId, String message, SeverityLevel level, IDictionary tags, string? caller) + public void Log(Guid correlationId, String message, SeverityLevel level, IReadOnlyDictionary tags, string? caller) { - System.Console.Out.WriteLine($"[{correlationId}:{caller}][{level}] {message}"); - LogTags(correlationId, caller, tags); + System.Console.Out.WriteLine($"[{correlationId}][{level}] {message}"); + LogTags(correlationId, tags); } - public void LogEvent(Guid correlationId, String evt, IDictionary tags, IDictionary? metrics, string? caller) + public void LogEvent(Guid correlationId, String evt, IReadOnlyDictionary tags, IReadOnlyDictionary? metrics, string? caller) { - System.Console.Out.WriteLine($"[{correlationId}:{caller}][Event] {evt}"); - LogTags(correlationId, caller, tags); - LogMetrics(correlationId, caller, metrics); + System.Console.Out.WriteLine($"[{correlationId}][Event] {evt}"); + LogTags(correlationId, tags); + LogMetrics(correlationId, metrics); } - public void LogException(Guid correlationId, Exception ex, IDictionary tags, IDictionary? metrics, string? caller) + public void LogException(Guid correlationId, Exception ex, IReadOnlyDictionary tags, IReadOnlyDictionary? metrics, string? caller) { - System.Console.Out.WriteLine($"[{correlationId}:{caller}][Exception] {ex}"); - LogTags(correlationId, caller, tags); - LogMetrics(correlationId, caller, metrics); + System.Console.Out.WriteLine($"[{correlationId}][Exception] {ex}"); + LogTags(correlationId, tags); + LogMetrics(correlationId, metrics); } public void Flush() { @@ -108,15 +123,17 @@ public void Flush() public interface ILogTracer { - IDictionary Tags { get; } + IReadOnlyDictionary Tags { get; } void Critical(string message); void Error(string message); - void Event(string evt, IDictionary? metrics); - void Exception(Exception ex, IDictionary? metrics); + void Event(string evt, IReadOnlyDictionary? metrics); + void Exception(Exception ex, IReadOnlyDictionary? metrics); void ForceFlush(); void Info(string message); void Warning(string message); + + ILogTracer AddTags((string, string)[]? tags); } public class LogTracer : ILogTracer @@ -129,15 +146,49 @@ public class LogTracer : ILogTracer private List _loggers; public Guid CorrelationId { get; } - public IDictionary Tags { get; } + public IReadOnlyDictionary Tags { get; } + - public LogTracer(Guid correlationId, List loggers) + private static List> ConvertTags((string, string)[]? tags) + { + List> converted = new List>(); + if (tags is null) + { + return converted; + } + else + { + foreach (var (k, v) in tags) + { + converted.Add(new KeyValuePair(k, v)); + } + return converted; + } + } + + public LogTracer(Guid correlationId, (string, string)[]? tags, List loggers) : this(correlationId, new Dictionary(ConvertTags(tags)), loggers) { } + + + public LogTracer(Guid correlationId, IReadOnlyDictionary tags, List loggers) { CorrelationId = correlationId; - Tags = new Dictionary(); + Tags = tags; _loggers = loggers; } + public ILogTracer AddTags((string, string)[]? tags) + { + var newTags = new Dictionary(Tags); + if (tags is not null) + { + foreach (var (k, v) in tags) + { + newTags[k] = v; + } + } + return new LogTracer(CorrelationId, newTags, _loggers); + } + public void Info(string message) { var caller = GetCaller(); @@ -174,7 +225,7 @@ public void Critical(string message) } } - public void Event(string evt, IDictionary? metrics) + public void Event(string evt, IReadOnlyDictionary? metrics) { var caller = GetCaller(); foreach (var logger in _loggers) @@ -183,7 +234,7 @@ public void Event(string evt, IDictionary? metrics) } } - public void Exception(Exception ex, IDictionary? metrics) + public void Exception(Exception ex, IReadOnlyDictionary? metrics) { var caller = GetCaller(); foreach (var logger in _loggers) @@ -203,7 +254,7 @@ public void ForceFlush() public interface ILogTracerFactory { - LogTracer MakeLogTracer(Guid correlationId); + LogTracer MakeLogTracer(Guid correlationId, (string, string)[]? tags = null); } public class LogTracerFactory : ILogTracerFactory @@ -215,9 +266,9 @@ public LogTracerFactory(List loggers) _loggers = loggers; } - public LogTracer MakeLogTracer(Guid correlationId) + public LogTracer MakeLogTracer(Guid correlationId, (string, string)[]? tags = null) { - return new(correlationId, _loggers); + return new(correlationId, tags, _loggers); } } diff --git a/src/ApiService/ApiService/QueueProxyHeartbeat.cs b/src/ApiService/ApiService/QueueProxyHeartbeat.cs index 8705a98d40..7e25017fc4 100644 --- a/src/ApiService/ApiService/QueueProxyHeartbeat.cs +++ b/src/ApiService/ApiService/QueueProxyHeartbeat.cs @@ -28,14 +28,11 @@ public async Task Run([QueueTrigger("myqueue-items", Connection = "AzureWebJobsS var hb = JsonSerializer.Deserialize(msg, EntityConverter.GetJsonSerializerOptions()).EnsureNotNull($"wrong data {msg}"); ; var newHb = hb with { TimeStamp = DateTimeOffset.UtcNow }; - log.Tags["Proxy ID"] = newHb.ProxyId.ToString(); - - var proxy = await _proxy.GetByProxyId(newHb.ProxyId); if (proxy == null) { - log.Warning($"invalid proxy id: {newHb.ProxyId}"); + log.AddTags(new[] { ("Proxy ID", newHb.ProxyId.ToString()) }).Warning($"invalid proxy id: {newHb.ProxyId}"); return; } var newProxy = proxy with { heartbeat = newHb }; diff --git a/src/ApiService/ApiService/onefuzzlib/Events.cs b/src/ApiService/ApiService/onefuzzlib/Events.cs index 65aadf9bfd..37fced6242 100644 --- a/src/ApiService/ApiService/onefuzzlib/Events.cs +++ b/src/ApiService/ApiService/onefuzzlib/Events.cs @@ -68,13 +68,11 @@ public void LogEvent(ILogTracer log, BaseEvent anEvent, EventType eventType) options.DefaultIgnoreCondition = JsonIgnoreCondition.WhenWritingNull; options.Converters.Add(new RemoveUserInfo()); var serializedEvent = JsonSerializer.Serialize(anEvent, options); - log.Tags["Event Type"] = eventType.ToString(); - log.Info($"sending event: {eventType} - {serializedEvent}"); + log.AddTags(new[] { ("Event Type", eventType.ToString()) }).Info($"sending event: {eventType} - {serializedEvent}"); } } - internal class RemoveUserInfo : JsonConverter { public override UserInfo? Read(ref Utf8JsonReader reader, Type typeToConvert, JsonSerializerOptions options) diff --git a/src/ApiService/ApiService/onefuzzlib/WebhookOperations.cs b/src/ApiService/ApiService/onefuzzlib/WebhookOperations.cs index 2a83447e07..ebc4bb1357 100644 --- a/src/ApiService/ApiService/onefuzzlib/WebhookOperations.cs +++ b/src/ApiService/ApiService/onefuzzlib/WebhookOperations.cs @@ -43,9 +43,12 @@ public async Task QueueWebhook(WebhookMessageLog webhookLog) if (visibilityTimeout == null) { - log.Tags["WebhookId"] = webhookLog.WebhookId.ToString(); - log.Tags["EventId"] = webhookLog.EventId.ToString(); - log.Error($"invalid WebhookMessage queue state, not queuing. {webhookLog.WebhookId}:{webhookLog.EventId} - {webhookLog.State}"); + log.AddTags( + new[] { + ("WebhookId", webhookLog.WebhookId.ToString()), + ("EventId", webhookLog.EventId.ToString()) } + ). + Error($"invalid WebhookMessage queue state, not queuing. {webhookLog.WebhookId}:{webhookLog.EventId} - {webhookLog.State}"); } else {