Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Query: Add logging #21924

Merged
1 commit merged into from
Aug 4, 2020
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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();
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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;
Expand All @@ -56,7 +56,7 @@ public CosmosQueryableMethodTranslatingExpressionVisitor(
_sqlExpressionFactory,
_memberTranslatorProvider,
_methodCallTranslatorProvider);
_projectionBindingExpressionVisitor = new CosmosProjectionBindingExpressionVisitor(_model, _sqlTranslator);
_projectionBindingExpressionVisitor = new CosmosProjectionBindingExpressionVisitor(_queryCompilationContext.Model, _sqlTranslator);
}

/// <summary>
Expand All @@ -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>
Expand Down Expand Up @@ -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(
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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;
Expand Down Expand Up @@ -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;
Expand Down Expand Up @@ -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;
}
Expand Down
8 changes: 5 additions & 3 deletions src/EFCore.Relational/Diagnostics/RelationalEventId.cs
Original file line number Diff line number Diff line change
@@ -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;
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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>
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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)
{
Expand Down
Original file line number Diff line number Diff line change
@@ -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
Expand Down Expand Up @@ -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>
Expand Down Expand Up @@ -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
Expand Down

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

2 changes: 1 addition & 1 deletion src/EFCore.Relational/Properties/RelationalStrings.resx
Original file line number Diff line number Diff line change
Expand Up @@ -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>
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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;
Expand Down Expand Up @@ -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;
Expand Down
57 changes: 54 additions & 3 deletions src/EFCore/Diagnostics/CoreEventId.cs
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down Expand Up @@ -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);

Expand Down
Loading