Added basic event counters for hosting (#10884)

- Added Request Rate counter (RPS), Total Requests counter, current requests and failed requests.
- Counters do nothing until enabled
- Added tests for counters and improved tests to use unique event source names
- Renamed EventSource to match the convention in the runtime Microsoft.AspNetCore.Hosting
This commit is contained in:
David Fowler 2019-06-05 14:06:34 -07:00 committed by GitHub
parent f066f7c32f
commit bba6b44044
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
6 changed files with 199 additions and 30 deletions

View File

@ -145,7 +145,6 @@ namespace Microsoft.AspNetCore.Hosting.Internal
public static void Initialize(this Microsoft.AspNetCore.Hosting.IHostingEnvironment hostingEnvironment, string contentRootPath, Microsoft.AspNetCore.Hosting.Internal.WebHostOptions options) { } public static void Initialize(this Microsoft.AspNetCore.Hosting.IHostingEnvironment hostingEnvironment, string contentRootPath, Microsoft.AspNetCore.Hosting.Internal.WebHostOptions options) { }
public static void Initialize(this Microsoft.AspNetCore.Hosting.IWebHostEnvironment hostingEnvironment, string contentRootPath, Microsoft.AspNetCore.Hosting.Internal.WebHostOptions options) { } public static void Initialize(this Microsoft.AspNetCore.Hosting.IWebHostEnvironment hostingEnvironment, string contentRootPath, Microsoft.AspNetCore.Hosting.Internal.WebHostOptions options) { }
} }
[System.Diagnostics.Tracing.EventSourceAttribute(Name="Microsoft-AspNetCore-Hosting")]
public sealed partial class HostingEventSource : System.Diagnostics.Tracing.EventSource public sealed partial class HostingEventSource : System.Diagnostics.Tracing.EventSource
{ {
internal HostingEventSource() { } internal HostingEventSource() { }
@ -154,6 +153,7 @@ namespace Microsoft.AspNetCore.Hosting.Internal
public void HostStart() { } public void HostStart() { }
[System.Diagnostics.Tracing.EventAttribute(2, Level=System.Diagnostics.Tracing.EventLevel.Informational)] [System.Diagnostics.Tracing.EventAttribute(2, Level=System.Diagnostics.Tracing.EventLevel.Informational)]
public void HostStop() { } public void HostStop() { }
protected override void OnEventCommand(System.Diagnostics.Tracing.EventCommandEventArgs command) { }
[System.Diagnostics.Tracing.EventAttribute(3, Level=System.Diagnostics.Tracing.EventLevel.Informational)] [System.Diagnostics.Tracing.EventAttribute(3, Level=System.Diagnostics.Tracing.EventLevel.Informational)]
public void RequestStart(string method, string path) { } public void RequestStart(string method, string path) { }
[System.Runtime.CompilerServices.MethodImpl(System.Runtime.CompilerServices.MethodImplOptions.NoInlining)][System.Diagnostics.Tracing.EventAttribute(4, Level=System.Diagnostics.Tracing.EventLevel.Informational)] [System.Runtime.CompilerServices.MethodImpl(System.Runtime.CompilerServices.MethodImplOptions.NoInlining)][System.Diagnostics.Tracing.EventAttribute(4, Level=System.Diagnostics.Tracing.EventLevel.Informational)]

View File

@ -136,10 +136,19 @@ namespace Microsoft.AspNetCore.Hosting.Internal
StopActivity(httpContext, activity, context.HasDiagnosticListener); StopActivity(httpContext, activity, context.HasDiagnosticListener);
} }
if (context.EventLogEnabled && exception != null) if (context.EventLogEnabled)
{ {
// Non-inline if (exception != null)
HostingEventSource.Log.UnhandledException(); {
// Non-inline
HostingEventSource.Log.UnhandledException();
}
// Count 500 as failed requests
if (httpContext.Response.StatusCode >= 500)
{
HostingEventSource.Log.RequestFailed();
}
} }
// Logging Scope is finshed with // Logging Scope is finshed with

View File

