Skip to content
This repository has been archived by the owner on Nov 1, 2023. It is now read-only.

Commit

Permalink
switch to our logger (#1780)
Browse files Browse the repository at this point in the history 
* switch to our logger

* preserve correlation id when calling CorpusAccounts

Co-authored-by: Stas Tishkin <statis@microsoft.com>
  • Loading branch information
@stishkin
stishkin and Stas Tishkin authored Apr 12, 2022
1 parent 75039a9 commit 50637d4
Show file tree
Hide file tree
Showing 13 changed files with 140 additions and 95 deletions.
4 changes: 4 additions & 0 deletions src/ApiService/ApiService/EnvironmentVariables.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -12,7 +12,11 @@ public static class EnvironmentVariables

static EnvironmentVariables()
{
#if DEBUG
LogDestinations = new LogDestination[] { LogDestination.AppInsights, LogDestination.Console };
#else
LogDestinations = new LogDestination[] { LogDestination.AppInsights };
#endif
}

//TODO: Add environment variable to control where to write logs to
Expand Down
40 changes: 40 additions & 0 deletions src/ApiService/ApiService/Info.cs
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,40 @@
using System;
using System.Threading.Tasks;
using Microsoft.Azure.Functions.Worker;
using Microsoft.Azure.Functions.Worker.Http;

namespace Microsoft.OneFuzz.Service;

public record FunctionInfo(string Name, string ResourceGroup, string? SlotName);


public class Info
{

private readonly ILogTracerFactory _loggerFactory;


public Info(ILogTracerFactory loggerFactory)
{
_loggerFactory = loggerFactory;
}

[Function("Info")]
public async Task<HttpResponseData> Run([HttpTrigger(AuthorizationLevel.Anonymous, "get", Route = null)] HttpRequestData req)
{
var log = _loggerFactory.MakeLogTracer(Guid.NewGuid());
log.Info("Creating function info response");
var response = req.CreateResponse();
FunctionInfo info = new(
$"{EnvironmentVariables.OneFuzz.InstanceName}",
$"{EnvironmentVariables.OneFuzz.ResourceGroup}",
Environment.GetEnvironmentVariable("WEBSITE_SLOT_NAME"));


log.Info("Returning function info");
await response.WriteAsJsonAsync(info);
log.Info("Returned function info");
return response;
}

}
84 changes: 43 additions & 41 deletions src/ApiService/ApiService/Log.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -24,21 +24,21 @@ class AppInsights : ILog

public void Log(Guid correlationId, String message, SeverityLevel level, IDictionary<string, string> tags, string? caller)
{
tags.Add("Correlation ID", correlationId.ToString());
if (caller is not null) tags.Add("CalledBy", caller);
tags["Correlation ID"] = correlationId.ToString();
if (caller is not null) tags["CalledBy"] = caller;
telemetryClient.TrackTrace(message, level, tags);
}
public void LogEvent(Guid correlationId, String evt, IDictionary<string, string> tags, IDictionary<string, double>? metrics, string? caller)
{
tags.Add("Correlation ID", correlationId.ToString());
if (caller is not null) tags.Add("CalledBy", caller);
tags["Correlation ID"] = correlationId.ToString();
if (caller is not null) tags["CalledBy"] = caller;
telemetryClient.TrackEvent(evt, properties: tags, metrics: metrics);
}
public void LogException(Guid correlationId, Exception ex, IDictionary<string, string> tags, IDictionary<string, double>? metrics, string? caller)
{
tags.Add("Correlation ID", correlationId.ToString());
tags["Correlation ID"] = correlationId.ToString();

if (caller is not null) tags.Add("CalledBy", caller);
if (caller is not null) tags["CalledBy"] = caller;
telemetryClient.TrackException(ex, tags, metrics);
}

Expand Down Expand Up @@ -69,7 +69,7 @@ private void LogTags(Guid correlationId, string? caller, IDictionary<string, str
var ts = DictToString(tags);
if (!string.IsNullOrEmpty(ts))
{
System.Console.WriteLine("[{0}:{1}] Tags:{2}", correlationId, caller, ts);
System.Console.WriteLine($"[{correlationId}:{caller}] Tags:{ts}");
}
}

Expand All @@ -78,25 +78,25 @@ private void LogMetrics(Guid correlationId, string? caller, IDictionary<string,
var ms = DictToString(metrics);
if (!string.IsNullOrEmpty(ms))
{
System.Console.Out.WriteLine("[{0}:{1}] Metrics:{2}", correlationId, caller, DictToString(metrics));
System.Console.Out.WriteLine($"[{correlationId}:{caller}] Metrics:{DictToString(metrics)}");
}
}

public void Log(Guid correlationId, String message, SeverityLevel level, IDictionary<string, string> tags, string? caller)
{
System.Console.Out.WriteLine("[{0}:{1}][{2}] {3}", correlationId, caller, level, message);
System.Console.Out.WriteLine($"[{correlationId}:{caller}][{level}] {message}");
LogTags(correlationId, caller, tags);
}

public void LogEvent(Guid correlationId, String evt, IDictionary<string, string> tags, IDictionary<string, double>? metrics, string? caller)
{
System.Console.Out.WriteLine("[{0}:{1}][Event] {2}", correlationId, caller, evt);
System.Console.Out.WriteLine($"[{correlationId}:{caller}][Event] {evt}");
LogTags(correlationId, caller, tags);
LogMetrics(correlationId, caller, metrics);
}
public void LogException(Guid correlationId, Exception ex, IDictionary<string, string> tags, IDictionary<string, double>? metrics, string? caller)
{
System.Console.Out.WriteLine("[{0}:{1}][Exception] {2}", correlationId, caller, ex);
System.Console.Out.WriteLine($"[{correlationId}:{caller}][Exception] {ex}");
LogTags(correlationId, caller, tags);
LogMetrics(correlationId, caller, metrics);
}
Expand All @@ -121,77 +121,80 @@ public interface ILogTracer

public class LogTracer : ILogTracer
{
private string? GetCaller()
{
return new StackTrace()?.GetFrame(2)?.GetMethod()?.DeclaringType?.FullName;
}

private List<ILog> loggers;
private List<ILog> _loggers;

private IDictionary<string, string> tags = new Dictionary<string, string>();
private Guid correlationId;
public Guid CorrelationId { get; }
public IDictionary<string, string> Tags { get; }

public LogTracer(Guid correlationId, List<ILog> loggers)
{
this.correlationId = correlationId;
this.loggers = loggers;
CorrelationId = correlationId;
Tags = new Dictionary<string, string>();
_loggers = loggers;
}

public IDictionary<string, string> Tags => tags;

public void Info(string message)
{
var caller = new StackTrace()?.GetFrame(1)?.GetMethod()?.Name;
foreach (var logger in loggers)
var caller = GetCaller();
foreach (var logger in _loggers)
{
logger.Log(correlationId, message, SeverityLevel.Information, Tags, caller);
logger.Log(CorrelationId, message, SeverityLevel.Information, Tags, caller);
}
}

public void Warning(string message)
{
var caller = new StackTrace()?.GetFrame(1)?.GetMethod()?.Name;
foreach (var logger in loggers)
var caller = GetCaller();
foreach (var logger in _loggers)
{
logger.Log(correlationId, message, SeverityLevel.Warning, Tags, caller);
logger.Log(CorrelationId, message, SeverityLevel.Warning, Tags, caller);
}
}

public void Error(string message)
{
var caller = new StackTrace()?.GetFrame(1)?.GetMethod()?.Name;
foreach (var logger in loggers)
var caller = GetCaller();
foreach (var logger in _loggers)
{
logger.Log(correlationId, message, SeverityLevel.Error, Tags, caller);
logger.Log(CorrelationId, message, SeverityLevel.Error, Tags, caller);
}
}

public void Critical(string message)
{
var caller = new StackTrace()?.GetFrame(1)?.GetMethod()?.Name;
foreach (var logger in loggers)
var caller = GetCaller();
foreach (var logger in _loggers)
{
logger.Log(correlationId, message, SeverityLevel.Critical, Tags, caller);
logger.Log(CorrelationId, message, SeverityLevel.Critical, Tags, caller);
}
}

public void Event(string evt, IDictionary<string, double>? metrics)
{
var caller = new StackTrace()?.GetFrame(1)?.GetMethod()?.Name;
foreach (var logger in loggers)
var caller = GetCaller();
foreach (var logger in _loggers)
{
logger.LogEvent(correlationId, evt, Tags, metrics, caller);
logger.LogEvent(CorrelationId, evt, Tags, metrics, caller);
}
}

public void Exception(Exception ex, IDictionary<string, double>? metrics)
{
var caller = new StackTrace()?.GetFrame(1)?.GetMethod()?.Name;
foreach (var logger in loggers)
var caller = GetCaller();
foreach (var logger in _loggers)
{
logger.LogException(correlationId, ex, Tags, metrics, caller);
logger.LogException(CorrelationId, ex, Tags, metrics, caller);
}
}

public void ForceFlush()
{
foreach (var logger in loggers)
foreach (var logger in _loggers)
{
logger.Flush();
}
Expand All @@ -205,17 +208,16 @@ public interface ILogTracerFactory

public class LogTracerFactory : ILogTracerFactory
{

private List<ILog> loggers;
private List<ILog> _loggers;

public LogTracerFactory(List<ILog> loggers)
{
this.loggers = loggers;
_loggers = loggers;
}

public LogTracer MakeLogTracer(Guid correlationId)
{
return new LogTracer(correlationId, this.loggers);
return new(correlationId, _loggers);
}

}
16 changes: 8 additions & 8 deletions src/ApiService/ApiService/QueueFileChanges.cs
View file
Original file line number Diff line number Diff line change
@@ -1,6 +1,5 @@
using System;
using Microsoft.Azure.Functions.Worker;
using Microsoft.Extensions.Logging;
using System.Collections.Generic;
using System.Text.Json;
using System.Threading.Tasks;
Expand All @@ -15,14 +14,14 @@ public class QueueFileChanges
// https://docs.microsoft.com/en-us/azure/azure-functions/functions-bindings-storage-queue-trigger?tabs=csharp#poison-messages
const int MAX_DEQUEUE_COUNT = 5;

private readonly ILogger _logger;
private readonly ILogTracerFactory _loggerFactory;
private readonly IStorageProvider _storageProvider;

private readonly IStorage _storage;

public QueueFileChanges(ILoggerFactory loggerFactory, IStorageProvider storageProvider, IStorage storage)
public QueueFileChanges(ILogTracerFactory loggerFactory, IStorageProvider storageProvider, IStorage storage)
{
_logger = loggerFactory.CreateLogger<QueueFileChanges>();
_loggerFactory = loggerFactory;
_storageProvider = storageProvider;
_storage = storage;
}
Expand All @@ -32,6 +31,7 @@ public Task Run(
[QueueTrigger("file-changes-refactored", Connection = "AzureWebJobsStorage")] string msg,
int dequeueCount)
{
var log = _loggerFactory.MakeLogTracer(Guid.NewGuid());
var fileChangeEvent = JsonSerializer.Deserialize<Dictionary<string, string>>(msg, EntityConverter.GetJsonSerializerOptions());
var lastTry = dequeueCount == MAX_DEQUEUE_COUNT;

Expand All @@ -47,16 +47,16 @@ public Task Run(

const string topic = "topic";
if (!fileChangeEvent.ContainsKey(topic)
|| !_storage.CorpusAccounts().Contains(fileChangeEvent[topic]))
|| !_storage.CorpusAccounts(log).Contains(fileChangeEvent[topic]))
{
return Task.CompletedTask;
}

file_added(fileChangeEvent, lastTry);
file_added(log, fileChangeEvent, lastTry);
return Task.CompletedTask;
}

private void file_added(Dictionary<string, string> fileChangeEvent, bool failTaskOnTransientError)
private void file_added(ILogTracer log, Dictionary<string, string> fileChangeEvent, bool failTaskOnTransientError)
{
var data = JsonSerializer.Deserialize<Dictionary<string, string>>(fileChangeEvent["data"])!;
var url = data["url"];
Expand All @@ -65,7 +65,7 @@ private void file_added(Dictionary<string, string> fileChangeEvent, bool failTas
var container = parts[0];
var path = string.Join('/', parts.Skip(1));

_logger.LogInformation($"file added container: {container} - path: {path}");
log.Info($"file added container: {container} - path: {path}");
// TODO: new_files(container, path, fail_task_on_transient_error)
}
}
12 changes: 6 additions & 6 deletions src/ApiService/ApiService/QueueNodeHearbeat.cs
View file
Original file line number Diff line number Diff line change
@@ -1,6 +1,5 @@
using System;
using Microsoft.Azure.Functions.Worker;
using Microsoft.Extensions.Logging;
using System.Text.Json;
using System.Threading.Tasks;
using Microsoft.OneFuzz.Service.OneFuzzLib.Orm;
Expand All @@ -10,30 +9,31 @@ namespace Microsoft.OneFuzz.Service;

public class QueueNodeHearbeat
{
private readonly ILogger _logger;
private readonly ILogTracerFactory _loggerFactory;

private readonly IEvents _events;
private readonly INodeOperations _nodes;

public QueueNodeHearbeat(ILoggerFactory loggerFactory, INodeOperations nodes, IEvents events)
public QueueNodeHearbeat(ILogTracerFactory loggerFactory, INodeOperations nodes, IEvents events)
{
_logger = loggerFactory.CreateLogger<QueueNodeHearbeat>();
_loggerFactory = loggerFactory;
_nodes = nodes;
_events = events;
}

[Function("QueueNodeHearbeat")]
public async Task Run([QueueTrigger("myqueue-items", Connection = "AzureWebJobsStorage")] string msg)
{
_logger.LogInformation($"heartbeat: {msg}");
var log = _loggerFactory.MakeLogTracer(Guid.NewGuid());
log.Info($"heartbeat: {msg}");

var hb = JsonSerializer.Deserialize<NodeHeartbeatEntry>(msg, EntityConverter.GetJsonSerializerOptions()).EnsureNotNull($"wrong data {msg}");

var node = await _nodes.GetByMachineId(hb.NodeId);

if (node == null)
{
_logger.LogWarning($"invalid node id: {hb.NodeId}");
log.Warning($"invalid node id: {hb.NodeId}");
return;
}

Expand Down
Loading

0 comments on commit 50637d4

Please sign in to comment.