private void HandleLoggingEvents(EventPipeEventSource source)
{
string lastFormattedMessage = string.Empty;
var logActivities = new Dictionary <Guid, LogActivityItem>();
var stack = new Stack <Guid>();
source.Dynamic.AddCallbackForProviderEvent(LoggingSourceConfiguration.MicrosoftExtensionsLoggingProviderName, "ActivityJson/Start", (traceEvent) =>
{
var factoryId = (int)traceEvent.PayloadByName("FactoryID");
var categoryName = (string)traceEvent.PayloadByName("LoggerName");
var argsJson = (string)traceEvent.PayloadByName("ArgumentsJson");
// TODO: Store this information by logger factory id
var item = new LogActivityItem
{
ActivityID = traceEvent.ActivityID,
ScopedObject = new LogObject(JsonDocument.Parse(argsJson).RootElement),
};
if (stack.Count > 0)
{
Guid parentId = stack.Peek();
if (logActivities.TryGetValue(parentId, out var parentItem))
{
item.Parent = parentItem;
}
}
stack.Push(traceEvent.ActivityID);
logActivities[traceEvent.ActivityID] = item;
});
source.Dynamic.AddCallbackForProviderEvent(LoggingSourceConfiguration.MicrosoftExtensionsLoggingProviderName, "ActivityJson/Stop", (traceEvent) =>
{
var factoryId = (int)traceEvent.PayloadByName("FactoryID");
var categoryName = (string)traceEvent.PayloadByName("LoggerName");
stack.Pop();
logActivities.Remove(traceEvent.ActivityID);
});
source.Dynamic.AddCallbackForProviderEvent(LoggingSourceConfiguration.MicrosoftExtensionsLoggingProviderName, "MessageJson", (traceEvent) =>
{
// Level, FactoryID, LoggerName, EventID, EventName, ExceptionJson, ArgumentsJson
var logLevel = (LogLevel)traceEvent.PayloadByName("Level");
var factoryId = (int)traceEvent.PayloadByName("FactoryID");
var categoryName = (string)traceEvent.PayloadByName("LoggerName");
var eventId = (int)traceEvent.PayloadByName("EventId");
var eventName = (string)traceEvent.PayloadByName("EventName");
var exceptionJson = (string)traceEvent.PayloadByName("ExceptionJson");
var argsJson = (string)traceEvent.PayloadByName("ArgumentsJson");
// There's a bug that causes some of the columns to get mixed up
if (eventName.StartsWith("{"))
{
argsJson = exceptionJson;
exceptionJson = eventName;
eventName = null;
}
if (string.IsNullOrEmpty(argsJson))
{
return;
}
Exception exception = null;
ILogger logger = _loggerFactory.CreateLogger(categoryName);
var scopes = new List <IDisposable>();
if (logActivities.TryGetValue(traceEvent.ActivityID, out var logActivityItem))
{
// REVIEW: Does order matter here? We're combining everything anyways.
while (logActivityItem != null)
{
scopes.Add(logger.BeginScope(logActivityItem.ScopedObject));
logActivityItem = logActivityItem.Parent;
}
}
try
{
if (exceptionJson != "{}")
{
var exceptionMessage = JsonSerializer.Deserialize <JsonElement>(exceptionJson);
exception = new LoggerException(exceptionMessage);
}
var message = JsonSerializer.Deserialize <JsonElement>(argsJson);
if (message.TryGetProperty("{OriginalFormat}", out var formatElement))
{
var formatString = formatElement.GetString();
var formatter = new LogValuesFormatter(formatString);
object[] args = new object[formatter.ValueNames.Count];
for (int i = 0; i < args.Length; i++)
{
args[i] = message.GetProperty(formatter.ValueNames[i]).GetString();
}
logger.Log(logLevel, new EventId(eventId, eventName), exception, formatString, args);
}
else
{
var obj = new LogObject(message, lastFormattedMessage);
logger.Log(logLevel, new EventId(eventId, eventName), obj, exception, LogObject.Callback);
}
}
catch (Exception)
{
}
finally
{
scopes.ForEach(d => d.Dispose());
}
});
source.Dynamic.AddCallbackForProviderEvent(LoggingSourceConfiguration.MicrosoftExtensionsLoggingProviderName, "FormattedMessage", (traceEvent) =>
{
// Level, FactoryID, LoggerName, EventID, EventName, FormattedMessage
var logLevel = (LogLevel)traceEvent.PayloadByName("Level");
var factoryId = (int)traceEvent.PayloadByName("FactoryID");
var categoryName = (string)traceEvent.PayloadByName("LoggerName");
var eventId = (int)traceEvent.PayloadByName("EventId");
var eventName = (string)traceEvent.PayloadByName("EventName");
var formattedMessage = (string)traceEvent.PayloadByName("FormattedMessage");
if (string.IsNullOrEmpty(formattedMessage))
{
formattedMessage = eventName;
eventName = string.Empty;
}
lastFormattedMessage = formattedMessage;
});
}
protected override Task OnEventSourceAvailable(EventPipeEventSource eventSource, Func <Task> stopSessionAsync, CancellationToken token)
{
string lastFormattedMessage = string.Empty;
var logActivities = new Dictionary <Guid, LogActivityItem>();
var stack = new Stack <Guid>();
eventSource.Dynamic.AddCallbackForProviderEvent(LoggingSourceConfiguration.MicrosoftExtensionsLoggingProviderName, "ActivityJson/Start", (traceEvent) =>
{
var factoryId = (int)traceEvent.PayloadByName("FactoryID");
var categoryName = (string)traceEvent.PayloadByName("LoggerName");
var argsJson = (string)traceEvent.PayloadByName("ArgumentsJson");
// TODO: Store this information by logger factory id
var item = new LogActivityItem
{
ActivityID = traceEvent.ActivityID,
ScopedObject = new LogObject(JsonDocument.Parse(argsJson).RootElement),
};
if (stack.Count > 0)
{
Guid parentId = stack.Peek();
if (logActivities.TryGetValue(parentId, out var parentItem))
{
item.Parent = parentItem;
}
}
stack.Push(traceEvent.ActivityID);
logActivities[traceEvent.ActivityID] = item;
});
eventSource.Dynamic.AddCallbackForProviderEvent(LoggingSourceConfiguration.MicrosoftExtensionsLoggingProviderName, "ActivityJson/Stop", (traceEvent) =>
{
var factoryId = (int)traceEvent.PayloadByName("FactoryID");
var categoryName = (string)traceEvent.PayloadByName("LoggerName");
//If we begin collection in the middle of a request, we can receive a stop without having a start.
if (stack.Count > 0)
{
stack.Pop();
logActivities.Remove(traceEvent.ActivityID);
}
});
eventSource.Dynamic.AddCallbackForProviderEvent(LoggingSourceConfiguration.MicrosoftExtensionsLoggingProviderName, "MessageJson", (traceEvent) =>
{
// Level, FactoryID, LoggerName, EventID, EventName, ExceptionJson, ArgumentsJson
var logLevel = (LogLevel)traceEvent.PayloadByName("Level");
var factoryId = (int)traceEvent.PayloadByName("FactoryID");
var categoryName = (string)traceEvent.PayloadByName("LoggerName");
var eventId = (int)traceEvent.PayloadByName("EventId");
var eventName = (string)traceEvent.PayloadByName("EventName");
var exceptionJson = (string)traceEvent.PayloadByName("ExceptionJson");
var argsJson = (string)traceEvent.PayloadByName("ArgumentsJson");
// There's a bug that causes some of the columns to get mixed up
if (eventName.StartsWith("{"))
{
argsJson = exceptionJson;
exceptionJson = eventName;
eventName = null;
}
if (string.IsNullOrEmpty(argsJson))
{
return;
}
Exception exception = null;
ILogger logger = _factory.CreateLogger(categoryName);
var scopes = new List <IDisposable>();
if (logActivities.TryGetValue(traceEvent.ActivityID, out var logActivityItem))
{
// REVIEW: Does order matter here? We're combining everything anyways.
while (logActivityItem != null)
{
scopes.Add(logger.BeginScope(logActivityItem.ScopedObject));
logActivityItem = logActivityItem.Parent;
}
}
try
{
if (exceptionJson != "{}")
{
var exceptionMessage = JsonSerializer.Deserialize <JsonElement>(exceptionJson);
exception = new LoggerException(exceptionMessage);
}
var message = JsonSerializer.Deserialize <JsonElement>(argsJson);
if (message.TryGetProperty("{OriginalFormat}", out var formatElement))
{
var formatString = formatElement.GetString();
var formatter = new LogValuesFormatter(formatString);
object[] args = new object[formatter.ValueNames.Count];
for (int i = 0; i < args.Length; i++)
{
args[i] = message.GetProperty(formatter.ValueNames[i]).GetString();
}
//We want to propagate the timestamp to the underlying logger, but that's not part of the ILogger interface.
//We replicate LoggerExtensions.Log, but add an interface capability to the object
//CONSIDER FormattedLogValues maintains a cache of formatters. We are effectively duplicating this cache.
var logValues = new FormattedLogValues(traceEvent.TimeStamp, formatString, args);
logger.Log(logLevel, new EventId(eventId, eventName), logValues, exception, _messageFormatter);
}
else
{
var obj = new LogObject(message, lastFormattedMessage)
{
Timestamp = traceEvent.TimeStamp
};
logger.Log(logLevel, new EventId(eventId, eventName), obj, exception, LogObject.Callback);
}
}
catch (Exception)
{
}
finally
{
scopes.ForEach(d => d.Dispose());
}
});
eventSource.Dynamic.AddCallbackForProviderEvent(LoggingSourceConfiguration.MicrosoftExtensionsLoggingProviderName, "FormattedMessage", (traceEvent) =>
{
// Level, FactoryID, LoggerName, EventID, EventName, FormattedMessage
var logLevel = (LogLevel)traceEvent.PayloadByName("Level");
var factoryId = (int)traceEvent.PayloadByName("FactoryID");
var categoryName = (string)traceEvent.PayloadByName("LoggerName");
var eventId = (int)traceEvent.PayloadByName("EventId");
var eventName = (string)traceEvent.PayloadByName("EventName");
var formattedMessage = (string)traceEvent.PayloadByName("FormattedMessage");
if (string.IsNullOrEmpty(formattedMessage))
{
formattedMessage = eventName;
eventName = string.Empty;
}
lastFormattedMessage = formattedMessage;
});
return(Task.CompletedTask);
}