Skip to content

Commit

Permalink
Distinguish cancellation from failure
Browse files Browse the repository at this point in the history
  • Loading branch information
roji committed Dec 13, 2021
1 parent 1fa736f commit 17e5716
Show file tree
Hide file tree
Showing 52 changed files with 1,242 additions and 114 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -63,6 +63,7 @@ private sealed class Enumerator : IEnumerator<T>, IAsyncEnumerator<T>
private readonly bool _standAloneStateManager;
private readonly CancellationToken _cancellationToken;
private readonly IConcurrencyDetector? _concurrencyDetector;
private readonly IExceptionDetector _exceptionDetector;

private IEnumerator<ValueBuffer>? _enumerator;

Expand All @@ -75,6 +76,7 @@ public Enumerator(QueryingEnumerable<T> queryingEnumerable, CancellationToken ca
_queryLogger = queryingEnumerable._queryLogger;
_standAloneStateManager = queryingEnumerable._standAloneStateManager;
_cancellationToken = cancellationToken;
_exceptionDetector = _queryContext.ExceptionDetector;
Current = default!;

_concurrencyDetector = queryingEnumerable._threadSafetyChecksEnabled
Expand Down Expand Up @@ -104,7 +106,14 @@ public bool MoveNext()
}
catch (Exception exception)
{
_queryLogger.QueryIterationFailed(_contextType, exception);
if (_exceptionDetector.IsCancellation(exception))
{
_queryLogger.QueryCanceled(_contextType);
}
else
{
_queryLogger.QueryIterationFailed(_contextType, exception);
}

throw;
}
Expand All @@ -129,7 +138,14 @@ public ValueTask<bool> MoveNextAsync()
}
catch (Exception exception)
{
_queryLogger.QueryIterationFailed(_contextType, exception);
if (_exceptionDetector.IsCancellation(exception, _cancellationToken))
{
_queryLogger.QueryCanceled(_contextType);
}
else
{
_queryLogger.QueryIterationFailed(_contextType, exception);
}

throw;
}
Expand Down
4 changes: 3 additions & 1 deletion src/EFCore.InMemory/Storage/Internal/InMemoryDatabase.cs
Original file line number Diff line number Diff line change
Expand Up @@ -64,7 +64,9 @@ public override int SaveChanges(IList<IUpdateEntry> entries)
public override Task<int> SaveChangesAsync(
IList<IUpdateEntry> entries,
CancellationToken cancellationToken = default)
=> Task.FromResult(_store.ExecuteTransaction(entries, _updateLogger));
=> cancellationToken.IsCancellationRequested
? Task.FromCanceled<int>(cancellationToken)
: Task.FromResult(_store.ExecuteTransaction(entries, _updateLogger));

/// <summary>
/// This is an internal API that supports the Entity Framework Core infrastructure and not subject to
Expand Down
25 changes: 25 additions & 0 deletions src/EFCore.Relational/Diagnostics/DbCommandInterceptor.cs
Original file line number Diff line number Diff line change
Expand Up @@ -361,6 +361,31 @@ public virtual ValueTask<int> NonQueryExecutedAsync(
CancellationToken cancellationToken = default)
=> new(result);

/// <summary>
/// Called when a command was canceled.
/// </summary>
/// <param name="command">The command.</param>
/// <param name="eventData">Contextual information about the command and execution.</param>
public virtual void CommandCanceled(
DbCommand command,
CommandEndEventData eventData)
{
}

/// <summary>
/// Called when a command was canceled.
/// </summary>
/// <param name="command">The command.</param>
/// <param name="eventData">Contextual information about the command and execution.</param>
/// <param name="cancellationToken">A <see cref="CancellationToken" /> to observe while waiting for the task to complete.</param>
/// <returns>A <see cref="Task" /> representing the asynchronous operation.</returns>
/// <exception cref="OperationCanceledException">If the <see cref="CancellationToken" /> is canceled.</exception>
public virtual Task CommandCanceledAsync(
DbCommand command,
CommandEndEventData eventData,
CancellationToken cancellationToken = default)
=> Task.CompletedTask;

/// <summary>
/// Called when execution of a command has failed with an exception.
/// </summary>
Expand Down
22 changes: 22 additions & 0 deletions src/EFCore.Relational/Diagnostics/IDbCommandInterceptor.cs
Original file line number Diff line number Diff line change
Expand Up @@ -365,6 +365,28 @@ ValueTask<int> NonQueryExecutedAsync(
int result,
CancellationToken cancellationToken = default);

