Skip to content

Move SignalR connection start telemetry to transport start #48753

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 2 commits into from
Jun 14, 2023
Merged

Move SignalR connection start telemetry to transport start #48753

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
155c0db
Change connection start to happen when transport is selected
JamesNK Jun 13, 2023
6cc56f6
Update src/SignalR/common/Http.Connections/src/Internal/HttpConnectio…
JamesNK Jun 13, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 2 additions & 0 deletions src/SignalR/common/Http.Connections/src/Internal/HttpConnectionContext.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -114,6 +114,8 @@ public HttpConnectionContext(string connectionId, string connectionToken, ILogge

public HttpTransportType TransportType { get; set; }

internal long StartTimestamp { get; set; }

public SemaphoreSlim WriteLock { get; } = new SemaphoreSlim(1, 1);

// Used for testing only
Expand Down
8 changes: 8 additions & 0 deletions src/SignalR/common/Http.Connections/src/Internal/HttpConnectionDispatcher.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@
// The .NET Foundation licenses this file to you under the MIT license.

using System.Buffers;
using System.Diagnostics;
using System.Security.Claims;
using System.Security.Principal;
using Microsoft.AspNetCore.Authentication;
Expand Down Expand Up @@ -552,7 +553,14 @@ private async Task<bool> EnsureConnectionStateAsync(HttpConnectionContext connec

if (connection.TransportType == HttpTransportType.None)
{
if (HttpConnectionsEventSource.Log.IsEnabled() || connection.MetricsContext.ConnectionDurationEnabled)
{
connection.StartTimestamp = Stopwatch.GetTimestamp();
}

connection.TransportType = transportType;

HttpConnectionsEventSource.Log.ConnectionStart(connection.ConnectionId);
_metrics.ConnectionTransportStart(connection.MetricsContext, transportType);
}
else if (connection.TransportType != transportType)
Expand Down
42 changes: 18 additions & 24 deletions src/SignalR/common/Http.Connections/src/Internal/HttpConnectionManager.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,8 +19,8 @@ internal sealed partial class HttpConnectionManager
// TODO: Consider making this configurable? At least for testing?
private static readonly TimeSpan _heartbeatTickRate = TimeSpan.FromSeconds(1);

private readonly ConcurrentDictionary<string, (HttpConnectionContext Connection, long StartTimestamp)> _connections =
new ConcurrentDictionary<string, (HttpConnectionContext Connection, long StartTimestamp)>(StringComparer.Ordinal);
private readonly ConcurrentDictionary<string, HttpConnectionContext> _connections =
new ConcurrentDictionary<string, HttpConnectionContext>(StringComparer.Ordinal);
private readonly PeriodicTimer _nextHeartbeat;
private readonly ILogger<HttpConnectionManager> _logger;
private readonly ILogger<HttpConnectionContext> _connectionLogger;
Expand Down Expand Up @@ -48,14 +48,7 @@ public void Start()

internal bool TryGetConnection(string id, [NotNullWhen(true)] out HttpConnectionContext? connection)
{
connection = null;

if (_connections.TryGetValue(id, out var pair))
{
connection = pair.Connection;
return true;
}
return false;
return _connections.TryGetValue(id, out connection);
}

internal HttpConnectionContext CreateConnection()
Expand All @@ -82,31 +75,32 @@ internal HttpConnectionContext CreateConnection(HttpConnectionDispatcherOptions

var metricsContext = _metrics.CreateContext();

var startTimestamp = HttpConnectionsEventSource.Log.IsEnabled() || metricsContext.ConnectionDurationEnabled
? Stopwatch.GetTimestamp()
: default;

Log.CreatedNewConnection(_logger, id);
HttpConnectionsEventSource.Log.ConnectionStart(id);

var pair = CreateConnectionPair(options.TransportPipeOptions, options.AppPipeOptions);
var connection = new HttpConnectionContext(id, connectionToken, _connectionLogger, metricsContext, pair.Application, pair.Transport, options, useAck);

_connections.TryAdd(connectionToken, (connection, startTimestamp));
_connections.TryAdd(connectionToken, connection);

return connection;
}

public void RemoveConnection(string id, HttpTransportType transportType, HttpConnectionStopStatus status)
{
if (_connections.TryRemove(id, out var pair))
// Remove the connection completely
if (_connections.TryRemove(id, out var connection))
{
// Remove the connection completely
var currentTimestamp = (pair.StartTimestamp > 0) ? Stopwatch.GetTimestamp() : default;
// A connection is considered started when the transport is negotiated.
// You can't stop something that hasn't started so only log connection stop events if there is a transport.
if (connection.TransportType != HttpTransportType.None)
{
var currentTimestamp = (connection.StartTimestamp > 0) ? Stopwatch.GetTimestamp() : default;

HttpConnectionsEventSource.Log.ConnectionStop(id, connection.StartTimestamp, currentTimestamp);
_metrics.TransportStop(connection.MetricsContext, transportType);
_metrics.ConnectionStop(connection.MetricsContext, transportType, status, connection.StartTimestamp, currentTimestamp);
}

HttpConnectionsEventSource.Log.ConnectionStop(id, pair.StartTimestamp, currentTimestamp);
_metrics.TransportStop(pair.Connection.MetricsContext, transportType);
_metrics.ConnectionStop(pair.Connection.MetricsContext, transportType, status, pair.StartTimestamp, currentTimestamp);
Log.RemovedConnection(_logger, id);
}
}
Expand Down Expand Up @@ -152,7 +146,7 @@ public void Scan()
// Scan the registered connections looking for ones that have timed out
foreach (var c in _connections)
{
var connection = c.Value.Connection;
var connection = c.Value;
// Capture the connection state
var lastSeenTick = connection.LastSeenTicksIfInactive;

Expand Down Expand Up @@ -200,7 +194,7 @@ public void CloseConnections()
foreach (var c in _connections)
{
// We're shutting down so don't wait for closing the application
tasks.Add(DisposeAndRemoveAsync(c.Value.Connection, closeGracefully: false, HttpConnectionStopStatus.AppShutdown));
tasks.Add(DisposeAndRemoveAsync(c.Value, closeGracefully: false, HttpConnectionStopStatus.AppShutdown));
}

Task.WaitAll(tasks.ToArray(), TimeSpan.FromSeconds(5));
Expand Down
57 changes: 48 additions & 9 deletions src/SignalR/common/Http.Connections/test/HttpConnectionDispatcherTests.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1121,21 +1121,60 @@ public async Task Metrics()
Assert.Collection(connectionDuration.GetMeasurements(), m => AssertDuration(m, HttpConnectionStopStatus.NormalClosure, HttpTransportType.LongPolling));
Assert.Collection(currentConnections.GetMeasurements(), m => AssertTransport(m, 1, HttpTransportType.LongPolling), m => AssertTransport(m, -1, HttpTransportType.LongPolling));
}
}

static void AssertTransport(Measurement<long> measurement, long expected, HttpTransportType transportType)
[Fact]
public async Task Metrics_ListenStartAfterConnection_Empty()
{
using (StartVerifiableLog())
{
Assert.Equal(expected, measurement.Value);
Assert.Equal(transportType.ToString(), (string)measurement.Tags.ToArray().Single(t => t.Key == "transport").Value);
}
var testMeterFactory = new TestMeterFactory();
var metrics = new HttpConnectionsMetrics(testMeterFactory);
var manager = CreateConnectionManager(LoggerFactory, metrics);
var connection = manager.CreateConnection();

static void AssertDuration(Measurement<double> measurement, HttpConnectionStopStatus status, HttpTransportType transportType)
{
Assert.True(measurement.Value > 0);
Assert.Equal(status.ToString(), (string)measurement.Tags.ToArray().Single(t => t.Key == "status").Value);
Assert.Equal(transportType.ToString(), (string)measurement.Tags.ToArray().Single(t => t.Key == "transport").Value);
var dispatcher = CreateDispatcher(manager, LoggerFactory, metrics);

var services = new ServiceCollection();
services.AddSingleton<ImmediatelyCompleteConnectionHandler>();
var context = MakeRequest("/foo", connection, services);

var builder = new ConnectionBuilder(services.BuildServiceProvider());
builder.UseConnectionHandler<ImmediatelyCompleteConnectionHandler>();
var app = builder.Build();
// First poll will 200
await dispatcher.ExecuteAsync(context, new HttpConnectionDispatcherOptions(), app);
Assert.Equal(StatusCodes.Status200OK, context.Response.StatusCode);

using var connectionDuration = new InstrumentRecorder<double>(testMeterFactory, HttpConnectionsMetrics.MeterName, "signalr-http-transport-connection-duration");
using var currentConnections = new InstrumentRecorder<long>(testMeterFactory, HttpConnectionsMetrics.MeterName, "signalr-http-transport-current-connections");

await dispatcher.ExecuteAsync(context, new HttpConnectionDispatcherOptions(), app);

Assert.Equal(StatusCodes.Status204NoContent, context.Response.StatusCode);
AssertResponseHasCacheHeaders(context.Response);

var exists = manager.TryGetConnection(connection.ConnectionId, out _);
Assert.False(exists);

Assert.Empty(currentConnections.GetMeasurements());
Assert.Empty(connectionDuration.GetMeasurements());
}
}

private static void AssertTransport(Measurement<long> measurement, long expected, HttpTransportType transportType)
{
Assert.Equal(expected, measurement.Value);
Assert.Equal(transportType.ToString(), (string)measurement.Tags.ToArray().Single(t => t.Key == "transport").Value);
}

private static void AssertDuration(Measurement<double> measurement, HttpConnectionStopStatus status, HttpTransportType transportType)
{
Assert.True(measurement.Value > 0);
Assert.Equal(status.ToString(), (string)measurement.Tags.ToArray().Single(t => t.Key == "status").Value);
Assert.Equal(transportType.ToString(), (string)measurement.Tags.ToArray().Single(t => t.Key == "transport").Value);
}

[Fact]
public async Task LongPollingTimeoutSets200StatusCode()
{
Expand Down
53 changes: 0 additions & 53 deletions src/SignalR/common/Http.Connections/test/HttpConnectionManagerTests.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -425,59 +425,6 @@ public async Task ApplicationLifetimeCanStartBeforeHttpConnectionManagerInitiali
}
}

