Query: Add logging

Part of #17498

Added messages
- Starting query compilation
- Navigation included
- Skip/Take without order by (infra is in core but providers use to generate the warning)
- First without order by or predicate  (infra is in core but providers use to generate the warning)

Removed messages
- Include ignored (they get removed due to automatic pruning based on expression tree visitation
- Obsolete exception with aggregate operator in relational. We logged that when doing client eval of aggregate operation
- Optimized query model - there is no more optimization phase.

Other fixes
- Don't log parameter values in Cosmos when sensitive data logging is not enabled.

src/EFCore.Cosmos/Diagnostics/Internal/CosmosLoggerExtensions.cs

@@ -46,11 +46,17 @@ public static void ExecutingSqlQuery(
 
             definition.Log(
                 diagnosticsLogger,
-                FormatParameters(cosmosSqlQuery.Parameters),
+                FormatParameters(cosmosSqlQuery.Parameters, ShouldLogParameterValues(diagnosticsLogger, cosmosSqlQuery)),
                 Environment.NewLine,
                 cosmosSqlQuery.Query);
         }
 
+        private static bool ShouldLogParameterValues(
+            IDiagnosticsLogger<DbLoggerCategory.Database.Command> diagnostics,
+            CosmosSqlQuery cosmosSqlQuery)
+            => cosmosSqlQuery.Parameters.Count > 0
+                && diagnostics.ShouldLogSensitiveData();
+
         /// <summary>
         ///     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
@@ -77,21 +83,28 @@ public static void ExecutingReadItem(
                 $"{partitionKey}, {resourceId}");
         }
 
-        private static string FormatParameters(IReadOnlyList<SqlParameter> parameters)
+        private static string FormatParameters(IReadOnlyList<SqlParameter> parameters, bool shouldLogParameterValues)
         {
             return parameters.Count == 0
                 ? ""
-                : string.Join(", ", parameters.Select(FormatParameter));
+                : string.Join(", ", parameters.Select(e => FormatParameter(e, shouldLogParameterValues)));
         }
 
-        private static string FormatParameter(SqlParameter parameter)
+        private static string FormatParameter(SqlParameter parameter, bool shouldLogParameterValue)
         {
             var builder = new StringBuilder();
             builder
                 .Append(parameter.Name)
                 .Append("=");
 
-            FormatParameterValue(builder, parameter.Value);
+            if (shouldLogParameterValue)
+            {
+                FormatParameterValue(builder, parameter.Value);
+            }
+            else
+            {
+                builder.Append("?");
+            }
 
             return builder.ToString();
         }

src/EFCore.Cosmos/Query/Internal/CosmosQueryableMethodTranslatingExpressionVisitor.cs

