Skip to content

Use Environment.TickCount64 instead of UtcNow in SignalR #34382

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.

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 5 commits into from
Jul 28, 2021
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
Original file line number Diff line number Diff line change
Expand Up @@ -68,7 +68,7 @@ public HttpConnectionContext(string connectionId, string connectionToken, ILogge

ConnectionId = connectionId;
ConnectionToken = connectionToken;
LastSeenUtc = DateTime.UtcNow;
LastSeenTicks = Environment.TickCount64;
_options = options;

// The default behavior is that both formats are supported.
Expand Down Expand Up @@ -121,15 +121,15 @@ public HttpConnectionContext(string connectionId, string connectionToken, ILogge

public Task? ApplicationTask { get; set; }

public DateTime LastSeenUtc { get; set; }
public long LastSeenTicks { get; set; }

public DateTime? LastSeenUtcIfInactive
public long? LastSeenTicksIfInactive
{
get
{
lock (_stateLock)
{
return Status == HttpConnectionStatus.Inactive ? (DateTime?)LastSeenUtc : null;
return Status == HttpConnectionStatus.Inactive ? LastSeenTicks : null;
}
}
}
Expand Down Expand Up @@ -543,7 +543,7 @@ public void MarkInactive()
if (Status == HttpConnectionStatus.Active)
{
Status = HttpConnectionStatus.Inactive;
LastSeenUtc = DateTime.UtcNow;
LastSeenTicks = Environment.TickCount64;
}
}
}
Expand Down Expand Up @@ -575,7 +575,7 @@ internal void StartSendCancellation()
_sendCts = new CancellationTokenSource();
SendingToken = _sendCts.Token;
}
_startedSendTime = DateTime.UtcNow.Ticks;
_startedSendTime = Environment.TickCount64;
_activeSend = true;
}
}
Expand Down
Original file line number Diff line number Diff line change
@@ -1,17 +1,12 @@
// 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;
using System.Diagnostics.CodeAnalysis;
using System.IO;
using System.IO.Pipelines;
using System.Net.WebSockets;
using System.Security.Cryptography;
using System.Threading;
using System.Threading.Tasks;
using Microsoft.Extensions.Hosting;
using Microsoft.Extensions.Internal;
using Microsoft.Extensions.Logging;
Expand All @@ -29,14 +24,14 @@ internal partial class HttpConnectionManager
private readonly PeriodicTimer _nextHeartbeat;
private readonly ILogger<HttpConnectionManager> _logger;
private readonly ILogger<HttpConnectionContext> _connectionLogger;
private readonly TimeSpan _disconnectTimeout;
private readonly long _disconnectTimeoutTicks;

