Skip to content

Commit 62fb246

Browse files
ajcvickersajcvickers
authored
Add interception for DbDataReader.Close (#28290)
Part of #626 Fixes #23535 Also added tests to: - Show that this can be used to get statistics from a query, as requested in #23535. - Show that Close and/or Dispose can be suppressed, as requested in #24295.
1 parent df3ae11 commit 62fb246

18 files changed

+837
-80
lines changed

‎src/EFCore.Relational/Diagnostics/DataReaderClosingEventData.cs‎

Lines changed: 50 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,50 @@
1+
// Licensed to the .NET Foundation under one or more agreements.
2+
// The .NET Foundation licenses this file to you under the MIT license.
3+
4+
namespace Microsoft.EntityFrameworkCore.Diagnostics;
5+
6+
/// <summary>
7+
/// <see cref="DiagnosticSource" /> event payload for <see cref="RelationalEventId.DataReaderClosing" />.
8+
/// </summary>
9+
/// <remarks>
10+
/// See <see href="https://aka.ms/efcore-docs-diagnostics">Logging, events, and diagnostics</see> for more information and examples.
11+
/// </remarks>
12+
public class DataReaderClosingEventData : DataReaderEventData
13+
{
14+
/// <summary>
15+
/// Constructs a <see cref="DiagnosticSource" /> event payload for <see cref="RelationalEventId.DataReaderClosing" />.
16+
/// </summary>
17+
/// <param name="eventDefinition">The event definition.</param>
18+
/// <param name="messageGenerator">A delegate that generates a log message for this event.</param>
19+
/// <param name="command">The <see cref="DbCommand" /> that created the reader.</param>
20+
/// <param name="dataReader">The <see cref="DbDataReader" /> that is being disposed.</param>
21+
/// <param name="context">The <see cref="DbContext" /> currently being used, to null if not known.</param>
22+
/// <param name="commandId">A correlation ID that identifies the <see cref="DbCommand" /> instance being used.</param>
23+
/// <param name="connectionId">A correlation ID that identifies the <see cref="DbConnection" /> instance being used.</param>
24+
/// <param name="async">Indicates whether or not the command was executed asynchronously.</param>
25+
/// <param name="recordsAffected">Gets the number of rows changed, inserted, or deleted by execution of the SQL statement.</param>
26+
/// <param name="readCount">Gets the number of read operations performed by this reader.</param>
27+
/// <param name="startTime">The time when the data reader was created.</param>
28+
public DataReaderClosingEventData(
29+
EventDefinitionBase eventDefinition,
30+
Func<EventDefinitionBase, EventData, string> messageGenerator,
31+
DbCommand command,
32+
DbDataReader dataReader,
33+
DbContext? context,
34+
Guid commandId,
35+
Guid connectionId,
36+
bool async,
37+
int recordsAffected,
38+
int readCount,
39+
DateTimeOffset startTime)
40+
: base(
41+
eventDefinition, messageGenerator, command, dataReader, context, commandId, connectionId, recordsAffected, readCount, startTime)
42+
{
43+
IsAsync = async;
44+
}
45+
46+
/// <summary>
47+
/// Indicates whether or not the operation is being executed asynchronously.
48+
/// </summary>
49+
public virtual bool IsAsync { get; }
50+
}

‎src/EFCore.Relational/Diagnostics/DataReaderDisposingEventData.cs‎

Lines changed: 10 additions & 47 deletions
Original file line numberDiff line numberDiff line change
@@ -9,7 +9,7 @@ namespace Microsoft.EntityFrameworkCore.Diagnostics;
99
/// <remarks>
1010
/// See <see href="https://aka.ms/efcore-docs-diagnostics">Logging, events, and diagnostics</see> for more information and examples.
1111
/// </remarks>
12-
public class DataReaderDisposingEventData : DbContextEventData
12+
public class DataReaderDisposingEventData : DataReaderEventData
1313
{
1414
/// <summary>
1515
/// Constructs a <see cref="DiagnosticSource" /> event payload for <see cref="RelationalEventId.DataReaderDisposing" />.
@@ -23,8 +23,11 @@ public class DataReaderDisposingEventData : DbContextEventData
2323
/// <param name="connectionId">A correlation ID that identifies the <see cref="DbConnection" /> instance being used.</param>
2424
/// <param name="recordsAffected">Gets the number of rows changed, inserted, or deleted by execution of the SQL statement.</param>
2525
/// <param name="readCount">Gets the number of read operations performed by this reader.</param>
26-
/// <param name="startTime">The start time of this event.</param>
27-
/// <param name="duration">The duration this event.</param>
26+
/// <param name="startTime">The time when the data reader was created.</param>
27+
/// <param name="duration">
28+
/// The duration from the time the data reader is created until it is disposed. This corresponds to the time reading
29+
/// for reading results of a query.
30+
/// </param>
2831
public DataReaderDisposingEventData(
2932
EventDefinitionBase eventDefinition,
3033
Func<EventDefinitionBase, EventData, string> messageGenerator,
@@ -37,55 +40,15 @@ public DataReaderDisposingEventData(
3740
int readCount,
3841
DateTimeOffset startTime,
3942
TimeSpan duration)
40-
: base(eventDefinition, messageGenerator, context)
43+
: base(
44+
eventDefinition, messageGenerator, command, dataReader, context, commandId, connectionId, recordsAffected, readCount, startTime)
4145
{
42-
Command = command;
43-
DataReader = dataReader;
44-
CommandId = commandId;
45-
ConnectionId = connectionId;
46-
RecordsAffected = recordsAffected;
47-
ReadCount = readCount;
48-
StartTime = startTime;
4946
Duration = duration;
5047
}
5148

5249
/// <summary>
53-
/// The <see cref="DbCommand" /> that created the reader.
54-
/// </summary>
55-
public virtual DbCommand Command { get; }
56-
57-
/// <summary>
58-
/// The <see cref="DbDataReader" /> that is being disposed.
59-
/// </summary>
60-
public virtual DbDataReader DataReader { get; }
61-
62-
/// <summary>
63-
/// A correlation ID that identifies the <see cref="DbCommand" /> instance being used.
64-
/// </summary>
65-
public virtual Guid CommandId { get; }
66-
67-
/// <summary>
68-
/// A correlation ID that identifies the <see cref="DbConnection" /> instance being used.
69-
/// </summary>
70-
public virtual Guid ConnectionId { get; }
71-
72-
/// <summary>
73-
/// Gets the number of rows changed, inserted, or deleted by execution of the SQL statement.
74-
/// </summary>
75-
public virtual int RecordsAffected { get; }
76-
77-
/// <summary>
78-
/// Gets the number of read operations performed by this reader.
79-
/// </summary>
80-
public virtual int ReadCount { get; }
81-
82-
/// <summary>
83-
/// The start time of this event.
84-
/// </summary>
85-
public virtual DateTimeOffset StartTime { get; }
86-
87-
/// <summary>
88-
/// The duration this event.
50+
/// The duration from the time the data reader is created until it is disposed. This corresponds to the time reading
51+
/// for reading results of a query.
8952
/// </summary>
9053
public virtual TimeSpan Duration { get; }
9154
}

‎src/EFCore.Relational/Diagnostics/DataReaderEventData.cs‎

Lines changed: 83 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,83 @@
1+
// Licensed to the .NET Foundation under one or more agreements.
2+
// The .NET Foundation licenses this file to you under the MIT license.
3+
4+
namespace Microsoft.EntityFrameworkCore.Diagnostics;
5+
6+
/// <summary>
7+
/// <see cref="DiagnosticSource" /> event payload for <see cref="RelationalEventId.DataReaderClosing" />.
8+
/// </summary>
9+
/// <remarks>
10+
/// See <see href="https://aka.ms/efcore-docs-diagnostics">Logging, events, and diagnostics</see> for more information and examples.
11+
/// </remarks>
12+
public class DataReaderEventData : DbContextEventData
13+
{
14+
/// <summary>
15+
/// Constructs a <see cref="DiagnosticSource" /> event payload for <see cref="RelationalEventId.DataReaderClosing" />.
16+
/// </summary>
17+
/// <param name="eventDefinition">The event definition.</param>
18+
/// <param name="messageGenerator">A delegate that generates a log message for this event.</param>
19+
/// <param name="command">The <see cref="DbCommand" /> that created the reader.</param>
20+
/// <param name="dataReader">The <see cref="DbDataReader" /> that is being disposed.</param>
21+
/// <param name="context">The <see cref="DbContext" /> currently being used, to null if not known.</param>
22+
/// <param name="commandId">A correlation ID that identifies the <see cref="DbCommand" /> instance being used.</param>
23+
/// <param name="connectionId">A correlation ID that identifies the <see cref="DbConnection" /> instance being used.</param>
24+
/// <param name="recordsAffected">Gets the number of rows changed, inserted, or deleted by execution of the SQL statement.</param>
25+
/// <param name="readCount">Gets the number of read operations performed by this reader.</param>
26+
/// <param name="startTime">The start time of this event.</param>
27+
public DataReaderEventData(
28+
EventDefinitionBase eventDefinition,
29+
Func<EventDefinitionBase, EventData, string> messageGenerator,
30+
DbCommand command,
31+
DbDataReader dataReader,
32+
DbContext? context,
33+
Guid commandId,
34+
Guid connectionId,
35+
int recordsAffected,
36+
int readCount,
37+
DateTimeOffset startTime)
38+
: base(eventDefinition, messageGenerator, context)
39+
{
40+
Command = command;
41+
DataReader = dataReader;
42+
CommandId = commandId;
43+
ConnectionId = connectionId;
44+
RecordsAffected = recordsAffected;
45+
ReadCount = readCount;
46+
StartTime = startTime;
47+
}
48+
49+
/// <summary>
50+
/// The <see cref="DbCommand" /> that created the reader.
51+
/// </summary>
52+
public virtual DbCommand Command { get; }
53+
54+
/// <summary>
55+
/// The <see cref="DbDataReader" /> that is being disposed.
56+
/// </summary>
57+
public virtual DbDataReader DataReader { get; }
58+
59+
/// <summary>
60+
/// A correlation ID that identifies the <see cref="DbCommand" /> instance being used.
61+
/// </summary>
62+
public virtual Guid CommandId { get; }
63+
64+
/// <summary>
65+
/// A correlation ID that identifies the <see cref="DbConnection" /> instance being used.
66+
/// </summary>
67+
public virtual Guid ConnectionId { get; }
68+
69+
/// <summary>
70+
/// Gets the number of rows changed, inserted, or deleted by execution of the SQL statement.
71+
/// </summary>
72+
public virtual int RecordsAffected { get; }
73+
74+
/// <summary>
75+
/// Gets the number of read operations performed by this reader.
76+
/// </summary>
77+
public virtual int ReadCount { get; }
78+
79+
/// <summary>
80+
/// The start time of this event.
81+
/// </summary>
82+
public virtual DateTimeOffset StartTime { get; }
83+
}

‎src/EFCore.Relational/Diagnostics/IDbCommandInterceptor.cs‎

Lines changed: 42 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -412,6 +412,48 @@ void CommandFailed(DbCommand command, CommandErrorEventData eventData)
412412
Task CommandFailedAsync(DbCommand command, CommandErrorEventData eventData, CancellationToken cancellationToken = default)
413413
=> Task.CompletedTask;
414414

415+
/// <summary>
416+
/// Called just before EF intends to call <see cref="DbDataReader.Close()" />.
417+
/// </summary>
418+
/// <param name="command">The command.</param>
419+
/// <param name="eventData">Contextual information about the command.</param>
420+
/// <param name="result">
421+
/// Represents the current result if one exists.
422+
/// This value will have <see cref="InterceptionResult.IsSuppressed" /> set to <see langword="true" /> if some previous
423+
/// interceptor suppressed execution by calling <see cref="InterceptionResult.Suppress" />.
424+
/// This value is typically used as the return value for the implementation of this method.
425+
/// </param>
426+
/// <returns>
427+
/// If <see cref="InterceptionResult.IsSuppressed" /> is <see langword="false" />, then EF will continue as normal.
428+
/// If <see cref="InterceptionResult.IsSuppressed" /> is <see langword="true" />, then EF will suppress the operation
429+
/// it was about to perform.
430+
/// An implementation of this method for any interceptor that is not attempting to suppress
431+
/// the operation is to return the <paramref name="result" /> value passed in.
432+
/// </returns>
433+
InterceptionResult DataReaderClosing(DbCommand command, DataReaderClosingEventData eventData, InterceptionResult result)
434+
=> result;
435+
436+
/// <summary>
437+
/// Called just before EF intends to call <see cref="DbDataReader.CloseAsync()" /> in an async context.
438+
/// </summary>
439+
/// <param name="command">The command.</param>
440+
/// <param name="eventData">Contextual information about the command.</param>
441+
/// <param name="result">
442+
/// Represents the current result if one exists.
443+
/// This value will have <see cref="InterceptionResult.IsSuppressed" /> set to <see langword="true" /> if some previous
444+
/// interceptor suppressed execution by calling <see cref="InterceptionResult.Suppress" />.
445+
/// This value is typically used as the return value for the implementation of this method.
446+
/// </param>
447+
/// <returns>
448+
/// If <see cref="InterceptionResult.IsSuppressed" /> is <see langword="false" />, then EF will continue as normal.
449+
/// If <see cref="InterceptionResult.IsSuppressed" /> is <see langword="true" />, then EF will suppress the operation
450+
/// it was about to perform.
451+
/// An implementation of this method for any interceptor that is not attempting to suppress
452+
/// the operation is to return the <paramref name="result" /> value passed in.
453+
/// </returns>
454+
ValueTask<InterceptionResult> DataReaderClosingAsync(DbCommand command, DataReaderClosingEventData eventData, InterceptionResult result)
455+
=> new(result);
456+
415457
/// <summary>
416458
/// Called when execution of a <see cref="DbDataReader" /> is about to be disposed.
417459
/// </summary>

‎src/EFCore.Relational/Diagnostics/IRelationalCommandDiagnosticsLogger.cs‎

Lines changed: 45 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -496,6 +496,46 @@ InterceptionResult DataReaderDisposing(
496496
DateTimeOffset startTime,
497497
TimeSpan duration);
498498

499+
/// <summary>
500+
/// Logs for the <see cref="RelationalEventId.DataReaderClosing" /> event.
501+
/// </summary>
502+
/// <param name="connection">The connection.</param>
503+
/// <param name="command">The database command object.</param>
504+
/// <param name="dataReader">The data reader.</param>
505+
/// <param name="commandId">The correlation ID associated with the given <see cref="DbCommand" />.</param>
506+
/// <param name="recordsAffected">The number of records in the database that were affected.</param>
507+
/// <param name="readCount">The number of records that were read.</param>
508+
/// <param name="startTime">The time that the operation was started.</param>
509+
/// <returns>The result of execution, which may have been modified by an interceptor.</returns>
510+
InterceptionResult DataReaderClosing(
511+
IRelationalConnection connection,
512+
DbCommand command,
513+
DbDataReader dataReader,
514+
Guid commandId,
515+
int recordsAffected,
516+
int readCount,
517+
DateTimeOffset startTime);
518+
519+
/// <summary>
520+
/// Logs for the <see cref="RelationalEventId.DataReaderClosing" /> event.
521+
/// </summary>
522+
/// <param name="connection">The connection.</param>
523+
/// <param name="command">The database command object.</param>
524+
/// <param name="dataReader">The data reader.</param>
525+
/// <param name="commandId">The correlation ID associated with the given <see cref="DbCommand" />.</param>
526+
/// <param name="recordsAffected">The number of records in the database that were affected.</param>
527+
/// <param name="readCount">The number of records that were read.</param>
528+
/// <param name="startTime">The time that the operation was started.</param>
529+
/// <returns>The result of execution, which may have been modified by an interceptor.</returns>
530+
ValueTask<InterceptionResult> DataReaderClosingAsync(
531+
IRelationalConnection connection,
532+
DbCommand command,
533+
DbDataReader dataReader,
534+
Guid commandId,
535+
int recordsAffected,
536+
int readCount,
537+
DateTimeOffset startTime);
538+
499539
/// <summary>
500540
/// Whether <see cref="RelationalEventId.CommandCreating" /> or <see cref="RelationalEventId.CommandCreated" /> need
501541
/// to be logged.
@@ -508,11 +548,13 @@ InterceptionResult DataReaderDisposing(
508548
/// </summary>
509549
bool ShouldLogCommandExecute(DateTimeOffset now);
510550

551+
/// <summary>
552+
/// Whether <see cref="RelationalEventId.DataReaderClosing" /> needs to be logged.
553+
/// </summary>
554+
bool ShouldLogDataReaderClose(DateTimeOffset now);
555+
511556
/// <summary>
512557
/// Whether <see cref="RelationalEventId.DataReaderDisposing" /> needs to be logged.
513558
/// </summary>
514559
bool ShouldLogDataReaderDispose(DateTimeOffset now);
515-
516-
private bool ShouldLogParameterValues(DbCommand command)
517-
=> command.Parameters.Count > 0 && ShouldLogSensitiveData();
518560
}

‎src/EFCore.Relational/Diagnostics/Internal/DbCommandInterceptorAggregator.cs‎

Lines changed: 24 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -273,6 +273,30 @@ await _interceptors[i].CommandFailedAsync(command, eventData, cancellationToken)
273273
}
274274
}
275275

276+
public InterceptionResult DataReaderClosing(DbCommand command, DataReaderClosingEventData eventData, InterceptionResult result)
277+
{
278+
for (var i = 0; i < _interceptors.Length; i++)
279+
{
280+
result = _interceptors[i].DataReaderClosing(command, eventData, result);
281+
}
282+
283+
return result;
284+
}
285+
286+
public async ValueTask<InterceptionResult> DataReaderClosingAsync(
287+
DbCommand command,
288+
DataReaderClosingEventData eventData,
289+
InterceptionResult result)
290+
{
291+
for (var i = 0; i < _interceptors.Length; i++)
292+
{
293+
result = await _interceptors[i].DataReaderClosingAsync(command, eventData, result)
294+
.ConfigureAwait(false);
295+
}
296+
297+
return result;
298+
}
299+
276300
public InterceptionResult DataReaderDisposing(
277301
DbCommand command,
278302
DataReaderDisposingEventData eventData,

0 commit comments

Comments
 (0)