@ -1,17 +1,37 @@
// Copyright (c) .NET Foundation. All rights reserved. // 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. // 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.Diagnostics.Tracing;
using System.Runtime.CompilerServices; using System.Runtime.CompilerServices;
using System.Threading;
namespace Microsoft.AspNetCore.Hosting.Internal namespace Microsoft.AspNetCore.Hosting.Internal
{ {
[EventSource(Name = "Microsoft-AspNetCore-Hosting")]
public sealed class HostingEventSource : EventSource public sealed class HostingEventSource : EventSource
{ {
public static readonly HostingEventSource Log = new HostingEventSource(); public static readonly HostingEventSource Log = new HostingEventSource();
private HostingEventSource() { } private IncrementingPollingCounter _requestsPerSecondCounter;
private PollingCounter _totalRequestsCounter;
private PollingCounter _failedRequestsCounter;
private PollingCounter _currentRequestsCounter;
private long _totalRequests;
private long _currentRequests;
private long _failedRequests;
internal HostingEventSource()
: this("Microsoft.AspNetCore.Hosting")
{
}
// Used for testing
internal HostingEventSource(string eventSourceName)
: base(eventSourceName)
{
}
// NOTE // NOTE
// - The 'Start' and 'Stop' suffixes on the following event names have special meaning in EventSource. They // - The 'Start' and 'Stop' suffixes on the following event names have special meaning in EventSource. They
@ -35,6 +55,8 @@ namespace Microsoft.AspNetCore.Hosting.Internal
[Event(3, Level = EventLevel.Informational)] [Event(3, Level = EventLevel.Informational)]
public void RequestStart(string method, string path) public void RequestStart(string method, string path)
{ {
Interlocked.Increment(ref _totalRequests);
Interlocked.Increment(ref _currentRequests);
WriteEvent(3, method, path); WriteEvent(3, method, path);
} }
@ -42,6 +64,7 @@ namespace Microsoft.AspNetCore.Hosting.Internal
[Event(4, Level = EventLevel.Informational)] [Event(4, Level = EventLevel.Informational)]
public void RequestStop() public void RequestStop()
{ {
Interlocked.Decrement(ref _currentRequests);
WriteEvent(4); WriteEvent(4);
} }
@ -51,5 +74,40 @@ namespace Microsoft.AspNetCore.Hosting.Internal
{ {
WriteEvent(5); WriteEvent(5);
} }
internal void RequestFailed()
{
Interlocked.Increment(ref _failedRequests);
}
protected override void OnEventCommand(EventCommandEventArgs command)
{
if (command.Command == EventCommand.Enable)
{
// This is the convention for initializing counters in the RuntimeEventSource (lazily on the first enable command).
// They aren't disabled afterwards...
_requestsPerSecondCounter ??= new IncrementingPollingCounter("requests-per-second", this, () => _totalRequests)
{
DisplayName = "Request Rate",
DisplayRateTimeScale = TimeSpan.FromSeconds(1)
};
_totalRequestsCounter ??= new PollingCounter("total-requests", this, () => _totalRequests)
{
DisplayName = "Total Requests",
};
_currentRequestsCounter ??= new PollingCounter("current-requests", this, () => _currentRequests)
{
DisplayName = "Current Requests"
};
_failedRequestsCounter ??= new PollingCounter("failed-requests", this, () => _failedRequests)
{
DisplayName = "Failed Requests"
};
}
}
} }
} }

View File

@ -0,0 +1,23 @@
using System;
using System.Text;
using System.Threading;
using System.Threading.Tasks;
namespace System.Collections.Generic
{
internal static class AsyncEnumerableExtensions
{
public static async Task<T> FirstOrDefault<T>(this IAsyncEnumerator<T> values, Func<T, bool> filter)
{
while (await values.MoveNextAsync())
{
if (filter(values.Current))
{
return values.Current;
}
}
return default;
}
}
}

View File

