diff --git a/src/EFCore/ChangeTracking/Internal/StateManager.cs b/src/EFCore/ChangeTracking/Internal/StateManager.cs index faffa5c53cc..13a5431e9f0 100644 --- a/src/EFCore/ChangeTracking/Internal/StateManager.cs +++ b/src/EFCore/ChangeTracking/Internal/StateManager.cs @@ -1114,6 +1114,8 @@ protected virtual async Task SaveChangesAsync( { using (_concurrencyDetector.EnterCriticalSection()) { + EntityFrameworkEventSource.Log.SavingChanges(); + return await _database.SaveChangesAsync(entriesToSave, cancellationToken) .ConfigureAwait(false); } diff --git a/src/EFCore/DbContext.cs b/src/EFCore/DbContext.cs index 31efe9f5c3e..8f0d0ad35d5 100644 --- a/src/EFCore/DbContext.cs +++ b/src/EFCore/DbContext.cs @@ -112,6 +112,8 @@ public DbContext([NotNull] DbContextOptions options) ServiceProviderCache.Instance.GetOrAdd(options, providerRequired: false) .GetRequiredService() .InitializeSets(this); + + EntityFrameworkEventSource.Log.DbContextInitializing(); } /// @@ -347,8 +349,6 @@ private IServiceProvider InternalServiceProvider { _initializing = true; - EntityFrameworkEventSource.Log.DbContextInitializing(); - var optionsBuilder = new DbContextOptionsBuilder(_options); OnConfiguring(optionsBuilder); @@ -642,6 +642,8 @@ public virtual async Task SaveChangesAsync( } catch (DbUpdateConcurrencyException exception) { + EntityFrameworkEventSource.Log.OptimisticConcurrencyFailure(); + await DbContextDependencies.UpdateLogger.OptimisticConcurrencyExceptionAsync(this, exception, cancellationToken) .ConfigureAwait(false); diff --git a/src/EFCore/Infrastructure/EntityFrameworkEventSource.cs b/src/EFCore/Infrastructure/EntityFrameworkEventSource.cs index 1832d42d444..7f56aed489a 100644 --- a/src/EFCore/Infrastructure/EntityFrameworkEventSource.cs +++ b/src/EFCore/Infrastructure/EntityFrameworkEventSource.cs @@ -5,6 +5,7 @@ using System.Diagnostics.Tracing; using System.Runtime.InteropServices; using System.Threading; +using JetBrains.Annotations; using Microsoft.EntityFrameworkCore.Storage; namespace Microsoft.EntityFrameworkCore.Infrastructure @@ -156,6 +157,10 @@ protected override void OnEventCommand(EventCommandEventArgs command) } } + [UsedImplicitly] + private void ResetCacheInfo() + => _compiledQueryCacheInfo = new CacheInfo(); + [StructLayout(LayoutKind.Explicit)] private struct CacheInfo { diff --git a/src/EFCore/Storage/ExecutionStrategy.cs b/src/EFCore/Storage/ExecutionStrategy.cs index 16240197fa0..4f947f62023 100644 --- a/src/EFCore/Storage/ExecutionStrategy.cs +++ b/src/EFCore/Storage/ExecutionStrategy.cs @@ -273,6 +273,9 @@ private async Task ExecuteImplementationAsync( catch (Exception ex) { Suspended = false; + + EntityFrameworkEventSource.Log.ExecutionStrategyOperationFailure(); + if (verifySucceeded != null && CallOnWrappedException(ex, ShouldVerifySuccessOn)) { diff --git a/test/EFCore.Tests/EventSourceTest.cs b/test/EFCore.Tests/EventSourceTest.cs new file mode 100644 index 00000000000..1891b19c861 --- /dev/null +++ b/test/EFCore.Tests/EventSourceTest.cs @@ -0,0 +1,293 @@ +// 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.Generic; +using System.Linq; +using System.Reflection; +using System.Threading.Tasks; +using Microsoft.EntityFrameworkCore.Infrastructure; +using Microsoft.EntityFrameworkCore.Storage; +using Xunit; + +namespace Microsoft.EntityFrameworkCore +{ + [Collection("EventSourceTest")] + public class EventSourceTest + { + private static readonly BindingFlags _bindingFlags = BindingFlags.Instance | BindingFlags.NonPublic; + + [ConditionalTheory] + [InlineData(false)] + [InlineData(true)] + public async Task Counts_when_query_is_executed(bool async) + { + TotalQueries = 0; + + for (var i = 1; i <= 3; i++) + { + using var context = new SomeDbContext(); + + _ = async ? await context.Foos.ToListAsync() : context.Foos.ToList(); + + Assert.Equal(i, TotalQueries); + } + } + + [ConditionalTheory] + [InlineData(false)] + [InlineData(true)] + public async Task Counts_when_SaveChanges_is_called(bool async) + { + TotalSaveChanges = 0; + + for (var i = 1; i <= 3; i++) + { + using var context = new SomeDbContext(); + + context.Add(new Foo()); + + _ = async ? await context.SaveChangesAsync() : context.SaveChanges(); + + Assert.Equal(i, TotalSaveChanges); + } + } + + [ConditionalTheory] + [InlineData(false)] + [InlineData(true)] + public async Task Counts_when_context_is_constructed_and_disposed(bool async) + { + ActiveDbContexts = 0; + var contexts = new List(); + + for (var i = 1; i <= 3; i++) + { + contexts.Add(new SomeDbContext()); + + Assert.Equal(i, ActiveDbContexts); + } + + for (var i = 2; i >= 0; i--) + { + if (async) + { + await ((IAsyncDisposable)contexts[i]).DisposeAsync(); + } + else + { + contexts[i].Dispose(); + } + + Assert.Equal(i, ActiveDbContexts); + } + } + + [ConditionalTheory] + [InlineData(false)] + [InlineData(true)] + public async Task Counts_query_cache_hits_and_misses(bool async) + { + ResetCacheInfo(); + + for (var i = 1; i <= 3; i++) + { + using var context = new SomeDbContext(); + + var query = context.Foos.Where(e => e.Id == new Guid("6898CFFC-3DCC-45A6-A472-A23057462EE6")); + + _ = async ? await query.ToListAsync() : query.ToList(); + + Assert.Equal(1, CompiledQueryCacheInfoMisses); + Assert.Equal(i - 1, CompiledQueryCacheInfoHits); + } + } + + [ConditionalTheory] + [InlineData(false)] + [InlineData(true)] + public async Task Counts_when_DbUpdateConcurrencyException_is_thrown(bool async) + { + TotalOptimisticConcurrencyFailures = 0; + + for (var i = 1; i <= 3; i++) + { + using var context = new SomeDbContext(); + + var entity = new Foo(); + context.Add(entity); + context.SaveChanges(); + + using (var innerContext = new SomeDbContext()) + { + innerContext.Foos.Find(entity.Id).Token = 1; + innerContext.SaveChanges(); + } + + entity.Token = 2; + + if (async) + { + await Assert.ThrowsAsync(async () => await context.SaveChangesAsync()); + } + else + { + Assert.Throws(() => context.SaveChanges()); + } + + Assert.Equal(i, TotalOptimisticConcurrencyFailures); + } + } + + [ConditionalTheory] + [InlineData(false)] + [InlineData(true)] + public async Task Counts_when_execution_strategy_retries(bool async) + { + TotalExecutionStrategyOperationFailures = 0; + + for (var i = 1; i <= 3; i++) + { + using var context = new SomeDbContext(); + + var executionCount = 0; + var executionStrategyMock = new ExecutionStrategyTest.TestExecutionStrategy( + context, + retryCount: 2, + shouldRetryOn: e => e is ArgumentOutOfRangeException, + getNextDelay: e => TimeSpan.FromTicks(0)); + + if (async) + { + Assert.IsType( + (await Assert.ThrowsAsync( + () => + executionStrategyMock.ExecuteAsync( + () => + { + if (executionCount++ < 3) + { + throw new ArgumentOutOfRangeException(); + } + + Assert.True(false); + return Task.FromResult(1); + }))).InnerException); + } + else + { + Assert.IsType( + Assert.Throws( + () => + executionStrategyMock.Execute( + () => + { + if (executionCount++ < 3) + { + throw new ArgumentOutOfRangeException(); + } + + Assert.True(false); + return 0; + })).InnerException); + } + + Assert.Equal(3, executionCount); + Assert.Equal(i * 3, TotalExecutionStrategyOperationFailures); + } + } + + private static readonly FieldInfo _activeDbContexts + = typeof(EntityFrameworkEventSource).GetField("_activeDbContexts", _bindingFlags); + + private static long ActiveDbContexts + { + get => (long)_activeDbContexts.GetValue(EntityFrameworkEventSource.Log); + set => _activeDbContexts.SetValue(EntityFrameworkEventSource.Log, value); + } + + private static readonly FieldInfo _totalQueries + = typeof(EntityFrameworkEventSource).GetField(nameof(_totalQueries), _bindingFlags); + + private static long TotalQueries + { + get => (long)_totalQueries.GetValue(EntityFrameworkEventSource.Log); + set => _totalQueries.SetValue(EntityFrameworkEventSource.Log, value); + } + + private static readonly FieldInfo _totalSaveChanges + = typeof(EntityFrameworkEventSource).GetField(nameof(_totalSaveChanges), _bindingFlags); + + private static long TotalSaveChanges + { + get => (long)_totalSaveChanges.GetValue(EntityFrameworkEventSource.Log); + set => _totalSaveChanges.SetValue(EntityFrameworkEventSource.Log, value); + } + + private static readonly FieldInfo _totalExecutionStrategyOperationFailures + = typeof(EntityFrameworkEventSource).GetField(nameof(_totalExecutionStrategyOperationFailures), _bindingFlags); + + private static long TotalExecutionStrategyOperationFailures + { + get => (long)_totalExecutionStrategyOperationFailures.GetValue(EntityFrameworkEventSource.Log); + set => _totalExecutionStrategyOperationFailures.SetValue(EntityFrameworkEventSource.Log, value); + } + + private static readonly FieldInfo _totalOptimisticConcurrencyFailures + = typeof(EntityFrameworkEventSource).GetField(nameof(_totalOptimisticConcurrencyFailures), _bindingFlags); + + private static long TotalOptimisticConcurrencyFailures + { + get => (long)_totalOptimisticConcurrencyFailures.GetValue(EntityFrameworkEventSource.Log); + set => _totalOptimisticConcurrencyFailures.SetValue(EntityFrameworkEventSource.Log, value); + } + + private static readonly FieldInfo _compiledQueryCacheInfo + = typeof(EntityFrameworkEventSource).GetField(nameof(_compiledQueryCacheInfo), _bindingFlags); + + private static readonly MethodInfo _resetCacheInfo + = typeof(EntityFrameworkEventSource).GetMethod("ResetCacheInfo", _bindingFlags); + + private static readonly FieldInfo _compiledQueryCacheInfoHits + = _compiledQueryCacheInfo.FieldType.GetField("Hits", _bindingFlags); + + private static int CompiledQueryCacheInfoHits + { + get => (int)_compiledQueryCacheInfoHits.GetValue(_compiledQueryCacheInfo.GetValue(EntityFrameworkEventSource.Log)); + } + + private static readonly FieldInfo _compiledQueryCacheInfoMisses + = _compiledQueryCacheInfo.FieldType.GetField("Misses", _bindingFlags); + + private static int CompiledQueryCacheInfoMisses + { + get => (int)_compiledQueryCacheInfoMisses.GetValue(_compiledQueryCacheInfo.GetValue(EntityFrameworkEventSource.Log)); + } + + private static void ResetCacheInfo() + => _resetCacheInfo.Invoke(EntityFrameworkEventSource.Log, null); + + private class SomeDbContext : DbContext + { + public DbSet Foos { get; set; } + + protected internal override void OnModelCreating(ModelBuilder modelBuilder) + => modelBuilder.Entity().Property(e => e.Token).IsConcurrencyToken(); + + protected internal override void OnConfiguring(DbContextOptionsBuilder optionsBuilder) + => optionsBuilder + .UseInMemoryDatabase(nameof(EventSourceTest)); + } + + private class Foo + { + public Guid Id { get; set; } + public int Token { get; set; } + } + } + + [CollectionDefinition("EventSourceTest", DisableParallelization = true)] + public class EventSourceTestCollection + { + } +} diff --git a/test/EFCore.Tests/Storage/ExecutionStrategyTest.cs b/test/EFCore.Tests/Storage/ExecutionStrategyTest.cs index 2cd963eb980..d2a2b7760a2 100644 --- a/test/EFCore.Tests/Storage/ExecutionStrategyTest.cs +++ b/test/EFCore.Tests/Storage/ExecutionStrategyTest.cs @@ -649,7 +649,7 @@ protected DbContext CreateContext() .AddScoped()), InMemoryTestHelpers.Instance.CreateOptions()); - private class TestExecutionStrategy : ExecutionStrategy + public class TestExecutionStrategy : ExecutionStrategy { private readonly Func _shouldRetryOn; private readonly Func _getNextDelay;