Skip to content
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

Jump to bottom

Add terse cancellation logging mode; #49

Merged
merged 2 commits into from
Oct 3, 2024
Merged

Add terse cancellation logging mode; #49

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
7f4187b
Add terse cancellation logging mode;
TonySkorik Oct 3, 2024
980909e
Fix tests;
TonySkorik Oct 3, 2024
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
8 changes: 8 additions & 0 deletions README.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -242,6 +242,14 @@ public static void LogErrorIfAny<T>(
[CallerMemberName] string operationName = null)
```

#### Cancellation logging

By default cancellations and therefore `OperationCancelledException` occurrences are treated as any other exceptions and logged accordingly. But there are times when one just need to know that cancellation heppened and doesn't need a full stacktrace for it.

It's possible to switch on the _terse cancellaiton logging_ by setting `MemcachedConfiguration.IsTerseCancellationLogging` config key to `true`.

In that case only the operation name and a short message will be logged upon cancellation.

### Batching

For `MultiStoreAsync` and `MultiGetAsync` methods there is an optional argument `batchingOptions`. If this argument is specified the store and get operations split input key or key-value collection into batches an processe every batch on every memcached node in parallel with specified maximum degree of parallelism (`Environment.ProcessorCount` by default).
Expand Down
1 change: 0 additions & 1 deletion docker-compose.yaml
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,4 +1,3 @@
version: "3"
services:
memcached-1:
image: memcached:latest
Expand Down
22 changes: 17 additions & 5 deletions src/Aer.Memcached.Client/CommandExecutor.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -24,7 +24,7 @@ public class CommandExecutor<TNode> : ICommandExecutor<TNode>
{
private const int FURTHER_AUTHENTICATION_STEPS_REQUIRED_STATUS_CODE = 0x21;

private readonly MemcachedConfiguration.SocketPoolConfiguration _config;
private readonly MemcachedConfiguration _config;
private readonly IAuthenticationProvider _authenticationProvider;
private readonly ILogger<CommandExecutor<TNode>> _logger;
private readonly ConcurrentDictionary<TNode, SocketPool> _socketPools;
Expand All @@ -43,7 +43,7 @@ public CommandExecutor(
ILogger<CommandExecutor<TNode>> logger,
INodeLocator<TNode> nodeLocator)
{
_config = config.Value.SocketPool;
_config = config.Value;
_authenticationProvider = authenticationProvider;
_logger = logger;
_nodeLocator = nodeLocator;
Expand Down Expand Up @@ -95,7 +95,7 @@ public IReadOnlyCollection<SocketPoolStatisctics> GetSocketPoolsStatistics(TNode
{
var ret = new List<SocketPoolStatisctics>(nodes.Length);

SocketPool ValueFactory(TNode node) => new(node.GetEndpoint(), _config, _logger);
SocketPool ValueFactory(TNode node) => new(node.GetEndpoint(), _config.SocketPool, _logger);

foreach (var node in nodes)
{
Expand Down Expand Up @@ -206,6 +206,12 @@ private async Task<CommandExecutionResult> ExecuteCommandInternalAsync(
// means no successful command found
return CommandExecutionResult.Unsuccessful(command, "All commands on all replica nodes failed");
}
catch (OperationCanceledException) when (_config.IsTerseCancellationLogging)
{
// just rethrow this exception and don't log any details.
// it will be handled in MemcachedClient
throw;
}
catch (Exception e)
{
_logger.LogError(
Expand Down Expand Up @@ -239,7 +245,7 @@ private async Task<CommandExecutionResult> ExecuteCommandInternalAsync(

try
{
await writeSocketTask.WaitAsync(_config.ReceiveTimeout, token);
await writeSocketTask.WaitAsync(_config.SocketPool.ReceiveTimeout, token);
}
catch (TimeoutException)
{
Expand All @@ -254,6 +260,12 @@ private async Task<CommandExecutionResult> ExecuteCommandInternalAsync(
? CommandExecutionResult.Successful(command)
: CommandExecutionResult.Unsuccessful(command, readResult.Message);
}
catch (OperationCanceledException) when (_config.IsTerseCancellationLogging)
{
// just rethrow this exception and don't log any details.
// it will be handled in MemcachedClient
throw;
}
catch (Exception e)
{
_logger.LogError(
Expand All @@ -274,7 +286,7 @@ private async Task<PooledSocket> GetSocketAsync(
var socketPool = _socketPools.GetOrAdd(
node,
valueFactory: static (n, args) =>
new SocketPool(n.GetEndpoint(), args.Config, args.Logger),
new SocketPool(n.GetEndpoint(), args.Config.SocketPool, args.Logger),
factoryArgument: (Config: _config, Logger: _logger)
);

Expand Down
8 changes: 8 additions & 0 deletions src/Aer.Memcached.Client/Config/MemcachedConfiguration.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -59,6 +59,9 @@ public class MemcachedConfiguration
/// </summary>
public MaintainerConfiguration MemcachedMaintainer { get; set; } = MaintainerConfiguration.DefaultConfiguration();

/// <summary>
/// Authentication configuration.
/// </summary>
public AuthenticationCredentials MemcachedAuth { get; set; }

/// <summary>
Expand Down Expand Up @@ -93,6 +96,11 @@ public class MemcachedConfiguration
/// </summary>
public bool IsAllowLongKeys { get; set; }

/// <summary>
/// If set to <c>true</c>, external cancellations will be logged in terse manner - only as operation name.
/// </summary>
public bool IsTerseCancellationLogging { get; set; }

/// <summary>
/// Checks that either <see cref="HeadlessServiceAddress"/> or <see cref="Servers"/> are specified.
/// </summary>
Expand Down
63 changes: 44 additions & 19 deletions src/Aer.Memcached.Client/Extensions/MemcachedClientResultExtensions.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -46,21 +46,31 @@ public static void LogErrorIfAny(
return;
}

if (!string.IsNullOrEmpty(customErrorMessage))
switch (customErrorMessage, RequestWasCancelled: target.RequestCancelled)
Copy link
Collaborator

Choose a reason for hiding this comment

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

Shouldn't LogErrorIfAny methods be in tests project if they are used only in test?

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

They are actually public helper methods which are extensively used in our projects 😎

{
logger.Log(
logLevel,
"{ErrorMessage}. Error details : {ErrorDetails}",
customErrorMessage,
target.ErrorMessage ?? DefaultErrorMessage);
}
else
{
logger.Log(
logLevel,
"Error happened during memcached {Operation} operation. Error details : {ErrorDetails}",
operationName,
target.ErrorMessage ?? DefaultErrorMessage);
case ({Length: > 0}, true):
case ({Length: > 0}, false):
logger.Log(
logLevel,
"{ErrorMessage}. Error details : {ErrorDetails}",
customErrorMessage,
target.ErrorMessage ?? DefaultErrorMessage);
break;

case (null, true):
logger.Log(
logLevel,
"Memcached operation {ErrorMessage} was cancelled",
target.ErrorMessage);
break;

case (null, false):
logger.Log(
logLevel,
"Error happened during memcached {Operation} operation. Error details : {ErrorDetails}",
operationName,
target.ErrorMessage ?? DefaultErrorMessage);
break;
}
}

Expand Down Expand Up @@ -92,17 +102,18 @@ public static void LogErrorIfAny<T>(
return;
}

switch (cacheKeysCount, customErrorMessage)
switch (cacheKeysCount, customErrorMessage, target.RequestCancelled)
{
case (_, {Length: > 0} specificErrorMessage):
case (_, {Length: > 0}, true):
case (_, {Length: > 0}, false):
logger.Log(
logLevel,
"{ErrorMessage}. Error details : {ErrorDetails}",
specificErrorMessage,
customErrorMessage,
target.ErrorMessage ?? DefaultErrorMessage);
break;

case ({ } keysCount, null):
case ({ } keysCount, null, false):
logger.Log(
logLevel,
"Error happened during memcached {Operation} operation with cache keys count : {CacheKeysCount}. Error details : {ErrorDetails}",
Expand All @@ -111,13 +122,27 @@ public static void LogErrorIfAny<T>(
target.ErrorMessage ?? DefaultErrorMessage);
break;

case (null, null):
case ({ } keysCount, null, true):
logger.Log(
logLevel,
"Memcached operation {ErrorMessage} was cancelled",
target.ErrorMessage);
break;

case (null, null, false):
logger.Log(
logLevel,
"Error happened during memcached {Operation} operation. Error details : {ErrorDetails}",
operationName,
target.ErrorMessage ?? DefaultErrorMessage);
break;

case (null, null, true):
logger.Log(
logLevel,
"Memcached operation {ErrorMessage} was cancelled",
target.ErrorMessage);
break;
}
}
}
46 changes: 45 additions & 1 deletion src/Aer.Memcached.Client/MemcachedClient.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -115,6 +115,10 @@ public async Task<MemcachedClientResult> StoreAsync<T>(
.WithSyncSuccess(syncSuccess);
}
}
catch (OperationCanceledException) when (_memcachedConfiguration.IsTerseCancellationLogging)
Copy link
Collaborator

Choose a reason for hiding this comment

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

The first thing that comes to mind is to extract error handling logic if it starts to extend. It may be a good idea in such scenarios, what do you think?

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

I'd say we take a note of it and next time a need for another exception handling extension arises - implement it in a separate class

{
return MemcachedClientResult.Cancelled(nameof(StoreAsync));
}
catch (Exception e)
{
return MemcachedClientResult.Unsuccessful(
Expand Down Expand Up @@ -163,6 +167,10 @@ public async Task<MemcachedClientResult> MultiStoreAsync<T>(

return MemcachedClientResult.Successful.WithSyncSuccess(syncSuccess);
}
catch (OperationCanceledException) when (_memcachedConfiguration.IsTerseCancellationLogging)
{
return MemcachedClientResult.Cancelled(nameof(MultiStoreAsync));
}
catch (Exception e)
{
return MemcachedClientResult.Unsuccessful(
Expand Down Expand Up @@ -219,6 +227,10 @@ public async Task<MemcachedClientResult> MultiStoreAsync<T>(

return MemcachedClientResult.Successful.WithSyncSuccess(syncSuccess);
}
catch (OperationCanceledException) when (_memcachedConfiguration.IsTerseCancellationLogging)
{
return MemcachedClientResult.Cancelled(nameof(MultiStoreAsync));
}
catch (Exception e)
{
return MemcachedClientResult.Unsuccessful(
Expand Down Expand Up @@ -268,6 +280,10 @@ public async Task<MemcachedClientValueResult<T>> GetAsync<T>(string key, Cancell
}
}
}
catch (OperationCanceledException) when (_memcachedConfiguration.IsTerseCancellationLogging)
{
return MemcachedClientValueResult<T>.Cancelled(nameof(GetAsync));
}
catch (Exception e)
{
return MemcachedClientValueResult<T>.Unsuccessful(
Expand All @@ -290,6 +306,13 @@ public async Task<MemcachedClientValueResult<IDictionary<string, T>>> MultiGetSa
getKeysResult,
isResultEmpty: getKeysResult is null or {Count: 0});
}
catch (OperationCanceledException) when (_memcachedConfiguration.IsTerseCancellationLogging)
{
return MemcachedClientValueResult<IDictionary<string, T>>.Cancelled(
nameof(MultiGetSafeAsync),
defaultResultValue: new Dictionary<string, T>()
);
}
catch (Exception e)
{
return MemcachedClientValueResult<IDictionary<string, T>>.Unsuccessful(
Expand All @@ -306,6 +329,7 @@ public async Task<IDictionary<string, T>> MultiGetAsync<T>(
BatchingOptions batchingOptions = null,
uint replicationFactor = 0)
{

var nodes = _nodeLocator.GetNodes(keys, replicationFactor);
if (nodes.Keys.Count == 0)
{
Expand Down Expand Up @@ -344,7 +368,7 @@ public async Task<IDictionary<string, T>> MultiGetAsync<T>(

var command = taskResult.GetCommandAs<MultiGetCommand>();

if (command.Result is null or { Count: 0 })
if (command.Result is null or {Count: 0})
{
// skip results that are empty
continue;
Expand Down Expand Up @@ -404,6 +428,10 @@ public async Task<MemcachedClientResult> DeleteAsync(
.WithSyncSuccess(syncSuccess);
}
}
catch (OperationCanceledException) when (_memcachedConfiguration.IsTerseCancellationLogging)
{
return MemcachedClientResult.Cancelled(nameof(DeleteAsync));
}
catch (Exception e)
{
return MemcachedClientResult.Unsuccessful(
Expand Down Expand Up @@ -464,6 +492,10 @@ public async Task<MemcachedClientResult> MultiDeleteAsync(

return MemcachedClientResult.Successful.WithSyncSuccess(syncSuccess);
}
catch (OperationCanceledException) when (_memcachedConfiguration.IsTerseCancellationLogging)
{
return MemcachedClientResult.Cancelled(nameof(MultiDeleteAsync));
}
catch (Exception e)
{
return MemcachedClientResult.Unsuccessful(
Expand Down Expand Up @@ -509,6 +541,10 @@ public async Task<MemcachedClientValueResult<ulong>> IncrAsync(
);
}
}
catch (OperationCanceledException) when (_memcachedConfiguration.IsTerseCancellationLogging)
{
return MemcachedClientValueResult<ulong>.Cancelled(nameof(IncrAsync));
}
catch (Exception e)
{
return MemcachedClientValueResult<ulong>.Unsuccessful(
Expand Down Expand Up @@ -553,6 +589,10 @@ public async Task<MemcachedClientValueResult<ulong>> DecrAsync(
);
}
}
catch (OperationCanceledException) when (_memcachedConfiguration.IsTerseCancellationLogging)
{
return MemcachedClientValueResult<ulong>.Cancelled(nameof(DecrAsync));
}
catch (Exception e)
{
return MemcachedClientValueResult<ulong>.Unsuccessful(
Expand Down Expand Up @@ -592,6 +632,10 @@ public async Task<MemcachedClientResult> FlushAsync(CancellationToken token)

return MemcachedClientResult.Successful;
}
catch (OperationCanceledException) when (_memcachedConfiguration.IsTerseCancellationLogging)
{
return MemcachedClientResult.Cancelled(nameof(FlushAsync));
}
catch (Exception e)
{
return MemcachedClientResult.Unsuccessful(
Expand Down
25 changes: 23 additions & 2 deletions src/Aer.Memcached.Client/Models/MemcachedClientResult.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,12 +1,24 @@
using System.Diagnostics.CodeAnalysis;

namespace Aer.Memcached.Client.Models;

/// <summary>
/// Represents a memcached result without a value.
/// </summary>
[SuppressMessage("ReSharper", "MemberCanBeInternal")]
public class MemcachedClientResult
{
/// <summary>
/// If set to <c>true</c>, then no errors occured on memcached side.
/// </summary>
public bool Success { get; }

/// <summary>
/// If set to <c>true</c>, then the request was cancelled by external cancellation token.
/// </summary>
/// When equals <c>true</c>, <see cref="ErrorMessage"/> contains a name of the operation that was cancelled.
public bool RequestCancelled { get; }

/// <summary>
/// If any errors occured on memcached side, this property contains the error message.
/// </summary>
Expand All @@ -22,11 +34,15 @@ public class MemcachedClientResult
/// Gets an instance of <see cref="MemcachedClientResult"/> with a successful result.
/// </summary>
public static MemcachedClientResult Successful { get; } = new(success: true);

internal MemcachedClientResult(bool success, string errorMessage = null)

internal MemcachedClientResult(
bool success,
string errorMessage = null,
bool isRequestCancelled = false)
{
Success = success;
ErrorMessage = errorMessage;
RequestCancelled = isRequestCancelled;
}

/// <summary>
Expand All @@ -35,4 +51,9 @@ internal MemcachedClientResult(bool success, string errorMessage = null)
/// <param name="errorMessage">The unsuccessful result error message.</param>
public static MemcachedClientResult Unsuccessful(string errorMessage)
=> new(success: false, errorMessage);

/// <summary>
/// Gets an instance of <see cref="MemcachedClientResult"/> that indicates request cancellation.
/// </summary>
internal static MemcachedClientResult Cancelled(string operationName) => new(success: false, isRequestCancelled: true, errorMessage: operationName);
}
Loading
Loading