From d4c0d4b81ea916af6146663575a0c88412be64a2 Mon Sep 17 00:00:00 2001 From: Nate McMaster Date: Mon, 13 Mar 2017 14:58:07 -0700 Subject: [PATCH] Adds an EventSource named 'Microsoft-AspNetCore-Server-Kestrel' with the following event and properties: ConnectionStart: - connectionId - scheme - localEndPoint - remoteEndPoint ConnectionStop: - connectionId --- .../Internal/Http/Connection.cs | 3 + .../Internal/Http/SocketOutput.cs | 2 +- .../Infrastructure/KestrelEventSource.cs | 73 +++++++++++++++++ .../EventSourceTests.cs | 81 +++++++++++++++++++ .../KestrelEventSourceTests.cs | 30 +++++++ test/shared/TestConnection.cs | 27 +++++-- test/shared/TestServer.cs | 6 +- 7 files changed, 213 insertions(+), 9 deletions(-) create mode 100644 src/Microsoft.AspNetCore.Server.Kestrel/Internal/Infrastructure/KestrelEventSource.cs create mode 100644 test/Microsoft.AspNetCore.Server.Kestrel.FunctionalTests/EventSourceTests.cs create mode 100644 test/Microsoft.AspNetCore.Server.KestrelTests/KestrelEventSourceTests.cs diff --git a/src/Microsoft.AspNetCore.Server.Kestrel/Internal/Http/Connection.cs b/src/Microsoft.AspNetCore.Server.Kestrel/Internal/Http/Connection.cs index 1de0607695..777d0b88dc 100644 --- a/src/Microsoft.AspNetCore.Server.Kestrel/Internal/Http/Connection.cs +++ b/src/Microsoft.AspNetCore.Server.Kestrel/Internal/Http/Connection.cs @@ -86,6 +86,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Internal.Http public void Start() { Log.ConnectionStart(ConnectionId); + KestrelEventSource.Log.ConnectionStart(this); // Start socket prior to applying the ConnectionAdapter _socket.ReadStart(_allocCallback, _readCallback, this); @@ -137,6 +138,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Internal.Http // Called on Libuv thread public virtual void OnSocketClosed() { + KestrelEventSource.Log.ConnectionStop(this); + _frame.FrameStartedTask.ContinueWith((task, state) => { var connection = (Connection)state; diff --git a/src/Microsoft.AspNetCore.Server.Kestrel/Internal/Http/SocketOutput.cs b/src/Microsoft.AspNetCore.Server.Kestrel/Internal/Http/SocketOutput.cs index 52a3d5b1c5..148a7b7582 100644 --- a/src/Microsoft.AspNetCore.Server.Kestrel/Internal/Http/SocketOutput.cs +++ b/src/Microsoft.AspNetCore.Server.Kestrel/Internal/Http/SocketOutput.cs @@ -199,7 +199,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Internal.Http ScheduleWrite(); } - // Return TaskCompletionSource's Task if set, otherwise completed Task + // Return TaskCompletionSource's Task if set, otherwise completed Task return tcs?.Task ?? TaskCache.CompletedTask; } diff --git a/src/Microsoft.AspNetCore.Server.Kestrel/Internal/Infrastructure/KestrelEventSource.cs b/src/Microsoft.AspNetCore.Server.Kestrel/Internal/Infrastructure/KestrelEventSource.cs new file mode 100644 index 0000000000..552b65ff33 --- /dev/null +++ b/src/Microsoft.AspNetCore.Server.Kestrel/Internal/Infrastructure/KestrelEventSource.cs @@ -0,0 +1,73 @@ +// 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 System.Runtime.CompilerServices; +using Microsoft.AspNetCore.Server.Kestrel.Internal.Http; + +namespace Microsoft.AspNetCore.Server.Kestrel.Internal.Infrastructure +{ + [EventSource(Name = "Microsoft-AspNetCore-Server-Kestrel")] + public sealed class KestrelEventSource : EventSource + { + public static readonly KestrelEventSource Log = new KestrelEventSource(); + + private KestrelEventSource() + { + } + + // 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. + // - Avoid renaming methods or parameters marked with EventAttribute. EventSource uses these to form the event object. + + [NonEvent] + public void ConnectionStart(Connection connection) + { + // avoid allocating strings unless this event source is enabled + if (IsEnabled()) + { + ConnectionStart( + connection.ConnectionId, + connection.ListenerContext.ListenOptions.Scheme, + connection.LocalEndPoint.ToString(), + connection.RemoteEndPoint.ToString()); + } + } + + [MethodImpl(MethodImplOptions.NoInlining)] + [Event(1, Level = EventLevel.Verbose)] + private void ConnectionStart(string connectionId, + string scheme, + string localEndPoint, + string remoteEndPoint) + { + WriteEvent( + 1, + connectionId, + scheme, + localEndPoint, + remoteEndPoint + ); + } + + [NonEvent] + public void ConnectionStop(Connection connection) + { + if (IsEnabled()) + { + ConnectionStop(connection.ConnectionId); + } + } + + [MethodImpl(MethodImplOptions.NoInlining)] + [Event(2, Level = EventLevel.Verbose)] + private void ConnectionStop(string connectionId) + { + WriteEvent(2, connectionId); + } + } +} diff --git a/test/Microsoft.AspNetCore.Server.Kestrel.FunctionalTests/EventSourceTests.cs b/test/Microsoft.AspNetCore.Server.Kestrel.FunctionalTests/EventSourceTests.cs new file mode 100644 index 0000000000..e61447c87c --- /dev/null +++ b/test/Microsoft.AspNetCore.Server.Kestrel.FunctionalTests/EventSourceTests.cs @@ -0,0 +1,81 @@ +// 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.Collections.Generic; +using System.Diagnostics.Tracing; +using System.Linq; +using System.Threading.Tasks; +using Microsoft.AspNetCore.Http.Features; +using Microsoft.AspNetCore.Server.Kestrel.Internal.Infrastructure; +using Microsoft.AspNetCore.Testing; +using Xunit; + +namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests +{ + public class EventSourceTests : IDisposable + { + private readonly TestEventListener _listener = new TestEventListener(); + + public EventSourceTests() + { + _listener.EnableEvents(KestrelEventSource.Log, EventLevel.Verbose); + } + + [Fact] + public async Task EmitsConnectionStartAndStop() + { + string connectionId = null; + int port; + using (var server = new TestServer(context => + { + connectionId = context.Features.Get().ConnectionId; + return Task.CompletedTask; + })) + { + port = server.Port; + using (var connection = server.CreateConnection()) + { + await connection.SendAll("GET / HTTP/1.1", + "", + "") + .TimeoutAfter(TimeSpan.FromSeconds(10)); + await connection.Receive("HTTP/1.1 200"); + } + } + + // capture list here as other tests executing in parallel may log events + Assert.NotNull(connectionId); + var events = _listener.EventData.Where(e => e != null && GetProperty(e, "connectionId") == connectionId).ToList(); + + var start = Assert.Single(events, e => e.EventName == "ConnectionStart"); + Assert.All(new[] { "connectionId", "scheme", "remoteEndPoint", "localEndPoint" }, p => Assert.Contains(p, start.PayloadNames)); + Assert.Equal("http", GetProperty(start, "scheme")); + Assert.Equal($"127.0.0.1:{port}", GetProperty(start, "localEndPoint")); + + var stop = Assert.Single(events, e => e.EventName == "ConnectionStop"); + Assert.All(new[] { "connectionId" }, p => Assert.Contains(p, start.PayloadNames)); + Assert.Same(KestrelEventSource.Log, start.EventSource); + } + + private string GetProperty(EventWrittenEventArgs data, string propName) + => data.Payload[data.PayloadNames.IndexOf(propName)] as string; + + private class TestEventListener : EventListener + { + private List _events = new List(); + + public IEnumerable EventData => _events; + + protected override void OnEventWritten(EventWrittenEventArgs eventData) + { + _events.Add(eventData); + } + } + + public void Dispose() + { + _listener.Dispose(); + } + } +} diff --git a/test/Microsoft.AspNetCore.Server.KestrelTests/KestrelEventSourceTests.cs b/test/Microsoft.AspNetCore.Server.KestrelTests/KestrelEventSourceTests.cs new file mode 100644 index 0000000000..4661097172 --- /dev/null +++ b/test/Microsoft.AspNetCore.Server.KestrelTests/KestrelEventSourceTests.cs @@ -0,0 +1,30 @@ +// 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.Server.Kestrel; +using Xunit; + +namespace Microsoft.AspNetCore.Server.KestrelTests +{ + public class KestrelEventSourceTests + { + [Fact] + public void ExistsWithCorrectId() + { + var esType = typeof(KestrelServer).GetTypeInfo().Assembly.GetType( + "Microsoft.AspNetCore.Server.Kestrel.Internal.Infrastructure.KestrelEventSource", + throwOnError: true, + ignoreCase: false + ); + + Assert.NotNull(esType); + + Assert.Equal("Microsoft-AspNetCore-Server-Kestrel", EventSource.GetName(esType)); + Assert.Equal(Guid.Parse("bdeb4676-a36e-5442-db99-4764e2326c7d"), EventSource.GetGuid(esType)); + Assert.NotEmpty(EventSource.GenerateManifest(esType, "assemblyPathToIncludeInManifest")); + } + } +} \ No newline at end of file diff --git a/test/shared/TestConnection.cs b/test/shared/TestConnection.cs index 13b9d67fa8..849962d378 100644 --- a/test/shared/TestConnection.cs +++ b/test/shared/TestConnection.cs @@ -23,13 +23,18 @@ namespace Microsoft.AspNetCore.Testing private StreamReader _reader; public TestConnection(int port) + : this(port, AddressFamily.InterNetwork) { - Create(port); } - public void Create(int port) + public TestConnection(int port, AddressFamily addressFamily) { - _socket = CreateConnectedLoopbackSocket(port); + Create(port, addressFamily); + } + + public void Create(int port, AddressFamily addressFamily) + { + _socket = CreateConnectedLoopbackSocket(port, addressFamily); _stream = new NetworkStream(_socket, false); _reader = new StreamReader(_stream, Encoding.ASCII); @@ -154,10 +159,20 @@ namespace Microsoft.AspNetCore.Testing } } - public static Socket CreateConnectedLoopbackSocket(int port) + public static Socket CreateConnectedLoopbackSocket(int port) => CreateConnectedLoopbackSocket(port, AddressFamily.InterNetwork); + + public static Socket CreateConnectedLoopbackSocket(int port, AddressFamily addressFamily) { - var socket = new Socket(AddressFamily.InterNetwork, SocketType.Stream, ProtocolType.Tcp); - socket.Connect(new IPEndPoint(IPAddress.Loopback, port)); + if (addressFamily != AddressFamily.InterNetwork && addressFamily != AddressFamily.InterNetworkV6) + { + throw new ArgumentException($"TestConnection does not support address family of type {addressFamily}", nameof(addressFamily)); + } + + var socket = new Socket(addressFamily, SocketType.Stream, ProtocolType.Tcp); + var address = addressFamily == AddressFamily.InterNetworkV6 + ? IPAddress.IPv6Loopback + : IPAddress.Loopback; + socket.Connect(new IPEndPoint(address, port)); return socket; } } diff --git a/test/shared/TestServer.cs b/test/shared/TestServer.cs index 95d5d81699..ec0a8fbd12 100644 --- a/test/shared/TestServer.cs +++ b/test/shared/TestServer.cs @@ -3,6 +3,7 @@ using System; using System.Net; +using System.Net.Sockets; using Microsoft.AspNetCore.Http; using Microsoft.AspNetCore.Server.Kestrel; using Microsoft.AspNetCore.Server.Kestrel.Internal; @@ -66,6 +67,7 @@ namespace Microsoft.AspNetCore.Testing } public int Port => _listenOptions.IPEndPoint.Port; + public AddressFamily AddressFamily => _listenOptions.IPEndPoint.AddressFamily; public Frame Frame => _frame; @@ -73,7 +75,7 @@ namespace Microsoft.AspNetCore.Testing public TestConnection CreateConnection() { - return new TestConnection(Port); + return new TestConnection(Port, AddressFamily); } public void Dispose() @@ -82,4 +84,4 @@ namespace Microsoft.AspNetCore.Testing _engine.Dispose(); } } -} \ No newline at end of file +}