Пример #1
0
        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);
        }