public HttpConnectionManager(ILoggerFactory loggerFactory, IHostApplicationLifetime appLifetime, IOptions<ConnectionOptions> connectionOptions)
{
_logger = loggerFactory.CreateLogger<HttpConnectionManager>();
_connectionLogger = loggerFactory.CreateLogger<HttpConnectionContext>();
_nextHeartbeat = new PeriodicTimer(_heartbeatTickRate);
_disconnectTimeout = connectionOptions.Value.DisconnectTimeout ?? ConnectionOptionsSetup.DefaultDisconectTimeout;
_disconnectTimeoutTicks = (long)(connectionOptions.Value.DisconnectTimeout ?? ConnectionOptionsSetup.DefaultDisconectTimeout).TotalMilliseconds;

// Register these last as the callbacks could run immediately
appLifetime.ApplicationStarted.Register(() => Start());
Expand Down Expand Up @@ -138,17 +133,19 @@ private async Task ExecuteTimerLoop()

public void Scan()
{
var now = DateTimeOffset.UtcNow;
var ticks = Environment.TickCount64;

// Scan the registered connections looking for ones that have timed out
foreach (var c in _connections)
{
var connection = c.Value.Connection;
// Capture the connection state
var lastSeenUtc = connection.LastSeenUtcIfInactive;
var lastSeenTick = connection.LastSeenTicksIfInactive;

var utcNow = DateTimeOffset.UtcNow;
// Once the decision has been made to dispose we don't check the status again
// But don't clean up connections while the debugger is attached.
if (!Debugger.IsAttached && lastSeenUtc.HasValue && (utcNow - lastSeenUtc.Value).TotalSeconds > _disconnectTimeout.TotalSeconds)
if (!Debugger.IsAttached && lastSeenTick.HasValue && (ticks - lastSeenTick.Value) > _disconnectTimeoutTicks)
{
Log.ConnectionTimedOut(_logger, connection.ConnectionId);
HttpConnectionsEventSource.Log.ConnectionTimedOut(connection.ConnectionId);
Expand All @@ -162,13 +159,13 @@ public void Scan()
{
if (!Debugger.IsAttached)
{
connection.TryCancelSend(utcNow.Ticks);
connection.TryCancelSend(ticks);
}

// Tick the heartbeat, if the connection is still active
connection.TickHeartbeat();

if (connection.IsAuthenticationExpirationEnabled && connection.AuthenticationExpiration < utcNow &&
if (connection.IsAuthenticationExpirationEnabled && connection.AuthenticationExpiration < now &&
!connection.ConnectionClosedRequested.IsCancellationRequested)
{
Log.AuthenticationExpired(_logger, connection.ConnectionId);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -504,7 +504,8 @@ public async Task TransportEndingGracefullyWaitsOnApplicationLongPolling()
{
using (StartVerifiableLog())
{
var manager = CreateConnectionManager(LoggerFactory, TimeSpan.FromSeconds(5));
var disconnectTimeout = TimeSpan.FromSeconds(5);
var manager = CreateConnectionManager(LoggerFactory, disconnectTimeout);
var dispatcher = new HttpConnectionDispatcher(manager, LoggerFactory);
var connection = manager.CreateConnection();
connection.TransportType = HttpTransportType.LongPolling;
Expand Down Expand Up @@ -550,7 +551,7 @@ public async Task TransportEndingGracefullyWaitsOnApplicationLongPolling()
await task.DefaultTimeout();

// We've been gone longer than the expiration time
connection.LastSeenUtc = DateTime.UtcNow.Subtract(TimeSpan.FromSeconds(10));
connection.LastSeenTicks = Environment.TickCount64 - (long)disconnectTimeout.TotalMilliseconds - 1;

// The application is still running here because the poll is only killed
// by the heartbeat so we pretend to do a scan and this should force the application task to complete
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -29,7 +29,7 @@ public void NewConnectionsHaveConnectionId()
Assert.Null(connection.ApplicationTask);
Assert.Null(connection.TransportTask);
Assert.Null(connection.Cancellation);
Assert.NotEqual(default, connection.LastSeenUtc);
Assert.NotEqual(default, connection.LastSeenTicks);
Assert.NotNull(connection.Transport);
Assert.NotNull(connection.Application);
}
Expand Down
17 changes: 2 additions & 15 deletions src/SignalR/common/Shared/ISystemClock.cs
Original file line number Diff line number Diff line change
@@ -1,26 +1,13 @@
// 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;

namespace Microsoft.AspNetCore.Internal
{
internal interface ISystemClock
{
/// <summary>
/// Retrieves the current UTC system time.
/// </summary>
DateTimeOffset UtcNow { get; }

/// <summary>
/// Retrieves ticks for the current UTC system time.
/// </summary>
long UtcNowTicks { get; }

/// <summary>
/// Retrieves the current UTC system time.
/// This is only safe to use from code called by the Heartbeat.
/// Retrieves ticks for the current system up time.
/// </summary>
DateTimeOffset UtcNowUnsynchronized { get; }
long CurrentTicks { get; }
}
}
18 changes: 2 additions & 16 deletions src/SignalR/common/Shared/SystemClock.cs
Original file line number Diff line number Diff line change
@@ -1,28 +1,14 @@
// 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;

namespace Microsoft.AspNetCore.Internal
{
/// <summary>
/// Provides access to the normal system clock.
/// </summary>
internal class SystemClock : ISystemClock
{
/// <summary>
/// Retrieves the current UTC system time.
/// </summary>
public DateTimeOffset UtcNow => DateTimeOffset.UtcNow;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Does this mean there were no tests for AuthenticationExpiration?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

There are, but they aren't using the clock abstraction.


/// <summary>
/// Retrieves ticks for the current UTC system time.
/// </summary>
public long UtcNowTicks => DateTimeOffset.UtcNow.Ticks;

/// <summary>
/// Retrieves the current UTC system time.
/// </summary>
public DateTimeOffset UtcNowUnsynchronized => DateTimeOffset.UtcNow;
/// <inheritdoc />
public long CurrentTicks => Environment.TickCount64;
}
}
22 changes: 11 additions & 11 deletions src/SignalR/server/Core/src/HubConnectionContext.cs
Original file line number Diff line number Diff line change
Expand Up @@ -42,7 +42,7 @@ public partial class HubConnectionContext
private readonly CancellationTokenRegistration? _closedRequestedRegistration;

private StreamTracker? _streamTracker;
private long _lastSendTimeStamp;
private long _lastSendTick;
private ReadOnlyMemory<byte> _cachedPingMessage;
private bool _clientTimeoutActive;
private volatile bool _connectionAborted;
Expand All @@ -51,7 +51,7 @@ public partial class HubConnectionContext
private readonly long? _maxMessageSize;
private bool _receivedMessageTimeoutEnabled;
private long _receivedMessageElapsedTicks;
private long _receivedMessageTimestamp;
private long _receivedMessageTick;
private ClaimsPrincipal? _user;

/// <summary>
Expand All @@ -62,8 +62,8 @@ public partial class HubConnectionContext
/// <param name="contextOptions">The options to configure the HubConnectionContext.</param>
public HubConnectionContext(ConnectionContext connectionContext, HubConnectionContextOptions contextOptions, ILoggerFactory loggerFactory)
{
_keepAliveInterval = contextOptions.KeepAliveInterval.Ticks;
_clientTimeoutInterval = contextOptions.ClientTimeoutInterval.Ticks;
_keepAliveInterval = (long)contextOptions.KeepAliveInterval.TotalMilliseconds;
_clientTimeoutInterval = (long)contextOptions.ClientTimeoutInterval.TotalMilliseconds;
_streamBufferCapacity = contextOptions.StreamBufferCapacity;
_maxMessageSize = contextOptions.MaximumReceiveMessageSize;

Expand All @@ -81,7 +81,7 @@ public HubConnectionContext(ConnectionContext connectionContext, HubConnectionCo
HubCallerContext = new DefaultHubCallerContext(this);

_systemClock = contextOptions.SystemClock ?? new SystemClock();
_lastSendTimeStamp = _systemClock.UtcNowTicks;
_lastSendTick = _systemClock.CurrentTicks;

// We'll be avoiding using the semaphore when the limit is set to 1, so no need to allocate it
var maxInvokeLimit = contextOptions.MaximumParallelInvocations;
Expand Down Expand Up @@ -623,15 +623,15 @@ private async Task AbortAsyncSlow()

private void KeepAliveTick()
{
var currentTime = _systemClock.UtcNowTicks;
var currentTime = _systemClock.CurrentTicks;

// Implements the keep-alive tick behavior
// Each tick, we check if the time since the last send is larger than the keep alive duration (in ticks).
// If it is, we send a ping frame, if not, we no-op on this tick. This means that in the worst case, the
// true "ping rate" of the server could be (_hubOptions.KeepAliveInterval + HubEndPoint.KeepAliveTimerInterval),
// because if the interval elapses right after the last tick of this timer, it won't be detected until the next tick.

if (currentTime - Volatile.Read(ref _lastSendTimeStamp) > _keepAliveInterval)
if (currentTime - Volatile.Read(ref _lastSendTick) > _keepAliveInterval)
{
// Haven't sent a message for the entire keep-alive duration, so send a ping.
// If the transport channel is full, this will fail, but that's OK because
Expand All @@ -641,7 +641,7 @@ private void KeepAliveTick()

// We only update the timestamp here, because updating on each sent message is bad for performance
// There can be a lot of sent messages per 15 seconds
Volatile.Write(ref _lastSendTimeStamp, currentTime);
Volatile.Write(ref _lastSendTick, currentTime);
}
}

Expand All @@ -666,7 +666,7 @@ private void CheckClientTimeout()
{
if (_receivedMessageTimeoutEnabled)
{
_receivedMessageElapsedTicks = _systemClock.UtcNowTicks - _receivedMessageTimestamp;
_receivedMessageElapsedTicks = _systemClock.CurrentTicks - _receivedMessageTick;

if (_receivedMessageElapsedTicks >= _clientTimeoutInterval)
{
Expand Down Expand Up @@ -716,7 +716,7 @@ internal void BeginClientTimeout()
lock (_receiveMessageTimeoutLock)
{
_receivedMessageTimeoutEnabled = true;
_receivedMessageTimestamp = _systemClock.UtcNowTicks;
_receivedMessageTick = _systemClock.CurrentTicks;
}
}

Expand All @@ -727,7 +727,7 @@ internal void StopClientTimeout()
// we received a message so stop the timer and reset it
// it will resume after the message has been processed
_receivedMessageElapsedTicks = 0;
_receivedMessageTimestamp = 0;
_receivedMessageTick = 0;
_receivedMessageTimeoutEnabled = false;
}
}
Expand Down
Original file line number Diff line number Diff line change
@@ -1,42 +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.Threading;
using Microsoft.AspNetCore.Internal;

namespace Microsoft.AspNetCore.SignalR.Tests
{
public class MockSystemClock : ISystemClock
{
private long _utcNowTicks;
private long _nowTicks;

public MockSystemClock()
{
// Use a random DateTimeOffset to ensure tests that incorrectly use the current DateTimeOffset fail always instead of only rarely.
// Pick a date between the min DateTimeOffset and a day before the max DateTimeOffset so there's room to advance the clock.
_utcNowTicks = NextLong(DateTimeOffset.MinValue.Ticks, DateTimeOffset.MaxValue.Ticks - TimeSpan.FromDays(1).Ticks);
_nowTicks = NextLong(0, long.MaxValue - (long)TimeSpan.FromDays(1).TotalMilliseconds);
}

public DateTimeOffset UtcNow
public long CurrentTicks
{
get
{
UtcNowCalled++;
return new DateTimeOffset(Interlocked.Read(ref _utcNowTicks), TimeSpan.Zero);
}
get => _nowTicks;
set
{
Interlocked.Exchange(ref _utcNowTicks, value.Ticks);
Interlocked.Exchange(ref _nowTicks, value);
}
}

public long UtcNowTicks => UtcNow.Ticks;

public DateTimeOffset UtcNowUnsynchronized => UtcNow;

public int UtcNowCalled { get; private set; }

private long NextLong(long minValue, long maxValue)
{
return (long)(Random.Shared.NextDouble() * (maxValue - minValue) + minValue);
Expand Down
Loading