Remove KestrelEventSource events with broken ActivityId tracking (#26684)
* Remove KestrelEventSource events with broken ActivityId tracking * Skip test requiring ALPN on macOS
This commit is contained in:
parent
95b05188da
commit
053052d405
|
|
@ -144,54 +144,12 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure
|
|||
public void ConnectionQueuedStart(BaseConnectionContext connection)
|
||||
{
|
||||
Interlocked.Increment(ref _connectionQueueLength);
|
||||
if (IsEnabled())
|
||||
{
|
||||
ConnectionQueuedStart(
|
||||
connection.ConnectionId,
|
||||
connection.LocalEndPoint?.ToString(),
|
||||
connection.RemoteEndPoint?.ToString());
|
||||
}
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.NoInlining)]
|
||||
[Event(6, Level = EventLevel.Informational)]
|
||||
private void ConnectionQueuedStart(string connectionId,
|
||||
string localEndPoint,
|
||||
string remoteEndPoint)
|
||||
{
|
||||
WriteEvent(
|
||||
6,
|
||||
connectionId,
|
||||
localEndPoint,
|
||||
remoteEndPoint
|
||||
);
|
||||
}
|
||||
|
||||
[NonEvent]
|
||||
public void ConnectionQueuedStop(BaseConnectionContext connection)
|
||||
{
|
||||
Interlocked.Decrement(ref _connectionQueueLength);
|
||||
if (IsEnabled())
|
||||
{
|
||||
ConnectionQueuedStop(
|
||||
connection.ConnectionId,
|
||||
connection.LocalEndPoint?.ToString(),
|
||||
connection.RemoteEndPoint?.ToString());
|
||||
}
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.NoInlining)]
|
||||
[Event(7, Level = EventLevel.Informational)]
|
||||
private void ConnectionQueuedStop(string connectionId,
|
||||
string localEndPoint,
|
||||
string remoteEndPoint)
|
||||
{
|
||||
WriteEvent(
|
||||
7,
|
||||
connectionId,
|
||||
localEndPoint,
|
||||
remoteEndPoint
|
||||
);
|
||||
}
|
||||
|
||||
[NonEvent]
|
||||
|
|
@ -245,70 +203,24 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure
|
|||
public void RequestQueuedStart(HttpProtocol httpProtocol, string httpVersion)
|
||||
{
|
||||
Interlocked.Increment(ref _httpRequestQueueLength);
|
||||
// avoid allocating the trace identifier unless logging is enabled
|
||||
if (IsEnabled())
|
||||
{
|
||||
RequestQueuedStart(httpProtocol.ConnectionIdFeature, httpProtocol.TraceIdentifier, httpVersion);
|
||||
}
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.NoInlining)]
|
||||
[Event(11, Level = EventLevel.Informational)]
|
||||
private void RequestQueuedStart(string connectionId, string requestId, string httpVersion)
|
||||
{
|
||||
WriteEvent(11, connectionId, requestId, httpVersion);
|
||||
}
|
||||
|
||||
[NonEvent]
|
||||
public void RequestQueuedStop(HttpProtocol httpProtocol, string httpVersion)
|
||||
{
|
||||
Interlocked.Decrement(ref _httpRequestQueueLength);
|
||||
// avoid allocating the trace identifier unless logging is enabled
|
||||
if (IsEnabled())
|
||||
{
|
||||
RequestQueuedStop(httpProtocol.ConnectionIdFeature, httpProtocol.TraceIdentifier, httpVersion);
|
||||
}
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.NoInlining)]
|
||||
[Event(12, Level = EventLevel.Informational)]
|
||||
private void RequestQueuedStop(string connectionId, string requestId, string httpVersion)
|
||||
{
|
||||
WriteEvent(12, connectionId, requestId, httpVersion);
|
||||
}
|
||||
|
||||
[NonEvent]
|
||||
public void RequestUpgradedStart(HttpProtocol httpProtocol)
|
||||
{
|
||||
Interlocked.Increment(ref _currentUpgradedHttpRequests);
|
||||
if (IsEnabled())
|
||||
{
|
||||
RequestUpgradedStart(httpProtocol.ConnectionIdFeature, httpProtocol.TraceIdentifier, httpProtocol.HttpVersion, httpProtocol.Path, httpProtocol.MethodText);
|
||||
}
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.NoInlining)]
|
||||
[Event(13, Level = EventLevel.Informational)]
|
||||
private void RequestUpgradedStart(string connectionId, string requestId, string httpVersion, string path, string method)
|
||||
{
|
||||
WriteEvent(13, connectionId, requestId, httpVersion, path, method);
|
||||
}
|
||||
|
||||
[NonEvent]
|
||||
public void RequestUpgradedStop(HttpProtocol httpProtocol)
|
||||
{
|
||||
Interlocked.Decrement(ref _currentUpgradedHttpRequests);
|
||||
if (IsEnabled())
|
||||
{
|
||||
RequestUpgradedStop(httpProtocol.ConnectionIdFeature, httpProtocol.TraceIdentifier, httpProtocol.HttpVersion, httpProtocol.Path, httpProtocol.MethodText);
|
||||
}
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.NoInlining)]
|
||||
[Event(14, Level = EventLevel.Informational)]
|
||||
private void RequestUpgradedStop(string connectionId, string requestId, string httpVersion, string path, string method)
|
||||
{
|
||||
WriteEvent(14, connectionId, requestId, httpVersion, path, method);
|
||||
}
|
||||
|
||||
protected override void OnEventCommand(EventCommandEventArgs command)
|
||||
|
|
|
|||
|
|
@ -36,7 +36,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests.Http2
|
|||
|
||||
[ConditionalFact]
|
||||
[OSSkipCondition(OperatingSystems.Linux | OperatingSystems.Windows)]
|
||||
// Mac SslStream is missing ALPN support: https://github.com/dotnet/corefx/issues/30492
|
||||
// Mac SslStream is missing ALPN support: https://github.com/dotnet/runtime/issues/27727
|
||||
public void TlsAndHttp2NotSupportedOnMac()
|
||||
{
|
||||
var ex = Assert.Throws<NotSupportedException>(() => new TestServer(context =>
|
||||
|
|
@ -79,7 +79,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests.Http2
|
|||
}
|
||||
|
||||
[ConditionalFact]
|
||||
[OSSkipCondition(OperatingSystems.MacOSX, SkipReason = "Missing SslStream ALPN support: https://github.com/dotnet/corefx/issues/30492")]
|
||||
[OSSkipCondition(OperatingSystems.MacOSX, SkipReason = "Missing SslStream ALPN support: https://github.com/dotnet/runtime/issues/27727")]
|
||||
[MinimumOSVersion(OperatingSystems.Windows, WindowsVersions.Win10)]
|
||||
public async Task TlsAlpnHandshakeSelectsHttp2From1and2()
|
||||
{
|
||||
|
|
@ -107,7 +107,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests.Http2
|
|||
}
|
||||
|
||||
[ConditionalFact]
|
||||
[OSSkipCondition(OperatingSystems.MacOSX, SkipReason = "Missing SslStream ALPN support: https://github.com/dotnet/corefx/issues/30492")]
|
||||
[OSSkipCondition(OperatingSystems.MacOSX, SkipReason = "Missing SslStream ALPN support: https://github.com/dotnet/runtime/issues/27727")]
|
||||
[MinimumOSVersion(OperatingSystems.Windows, WindowsVersions.Win10)]
|
||||
public async Task TlsAlpnHandshakeSelectsHttp2()
|
||||
{
|
||||
|
|
|
|||
|
|
@ -21,7 +21,7 @@ using Xunit;
|
|||
|
||||
namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests.Http2
|
||||
{
|
||||
[OSSkipCondition(OperatingSystems.MacOSX, SkipReason = "Missing SslStream ALPN support: https://github.com/dotnet/corefx/issues/30492")]
|
||||
[OSSkipCondition(OperatingSystems.MacOSX, SkipReason = "Missing SslStream ALPN support: https://github.com/dotnet/runtime/issues/27727")]
|
||||
[MinimumOSVersion(OperatingSystems.Windows, WindowsVersions.Win10)]
|
||||
public class ShutdownTests : TestApplicationErrorLoggerLoggedTest
|
||||
{
|
||||
|
|
|
|||
|
|
@ -1,108 +1,518 @@
|
|||
// 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.Concurrent;
|
||||
using System.Collections.Generic;
|
||||
using System.Diagnostics.Tracing;
|
||||
using System.IO;
|
||||
using System.Linq;
|
||||
using System.Net.Http;
|
||||
using System.Net.Security;
|
||||
using System.Security.Authentication;
|
||||
using System.Security.Cryptography.X509Certificates;
|
||||
using System.Text.Json;
|
||||
using System.Threading;
|
||||
using System.Threading.Tasks;
|
||||
using Microsoft.AspNetCore.Connections;
|
||||
using Microsoft.AspNetCore.Hosting;
|
||||
using Microsoft.AspNetCore.Http.Features;
|
||||
using Microsoft.AspNetCore.Server.Kestrel.Core;
|
||||
using Microsoft.AspNetCore.Server.Kestrel.Core.Internal;
|
||||
using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure;
|
||||
using Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests.TestTransport;
|
||||
using Microsoft.AspNetCore.Testing;
|
||||
using Microsoft.Extensions.Logging;
|
||||
using Xunit;
|
||||
|
||||
namespace Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests
|
||||
{
|
||||
public class EventSourceTests : LoggedTest
|
||||
{
|
||||
private readonly TestEventListener _listener = new TestEventListener();
|
||||
private static readonly X509Certificate2 _x509Certificate2 = TestResources.GetTestCertificate();
|
||||
|
||||
public EventSourceTests()
|
||||
{
|
||||
_listener.EnableEvents(KestrelEventSource.Log, EventLevel.Verbose);
|
||||
}
|
||||
// To log all KestrelEventSource events, add `_listener = new TestEventListener(Logger);` to the start of the test method.
|
||||
// We could always construct TestEventListener with the test logger, but other concurrent tests could make this noisy.
|
||||
private TestEventListener _listener = new TestEventListener();
|
||||
|
||||
[Fact]
|
||||
public async Task EmitsConnectionStartAndStop()
|
||||
public async Task Http1_EmitsStartAndStopEventsWithActivityIds()
|
||||
{
|
||||
string connectionId = null;
|
||||
string requestId = null;
|
||||
int port;
|
||||
string connectionId = null;
|
||||
|
||||
const int requestsToSend = 2;
|
||||
var requestIds = new string[requestsToSend];
|
||||
var requestsReceived = 0;
|
||||
|
||||
await using (var server = new TestServer(async context =>
|
||||
{
|
||||
connectionId = context.Features.Get<IHttpConnectionFeature>().ConnectionId;
|
||||
requestIds[requestsReceived++] = context.TraceIdentifier;
|
||||
|
||||
var upgradeFeature = context.Features.Get<IHttpUpgradeFeature>();
|
||||
|
||||
if (upgradeFeature.IsUpgradableRequest)
|
||||
{
|
||||
await upgradeFeature.UpgradeAsync();
|
||||
}
|
||||
},
|
||||
new TestServiceContext(LoggerFactory)))
|
||||
{
|
||||
port = server.Port;
|
||||
|
||||
using var connection = server.CreateConnection();
|
||||
|
||||
await connection.SendEmptyGet();
|
||||
await connection.Receive(
|
||||
"HTTP/1.1 200 OK",
|
||||
$"Date: {server.Context.DateHeaderValue}",
|
||||
"Content-Length: 0",
|
||||
"",
|
||||
"");
|
||||
|
||||
await connection.SendEmptyGetWithUpgrade();
|
||||
await connection.ReceiveEnd("HTTP/1.1 101 Switching Protocols",
|
||||
"Connection: Upgrade",
|
||||
$"Date: {server.Context.DateHeaderValue}",
|
||||
"",
|
||||
"");
|
||||
}
|
||||
|
||||
Assert.NotNull(connectionId);
|
||||
Assert.Equal(2, requestsReceived);
|
||||
|
||||
// Other tests executing in parallel may log events.
|
||||
var events = _listener.EventData.Where(e => e != null && GetProperty(e, "connectionId") == connectionId).ToList();
|
||||
var eventIndex = 0;
|
||||
|
||||
var connectionStart = events[eventIndex++];
|
||||
Assert.Equal("ConnectionStart", connectionStart.EventName);
|
||||
Assert.Equal(1, connectionStart.EventId);
|
||||
Assert.All(new[] { "connectionId", "remoteEndPoint", "localEndPoint" }, p => Assert.Contains(p, connectionStart.PayloadNames));
|
||||
Assert.Equal($"127.0.0.1:{port}", GetProperty(connectionStart, "localEndPoint"));
|
||||
Assert.Same(KestrelEventSource.Log, connectionStart.EventSource);
|
||||
Assert.NotEqual(Guid.Empty, connectionStart.ActivityId);
|
||||
|
||||
var firstRequestStart = events[eventIndex++];
|
||||
Assert.Equal("RequestStart", firstRequestStart.EventName);
|
||||
Assert.Equal(3, firstRequestStart.EventId);
|
||||
Assert.All(new[] { "connectionId", "requestId" }, p => Assert.Contains(p, firstRequestStart.PayloadNames));
|
||||
Assert.Equal(requestIds[0], GetProperty(firstRequestStart, "requestId"));
|
||||
Assert.Same(KestrelEventSource.Log, firstRequestStart.EventSource);
|
||||
Assert.NotEqual(Guid.Empty, firstRequestStart.ActivityId);
|
||||
Assert.Equal(connectionStart.ActivityId, firstRequestStart.RelatedActivityId);
|
||||
|
||||
var firstRequestStop = events[eventIndex++];
|
||||
Assert.Equal("RequestStop", firstRequestStop.EventName);
|
||||
Assert.Equal(4, firstRequestStop.EventId);
|
||||
Assert.All(new[] { "connectionId", "requestId" }, p => Assert.Contains(p, firstRequestStop.PayloadNames));
|
||||
Assert.Same(KestrelEventSource.Log, firstRequestStop.EventSource);
|
||||
Assert.Equal(requestIds[0], GetProperty(firstRequestStop, "requestId"));
|
||||
Assert.Equal(firstRequestStart.ActivityId, firstRequestStop.ActivityId);
|
||||
Assert.Equal(Guid.Empty, firstRequestStop.RelatedActivityId);
|
||||
|
||||
var secondRequestStart = events[eventIndex++];
|
||||
Assert.Equal("RequestStart", secondRequestStart.EventName);
|
||||
Assert.Equal(3, secondRequestStart.EventId);
|
||||
Assert.All(new[] { "connectionId", "requestId" }, p => Assert.Contains(p, secondRequestStart.PayloadNames));
|
||||
Assert.Equal(requestIds[1], GetProperty(secondRequestStart, "requestId"));
|
||||
Assert.Same(KestrelEventSource.Log, secondRequestStart.EventSource);
|
||||
Assert.NotEqual(Guid.Empty, secondRequestStart.ActivityId);
|
||||
Assert.Equal(connectionStart.ActivityId, secondRequestStart.RelatedActivityId);
|
||||
|
||||
var secondRequestStop = events[eventIndex++];
|
||||
Assert.Equal("RequestStop", secondRequestStop.EventName);
|
||||
Assert.Equal(4, secondRequestStop.EventId);
|
||||
Assert.All(new[] { "connectionId", "requestId" }, p => Assert.Contains(p, secondRequestStop.PayloadNames));
|
||||
Assert.Same(KestrelEventSource.Log, secondRequestStop.EventSource);
|
||||
Assert.Equal(requestIds[1], GetProperty(secondRequestStop, "requestId"));
|
||||
Assert.Equal(secondRequestStart.ActivityId, secondRequestStop.ActivityId);
|
||||
Assert.Equal(Guid.Empty, secondRequestStop.RelatedActivityId);
|
||||
|
||||
var connectionStop = events[eventIndex++];
|
||||
Assert.Equal("ConnectionStop", connectionStop.EventName);
|
||||
Assert.Equal(2, connectionStop.EventId);
|
||||
Assert.All(new[] { "connectionId" }, p => Assert.Contains(p, connectionStop.PayloadNames));
|
||||
Assert.Same(KestrelEventSource.Log, connectionStop.EventSource);
|
||||
Assert.Equal(connectionStart.ActivityId, connectionStop.ActivityId);
|
||||
Assert.Equal(Guid.Empty, connectionStop.RelatedActivityId);
|
||||
|
||||
Assert.Equal(eventIndex, events.Count);
|
||||
}
|
||||
|
||||
[ConditionalFact]
|
||||
[OSSkipCondition(OperatingSystems.MacOSX, SkipReason = "Missing SslStream ALPN support: https://github.com/dotnet/runtime/issues/27727")]
|
||||
[MinimumOSVersion(OperatingSystems.Windows, WindowsVersions.Win10)]
|
||||
public async Task Http2_EmitsStartAndStopEventsWithActivityIds()
|
||||
{
|
||||
int port;
|
||||
string connectionId = null;
|
||||
|
||||
const int requestsToSend = 2;
|
||||
var requestIds = new string[requestsToSend];
|
||||
var requestsReceived = 0;
|
||||
|
||||
await using (var server = new TestServer(context =>
|
||||
{
|
||||
connectionId = context.Features.Get<IHttpConnectionFeature>().ConnectionId;
|
||||
requestId = context.TraceIdentifier;
|
||||
requestIds[requestsReceived++] = context.TraceIdentifier;
|
||||
return Task.CompletedTask;
|
||||
}, new TestServiceContext(LoggerFactory)))
|
||||
},
|
||||
new TestServiceContext(LoggerFactory),
|
||||
listenOptions =>
|
||||
{
|
||||
listenOptions.UseHttps(_x509Certificate2);
|
||||
listenOptions.Protocols = HttpProtocols.Http2;
|
||||
}))
|
||||
{
|
||||
port = server.Port;
|
||||
using (var connection = server.CreateConnection())
|
||||
|
||||
using var connection = server.CreateConnection();
|
||||
|
||||
using var socketsHandler = new SocketsHttpHandler()
|
||||
{
|
||||
await connection.SendAll("GET / HTTP/1.1",
|
||||
"Host:",
|
||||
"",
|
||||
"")
|
||||
.DefaultTimeout();
|
||||
await connection.Receive("HTTP/1.1 200");
|
||||
ConnectCallback = (_, _) =>
|
||||
{
|
||||
// This test should only require a single connection.
|
||||
if (connectionId != null)
|
||||
{
|
||||
throw new InvalidOperationException();
|
||||
}
|
||||
|
||||
return new ValueTask<Stream>(connection.Stream);
|
||||
},
|
||||
SslOptions = new SslClientAuthenticationOptions
|
||||
{
|
||||
RemoteCertificateValidationCallback = (_, _, _, _) => true
|
||||
}
|
||||
};
|
||||
|
||||
using var httpClient = new HttpClient(socketsHandler);
|
||||
|
||||
for (int i = 0; i < requestsToSend; i++)
|
||||
{
|
||||
using var httpRequestMessage = new HttpRequestMessage()
|
||||
{
|
||||
RequestUri = new Uri("https://localhost/"),
|
||||
Version = new Version(2, 0),
|
||||
VersionPolicy = HttpVersionPolicy.RequestVersionExact,
|
||||
};
|
||||
|
||||
using var responseMessage = await httpClient.SendAsync(httpRequestMessage);
|
||||
responseMessage.EnsureSuccessStatusCode();
|
||||
}
|
||||
}
|
||||
|
||||
// capture list here as other tests executing in parallel may log events
|
||||
Assert.NotNull(connectionId);
|
||||
Assert.NotNull(requestId);
|
||||
Assert.Equal(2, requestsReceived);
|
||||
|
||||
// Other tests executing in parallel may log events.
|
||||
var events = _listener.EventData.Where(e => e != null && GetProperty(e, "connectionId") == connectionId).ToList();
|
||||
var eventIndex = 0;
|
||||
|
||||
var connectionStart = events[eventIndex++];
|
||||
Assert.Equal("ConnectionStart", connectionStart.EventName);
|
||||
Assert.Equal(1, connectionStart.EventId);
|
||||
Assert.All(new[] { "connectionId", "remoteEndPoint", "localEndPoint" }, p => Assert.Contains(p, connectionStart.PayloadNames));
|
||||
Assert.Same(KestrelEventSource.Log, connectionStart.EventSource);
|
||||
Assert.Equal($"127.0.0.1:{port}", GetProperty(connectionStart, "localEndPoint"));
|
||||
Assert.NotEqual(Guid.Empty, connectionStart.ActivityId);
|
||||
|
||||
var tlsHandshakeStart = events[eventIndex++];
|
||||
Assert.Equal("TlsHandshakeStart", tlsHandshakeStart.EventName);
|
||||
Assert.Equal(8, tlsHandshakeStart.EventId);
|
||||
Assert.All(new[] { "connectionId", "sslProtocols" }, p => Assert.Contains(p, tlsHandshakeStart.PayloadNames));
|
||||
Assert.Same(KestrelEventSource.Log, tlsHandshakeStart.EventSource);
|
||||
Assert.NotEqual(Guid.Empty, tlsHandshakeStart.ActivityId);
|
||||
Assert.Equal(connectionStart.ActivityId, tlsHandshakeStart.RelatedActivityId);
|
||||
|
||||
var tlsHandshakeStop = events[eventIndex++];
|
||||
Assert.Equal("TlsHandshakeStop", tlsHandshakeStop.EventName);
|
||||
Assert.Equal(9, tlsHandshakeStop.EventId);
|
||||
Assert.All(new[] { "connectionId", "sslProtocols", "applicationProtocol", "hostName" }, p => Assert.Contains(p, tlsHandshakeStop.PayloadNames));
|
||||
Assert.Equal("h2", GetProperty(tlsHandshakeStop, "applicationProtocol"));
|
||||
Assert.Same(KestrelEventSource.Log, tlsHandshakeStop.EventSource);
|
||||
Assert.Equal(tlsHandshakeStart.ActivityId, tlsHandshakeStop.ActivityId);
|
||||
Assert.Equal(Guid.Empty, tlsHandshakeStop.RelatedActivityId);
|
||||
|
||||
for (int i = 0; i < requestsToSend; i++)
|
||||
{
|
||||
var start = Assert.Single(events, e => e.EventName == "ConnectionStart");
|
||||
Assert.All(new[] { "connectionId", "remoteEndPoint", "localEndPoint" }, p => Assert.Contains(p, start.PayloadNames));
|
||||
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, stop.PayloadNames));
|
||||
Assert.Same(KestrelEventSource.Log, stop.EventSource);
|
||||
}
|
||||
{
|
||||
var requestStart = Assert.Single(events, e => e.EventName == "RequestStart");
|
||||
var requestStart = events[eventIndex++];
|
||||
Assert.Equal("RequestStart", requestStart.EventName);
|
||||
Assert.Equal(3, requestStart.EventId);
|
||||
Assert.All(new[] { "connectionId", "requestId" }, p => Assert.Contains(p, requestStart.PayloadNames));
|
||||
Assert.Equal(requestId, GetProperty(requestStart, "requestId"));
|
||||
Assert.Equal(requestIds[i], GetProperty(requestStart, "requestId"));
|
||||
Assert.Same(KestrelEventSource.Log, requestStart.EventSource);
|
||||
}
|
||||
{
|
||||
var requestStop = Assert.Single(events, e => e.EventName == "RequestStop");
|
||||
Assert.NotEqual(Guid.Empty, requestStart.ActivityId);
|
||||
Assert.Equal(connectionStart.ActivityId, requestStart.RelatedActivityId);
|
||||
|
||||
var requestStop = events[eventIndex++];
|
||||
Assert.Equal("RequestStop", requestStop.EventName);
|
||||
Assert.Equal(4, requestStop.EventId);
|
||||
Assert.All(new[] { "connectionId", "requestId" }, p => Assert.Contains(p, requestStop.PayloadNames));
|
||||
Assert.Equal(requestId, GetProperty(requestStop, "requestId"));
|
||||
Assert.Same(KestrelEventSource.Log, requestStop.EventSource);
|
||||
Assert.Equal(requestIds[i], GetProperty(requestStop, "requestId"));
|
||||
Assert.Equal(requestStart.ActivityId, requestStop.ActivityId);
|
||||
Assert.Equal(Guid.Empty, requestStop.RelatedActivityId);
|
||||
}
|
||||
|
||||
var connectionStop = events[eventIndex++];
|
||||
Assert.Equal("ConnectionStop", connectionStop.EventName);
|
||||
Assert.Equal(2, connectionStop.EventId);
|
||||
Assert.All(new[] { "connectionId" }, p => Assert.Contains(p, connectionStop.PayloadNames));
|
||||
Assert.Same(KestrelEventSource.Log, connectionStop.EventSource);
|
||||
Assert.Equal(connectionStart.ActivityId, connectionStop.ActivityId);
|
||||
Assert.Equal(Guid.Empty, connectionStop.RelatedActivityId);
|
||||
|
||||
Assert.Equal(eventIndex, events.Count);
|
||||
}
|
||||
|
||||
private string GetProperty(EventWrittenEventArgs data, string propName)
|
||||
=> data.Payload[data.PayloadNames.IndexOf(propName)] as string;
|
||||
[Fact]
|
||||
public async Task TlsHandshakeFailure_EmitsStartAndStopEventsWithActivityIds()
|
||||
{
|
||||
int port;
|
||||
string connectionId = null;
|
||||
|
||||
await using (var server = new TestServer(context => Task.CompletedTask, new TestServiceContext(LoggerFactory),
|
||||
listenOptions =>
|
||||
{
|
||||
listenOptions.Use(next =>
|
||||
{
|
||||
return connectionContext =>
|
||||
{
|
||||
connectionId = connectionContext.ConnectionId;
|
||||
return next(connectionContext);
|
||||
};
|
||||
});
|
||||
|
||||
listenOptions.UseHttps(_x509Certificate2);
|
||||
}))
|
||||
{
|
||||
port = server.Port;
|
||||
|
||||
using var connection = server.CreateConnection();
|
||||
await using var sslStream = new SslStream(connection.Stream);
|
||||
|
||||
var clientAuthOptions = new SslClientAuthenticationOptions
|
||||
{
|
||||
TargetHost = "localhost",
|
||||
|
||||
// Only enabling SslProtocols.Ssl2 should cause a handshake failure on all platforms.
|
||||
#pragma warning disable CS0618 // Type or member is obsolete
|
||||
EnabledSslProtocols = SslProtocols.Ssl2,
|
||||
#pragma warning restore CS0618 // Type or member is obsolete
|
||||
};
|
||||
|
||||
using var handshakeCts = new CancellationTokenSource(TestConstants.DefaultTimeout);
|
||||
await Assert.ThrowsAnyAsync<Exception>(() => sslStream.AuthenticateAsClientAsync(clientAuthOptions, handshakeCts.Token));
|
||||
}
|
||||
|
||||
Assert.NotNull(connectionId);
|
||||
|
||||
// Other tests executing in parallel may log events.
|
||||
var events = _listener.EventData.Where(e => e != null && GetProperty(e, "connectionId") == connectionId).ToList();
|
||||
var eventIndex = 0;
|
||||
|
||||
var connectionStart = events[eventIndex++];
|
||||
Assert.Equal("ConnectionStart", connectionStart.EventName);
|
||||
Assert.Equal(1, connectionStart.EventId);
|
||||
Assert.All(new[] { "connectionId", "remoteEndPoint", "localEndPoint" }, p => Assert.Contains(p, connectionStart.PayloadNames));
|
||||
Assert.Equal($"127.0.0.1:{port}", GetProperty(connectionStart, "localEndPoint"));
|
||||
Assert.Same(KestrelEventSource.Log, connectionStart.EventSource);
|
||||
Assert.NotEqual(Guid.Empty, connectionStart.ActivityId);
|
||||
|
||||
var tlsHandshakeStart = events[eventIndex++];
|
||||
Assert.Equal("TlsHandshakeStart", tlsHandshakeStart.EventName);
|
||||
Assert.Equal(8, tlsHandshakeStart.EventId);
|
||||
Assert.All(new[] { "connectionId", "sslProtocols" }, p => Assert.Contains(p, tlsHandshakeStart.PayloadNames));
|
||||
Assert.Same(KestrelEventSource.Log, tlsHandshakeStart.EventSource);
|
||||
Assert.NotEqual(Guid.Empty, tlsHandshakeStart.ActivityId);
|
||||
Assert.Equal(connectionStart.ActivityId, tlsHandshakeStart.RelatedActivityId);
|
||||
|
||||
var tlsHandshakeFailed = events[eventIndex++];
|
||||
Assert.Equal("TlsHandshakeFailed", tlsHandshakeFailed.EventName);
|
||||
Assert.Equal(10, tlsHandshakeFailed.EventId);
|
||||
Assert.All(new[] { "connectionId" }, p => Assert.Contains(p, tlsHandshakeFailed.PayloadNames));
|
||||
Assert.Same(KestrelEventSource.Log, tlsHandshakeFailed.EventSource);
|
||||
Assert.Equal(tlsHandshakeStart.ActivityId, tlsHandshakeFailed.ActivityId);
|
||||
Assert.Equal(Guid.Empty, tlsHandshakeFailed.RelatedActivityId);
|
||||
|
||||
var tlsHandshakeStop = events[eventIndex++];
|
||||
Assert.Equal("TlsHandshakeStop", tlsHandshakeStop.EventName);
|
||||
Assert.Equal(9, tlsHandshakeStop.EventId);
|
||||
Assert.All(new[] { "connectionId", "sslProtocols", "applicationProtocol", "hostName" }, p => Assert.Contains(p, tlsHandshakeStop.PayloadNames));
|
||||
Assert.Same(KestrelEventSource.Log, tlsHandshakeStop.EventSource);
|
||||
Assert.Equal(tlsHandshakeStart.ActivityId, tlsHandshakeStop.ActivityId);
|
||||
Assert.Equal(Guid.Empty, tlsHandshakeStop.RelatedActivityId);
|
||||
|
||||
var connectionStop = events[eventIndex++];
|
||||
Assert.Equal("ConnectionStop", connectionStop.EventName);
|
||||
Assert.Equal(2, connectionStop.EventId);
|
||||
Assert.All(new[] { "connectionId" }, p => Assert.Contains(p, connectionStop.PayloadNames));
|
||||
Assert.Same(KestrelEventSource.Log, connectionStop.EventSource);
|
||||
Assert.Equal(connectionStart.ActivityId, connectionStop.ActivityId);
|
||||
Assert.Equal(Guid.Empty, connectionStop.RelatedActivityId);
|
||||
|
||||
Assert.Equal(eventIndex, events.Count);
|
||||
}
|
||||
|
||||
[Fact]
|
||||
public async Task ConnectionLimitExceeded_EmitsStartAndStopEventsWithActivityIds()
|
||||
{
|
||||
int port;
|
||||
string connectionId = null;
|
||||
|
||||
var serviceContext = new TestServiceContext(LoggerFactory);
|
||||
|
||||
await using (var server = new TestServer(context => Task.CompletedTask, serviceContext,
|
||||
listenOptions =>
|
||||
{
|
||||
listenOptions.Use(next =>
|
||||
{
|
||||
return connectionContext =>
|
||||
{
|
||||
connectionId = connectionContext.ConnectionId;
|
||||
return next(connectionContext);
|
||||
};
|
||||
});
|
||||
|
||||
listenOptions.Use(next =>
|
||||
{
|
||||
return new ConnectionLimitMiddleware<ConnectionContext>(c => next(c), connectionLimit: 0, serviceContext.Log).OnConnectionAsync;
|
||||
});
|
||||
}))
|
||||
{
|
||||
port = server.Port;
|
||||
|
||||
using var connection = server.CreateConnection();
|
||||
await connection.ReceiveEnd();
|
||||
}
|
||||
|
||||
Assert.NotNull(connectionId);
|
||||
|
||||
// Other tests executing in parallel may log events.
|
||||
var events = _listener.EventData.Where(e => e != null && GetProperty(e, "connectionId") == connectionId).ToList();
|
||||
var eventIndex = 0;
|
||||
|
||||
var connectionStart = events[eventIndex++];
|
||||
Assert.Equal("ConnectionStart", connectionStart.EventName);
|
||||
Assert.Equal(1, connectionStart.EventId);
|
||||
Assert.All(new[] { "connectionId", "remoteEndPoint", "localEndPoint" }, p => Assert.Contains(p, connectionStart.PayloadNames));
|
||||
Assert.Equal($"127.0.0.1:{port}", GetProperty(connectionStart, "localEndPoint"));
|
||||
Assert.Same(KestrelEventSource.Log, connectionStart.EventSource);
|
||||
Assert.NotEqual(Guid.Empty, connectionStart.ActivityId);
|
||||
|
||||
var connectionRejected = events[eventIndex++];
|
||||
Assert.Equal("ConnectionRejected", connectionRejected.EventName);
|
||||
Assert.Equal(5, connectionRejected.EventId);
|
||||
Assert.All(new[] { "connectionId" }, p => Assert.Contains(p, connectionRejected.PayloadNames));
|
||||
Assert.Same(KestrelEventSource.Log, connectionRejected.EventSource);
|
||||
Assert.Equal(connectionStart.ActivityId, connectionRejected.ActivityId);
|
||||
Assert.Equal(Guid.Empty, connectionRejected.RelatedActivityId);
|
||||
|
||||
var connectionStop = events[eventIndex++];
|
||||
Assert.Equal("ConnectionStop", connectionStop.EventName);
|
||||
Assert.Equal(2, connectionStop.EventId);
|
||||
Assert.All(new[] { "connectionId" }, p => Assert.Contains(p, connectionStop.PayloadNames));
|
||||
Assert.Same(KestrelEventSource.Log, connectionStop.EventSource);
|
||||
Assert.Equal(connectionStart.ActivityId, connectionStop.ActivityId);
|
||||
Assert.Equal(Guid.Empty, connectionStop.RelatedActivityId);
|
||||
|
||||
Assert.Equal(eventIndex, events.Count);
|
||||
}
|
||||
|
||||
private string GetProperty(EventSnapshot data, string propName) => data.Payload[propName];
|
||||
|
||||
private class TestEventListener : EventListener
|
||||
{
|
||||
private volatile bool _disposed;
|
||||
private ConcurrentQueue<EventWrittenEventArgs> _events = new ConcurrentQueue<EventWrittenEventArgs>();
|
||||
private readonly ConcurrentQueue<EventSnapshot> _events = new ConcurrentQueue<EventSnapshot>();
|
||||
private readonly ILogger _logger;
|
||||
|
||||
public IEnumerable<EventWrittenEventArgs> EventData => _events;
|
||||
private readonly object _disposeLock = new object();
|
||||
private bool _disposed;
|
||||
|
||||
public TestEventListener()
|
||||
{
|
||||
EnableEvents(KestrelEventSource.Log, EventLevel.Verbose);
|
||||
}
|
||||
|
||||
public TestEventListener(ILogger logger)
|
||||
: this()
|
||||
{
|
||||
_logger = logger;
|
||||
}
|
||||
|
||||
public IEnumerable<EventSnapshot> EventData => _events;
|
||||
|
||||
protected override void OnEventSourceCreated(EventSource eventSource)
|
||||
{
|
||||
if (eventSource.Name == "System.Threading.Tasks.TplEventSource")
|
||||
{
|
||||
// Enable TasksFlowActivityIds
|
||||
EnableEvents(eventSource, EventLevel.Informational, (EventKeywords)0x80);
|
||||
}
|
||||
}
|
||||
|
||||
protected override void OnEventWritten(EventWrittenEventArgs eventData)
|
||||
{
|
||||
if (!_disposed)
|
||||
lock (_disposeLock)
|
||||
{
|
||||
_events.Enqueue(eventData);
|
||||
if (_disposed)
|
||||
{
|
||||
return;
|
||||
}
|
||||
|
||||
_logger?.LogInformation("{event}", JsonSerializer.Serialize(eventData, new JsonSerializerOptions
|
||||
{
|
||||
WriteIndented = true
|
||||
}));
|
||||
|
||||
// EventWrittenEventArgs.ActivityId sometimes falls back to EventSource.CurrentThreadActivityId,
|
||||
// so we need to take a snapshot to verify the ActivityId later on a different thread.
|
||||
// https://github.com/dotnet/runtime/blob/85162fbf9ccdeb4fa1df357f27308ae96579c066/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/EventSource.cs#L4551
|
||||
_events.Enqueue(new EventSnapshot(eventData));
|
||||
}
|
||||
}
|
||||
|
||||
public override void Dispose()
|
||||
{
|
||||
_disposed = true;
|
||||
lock (_disposeLock)
|
||||
{
|
||||
_disposed = true;
|
||||
}
|
||||
|
||||
base.Dispose();
|
||||
}
|
||||
}
|
||||
|
||||
private class EventSnapshot
|
||||
{
|
||||
public EventSnapshot(EventWrittenEventArgs eventWrittenEventArgs)
|
||||
{
|
||||
EventName = eventWrittenEventArgs.EventName;
|
||||
EventId = eventWrittenEventArgs.EventId;
|
||||
EventSource = eventWrittenEventArgs.EventSource;
|
||||
ActivityId = eventWrittenEventArgs.ActivityId;
|
||||
RelatedActivityId = eventWrittenEventArgs.RelatedActivityId;
|
||||
Payload = new Dictionary<string, string>(eventWrittenEventArgs.PayloadNames.Count);
|
||||
|
||||
for (int i = 0; i < eventWrittenEventArgs.PayloadNames.Count; i++)
|
||||
{
|
||||
Payload[eventWrittenEventArgs.PayloadNames[i]] = eventWrittenEventArgs.Payload[i] as string;
|
||||
}
|
||||
}
|
||||
|
||||
public string EventName { get; }
|
||||
public int EventId { get; }
|
||||
public EventSource EventSource { get; }
|
||||
public Guid ActivityId { get; }
|
||||
public Guid RelatedActivityId { get; }
|
||||
public Dictionary<string, string> Payload { get; }
|
||||
|
||||
public IEnumerable<string> PayloadNames => Payload.Keys;
|
||||
}
|
||||
|
||||
public override void Dispose()
|
||||
{
|
||||
_listener.Dispose();
|
||||
|
|
|
|||
|
|
@ -21,7 +21,7 @@ using Xunit;
|
|||
|
||||
namespace Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests.Http2
|
||||
{
|
||||
[OSSkipCondition(OperatingSystems.MacOSX, SkipReason = "Missing SslStream ALPN support: https://github.com/dotnet/corefx/issues/30492")]
|
||||
[OSSkipCondition(OperatingSystems.MacOSX, SkipReason = "Missing SslStream ALPN support: https://github.com/dotnet/runtime/issues/27727")]
|
||||
[MinimumOSVersion(OperatingSystems.Windows, WindowsVersions.Win10,
|
||||
SkipReason = "Missing Windows ALPN support: https://en.wikipedia.org/wiki/Application-Layer_Protocol_Negotiation#Support or incompatible ciphers on Windows 8.1")]
|
||||
public class TlsTests : LoggedTest
|
||||
|
|
|
|||
|
|
@ -733,7 +733,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests
|
|||
[InlineData(HttpProtocols.Http1)]
|
||||
[InlineData(HttpProtocols.Http2)]
|
||||
[InlineData(HttpProtocols.Http1AndHttp2)]
|
||||
[OSSkipCondition(OperatingSystems.MacOSX, SkipReason = "Missing SslStream ALPN support: https://github.com/dotnet/corefx/issues/30492")]
|
||||
[OSSkipCondition(OperatingSystems.MacOSX, SkipReason = "Missing SslStream ALPN support: https://github.com/dotnet/runtime/issues/27727")]
|
||||
[MinimumOSVersion(OperatingSystems.Windows, WindowsVersions.Win10)]
|
||||
public async Task ListenOptionsProtolsCanBeSetAfterUseHttps(HttpProtocols httpProtocols)
|
||||
{
|
||||
|
|
|
|||
|
|
@ -64,7 +64,7 @@ namespace Interop.FunctionalTests
|
|||
}
|
||||
|
||||
[ConditionalTheory(Skip = "Disabling while debugging. https://github.com/dotnet/aspnetcore-internal/issues/1363")]
|
||||
[OSSkipCondition(OperatingSystems.MacOSX, SkipReason = "Missing SslStream ALPN support: https://github.com/dotnet/corefx/issues/30492")]
|
||||
[OSSkipCondition(OperatingSystems.MacOSX, SkipReason = "Missing SslStream ALPN support: https://github.com/dotnet/runtime/issues/27727")]
|
||||
[MinimumOSVersion(OperatingSystems.Windows, WindowsVersions.Win81, SkipReason = "Missing Windows ALPN support: https://en.wikipedia.org/wiki/Application-Layer_Protocol_Negotiation#Support")]
|
||||
[InlineData("", "Interop HTTP/2 GET")]
|
||||
[InlineData("?TestMethod=POST", "Interop HTTP/2 POST")]
|
||||
|
|
|
|||
|
|
@ -11,7 +11,7 @@ namespace Interop.FunctionalTests
|
|||
{
|
||||
return // "Missing Windows ALPN support: https://en.wikipedia.org/wiki/Application-Layer_Protocol_Negotiation#Support" or missing compatible ciphers (Win8.1)
|
||||
new MinimumOSVersionAttribute(OperatingSystems.Windows, WindowsVersions.Win10).IsMet
|
||||
// "Missing SslStream ALPN support: https://github.com/dotnet/corefx/issues/30492"
|
||||
// "Missing SslStream ALPN support: https://github.com/dotnet/runtime/issues/27727"
|
||||
&& new OSSkipConditionAttribute(OperatingSystems.MacOSX).IsMet;
|
||||
}
|
||||
}
|
||||
|
|
|
|||
Loading…
Reference in New Issue