@ -2,8 +2,11 @@
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
using System; using System;
using System.Collections.Generic;
using System.Diagnostics.Tracing; using System.Diagnostics.Tracing;
using System.Reflection; using System.Threading;
using System.Threading.Channels;
using System.Threading.Tasks;
using Microsoft.AspNetCore.Http; using Microsoft.AspNetCore.Http;
using Microsoft.AspNetCore.Testing; using Microsoft.AspNetCore.Testing;
using Microsoft.AspNetCore.Testing.xunit; using Microsoft.AspNetCore.Testing.xunit;
@ -17,16 +20,11 @@ namespace Microsoft.AspNetCore.Hosting.Internal
public void MatchesNameAndGuid() public void MatchesNameAndGuid()
{ {
// Arrange & Act // Arrange & Act
var eventSourceType = typeof(WebHost).GetTypeInfo().Assembly.GetType( var eventSource = new HostingEventSource();
"Microsoft.AspNetCore.Hosting.Internal.HostingEventSource",
throwOnError: true,
ignoreCase: false);
// Assert // Assert
Assert.NotNull(eventSourceType); Assert.Equal("Microsoft.AspNetCore.Hosting", eventSource.Name);
Assert.Equal("Microsoft-AspNetCore-Hosting", EventSource.GetName(eventSourceType)); Assert.Equal(Guid.Parse("9ded64a4-414c-5251-dcf7-1e4e20c15e70"), eventSource.Guid);
Assert.Equal(Guid.Parse("9e620d2a-55d4-5ade-deb7-c26046d245a8"), EventSource.GetGuid(eventSourceType));
Assert.NotEmpty(EventSource.GenerateManifest(eventSourceType, "assemblyPathToIncludeInManifest"));
} }
[Fact] [Fact]
@ -35,7 +33,7 @@ namespace Microsoft.AspNetCore.Hosting.Internal
// Arrange // Arrange
var expectedEventId = 1; var expectedEventId = 1;
var eventListener = new TestEventListener(expectedEventId); var eventListener = new TestEventListener(expectedEventId);
var hostingEventSource = HostingEventSource.Log; var hostingEventSource = GetHostingEventSource();
eventListener.EnableEvents(hostingEventSource, EventLevel.Informational); eventListener.EnableEvents(hostingEventSource, EventLevel.Informational);
// Act // Act
@ -58,7 +56,7 @@ namespace Microsoft.AspNetCore.Hosting.Internal
// Arrange // Arrange
var expectedEventId = 2; var expectedEventId = 2;
var eventListener = new TestEventListener(expectedEventId); var eventListener = new TestEventListener(expectedEventId);
var hostingEventSource = HostingEventSource.Log; var hostingEventSource = GetHostingEventSource();
eventListener.EnableEvents(hostingEventSource, EventLevel.Informational); eventListener.EnableEvents(hostingEventSource, EventLevel.Informational);
// Act // Act
@ -115,7 +113,7 @@ namespace Microsoft.AspNetCore.Hosting.Internal
// Arrange // Arrange
var expectedEventId = 3; var expectedEventId = 3;
var eventListener = new TestEventListener(expectedEventId); var eventListener = new TestEventListener(expectedEventId);
var hostingEventSource = HostingEventSource.Log; var hostingEventSource = GetHostingEventSource();
eventListener.EnableEvents(hostingEventSource, EventLevel.Informational); eventListener.EnableEvents(hostingEventSource, EventLevel.Informational);
// Act // Act
@ -144,7 +142,7 @@ namespace Microsoft.AspNetCore.Hosting.Internal
// Arrange // Arrange
var expectedEventId = 4; var expectedEventId = 4;
var eventListener = new TestEventListener(expectedEventId); var eventListener = new TestEventListener(expectedEventId);
var hostingEventSource = HostingEventSource.Log; var hostingEventSource = GetHostingEventSource();
eventListener.EnableEvents(hostingEventSource, EventLevel.Informational); eventListener.EnableEvents(hostingEventSource, EventLevel.Informational);
// Act // Act
@ -166,7 +164,7 @@ namespace Microsoft.AspNetCore.Hosting.Internal
// Arrange // Arrange
var expectedEventId = 5; var expectedEventId = 5;
var eventListener = new TestEventListener(expectedEventId); var eventListener = new TestEventListener(expectedEventId);
var hostingEventSource = HostingEventSource.Log; var hostingEventSource = GetHostingEventSource();
eventListener.EnableEvents(hostingEventSource, EventLevel.Informational); eventListener.EnableEvents(hostingEventSource, EventLevel.Informational);
// Act // Act
@ -182,16 +180,65 @@ namespace Microsoft.AspNetCore.Hosting.Internal
Assert.Empty(eventData.Payload); Assert.Empty(eventData.Payload);
} }
private static Exception GetException() [Fact]
public async Task VerifyCountersFireWithCorrectValues()
{ {
try // Arrange
{ var eventListener = new CounterListener(new[] {
throw new InvalidOperationException("An invalid operation has occurred"); "requests-per-second",
} "total-requests",
catch (Exception ex) "current-requests",
{ "failed-requests"
return ex; });
}
var hostingEventSource = GetHostingEventSource();
using var timeoutTokenSource = new CancellationTokenSource(TimeSpan.FromSeconds(5));
var rpsValues = eventListener.GetCounterValues("requests-per-second", timeoutTokenSource.Token).GetAsyncEnumerator();
var totalRequestValues = eventListener.GetCounterValues("total-requests", timeoutTokenSource.Token).GetAsyncEnumerator();
var currentRequestValues = eventListener.GetCounterValues("current-requests", timeoutTokenSource.Token).GetAsyncEnumerator();
var failedRequestValues = eventListener.GetCounterValues("failed-requests", timeoutTokenSource.Token).GetAsyncEnumerator();
eventListener.EnableEvents(hostingEventSource, EventLevel.Informational, EventKeywords.None,
new Dictionary<string, string>
{
{ "EventCounterIntervalSec", "1" }
});
hostingEventSource.RequestStart("GET", "/");
Assert.Equal(1, await totalRequestValues.FirstOrDefault(v => v == 1));
Assert.Equal(1, await rpsValues.FirstOrDefault(v => v == 1));
Assert.Equal(1, await currentRequestValues.FirstOrDefault(v => v == 1));
Assert.Equal(0, await failedRequestValues.FirstOrDefault(v => v == 0));
hostingEventSource.RequestStop();
Assert.Equal(1, await totalRequestValues.FirstOrDefault(v => v == 1));
Assert.Equal(0, await rpsValues.FirstOrDefault(v => v == 0));
Assert.Equal(0, await currentRequestValues.FirstOrDefault(v => v == 0));
Assert.Equal(0, await failedRequestValues.FirstOrDefault(v => v == 0));
hostingEventSource.RequestStart("POST", "/");
Assert.Equal(2, await totalRequestValues.FirstOrDefault(v => v == 2));
Assert.Equal(1, await rpsValues.FirstOrDefault(v => v == 1));
Assert.Equal(1, await currentRequestValues.FirstOrDefault(v => v == 1));
Assert.Equal(0, await failedRequestValues.FirstOrDefault(v => v == 0));
hostingEventSource.RequestFailed();
hostingEventSource.RequestStop();
Assert.Equal(2, await totalRequestValues.FirstOrDefault(v => v == 2));
Assert.Equal(0, await rpsValues.FirstOrDefault(v => v == 0));
Assert.Equal(0, await currentRequestValues.FirstOrDefault(v => v == 0));
Assert.Equal(1, await failedRequestValues.FirstOrDefault(v => v == 1));
}
private static HostingEventSource GetHostingEventSource()
{
return new HostingEventSource(Guid.NewGuid().ToString());
} }
private class TestEventListener : EventListener private class TestEventListener : EventListener
@ -216,5 +263,36 @@ namespace Microsoft.AspNetCore.Hosting.Internal
} }
} }
} }
private class CounterListener : EventListener
{
private readonly Dictionary<string, Channel<double>> _counters = new Dictionary<string, Channel<double>>();
public CounterListener(string[] counterNames)
{
foreach (var item in counterNames)
{
_counters[item] = Channel.CreateUnbounded<double>();
}
}
public IAsyncEnumerable<double> GetCounterValues(string counterName, CancellationToken cancellationToken = default)
{
return _counters[counterName].Reader.ReadAllAsync(cancellationToken);
}
protected override void OnEventWritten(EventWrittenEventArgs eventData)
{
if (eventData.EventName == "EventCounters")
{
var payload = (IDictionary<string, object>)eventData.Payload[0];
var counter = (string)payload["Name"];
payload.TryGetValue("Increment", out var increment);
payload.TryGetValue("Mean", out var mean);
var writer = _counters[counter].Writer;
writer.TryWrite((double)(increment ?? mean));
}
}
}
} }
} }

View File

@ -19,6 +19,7 @@
<Reference Include="Microsoft.Extensions.Hosting" /> <Reference Include="Microsoft.Extensions.Hosting" />
<Reference Include="Microsoft.Extensions.Logging.Testing" /> <Reference Include="Microsoft.Extensions.Logging.Testing" />
<Reference Include="Microsoft.Extensions.Options" /> <Reference Include="Microsoft.Extensions.Options" />
<Reference Include="System.Threading.Channels" />
</ItemGroup> </ItemGroup>
</Project> </Project>