/// <summary>
/// Called when a command was canceled.
/// </summary>
/// <param name="command">The command.</param>
/// <param name="eventData">Contextual information about the command and execution.</param>
void CommandCanceled(
DbCommand command,
CommandEndEventData eventData);

/// <summary>
/// Called when a command was canceled.
/// </summary>
/// <param name="command">The command.</param>
/// <param name="eventData">Contextual information about the command and execution.</param>
/// <param name="cancellationToken">A <see cref="CancellationToken" /> to observe while waiting for the task to complete.</param>
/// <returns>A <see cref="Task" /> representing the asynchronous operation.</returns>
/// <exception cref="OperationCanceledException">If the <see cref="CancellationToken" /> is canceled.</exception>
Task CommandCanceledAsync(
DbCommand command,
CommandEndEventData eventData,
CancellationToken cancellationToken = default);

/// <summary>
/// Called when execution of a command has failed with an exception.
/// </summary>
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -400,6 +400,56 @@ Task CommandErrorAsync(
CommandSource commandSource,
CancellationToken cancellationToken = default);

/// <summary>
/// Logs for the <see cref="RelationalEventId.CommandCanceled" /> event.
/// </summary>
/// <param name="connection">The connection.</param>
/// <param name="command">The database command object.</param>
/// <param name="context">The <see cref="DbContext" /> currently being used, to null if not known.</param>
/// <param name="executeMethod">Represents the method that will be called to execute the command.</param>
/// <param name="commandId">The correlation ID associated with the given <see cref="DbCommand" />.</param>
/// <param name="connectionId">The correlation ID associated with the <see cref="DbConnection" /> being used.</param>
/// <param name="startTime">The time that execution began.</param>
/// <param name="duration">The amount of time that passed until the exception was raised.</param>
/// <param name="commandSource">Source of the command.</param>
void CommandCanceled(
IRelationalConnection connection,
DbCommand command,
DbContext? context,
DbCommandMethod executeMethod,
Guid commandId,
Guid connectionId,
DateTimeOffset startTime,
TimeSpan duration,
CommandSource commandSource);

/// <summary>
/// Logs for the <see cref="RelationalEventId.CommandCanceled" /> event.
/// </summary>
/// <param name="connection">The connection.</param>
/// <param name="command">The database command object.</param>
/// <param name="context">The <see cref="DbContext" /> currently being used, to null if not known.</param>
/// <param name="executeMethod">Represents the method that will be called to execute the command.</param>
/// <param name="commandId">The correlation ID associated with the given <see cref="DbCommand" />.</param>
/// <param name="connectionId">The correlation ID associated with the <see cref="DbConnection" /> being used.</param>
/// <param name="startTime">The time that execution began.</param>
/// <param name="duration">The amount of time that passed until the exception was raised.</param>
/// <param name="commandSource">Source of the command.</param>
/// <param name="cancellationToken">A <see cref="CancellationToken" /> to observe while waiting for the task to complete.</param>
/// <returns>A <see cref="Task" /> representing the async operation.</returns>
/// <exception cref="OperationCanceledException">If the <see cref="CancellationToken" /> is canceled.</exception>
Task CommandCanceledAsync(
IRelationalConnection connection,
DbCommand command,
DbContext? context,
DbCommandMethod executeMethod,
Guid commandId,
Guid connectionId,
DateTimeOffset startTime,
TimeSpan duration,
CommandSource commandSource,
CancellationToken cancellationToken = default);

/// <summary>
/// Logs for the <see cref="RelationalEventId.DataReaderDisposing" /> event.
/// </summary>
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -221,6 +221,26 @@ public async ValueTask<int> NonQueryExecutedAsync(
return result;
}

public void CommandCanceled(DbCommand command, CommandEndEventData eventData)
{
for (var i = 0; i < _interceptors.Length; i++)
{
_interceptors[i].CommandCanceled(command, eventData);
}
}

public async Task CommandCanceledAsync(
DbCommand command,
CommandEndEventData eventData,
CancellationToken cancellationToken = default)
{
for (var i = 0; i < _interceptors.Length; i++)
{
await _interceptors[i].CommandCanceledAsync(command, eventData, cancellationToken)
.ConfigureAwait(false);
}
}

