From de0bd13cdab5c2fafe793bdf7785c5b7d8798d44 Mon Sep 17 00:00:00 2001 From: Quin Lynch <49576606+quinchs@users.noreply.github.com> Date: Thu, 18 Apr 2024 18:19:16 -0300 Subject: [PATCH] Fix: Reconnection logic for parse (#80) --- .../Binary/Protocol/IProtocolProvider.cs | 2 + .../Protocol/V1.0/V1ProtocolProvider.cs | 8 +++ .../Clients/EdgeDBBinaryClient.cs | 53 +++++++++++-------- src/EdgeDB.Net.Driver/Log.cs | 11 ++++ 4 files changed, 51 insertions(+), 23 deletions(-) diff --git a/src/EdgeDB.Net.Driver/Binary/Protocol/IProtocolProvider.cs b/src/EdgeDB.Net.Driver/Binary/Protocol/IProtocolProvider.cs index b3caba8f..3f70d979 100644 --- a/src/EdgeDB.Net.Driver/Binary/Protocol/IProtocolProvider.cs +++ b/src/EdgeDB.Net.Driver/Binary/Protocol/IProtocolProvider.cs @@ -32,6 +32,8 @@ internal interface IProtocolProvider int? SuggestedPoolConcurrency { get; } + void Reset(); + public static IProtocolProvider GetDefaultProvider(EdgeDBBinaryClient client) => (_defaultProvider ??= Providers[ProtocolVersion.EdgeDBBinaryDefaultVersion].Factory)(client); diff --git a/src/EdgeDB.Net.Driver/Binary/Protocol/V1.0/V1ProtocolProvider.cs b/src/EdgeDB.Net.Driver/Binary/Protocol/V1.0/V1ProtocolProvider.cs index d08c3d66..ebfe38a4 100644 --- a/src/EdgeDB.Net.Driver/Binary/Protocol/V1.0/V1ProtocolProvider.cs +++ b/src/EdgeDB.Net.Driver/Binary/Protocol/V1.0/V1ProtocolProvider.cs @@ -39,6 +39,13 @@ private ILogger Logger public virtual ProtocolVersion Version { get; } = (1, 0); + public void Reset() + { + Phase = ProtocolPhase.Connection; + _rawServerConfig.Clear(); + _serverKey = Array.Empty(); + } + public virtual PacketReadFactory? GetPacketFactory(ServerMessageType type) => type switch { @@ -491,6 +498,7 @@ public virtual ValueTask ProcessAsync(in T message) where T : IReceiveable if (authStatus.AuthStatus != AuthStatus.AuthenticationOK) throw new UnexpectedMessageException("Expected AuthenticationRequiredSASLMessage, got " + authStatus.AuthStatus); + Logger.LogDebug("Got authentication OK"); break; case ServerKeyData keyData: _serverKey = keyData.KeyBuffer; diff --git a/src/EdgeDB.Net.Driver/Clients/EdgeDBBinaryClient.cs b/src/EdgeDB.Net.Driver/Clients/EdgeDBBinaryClient.cs index ffecfc7e..77e04442 100644 --- a/src/EdgeDB.Net.Driver/Clients/EdgeDBBinaryClient.cs +++ b/src/EdgeDB.Net.Driver/Clients/EdgeDBBinaryClient.cs @@ -219,15 +219,20 @@ await Task.WhenAll( } catch (EdgeDBException x) when (x.ShouldReconnect && !isRetry) { + Logger.LogDebug("Execute threw an exception which allows reconnects, reconnecting..."); + await ReconnectAsync(token).ConfigureAwait(false); _semaphore.Release(); released = true; + Logger.LogDebug("Preforming retry after a reconnect exception"); return await ExecuteInternalAsync(query, args, cardinality, capabilities, format, true, implicitTypeName, preheat, token).ConfigureAwait(false); } catch (EdgeDBException x) when (x.ShouldRetry && !isRetry) { + Logger.LogDebug("Execute threw an exception which allows retries, retrying..."); + _semaphore.Release(); released = true; @@ -527,35 +532,35 @@ public override async ValueTask ConnectAsync(CancellationToken token = default) try { + Logger.ConnectionMessageProcessing(message.Type); await _protocolProvider.ProcessAsync(in message); } catch (EdgeDBErrorException x) when (x.ShouldReconnect) { - if (ClientConfig.RetryMode is ConnectionRetryMode.AlwaysRetry) + if (ClientConfig.RetryMode is not ConnectionRetryMode.AlwaysRetry) throw; + + if (_currentRetries < ClientConfig.MaxConnectionRetries) { - if (_currentRetries < ClientConfig.MaxConnectionRetries) - { - _currentRetries++; - - Logger.AttemptToReconnect(_currentRetries, ClientConfig.MaxConnectionRetries, x); - - // do not forward the linked token in this method to the new - // reconnection, only supply the external token. We also don't - // want to call 'ReconnectAsync' since we queue up a disconnect - // and connect request, if this method was called externally - // while we handle the error, it would be next in line to attempt - // to connect, if that external call completes we would then disconnect - // and connect after a successful connection attempt which wouldn't be ideal. - await DisconnectAsync(token); - - _connectSemaphone.Release(); - - await ConnectAsync(token); - return; - } - else - Logger.MaxConnectionRetries(ClientConfig.MaxConnectionRetries, x); + _currentRetries++; + + Logger.AttemptToReconnect(_currentRetries, ClientConfig.MaxConnectionRetries, x); + + // do not forward the linked token in this method to the new + // reconnection, only supply the external token. We also don't + // want to call 'ReconnectAsync' since we queue up a disconnect + // and connect request, if this method was called externally + // while we handle the error, it would be next in line to attempt + // to connect, if that external call completes we would then disconnect + // and connect after a successful connection attempt which wouldn't be ideal. + await DisconnectAsync(token); + + _connectSemaphone.Release(); + + await ConnectAsync(token); + return; } + else + Logger.MaxConnectionRetries(ClientConfig.MaxConnectionRetries, x); throw; } @@ -564,6 +569,7 @@ public override async ValueTask ConnectAsync(CancellationToken token = default) { // reset connection attempts _currentRetries = 0; + Logger.ConnectionPhaseComplete(_protocolProvider.Phase); break; } } @@ -589,6 +595,7 @@ private async Task ConnectInternalAsync(int attempts = 0, CancellationToken toke _readyCancelTokenSource = new CancellationTokenSource(); _readySource = new TaskCompletionSource(); + _protocolProvider.Reset(); Duplexer.Reset(); diff --git a/src/EdgeDB.Net.Driver/Log.cs b/src/EdgeDB.Net.Driver/Log.cs index dcb28f77..8e3b8175 100644 --- a/src/EdgeDB.Net.Driver/Log.cs +++ b/src/EdgeDB.Net.Driver/Log.cs @@ -1,5 +1,6 @@ using EdgeDB.Binary; using EdgeDB.Binary.Codecs; +using EdgeDB.Binary.Protocol; using Microsoft.Extensions.Logging; namespace EdgeDB; @@ -228,4 +229,14 @@ public static partial void BeginProtocolNegotiation(this ILogger logget, Protoco LogLevel.Trace, "Codec tree information:\n{CodecTree}")] public static partial void CodecTree(this ILogger logger, string codecTree); + + [LoggerMessage(34, + LogLevel.Debug, + "Processing {Type} in connection step")] + public static partial void ConnectionMessageProcessing(this ILogger logger, ServerMessageType type); + + [LoggerMessage(35, + LogLevel.Debug, + "Protocol phase is {Phase}. Ending connection task")] + public static partial void ConnectionPhaseComplete(this ILogger logger, ProtocolPhase phase); }