From b0db86c74851bb5f8a3c46a13323661a6bf0dcbf Mon Sep 17 00:00:00 2001 From: Smit Patel Date: Thu, 25 Jun 2020 17:09:02 -0700 Subject: [PATCH] Query: Generate a warning for multiple collection Includes Resolves #19933 --- .../Diagnostics/RelationalEventId.cs | 11 + .../Diagnostics/RelationalLoggerExtensions.cs | 24 ++ .../RelationalLoggingDefinitions.cs | 9 + .../Properties/RelationalStrings.Designer.cs | 24 ++ .../Properties/RelationalStrings.resx | 4 + ...CollectionJoinApplyingExpressionVisitor.cs | 14 +- .../RelationalQueryCompilationContext.cs | 8 +- .../Query/QueryBugsTest.cs | 215 +++++++++++++++--- ...ServerDbContextOptionsBuilderExtensions.cs | 2 + .../TestUtilities/SqliteTestStore.cs | 1 + 10 files changed, 276 insertions(+), 36 deletions(-) diff --git a/src/EFCore.Relational/Diagnostics/RelationalEventId.cs b/src/EFCore.Relational/Diagnostics/RelationalEventId.cs index 8fcff84a13e..b8909b91673 100644 --- a/src/EFCore.Relational/Diagnostics/RelationalEventId.cs +++ b/src/EFCore.Relational/Diagnostics/RelationalEventId.cs @@ -77,6 +77,7 @@ private enum Id QueryPossibleUnintendedUseOfEqualsWarning, QueryPossibleExceptionWithAggregateOperatorWarning, ValueConversionSqlLiteralWarning, // This warning has been removed. + MultipleCollectionIncludeWarning, // Model validation events ModelValidationKeyDefaultValueWarning = CoreEventId.RelationalBaseId + 600, @@ -611,6 +612,16 @@ private enum Id public static readonly EventId QueryPossibleExceptionWithAggregateOperatorWarning = MakeQueryId(Id.QueryPossibleExceptionWithAggregateOperatorWarning); + /// + /// + /// A query is loading multiple related collections without configuring a . + /// + /// + /// This event is in the category. + /// + /// + public static readonly EventId MultipleCollectionIncludeWarning = MakeQueryId(Id.MultipleCollectionIncludeWarning); + private static readonly string _validationPrefix = DbLoggerCategory.Model.Validation.Name + "."; private static EventId MakeValidationId(Id id) => new EventId((int)id, _validationPrefix + id); diff --git a/src/EFCore.Relational/Diagnostics/RelationalLoggerExtensions.cs b/src/EFCore.Relational/Diagnostics/RelationalLoggerExtensions.cs index 034b54b83aa..c7ff515751b 100644 --- a/src/EFCore.Relational/Diagnostics/RelationalLoggerExtensions.cs +++ b/src/EFCore.Relational/Diagnostics/RelationalLoggerExtensions.cs @@ -4183,6 +4183,30 @@ public static void QueryPossibleExceptionWithAggregateOperatorWarning( } } + /// + /// Logs for the event. + /// + /// The diagnostics logger to use. + public static void MultipleCollectionIncludeWarning( + [NotNull] this IDiagnosticsLogger diagnostics) + { + var definition = RelationalResources.LogMultipleCollectionIncludeWarning(diagnostics); + + if (diagnostics.ShouldLog(definition)) + { + definition.Log(diagnostics); + } + + if (diagnostics.NeedsEventData(definition, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + var eventData = new EventData( + definition, + (d, p) => ((EventDefinition)d).GenerateMessage()); + + diagnostics.DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); + } + } + /// /// Logs for the event. /// diff --git a/src/EFCore.Relational/Diagnostics/RelationalLoggingDefinitions.cs b/src/EFCore.Relational/Diagnostics/RelationalLoggingDefinitions.cs index 0e67c8edf53..feb1fb0b25d 100644 --- a/src/EFCore.Relational/Diagnostics/RelationalLoggingDefinitions.cs +++ b/src/EFCore.Relational/Diagnostics/RelationalLoggingDefinitions.cs @@ -474,5 +474,14 @@ public abstract class RelationalLoggingDefinitions : LoggingDefinitions /// [EntityFrameworkInternal] public EventDefinitionBase LogUnnamedIndexPropertiesMappedToNonOverlappingTables; + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + [EntityFrameworkInternal] + public EventDefinitionBase LogMultipleCollectionIncludeWarning; } } diff --git a/src/EFCore.Relational/Properties/RelationalStrings.Designer.cs b/src/EFCore.Relational/Properties/RelationalStrings.Designer.cs index 62dce1d6429..585b69678cb 100644 --- a/src/EFCore.Relational/Properties/RelationalStrings.Designer.cs +++ b/src/EFCore.Relational/Properties/RelationalStrings.Designer.cs @@ -2103,5 +2103,29 @@ public static EventDefinition Lo return (EventDefinition)definition; } + + /// + /// Compiling a query which loads related collections for more than one collection navigation property either via 'Include' or through projection but no 'QuerySplittingBehavior' has been configured. By default EF Core will use 'QuerySplittingBehavior.SingleQuery' which can potentially result in slow query performance. See https://go.microsoft.com/fwlink/?linkid=2134277 for more information. To identify the query that's triggering this warning call .ConfigureWarnings(w => w.Throw(RelationalEventId.LogTooManyIncludesWarning)) + /// + public static EventDefinition LogMultipleCollectionIncludeWarning([NotNull] IDiagnosticsLogger logger) + { + var definition = ((RelationalLoggingDefinitions)logger.Definitions).LogMultipleCollectionIncludeWarning; + if (definition == null) + { + definition = LazyInitializer.EnsureInitialized( + ref ((RelationalLoggingDefinitions)logger.Definitions).LogMultipleCollectionIncludeWarning, + () => new EventDefinition( + logger.Options, + RelationalEventId.MultipleCollectionIncludeWarning, + LogLevel.Warning, + "RelationalEventId.MultipleCollectionIncludeWarning", + level => LoggerMessage.Define( + level, + RelationalEventId.MultipleCollectionIncludeWarning, + _resourceManager.GetString("LogMultipleCollectionIncludeWarning")))); + } + + return (EventDefinition)definition; + } } } diff --git a/src/EFCore.Relational/Properties/RelationalStrings.resx b/src/EFCore.Relational/Properties/RelationalStrings.resx index 641d0f75e01..e09e7f0ac77 100644 --- a/src/EFCore.Relational/Properties/RelationalStrings.resx +++ b/src/EFCore.Relational/Properties/RelationalStrings.resx @@ -660,4 +660,8 @@ Cannot use table '{table}' for entity type '{entityType}' since it is being used for entity type '{otherEntityType}' and it excluded from migration on one entity type, but not the other. Exclude the table from migrations on all entity types mapped to the table. + + Compiling a query which loads related collections for more than one collection navigation property either via 'Include' or through projection but no 'QuerySplittingBehavior' has been configured. By default EF Core will use 'QuerySplittingBehavior.SingleQuery' which can potentially result in slow query performance. See https://go.microsoft.com/fwlink/?linkid=2134277 for more information. To identify the query that's triggering this warning call .ConfigureWarnings(w => w.Throw(RelationalEventId.LogTooManyIncludesWarning)) + Warning RelationalEventId.MultipleCollectionIncludeWarning + \ No newline at end of file diff --git a/src/EFCore.Relational/Query/Internal/CollectionJoinApplyingExpressionVisitor.cs b/src/EFCore.Relational/Query/Internal/CollectionJoinApplyingExpressionVisitor.cs index fe89c6b7668..97acb2172e6 100644 --- a/src/EFCore.Relational/Query/Internal/CollectionJoinApplyingExpressionVisitor.cs +++ b/src/EFCore.Relational/Query/Internal/CollectionJoinApplyingExpressionVisitor.cs @@ -3,6 +3,7 @@ using System.Linq.Expressions; using JetBrains.Annotations; +using Microsoft.EntityFrameworkCore.Diagnostics; using Microsoft.EntityFrameworkCore.Infrastructure; using Microsoft.EntityFrameworkCore.Query.SqlExpressions; using Microsoft.EntityFrameworkCore.Utilities; @@ -18,7 +19,8 @@ namespace Microsoft.EntityFrameworkCore.Query.Internal public class CollectionJoinApplyingExpressionVisitor : ExpressionVisitor { private readonly bool _splitQuery; - private readonly bool _userConfiguredBehavior; + private readonly bool _noConfiguredBehavior; + private readonly IDiagnosticsLogger _logger; private int _collectionId; /// @@ -32,7 +34,8 @@ public CollectionJoinApplyingExpressionVisitor([NotNull] RelationalQueryCompilat Check.NotNull(queryCompilationContext, nameof(queryCompilationContext)); _splitQuery = queryCompilationContext.QuerySplittingBehavior == QuerySplittingBehavior.SplitQuery; - _userConfiguredBehavior = RelationalOptionsExtension.Extract(queryCompilationContext.ContextOptions).QuerySplittingBehavior.HasValue; + _noConfiguredBehavior = queryCompilationContext.QuerySplittingBehavior == null; + _logger = queryCompilationContext.Logger; } /// @@ -48,6 +51,13 @@ protected override Expression VisitExtension(Expression extensionExpression) if (extensionExpression is CollectionShaperExpression collectionShaperExpression) { var collectionId = _collectionId++; + + if (_noConfiguredBehavior + && _collectionId == 2) + { + _logger.MultipleCollectionIncludeWarning(); + } + var projectionBindingExpression = (ProjectionBindingExpression)collectionShaperExpression.Projection; var selectExpression = (SelectExpression)projectionBindingExpression.QueryExpression; // Do pushdown beforehand so it updates all pending collections first diff --git a/src/EFCore.Relational/Query/RelationalQueryCompilationContext.cs b/src/EFCore.Relational/Query/RelationalQueryCompilationContext.cs index fa3ca986fc6..2d46df90395 100644 --- a/src/EFCore.Relational/Query/RelationalQueryCompilationContext.cs +++ b/src/EFCore.Relational/Query/RelationalQueryCompilationContext.cs @@ -33,8 +33,7 @@ public RelationalQueryCompilationContext( Check.NotNull(relationalDependencies, nameof(relationalDependencies)); RelationalDependencies = relationalDependencies; - QuerySplittingBehavior = RelationalOptionsExtension.Extract(ContextOptions).QuerySplittingBehavior - ?? QuerySplittingBehavior.SingleQuery; + QuerySplittingBehavior = RelationalOptionsExtension.Extract(ContextOptions).QuerySplittingBehavior; } /// @@ -43,8 +42,9 @@ public RelationalQueryCompilationContext( protected virtual RelationalQueryCompilationContextDependencies RelationalDependencies { get; } /// - /// A value indicating the of the query. + /// A value indicating the configured for the query. + /// If no value has been configured then will be used. /// - public virtual QuerySplittingBehavior QuerySplittingBehavior { get; internal set; } + public virtual QuerySplittingBehavior? QuerySplittingBehavior { get; internal set; } } } diff --git a/test/EFCore.SqlServer.FunctionalTests/Query/QueryBugsTest.cs b/test/EFCore.SqlServer.FunctionalTests/Query/QueryBugsTest.cs index d00d7ae0d48..35fd3817aab 100644 --- a/test/EFCore.SqlServer.FunctionalTests/Query/QueryBugsTest.cs +++ b/test/EFCore.SqlServer.FunctionalTests/Query/QueryBugsTest.cs @@ -14,8 +14,10 @@ using System.Threading.Tasks; using Microsoft.Data.SqlClient; using Microsoft.EntityFrameworkCore.Diagnostics; +using Microsoft.EntityFrameworkCore.Diagnostics.Internal; using Microsoft.EntityFrameworkCore.Infrastructure; using Microsoft.EntityFrameworkCore.Query.Internal; +using Microsoft.EntityFrameworkCore.SqlServer.Diagnostics.Internal; using Microsoft.EntityFrameworkCore.Storage.ValueConversion; using Microsoft.EntityFrameworkCore.TestUtilities; using Microsoft.Extensions.Caching.Memory; @@ -7282,54 +7284,194 @@ protected override void OnModelCreating(ModelBuilder modelBuilder) #region Issue21355 [ConditionalFact] - public virtual void Can_use_default_split_query() + public virtual void Can_configure_SingleQuery_at_context_level() { - var (serviceProvider, options) = CreateOptions21355(); + var (options, testSqlLoggerFactory) = CreateOptions21355(QuerySplittingBehavior.SingleQuery); using var context = new BugContext21355(options); - var testSqlLoggerFactory = (TestSqlLoggerFactory)serviceProvider.GetRequiredService(); - testSqlLoggerFactory.Clear(); - var result = context.Parents.Include(p => p.Children).ToList(); + var result = context.Parents.Include(p => p.Children1).ToList(); - Assert.Equal( - @"SELECT [p].[Id] + testSqlLoggerFactory.AssertBaseline( + new[] + { + @"SELECT [p].[Id], [c].[Id], [c].[ParentId] +FROM [Parents] AS [p] +LEFT JOIN [Child21355] AS [c] ON [p].[Id] = [c].[ParentId] +ORDER BY [p].[Id], [c].[Id]" + }); + } + + [ConditionalFact] + public virtual void Can_configure_SplitQuery_at_context_level() + { + var (options, testSqlLoggerFactory) = CreateOptions21355(QuerySplittingBehavior.SplitQuery); + using var context = new BugContext21355(options); + + var result = context.Parents.Include(p => p.Children1).ToList(); + + testSqlLoggerFactory.AssertBaseline( + new[] + { + @"SELECT [p].[Id] FROM [Parents] AS [p] ORDER BY [p].[Id]", - testSqlLoggerFactory.SqlStatements[0], - ignoreLineEndingDifferences: true); + // + @"SELECT [c].[Id], [c].[ParentId], [p].[Id] +FROM [Parents] AS [p] +INNER JOIN [Child21355] AS [c] ON [p].[Id] = [c].[ParentId] +ORDER BY [p].[Id]" + }); + } - Assert.Equal( - @"SELECT [c].[Id], [c].[ParentId], [p].[Id] + [ConditionalFact] + public virtual void Can_override_context_level_SingleQuery_with_AsSplitQuery() + { + var (options, testSqlLoggerFactory) = CreateOptions21355(QuerySplittingBehavior.SingleQuery); + using var context = new BugContext21355(options); + + var result = context.Parents.Include(p => p.Children1).AsSplitQuery().ToList(); + + testSqlLoggerFactory.AssertBaseline( + new[] + { + @"SELECT [p].[Id] +FROM [Parents] AS [p] +ORDER BY [p].[Id]", + // + @"SELECT [c].[Id], [c].[ParentId], [p].[Id] FROM [Parents] AS [p] INNER JOIN [Child21355] AS [c] ON [p].[Id] = [c].[ParentId] +ORDER BY [p].[Id]" + }); + } + + [ConditionalFact] + public virtual void Can_override_context_level_SplitQuery_with_AsSingleQuery() + { + var (options, testSqlLoggerFactory) = CreateOptions21355(QuerySplittingBehavior.SplitQuery); + using var context = new BugContext21355(options); + + var result = context.Parents.Include(p => p.Children1).AsSingleQuery().ToList(); + + testSqlLoggerFactory.AssertBaseline( + new[] + { + @"SELECT [p].[Id], [c].[Id], [c].[ParentId] +FROM [Parents] AS [p] +LEFT JOIN [Child21355] AS [c] ON [p].[Id] = [c].[ParentId] +ORDER BY [p].[Id], [c].[Id]" + }); + } + + [ConditionalFact] + public virtual void Unconfigured_query_splitting_behavior_throws_a_warning() + { + var (options, testSqlLoggerFactory) = CreateOptions21355(null); + using var context = new BugContext21355(options); + + Assert.Contains( + RelationalResources.LogMultipleCollectionIncludeWarning(new TestLogger()).GenerateMessage(), + Assert.Throws( + () => context.Parents.Include(p => p.Children1).Include(p => p.Children2).ToList()).Message); + } + + [ConditionalFact] + public virtual void Context_configured_single_query_splitting_behavior_does_not_throw_warning() + { + var (options, testSqlLoggerFactory) = CreateOptions21355(QuerySplittingBehavior.SingleQuery); + using var context = new BugContext21355(options); + + context.Parents.Include(p => p.Children1).Include(p => p.Children2).ToList(); + + testSqlLoggerFactory.AssertBaseline( + new[] + { + @"SELECT [p].[Id], [c].[Id], [c].[ParentId], [a].[Id], [a].[ParentId] +FROM [Parents] AS [p] +LEFT JOIN [Child21355] AS [c] ON [p].[Id] = [c].[ParentId] +LEFT JOIN [AnotherChild21355] AS [a] ON [p].[Id] = [a].[ParentId] +ORDER BY [p].[Id], [c].[Id], [a].[Id]" + }); + } + + [ConditionalFact] + public virtual void Context_configured_split_query_splitting_behavior_does_not_throw_warning() + { + var (options, testSqlLoggerFactory) = CreateOptions21355(QuerySplittingBehavior.SplitQuery); + using var context = new BugContext21355(options); + + context.Parents.Include(p => p.Children1).Include(p => p.Children2).ToList(); + + testSqlLoggerFactory.AssertBaseline( + new[] + { + @"SELECT [p].[Id] +FROM [Parents] AS [p] ORDER BY [p].[Id]", - testSqlLoggerFactory.SqlStatements[1], - ignoreLineEndingDifferences: true); + // + @"SELECT [c].[Id], [c].[ParentId], [p].[Id] +FROM [Parents] AS [p] +INNER JOIN [Child21355] AS [c] ON [p].[Id] = [c].[ParentId] +ORDER BY [p].[Id]", + // + @"SELECT [a].[Id], [a].[ParentId], [p].[Id] +FROM [Parents] AS [p] +INNER JOIN [AnotherChild21355] AS [a] ON [p].[Id] = [a].[ParentId] +ORDER BY [p].[Id]" + }); } [ConditionalFact] - public virtual void Can_override_default_split_query() + public virtual void Using_AsSingleQuery_withouth_context_configuration_does_not_throw_warning() { - var (serviceProvider, options) = CreateOptions21355(); + var (options, testSqlLoggerFactory) = CreateOptions21355(null); using var context = new BugContext21355(options); - var testSqlLoggerFactory = (TestSqlLoggerFactory)serviceProvider.GetRequiredService(); - testSqlLoggerFactory.Clear(); - var result = context.Parents.Include(p => p.Children).AsSingleQuery().ToList(); + context.Parents.Include(p => p.Children1).Include(p => p.Children2).AsSingleQuery().ToList(); - Assert.Equal( - @"SELECT [p].[Id], [c].[Id], [c].[ParentId] + testSqlLoggerFactory.AssertBaseline( + new[] + { + @"SELECT [p].[Id], [c].[Id], [c].[ParentId], [a].[Id], [a].[ParentId] FROM [Parents] AS [p] LEFT JOIN [Child21355] AS [c] ON [p].[Id] = [c].[ParentId] -ORDER BY [p].[Id], [c].[Id]", - testSqlLoggerFactory.SqlStatements[0], - ignoreLineEndingDifferences: true); +LEFT JOIN [AnotherChild21355] AS [a] ON [p].[Id] = [a].[ParentId] +ORDER BY [p].[Id], [c].[Id], [a].[Id]" + }); + } + + [ConditionalFact] + public virtual void Using_AsSplitQuery_withouth_context_configuration_does_not_throw_warning() + { + var (options, testSqlLoggerFactory) = CreateOptions21355(null); + using var context = new BugContext21355(options); + + context.Parents.Include(p => p.Children1).Include(p => p.Children2).AsSplitQuery().ToList(); + + testSqlLoggerFactory.AssertBaseline( + new[] + { + @"SELECT [p].[Id] +FROM [Parents] AS [p] +ORDER BY [p].[Id]", + // + @"SELECT [c].[Id], [c].[ParentId], [p].[Id] +FROM [Parents] AS [p] +INNER JOIN [Child21355] AS [c] ON [p].[Id] = [c].[ParentId] +ORDER BY [p].[Id]", + // + @"SELECT [a].[Id], [a].[ParentId], [p].[Id] +FROM [Parents] AS [p] +INNER JOIN [AnotherChild21355] AS [a] ON [p].[Id] = [a].[ParentId] +ORDER BY [p].[Id]" + }); } private class Parent21355 { public string Id { get; set; } - public List Children { get; set; } + public List Children1 { get; set; } + public List Children2 { get; set; } } private class Child21355 @@ -7339,17 +7481,28 @@ private class Child21355 public Parent21355 Parent { get; set; } } - private (ServiceProvider, DbContextOptions) CreateOptions21355() + private class AnotherChild21355 + { + public int Id { get; set; } + public string ParentId { get; set; } + public Parent21355 Parent { get; set; } + } + + private (DbContextOptions, TestSqlLoggerFactory) CreateOptions21355(QuerySplittingBehavior? querySplittingBehavior) { var testStore = SqlServerTestStore.CreateInitialized("QueryBugsTest", multipleActiveResultSets: true); - var serviceProvider = new ServiceCollection().AddSingleton(new TestSqlLoggerFactory()).BuildServiceProvider(); + var testSqlLoggerFactory = new TestSqlLoggerFactory(); + var serviceProvider = new ServiceCollection().AddSingleton(testSqlLoggerFactory).BuildServiceProvider(); - var optionsBuilder = Fixture.AddOptions(testStore.AddProviderOptions(new DbContextOptionsBuilder())) + var optionsBuilder = Fixture.AddOptions(new DbContextOptionsBuilder().UseSqlServer(testStore.ConnectionString)) .EnableDetailedErrors() .EnableServiceProviderCaching(false) .UseApplicationServiceProvider(serviceProvider); - new SqlServerDbContextOptionsBuilder(optionsBuilder).UseQuerySplittingBehavior(QuerySplittingBehavior.SplitQuery); + if (querySplittingBehavior.HasValue) + { + new SqlServerDbContextOptionsBuilder(optionsBuilder).UseQuerySplittingBehavior(querySplittingBehavior.Value); + } var context = new BugContext21355(optionsBuilder.Options); if (context.Database.EnsureCreatedResiliently()) @@ -7357,7 +7510,7 @@ private class Child21355 context.Add(new Parent21355 { Id = "Parent1", - Children = new List + Children1 = new List { new Child21355(), new Child21355() @@ -7366,7 +7519,9 @@ private class Child21355 context.SaveChanges(); } - return (serviceProvider, optionsBuilder.Options); + testSqlLoggerFactory.Clear(); + + return (optionsBuilder.Options, testSqlLoggerFactory); } private class BugContext21355 : DbContext diff --git a/test/EFCore.SqlServer.FunctionalTests/TestUtilities/SqlServerDbContextOptionsBuilderExtensions.cs b/test/EFCore.SqlServer.FunctionalTests/TestUtilities/SqlServerDbContextOptionsBuilderExtensions.cs index cf122c86f5e..3d80b352155 100644 --- a/test/EFCore.SqlServer.FunctionalTests/TestUtilities/SqlServerDbContextOptionsBuilderExtensions.cs +++ b/test/EFCore.SqlServer.FunctionalTests/TestUtilities/SqlServerDbContextOptionsBuilderExtensions.cs @@ -15,6 +15,8 @@ public static SqlServerDbContextOptionsBuilder ApplyConfiguration(this SqlServer optionsBuilder.MaxBatchSize(maxBatch.Value); } + optionsBuilder.UseQuerySplittingBehavior(QuerySplittingBehavior.SingleQuery); + optionsBuilder.ExecutionStrategy(d => new TestSqlServerRetryingExecutionStrategy(d)); optionsBuilder.CommandTimeout(SqlServerTestStore.CommandTimeout); diff --git a/test/EFCore.Sqlite.FunctionalTests/TestUtilities/SqliteTestStore.cs b/test/EFCore.Sqlite.FunctionalTests/TestUtilities/SqliteTestStore.cs index 839fbb367b0..5ad84c97759 100644 --- a/test/EFCore.Sqlite.FunctionalTests/TestUtilities/SqliteTestStore.cs +++ b/test/EFCore.Sqlite.FunctionalTests/TestUtilities/SqliteTestStore.cs @@ -52,6 +52,7 @@ public virtual DbContextOptionsBuilder AddProviderOptions( Connection, b => { b.CommandTimeout(CommandTimeout); + b.UseQuerySplittingBehavior(QuerySplittingBehavior.SingleQuery); configureSqlite?.Invoke(b); });