@@ -26,7 +26,7 @@ namespace Microsoft.EntityFrameworkCore.Cosmos.Query.Internal
     /// </summary>
     public class CosmosQueryableMethodTranslatingExpressionVisitor : QueryableMethodTranslatingExpressionVisitor
     {
-        private readonly IModel _model;
+        private readonly QueryCompilationContext _queryCompilationContext;
         private readonly ISqlExpressionFactory _sqlExpressionFactory;
         private readonly IMemberTranslatorProvider _memberTranslatorProvider;
         private readonly IMethodCallTranslatorProvider _methodCallTranslatorProvider;
@@ -47,7 +47,7 @@ public CosmosQueryableMethodTranslatingExpressionVisitor(
             [NotNull] IMethodCallTranslatorProvider methodCallTranslatorProvider)
             : base(dependencies, queryCompilationContext, subquery: false)
         {
-            _model = queryCompilationContext.Model;
+            _queryCompilationContext = queryCompilationContext;
             _sqlExpressionFactory = sqlExpressionFactory;
             _memberTranslatorProvider = memberTranslatorProvider;
             _methodCallTranslatorProvider = methodCallTranslatorProvider;
@@ -56,7 +56,7 @@ public CosmosQueryableMethodTranslatingExpressionVisitor(
                 _sqlExpressionFactory,
                 _memberTranslatorProvider,
                 _methodCallTranslatorProvider);
-            _projectionBindingExpressionVisitor = new CosmosProjectionBindingExpressionVisitor(_model, _sqlTranslator);
+            _projectionBindingExpressionVisitor = new CosmosProjectionBindingExpressionVisitor(_queryCompilationContext.Model, _sqlTranslator);
         }
 
         /// <summary>
@@ -69,14 +69,14 @@ protected CosmosQueryableMethodTranslatingExpressionVisitor(
             [NotNull] CosmosQueryableMethodTranslatingExpressionVisitor parentVisitor)
             : base(parentVisitor.Dependencies, parentVisitor.QueryCompilationContext, subquery: true)
         {
-            _model = parentVisitor._model;
+            _queryCompilationContext = parentVisitor._queryCompilationContext;
             _sqlExpressionFactory = parentVisitor._sqlExpressionFactory;
             _sqlTranslator = new CosmosSqlTranslatingExpressionVisitor(
                 QueryCompilationContext,
                 _sqlExpressionFactory,
                 _memberTranslatorProvider,
                 _methodCallTranslatorProvider);
-            _projectionBindingExpressionVisitor = new CosmosProjectionBindingExpressionVisitor(_model, _sqlTranslator);
+            _projectionBindingExpressionVisitor = new CosmosProjectionBindingExpressionVisitor(_queryCompilationContext.Model, _sqlTranslator);
         }
 
         /// <summary>
@@ -212,7 +212,7 @@ protected override ShapedQueryExpression CreateShapedQueryExpression(Type elemen
         {
             Check.NotNull(elementType, nameof(elementType));
 
-            var entityType = _model.FindEntityType(elementType);
+            var entityType = _queryCompilationContext.Model.FindEntityType(elementType);
             var selectExpression = _sqlExpressionFactory.Select(entityType);
 
             return new ShapedQueryExpression(
@@ -471,6 +471,12 @@ protected override ShapedQueryExpression TranslateFirstOrDefault(
             }
 
             var selectExpression = (SelectExpression)source.QueryExpression;
+            if (selectExpression.Predicate == null
+                && selectExpression.Orderings.Count == 0)
+            {
+                _queryCompilationContext.Logger.FirstWithoutOrderByAndFilterWarning();
+            }
+
             selectExpression.ApplyLimit(TranslateExpression(Expression.Constant(1)));
 
             return source.ShaperExpression.Type != returnType
@@ -909,6 +915,11 @@ protected override ShapedQueryExpression TranslateSkip(ShapedQueryExpression sou
 
             if (translation != null)
             {
+                if (selectExpression.Orderings.Count == 0)
+                {
+                    _queryCompilationContext.Logger.RowLimitingOperationWithoutOrderByWarning();
+                }
+
                 selectExpression.ApplyOffset(translation);
 
                 return source;
@@ -980,6 +991,11 @@ protected override ShapedQueryExpression TranslateTake(ShapedQueryExpression sou
 
             if (translation != null)
             {
+                if (selectExpression.Orderings.Count == 0)
+                {
+                    _queryCompilationContext.Logger.RowLimitingOperationWithoutOrderByWarning();
+                }
+
                 selectExpression.ApplyLimit(translation);
 
                 return source;
@@ -1144,7 +1160,7 @@ when methodCallExpression.TryGetEFPropertyArguments(out _, out var propertyName)
                         break;
 
                     case MethodCallExpression methodCallExpression
-                    when methodCallExpression.TryGetIndexerArguments(_model, out _, out var propertyName):
+                    when methodCallExpression.TryGetIndexerArguments(_queryCompilationContext.Model, out _, out var propertyName):
                         property = entityType.FindProperty(propertyName);
                         break;
                 }

src/EFCore.Relational/Diagnostics/RelationalEventId.cs

@@ -1,6 +1,7 @@
 // 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.Data.Common;
 using System.Diagnostics;
 using Microsoft.EntityFrameworkCore.Infrastructure;
@@ -75,8 +76,8 @@ private enum Id
             // Query events
             QueryClientEvaluationWarning = CoreEventId.RelationalBaseId + 500,
             QueryPossibleUnintendedUseOfEqualsWarning,
-            QueryPossibleExceptionWithAggregateOperatorWarning,
-            ValueConversionSqlLiteralWarning, // This warning has been removed.
+            Obsolete_QueryPossibleExceptionWithAggregateOperatorWarning,
+            Obsolete_ValueConversionSqlLiteralWarning,
             MultipleCollectionIncludeWarning,
 
             // Model validation events
@@ -611,8 +612,9 @@ private enum Id
         ///         This event is in the <see cref="DbLoggerCategory.Query" /> category.
         ///     </para>
         /// </summary>
+        [Obsolete]
         public static readonly EventId QueryPossibleExceptionWithAggregateOperatorWarning =
-            MakeQueryId(Id.QueryPossibleExceptionWithAggregateOperatorWarning);
+            MakeQueryId(Id.Obsolete_QueryPossibleExceptionWithAggregateOperatorWarning);
 
         /// <summary>
         ///     <para>

src/EFCore.Relational/Diagnostics/RelationalLoggerExtensions.cs

@@ -4163,6 +4163,7 @@ private static string QueryPossibleUnintendedUseOfEqualsWarning(EventDefinitionB
         ///     Logs for the <see cref="RelationalEventId.QueryPossibleExceptionWithAggregateOperatorWarning" /> event.
         /// </summary>
         /// <param name="diagnostics"> The diagnostics logger to use. </param>
+        [Obsolete]
         public static void QueryPossibleExceptionWithAggregateOperatorWarning(
             [NotNull] this IDiagnosticsLogger<DbLoggerCategory.Query> diagnostics)
         {

src/EFCore.Relational/Diagnostics/RelationalLoggingDefinitions.cs

@@ -1,6 +1,7 @@
 // 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 Microsoft.EntityFrameworkCore.Infrastructure;
 
 namespace Microsoft.EntityFrameworkCore.Diagnostics
@@ -239,6 +240,7 @@ public abstract class RelationalLoggingDefinitions : LoggingDefinitions
         ///     doing so can result in application failures when updating to a new Entity Framework Core release.
         /// </summary>
         [EntityFrameworkInternal]
+        [Obsolete]
         public EventDefinitionBase LogQueryPossibleExceptionWithAggregateOperatorWarning;
 
         /// <summary>
@@ -412,15 +414,6 @@ public abstract class RelationalLoggingDefinitions : LoggingDefinitions
         [EntityFrameworkInternal]
         public EventDefinitionBase LogMigrationAttributeMissingWarning;
 
-        /// <summary>
-        ///     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.
-        /// </summary>
-        [EntityFrameworkInternal]
-        public EventDefinitionBase LogValueConversionSqlLiteralWarning;
-
         /// <summary>
         ///     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

src/EFCore.Relational/Properties/RelationalStrings.resx

@@ -272,7 +272,7 @@
   </data>
   <data name="LogQueryPossibleExceptionWithAggregateOperatorWarning" xml:space="preserve">
     <value>Possible unintended use of a potentially throwing aggregate method (Min, Max, Average) in a subquery. Client evaluation will be used and operator will throw if no data exists. Changing the subquery result type to a nullable type will allow full translation.</value>
-    <comment>Warning RelationalEventId.QueryPossibleExceptionWithAggregateOperatorWarning</comment>
+    <comment>Obsolete Warning RelationalEventId.QueryPossibleExceptionWithAggregateOperatorWarning</comment>
   </data>
   <data name="LogGeneratingDown" xml:space="preserve">
     <value>Generating down script for migration '{migration}'.</value>

src/EFCore.Relational/Query/RelationalQueryableMethodTranslatingExpressionVisitor.cs

@@ -420,6 +420,11 @@ protected override ShapedQueryExpression TranslateFirstOrDefault(
             }
 
             var selectExpression = (SelectExpression)source.QueryExpression;
+            if (selectExpression.Predicate == null
+                && selectExpression.Orderings.Count == 0)
+            {
+                _queryCompilationContext.Logger.FirstWithoutOrderByAndFilterWarning();
+            }
             selectExpression.ApplyLimit(TranslateExpression(Expression.Constant(1)));
 
             return source.ShaperExpression.Type != returnType
@@ -1035,6 +1040,11 @@ protected override ShapedQueryExpression TranslateSkip(ShapedQueryExpression sou
                 return null;
             }
 
+            if (selectExpression.Orderings.Count == 0)
+            {
+                _queryCompilationContext.Logger.RowLimitingOperationWithoutOrderByWarning();
+            }
+
             selectExpression.ApplyOffset(translation);
 
             return source;
@@ -1096,6 +1106,11 @@ protected override ShapedQueryExpression TranslateTake(ShapedQueryExpression sou
                 return null;
             }
 
+            if (selectExpression.Orderings.Count == 0)
+            {
+                _queryCompilationContext.Logger.RowLimitingOperationWithoutOrderByWarning();
+            }
+
             selectExpression.ApplyLimit(translation);
 
             return source;

src/EFCore/Diagnostics/CoreEventId.cs

@@ -59,15 +59,16 @@ private enum Id
             // Query events
             QueryIterationFailed = CoreBaseId + 100,
             Obsolete_QueryModelCompiling,
-            Obsolete_RowLimitingOperationWithoutOrderByWarning,
-            Obsolete_FirstWithoutOrderByAndFilterWarning,
+            RowLimitingOperationWithoutOrderByWarning,
+            FirstWithoutOrderByAndFilterWarning,
             Obsolete_QueryModelOptimized,
-            Obsolete_NavigationIncluded,
+            NavigationIncluded,
             Obsolete_IncludeIgnoredWarning,
             QueryExecutionPlanned,
             PossibleUnintendedCollectionNavigationNullComparisonWarning,
             PossibleUnintendedReferenceComparisonWarning,
             InvalidIncludePathError,
+            QueryCompilationStarting,
 
             // Infrastructure events
             SensitiveDataLoggingEnabledWarning = CoreBaseId + 400,
@@ -215,6 +216,56 @@ public static readonly EventId PossibleUnintendedReferenceComparisonWarning
         public static readonly EventId InvalidIncludePathError
             = MakeQueryId(Id.InvalidIncludePathError);
 
+        /// <summary>
+        ///     <para>
+        ///         Starting query compilation.
+        ///     </para>
+        ///     <para>
+        ///         This event is in the <see cref="DbLoggerCategory.Query" /> category.
+        ///     </para>
+        ///     <para>
+        ///         This event uses the <see cref="QueryExpressionEventData" /> payload when used with a <see cref="DiagnosticSource" />.
+        ///     </para>
+        /// </summary>
+        public static readonly EventId QueryCompilationStarting
+            = MakeQueryId(Id.QueryCompilationStarting);
+
+        /// <summary>
+        ///     <para>
+        ///         A navigation was included in the query.
+        ///     </para>
+        ///     <para>
+        ///         This event is in the <see cref="DbLoggerCategory.Query" /> category.
+        ///     </para>
+        ///     <para>
+        ///         This event uses the <see cref="QueryExpressionEventData" /> payload when used with a <see cref="DiagnosticSource" />.
+        ///     </para>
+        /// </summary>
+        public static readonly EventId NavigationIncluded
+            = MakeQueryId(Id.NavigationIncluded);
+
+        /// <summary>
+        ///     <para>
+        ///         A query uses a row limiting operation (Skip/Take) without OrderBy which may lead to unpredictable results.
+        ///     </para>
+        ///     <para>
+        ///         This event is in the <see cref="DbLoggerCategory.Query" /> category.
+        ///     </para>
+        /// </summary>
+        public static readonly EventId RowLimitingOperationWithoutOrderByWarning
+            = MakeQueryId(Id.RowLimitingOperationWithoutOrderByWarning);
+
+        /// <summary>
+        ///     <para>
+        ///         A query uses First/FirstOrDefault operation without OrderBy and filter which may lead to unpredictable results.
+        ///     </para>
+        ///     <para>
+        ///         This event is in the <see cref="DbLoggerCategory.Query" /> category.
+        ///     </para>
+        /// </summary>
+        public static readonly EventId FirstWithoutOrderByAndFilterWarning
+            = MakeQueryId(Id.FirstWithoutOrderByAndFilterWarning);
+
         private static readonly string _infraPrefix = DbLoggerCategory.Infrastructure.Name + ".";
         private static EventId MakeInfraId(Id id) => new EventId((int)id, _infraPrefix + id);