From 4abb48e1aaa730062cef7f0f0fd08c9c5b72413d Mon Sep 17 00:00:00 2001 From: Kiran Challa Date: Mon, 14 Nov 2016 13:48:12 -0800 Subject: [PATCH] Added EventSource to Hosting --- .../Internal/HostingApplication.cs | 6 + .../Internal/HostingEventSource.cs | 53 ++++ .../Internal/WebHost.cs | 10 +- .../HostingApplicationTests.cs | 4 +- .../Internal/HostingEventSourceTests.cs | 227 ++++++++++++++++++ 5 files changed, 295 insertions(+), 5 deletions(-) create mode 100644 src/Microsoft.AspNetCore.Hosting/Internal/HostingEventSource.cs create mode 100644 test/Microsoft.AspNetCore.Hosting.Tests/Internal/HostingEventSourceTests.cs diff --git a/src/Microsoft.AspNetCore.Hosting/Internal/HostingApplication.cs b/src/Microsoft.AspNetCore.Hosting/Internal/HostingApplication.cs index 09f419020c..af2a607b1f 100644 --- a/src/Microsoft.AspNetCore.Hosting/Internal/HostingApplication.cs +++ b/src/Microsoft.AspNetCore.Hosting/Internal/HostingApplication.cs @@ -43,6 +43,8 @@ namespace Microsoft.AspNetCore.Hosting.Internal _diagnosticSource.Write("Microsoft.AspNetCore.Hosting.BeginRequest", new { httpContext = httpContext, timestamp = startTimestamp }); } + HostingEventSource.Log.RequestStart(httpContext.Request.Method, httpContext.Request.Path); + return new Context { HttpContext = httpContext, @@ -78,8 +80,12 @@ namespace Microsoft.AspNetCore.Hosting.Internal { _diagnosticSource.Write("Microsoft.AspNetCore.Hosting.UnhandledException", new { httpContext = httpContext, timestamp = currentTimestamp, exception = exception }); } + + HostingEventSource.Log.UnhandledException(); } + HostingEventSource.Log.RequestStop(); + context.Scope?.Dispose(); _httpContextFactory.Dispose(httpContext); diff --git a/src/Microsoft.AspNetCore.Hosting/Internal/HostingEventSource.cs b/src/Microsoft.AspNetCore.Hosting/Internal/HostingEventSource.cs new file mode 100644 index 0000000000..82ec37c2c9 --- /dev/null +++ b/src/Microsoft.AspNetCore.Hosting/Internal/HostingEventSource.cs @@ -0,0 +1,53 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System.Diagnostics.Tracing; +using Microsoft.AspNetCore.Http; + +namespace Microsoft.AspNetCore.Hosting.Internal +{ + [EventSource(Name = "Microsoft-AspNetCore-Hosting")] + public sealed class HostingEventSource : EventSource + { + public static readonly HostingEventSource Log = new HostingEventSource(); + + private HostingEventSource() { } + + // NOTE + // - The 'Start' and 'Stop' suffixes on the following event names have special meaning in EventSource. They + // enable creating 'activities'. + // For more information, take a look at the following blog post: + // https://blogs.msdn.microsoft.com/vancem/2015/09/14/exploring-eventsource-activity-correlation-and-causation-features/ + // - A stop event's event id must be next one after its start event. + + [Event(1, Level = EventLevel.Informational)] + public void HostStart() + { + WriteEvent(1); + } + + [Event(2, Level = EventLevel.Informational)] + public void HostStop() + { + WriteEvent(2); + } + + [Event(3, Level = EventLevel.Informational)] + public void RequestStart(string method, string path) + { + WriteEvent(3, method, path); + } + + [Event(4, Level = EventLevel.Informational)] + public void RequestStop() + { + WriteEvent(4); + } + + [Event(5, Level = EventLevel.Error)] + public void UnhandledException() + { + WriteEvent(5); + } + } +} diff --git a/src/Microsoft.AspNetCore.Hosting/Internal/WebHost.cs b/src/Microsoft.AspNetCore.Hosting/Internal/WebHost.cs index 440b17321d..8859fb6fac 100644 --- a/src/Microsoft.AspNetCore.Hosting/Internal/WebHost.cs +++ b/src/Microsoft.AspNetCore.Hosting/Internal/WebHost.cs @@ -97,15 +97,15 @@ namespace Microsoft.AspNetCore.Hosting.Internal public virtual void Start() { + HostingEventSource.Log.HostStart(); + _logger = _applicationServices.GetRequiredService>(); + _logger.Starting(); + Initialize(); _applicationLifetime = _applicationServices.GetRequiredService() as ApplicationLifetime; - _logger = _applicationServices.GetRequiredService>(); var diagnosticSource = _applicationServices.GetRequiredService(); var httpContextFactory = _applicationServices.GetRequiredService(); - - _logger.Starting(); - Server.Start(new HostingApplication(_application, _logger, diagnosticSource, httpContextFactory)); _applicationLifetime?.NotifyStarted(); @@ -247,6 +247,8 @@ namespace Microsoft.AspNetCore.Hosting.Internal (_hostingServiceProvider as IDisposable)?.Dispose(); (_applicationServices as IDisposable)?.Dispose(); _applicationLifetime?.NotifyStopped(); + + HostingEventSource.Log.HostStop(); } } } diff --git a/test/Microsoft.AspNetCore.Hosting.Tests/HostingApplicationTests.cs b/test/Microsoft.AspNetCore.Hosting.Tests/HostingApplicationTests.cs index 16530e5edc..7c285f1a0e 100644 --- a/test/Microsoft.AspNetCore.Hosting.Tests/HostingApplicationTests.cs +++ b/test/Microsoft.AspNetCore.Hosting.Tests/HostingApplicationTests.cs @@ -22,7 +22,9 @@ namespace Microsoft.AspNetCore.Hosting.Tests // Arrange var httpContextFactory = new HttpContextFactory(new DefaultObjectPoolProvider(), Options.Create(new FormOptions()), new HttpContextAccessor()); var hostingApplication = new HostingApplication(ctx => Task.FromResult(0), new NullScopeLogger(), new NoopDiagnosticSource(), httpContextFactory); - var context = hostingApplication.CreateContext(new FeatureCollection()); + var features = new FeatureCollection(); + features.Set(new HttpRequestFeature()); + var context = hostingApplication.CreateContext(features); // Act/Assert hostingApplication.DisposeContext(context, null); diff --git a/test/Microsoft.AspNetCore.Hosting.Tests/Internal/HostingEventSourceTests.cs b/test/Microsoft.AspNetCore.Hosting.Tests/Internal/HostingEventSourceTests.cs new file mode 100644 index 0000000000..f1ecb6476f --- /dev/null +++ b/test/Microsoft.AspNetCore.Hosting.Tests/Internal/HostingEventSourceTests.cs @@ -0,0 +1,227 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; +using System.Diagnostics.Tracing; +using System.Reflection; +using Microsoft.AspNetCore.Http; +using Xunit; + +namespace Microsoft.AspNetCore.Hosting.Internal +{ + public class HostingEventSourceTests + { + [Fact] + public void MatchesNameAndGuid() + { + // Arrange & Act + var eventSourceType = typeof(WebHost).GetTypeInfo().Assembly.GetType( + "Microsoft.AspNetCore.Hosting.Internal.HostingEventSource", + throwOnError: true, + ignoreCase: false); + + // Assert + Assert.NotNull(eventSourceType); + Assert.Equal("Microsoft-AspNetCore-Hosting", EventSource.GetName(eventSourceType)); + Assert.Equal(Guid.Parse("9e620d2a-55d4-5ade-deb7-c26046d245a8"), EventSource.GetGuid(eventSourceType)); + Assert.NotEmpty(EventSource.GenerateManifest(eventSourceType, "assemblyPathToIncludeInManifest")); + } + + [Fact] + public void HostStart() + { + // Arrange + var expectedEventId = 1; + var eventListener = new TestEventListener(expectedEventId); + var hostingEventSource = HostingEventSource.Log; + eventListener.EnableEvents(hostingEventSource, EventLevel.Informational); + + // Act + hostingEventSource.HostStart(); + + // Assert + var eventData = eventListener.EventData; + Assert.NotNull(eventData); + Assert.Equal(expectedEventId, eventData.EventId); +#if NETCOREAPP1_1 + Assert.Equal("HostStart", eventData.EventName); +#endif + Assert.Equal(EventLevel.Informational, eventData.Level); + Assert.Same(hostingEventSource, eventData.EventSource); + Assert.Null(eventData.Message); + Assert.Empty(eventData.Payload); + } + + [Fact] + public void HostStop() + { + // Arrange + var expectedEventId = 2; + var eventListener = new TestEventListener(expectedEventId); + var hostingEventSource = HostingEventSource.Log; + eventListener.EnableEvents(hostingEventSource, EventLevel.Informational); + + // Act + hostingEventSource.HostStop(); + + // Assert + var eventData = eventListener.EventData; + Assert.NotNull(eventData); + Assert.Equal(expectedEventId, eventData.EventId); +#if NETCOREAPP1_1 + Assert.Equal("HostStop", eventData.EventName); +#endif + Assert.Equal(EventLevel.Informational, eventData.Level); + Assert.Same(hostingEventSource, eventData.EventSource); + Assert.Null(eventData.Message); + Assert.Empty(eventData.Payload); + } + + public static TheoryData RequestStartData + { + get + { + var variations = new TheoryData(); + + var context = new DefaultHttpContext(); + context.Request.Method = "GET"; + context.Request.Path = "/Home/Index"; + variations.Add( + context, + new string[] + { + "GET", + "/Home/Index" + }); + + context = new DefaultHttpContext(); + context.Request.Method = "POST"; + context.Request.Path = "/"; + variations.Add( + context, + new string[] + { + "POST", + "/" + }); + + return variations; + } + } + + [Theory] + [MemberData(nameof(RequestStartData))] + public void RequestStart(DefaultHttpContext httpContext, string[] expected) + { + // Arrange + var expectedEventId = 3; + var eventListener = new TestEventListener(expectedEventId); + var hostingEventSource = HostingEventSource.Log; + eventListener.EnableEvents(hostingEventSource, EventLevel.Informational); + + // Act + hostingEventSource.RequestStart(httpContext.Request.Method, httpContext.Request.Path); + + // Assert + var eventData = eventListener.EventData; + Assert.NotNull(eventData); + Assert.Equal(expectedEventId, eventData.EventId); +#if NETCOREAPP1_1 + Assert.Equal("RequestStart", eventData.EventName); +#endif + Assert.Equal(EventLevel.Informational, eventData.Level); + Assert.Same(hostingEventSource, eventData.EventSource); + Assert.Null(eventData.Message); + + var payloadList = eventData.Payload; + Assert.Equal(expected.Length, payloadList.Count); + for (var i = 0; i < expected.Length; i++) + { + Assert.Equal(expected[i], payloadList[i]); + } + } + + [Fact] + public void RequestStop() + { + // Arrange + var expectedEventId = 4; + var eventListener = new TestEventListener(expectedEventId); + var hostingEventSource = HostingEventSource.Log; + eventListener.EnableEvents(hostingEventSource, EventLevel.Informational); + + // Act + hostingEventSource.RequestStop(); + + // Assert + var eventData = eventListener.EventData; + Assert.Equal(expectedEventId, eventData.EventId); +#if NETCOREAPP1_1 + Assert.Equal("RequestStop", eventData.EventName); +#endif + Assert.Equal(EventLevel.Informational, eventData.Level); + Assert.Same(hostingEventSource, eventData.EventSource); + Assert.Null(eventData.Message); + Assert.Equal(0, eventData.Payload.Count); + } + + [Fact] + public void UnhandledException() + { + // Arrange + var expectedEventId = 5; + var eventListener = new TestEventListener(expectedEventId); + var hostingEventSource = HostingEventSource.Log; + eventListener.EnableEvents(hostingEventSource, EventLevel.Informational); + + // Act + hostingEventSource.UnhandledException(); + + // Assert + var eventData = eventListener.EventData; + Assert.Equal(expectedEventId, eventData.EventId); +#if NETCOREAPP1_1 + Assert.Equal("UnhandledException", eventData.EventName); +#endif + Assert.Equal(EventLevel.Error, eventData.Level); + Assert.Same(hostingEventSource, eventData.EventSource); + Assert.Null(eventData.Message); + Assert.Equal(0, eventData.Payload.Count); + } + + private static Exception GetException() + { + try + { + throw new InvalidOperationException("An invalid operation has occurred"); + } + catch (Exception ex) + { + return ex; + } + } + + private class TestEventListener : EventListener + { + private readonly int _eventId; + + public TestEventListener(int eventId) + { + _eventId = eventId; + } + + public EventWrittenEventArgs EventData { get; private set; } + + protected override void OnEventWritten(EventWrittenEventArgs eventData) + { + // The tests here run in parallel and since the single publisher instance (HostingEventingSource) + // notifies all listener instances in these tests, capture the EventData that a test is explicitly + // looking for and not give back other tests' data. + if (eventData.EventId == _eventId) + { + EventData = eventData; + } + } + } + } +}