[Fact]
public void Metrics()
{
using (StartVerifiableLog())
{
var testMeterFactory = new TestMeterFactory();
using var connectionDuration = new InstrumentRecorder<double>(testMeterFactory, HttpConnectionsMetrics.MeterName, "signalr-http-transport-connection-duration");

var connectionManager = CreateConnectionManager(LoggerFactory, metrics: new HttpConnectionsMetrics(testMeterFactory));
var connection = connectionManager.CreateConnection();

Assert.NotNull(connection.ConnectionId);

Assert.Empty(connectionDuration.GetMeasurements());

connection.TransportType = HttpTransportType.WebSockets;

connectionManager.RemoveConnection(connection.ConnectionId, connection.TransportType, HttpConnectionStopStatus.NormalClosure);

Assert.Collection(connectionDuration.GetMeasurements(), m => AssertDuration(m, HttpConnectionStopStatus.NormalClosure, HttpTransportType.WebSockets));
}
}

[Fact]
public void Metrics_ListenStartAfterConnection_Empty()
{
using (StartVerifiableLog())
{
var testMeterFactory = new TestMeterFactory();
var connectionManager = CreateConnectionManager(LoggerFactory, metrics: new HttpConnectionsMetrics(testMeterFactory));
var connection = connectionManager.CreateConnection();

using var connectionDuration = new InstrumentRecorder<double>(testMeterFactory, HttpConnectionsMetrics.MeterName, "http-server-connection-duration");
using var currentConnections = new InstrumentRecorder<long>(testMeterFactory, HttpConnectionsMetrics.MeterName, "http-server-current-connections");

Assert.NotNull(connection.ConnectionId);

connection.TransportType = HttpTransportType.WebSockets;

connectionManager.RemoveConnection(connection.ConnectionId, connection.TransportType, HttpConnectionStopStatus.NormalClosure);

Assert.Empty(currentConnections.GetMeasurements());
Assert.Empty(connectionDuration.GetMeasurements());
}
}

private static void AssertDuration(Measurement<double> measurement, HttpConnectionStopStatus status, HttpTransportType transportType)
{
Assert.True(measurement.Value > 0);
Assert.Equal(status.ToString(), (string)measurement.Tags.ToArray().Single(t => t.Key == "status").Value);
Assert.Equal(transportType.ToString(), (string)measurement.Tags.ToArray().Single(t => t.Key == "transport").Value);
}

private static HttpConnectionManager CreateConnectionManager(ILoggerFactory loggerFactory, IHostApplicationLifetime lifetime = null, HttpConnectionsMetrics metrics = null)
{
lifetime ??= new EmptyApplicationLifetime();
Expand Down