public void CommandFailed(DbCommand command, CommandErrorEventData eventData)
{
for (var i = 0; i < _interceptors.Length; i++)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -1257,6 +1257,158 @@ static string CommandError(EventDefinitionBase definition, EventData payload)

#endregion CommandError

#region CommandCanceled

/// <inheritdoc />
public virtual void CommandCanceled(
IRelationalConnection connection,
DbCommand command,
DbContext? context,
DbCommandMethod executeMethod,
Guid commandId,
Guid connectionId,
DateTimeOffset startTime,
TimeSpan duration,
CommandSource commandSource)
{
var definition = RelationalResources.LogCommandCanceled(this);

LogCommandCanceled(command, duration, definition);

if (NeedsEventData<IDbCommandInterceptor>(
definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled))
{
var eventData = BroadcastCommandCanceled(
connection.DbConnection,
command,
context,
executeMethod,
commandId,
connectionId,
false,
startTime,
duration,
definition,
diagnosticSourceEnabled,
simpleLogEnabled,
commandSource);

interceptor?.CommandCanceled(command, eventData);
}
}

/// <inheritdoc />
public virtual Task CommandCanceledAsync(
IRelationalConnection connection,
DbCommand command,
DbContext? context,
DbCommandMethod executeMethod,
Guid commandId,
Guid connectionId,
DateTimeOffset startTime,
TimeSpan duration,
CommandSource commandSource,
CancellationToken cancellationToken = default)
{
var definition = RelationalResources.LogCommandCanceled(this);

LogCommandCanceled(command, duration, definition);

if (NeedsEventData<IDbCommandInterceptor>(
definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled))
{
var eventData = BroadcastCommandCanceled(
connection.DbConnection,
command,
context,
executeMethod,
commandId,
connectionId,
true,
startTime,
duration,
definition,
diagnosticSourceEnabled,
simpleLogEnabled,
commandSource);

if (interceptor != null)
{
return interceptor.CommandCanceledAsync(command, eventData, cancellationToken);
}
}

return Task.CompletedTask;
}

private void LogCommandCanceled(
DbCommand command,
TimeSpan duration,
EventDefinition<string, string, CommandType, int, string, string> definition)
{
if (ShouldLog(definition))
{
definition.Log(
this,
string.Format(CultureInfo.InvariantCulture, "{0:N0}", duration.TotalMilliseconds),
command.Parameters.FormatParameters(ShouldLogParameterValues(command)),
command.CommandType,
command.CommandTimeout,
Environment.NewLine,
command.CommandText.TrimEnd());
}
}

private CommandEndEventData BroadcastCommandCanceled(
DbConnection connection,
DbCommand command,
DbContext? context,
DbCommandMethod executeMethod,
Guid commandId,
Guid connectionId,
bool async,
DateTimeOffset startTime,
TimeSpan duration,
EventDefinition<string, string, CommandType, int, string, string> definition,
bool diagnosticSourceEnabled,
bool simpleLogEnabled,
CommandSource commandSource)
{
var eventData = new CommandEndEventData(
definition,
CommandCanceled,
connection,
command,
context,
executeMethod,
commandId,
connectionId,
async,
ShouldLogParameterValues(command),
startTime,
duration,
commandSource);

DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled);

return eventData;

static string CommandCanceled(EventDefinitionBase definition, EventData payload)
{
var d = (EventDefinition<string, string, CommandType, int, string, string>)definition;
var p = (CommandEndEventData)payload;
return d.GenerateMessage(
string.Format(CultureInfo.InvariantCulture, "{0:N0}", p.Duration.TotalMilliseconds),
p.Command.Parameters.FormatParameters(p.LogParameterValues),
p.Command.CommandType,
p.Command.CommandTimeout,
Environment.NewLine,
p.Command.CommandText.TrimEnd());
}
}

#endregion CommandCanceled

#region DataReaderDisposing

/// <summary>
Expand Down
14 changes: 14 additions & 0 deletions src/EFCore.Relational/Diagnostics/RelationalEventId.cs
Original file line number Diff line number Diff line change
Expand Up @@ -36,6 +36,7 @@ private enum Id
CommandError,
CommandCreating,
CommandCreated,
CommandCanceled,

// Transaction events
TransactionStarted = CoreEventId.RelationalBaseId + 200,
Expand Down Expand Up @@ -171,6 +172,19 @@ private static EventId MakeConnectionId(Id id)
private static EventId MakeCommandId(Id id)
=> new((int)id, _sqlPrefix + id);

/// <summary>
/// A <see cref="DbCommand" /> has been canceled.
/// </summary>
/// <remarks>
/// <para>
/// This event is in the <see cref="DbLoggerCategory.Database.Command" /> category.
/// </para>
/// <para>
/// This event uses the <see cref="CommandEndEventData" /> payload when used with a <see cref="DiagnosticSource" />.
/// </para>
/// </remarks>
public static readonly EventId CommandCanceled = MakeCommandId(Id.CommandCanceled);

/// <summary>
/// A <see cref="DbCommand" /> is being created.
/// </summary>
Expand Down
Loading

0 comments on commit 17e5716

Please sign in to comment.