logo标签列表

Entity Framework 6 - 查询时机

c#sql-serverentity-frameworkentity-framework-6
21

我正在使用Entity Framework 6，它具有出色的数据库拦截器功能来记录从应用程序发送到数据库的查询。但是，我很难对这些查询进行计时，因为我有一个长时间运行的查询，返回几十万到数百万行数据，所以根据返回数据量的多少，需要大约6到15秒的时间。由于Entity Framework返回SqlDataReader，所以无法获取确切的结果获取时间。我想知道从发送查询到读取最后一行的完整执行时间。是否有方法可以实现？

如果您想查看 SQL 运行的时间，可以使用 Profiler。 - Dave.Gugg
除了SQL Server Profiler工具建议之外，报告的持续时间将反映SQL Server接收请求的时间，直到服务器填充最后一个TDS缓冲区。 SQL Server无法测量初始请求的网络延迟或最终响应的接收时间，只能测量与数据库引擎的时间。 对于像您这样的大型结果集可能不是问题，但是这种延迟可能是返回单个结果缓冲区的小查询的端到端响应时间的主要部分。 - Dan Guzman
谢谢您的建议。但是，我想要记录一些元数据和查询一起，例如触发此查询的用户以及其他存储在Web服务器上的元数据。这是否可以从Web服务器层进行？ - Yogesh
将调用包装在跟踪记录器中。如果它花费的时间超过一定时间，记录传递的元数据和其他任何您想要的内容。 - Jeff Dunlop
在跟踪记录器中，wrap是什么意思？ - Yogesh
8个回答
33

这是我通常用于EF的记录器。

public class EFLoggerForTesting : IDbCommandInterceptor
{
    static readonly ConcurrentDictionary<DbCommand, DateTime> m_StartTime = new ConcurrentDictionary<DbCommand, DateTime>();

    public void ReaderExecuted(DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
    {
        Log(command, interceptionContext);
    }

    public void NonQueryExecuted(DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
    {
        Log(command, interceptionContext);
    }

    public void ScalarExecuted(DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
    {
        Log(command, interceptionContext);
    }

    private static void Log<T>(DbCommand command, DbCommandInterceptionContext<T> interceptionContext)
    {
        DateTime startTime;
        TimeSpan duration;


        if (m_StartTime.TryRemove(command, out startTime))
        {
            duration = DateTime.Now - startTime;
        }
        else
            duration = TimeSpan.Zero;

        var requestId =-1;
        string message;

        var parameters = new StringBuilder();
        foreach (DbParameter param in command.Parameters)
        {
            parameters.AppendLine(param.ParameterName + " " + param.DbType + " = " + param.Value);
        }

        if (interceptionContext.Exception == null)
        {
            message = string.Format("Database call took {0} sec. RequestId {1} \r\nCommand:\r\n{2}", duration.TotalSeconds.ToString("N3"), requestId, parameters.ToString() + command.CommandText);
        }
        else
        {
            message = string.Format("EF Database call failed after {0} sec. RequestId {1} \r\nCommand:\r\n{2}\r\nError:{3} ", duration.TotalSeconds.ToString("N3"), requestId, parameters.ToString() + command.CommandText, interceptionContext.Exception);
        }

        Debug.WriteLine(message);
    }


    public void NonQueryExecuting(DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
    {
        OnStart(command);
    }

    public void ReaderExecuting(DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
    {
        OnStart(command);
    }

    public void ScalarExecuting(DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
    {
        OnStart(command);
    }
    private static void OnStart(DbCommand command)
    {
        m_StartTime.TryAdd(command, DateTime.Now);
    }
}

很遗憾，文档不存在，所以我不知道这是否适用于您的情况。

4
@Jonathan Allen，你使用 requestId 有什么用途？ - Kevin Kalitowski
1
将网站调用与数据库调用相关联。假设有人访问//myapp.com//user/23页面。我会生成一个新的请求ID，比如107，并将其用于每个数据库调用。然后，如果我看到请求107对用户表进行了15次数据库调用，我就知道出了问题。（是的，这是一个真实的例子。EF使得在不考虑情况的情况下轻松调用数据库。） - Jonathan Allen
2
PS：我上面的示例缺少从HttpContext.Current读取以获取真实请求ID的代码。-1是一个占位符，用于与Web请求无关的数据库调用。 - Jonathan Allen
4
我在别处提出了问题：http://stackoverflow.com/q/40339358/1380710。奇怪的时间是因为`DateTime`不能保证准确性高于系统定时器，对于Windows NT而言定时器精度为10毫秒，对于Windows 8+则为1毫秒。我不得不使用System.Diagnostics.Stopwatch来获得更高的精度。 - Aske B.
1
你可以检查 m_StartTime.TryRemove(command, out startTime) 的布尔结果，而不是用 startTime != default(DateTime) 吗？ - Sora2455
显示剩余8条评论
4
我不想追踪整个周期，我只想了解有关Entity Framework部分的信息。 - Yogesh
4
这里的想法是自己学习并亲手实践，而不是使用现成的解决方案。 - Yogesh
3
您可以尝试这里解释的示例 在此示例中，当一个命令开始执行时，我们启动一个Stopwatch并在命令完成时停止Stopwatch，从而可以识别缓慢的查询并记录它们。
public class SqlMonitorInterceptor : IDbCommandInterceptor
{
    private static readonly ILog logger = LogManager.GetCurrentClassLogger();
    private static readonly int sqlWarningThresholdMs = int.Parse(ConfigurationManager.AppSettings["sqlPerformance_warningThresholdMilliseconds"]);
    private readonly Stopwatch _stopwatch = new Stopwatch();

    public void NonQueryExecuting(DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
    {
        CommandExecuting();
    }

    public void NonQueryExecuted(DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
    {
        CommandExecuted(command, interceptionContext);
    }

    public void ReaderExecuting(DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
    {
        CommandExecuting();
    }

    public void ReaderExecuted(DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
    {
        CommandExecuted(command, interceptionContext);
    }

    public void ScalarExecuting(DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
    {
        CommandExecuting();
    }

    public void ScalarExecuted(DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
    {
        CommandExecuted(command, interceptionContext);
    }

    private void CommandExecuting() {
        _stopwatch.Restart();
    }

    private void CommandExecuted<TResult>(DbCommand command, DbCommandInterceptionContext<TResult> interceptionContext)
    {
        _stopwatch.Stop();
        LogIfError(command, interceptionContext);
        LogIfTooSlow(command, _stopwatch.Elapsed);
    }

    private void LogIfError<TResult>(DbCommand command, DbCommandInterceptionContext<TResult> interceptionContext)
    {
        if (interceptionContext.Exception != null)
        {
            logger.ErrorFormat("Command {0} failed with exception {1}",
                command.CommandText, interceptionContext.Exception);
        }
    }

    private void LogIfTooSlow(DbCommand command, TimeSpan completionTime)
    {
        if (completionTime.TotalMilliseconds > sqlWarningThresholdMs)
        {
            logger.WarnFormat("Query time ({0}ms) exceeded the threshold of {1}ms. Command: \"{2}\"",
                completionTime.TotalMilliseconds, sqlWarningThresholdMs, command.CommandText);
        }
    }
}
2
正如@Ricardo Peres的答案所建议的那样，Glimpse非常适合这种情况。它带有Glimpse.Ado插件，可以用于轻松地对任何DbConnection进行性能分析，这是需要扩展的主要类。
在Glimpse中，ADO的手动集成点是将DbConnection包装在GlimpseDbConnection中，如此博客文章所示：http://getglimpse.com/Docs/Manual-ADO-Integration。其他提供程序（如EF）已自动与Glimpse.Ef包集成。
如果您仍然决定要手动实现此功能，我建议自己包装DbConneciton并在常规DbConnection的位置使用它。这样可以获得简单的计时。
您可以在他们的GitHub上看到Glimpse是如何做到的：https://github.com/Glimpse/Glimpse/tree/master/source/Glimpse.Ado/AlternateType 另外，根据您需要记录的日志量，还可以选择在存储库级别或方法级别添加此类日志记录。
2

以下是Johnathan 接受答案的 EF Core 版本，供需要的人查询：

using Microsoft.EntityFrameworkCore.Diagnostics;
using System.Data.Common;


public class EFLogger: DbCommandInterceptor
{
    private static readonly ConcurrentDictionary<Guid, DateTime> _startTimes = new ConcurrentDictionary<Guid, DateTime>();

    public override DbDataReader ReaderExecuted(DbCommand command, CommandExecutedEventData eventData, DbDataReader reader)
    {
        Log(command, eventData);
        return reader;
    }

    public override int NonQueryExecuted(DbCommand command, CommandExecutedEventData eventData, int result)
    {
        Log(command, eventData);
        return result;
    }

    public override object ScalarExecuted(DbCommand command, CommandExecutedEventData eventData, object result)
    {
        Log(command, eventData);
        return result;
    }

    public override void CommandFailed(DbCommand command, CommandErrorEventData eventData)
    {
        Log(command, eventData);
    }

    private static void Log(DbCommand command, CommandEventData eventData)
    {
        TimeSpan? duration = null;
        if (_startTimes.TryRemove(eventData.CommandId, out DateTime startTime))
            duration = DateTime.Now - startTime;

        var parameters = new StringBuilder();
        foreach (DbParameter param in command.Parameters)
        {
            parameters.AppendLine(param.ParameterName + " " + param.DbType + " = " + param.Value);
        }

        string message = $"Database call {(eventData is CommandErrorEventData ? "FAILED" : "succeeded")} in {duration?.TotalMilliseconds ?? -1:N3} ms. CommandId {eventData.CommandId} \r\nCommand:\r\n{parameters}{command.CommandText}";
        Console.WriteLine(message);
    }

    public override InterceptionResult<int> NonQueryExecuting(DbCommand command, CommandEventData eventData, InterceptionResult<int> result)
    {
        OnStart(eventData.CommandId);
        return result;
    }
    public override InterceptionResult<DbDataReader> ReaderExecuting(DbCommand command, CommandEventData eventData, InterceptionResult<DbDataReader> result)
    {
        OnStart(eventData.CommandId);
        return result;
    }

    public override InterceptionResult<object> ScalarExecuting(DbCommand command, CommandEventData eventData, InterceptionResult<object> result)
    {
        OnStart(eventData.CommandId);
        return result;
    }

    private void OnStart(Guid commandId)
    {
        _startTimes.TryAdd(commandId, DateTime.Now);
    }
}
1
以下是我对原始DatabaseLogFormatter的简化版本。主要区别在于这个版本没有过滤，也不记录实际的SQL查询或其参数（因为我只关心查询的时间）。它记录了何时打开了连接、执行了查询以及何时再次关闭了连接。正如@aske-b 上面提到的，使用DateTime（就像被接受的答案所做的那样）并不是很准确。 
public class CustomDatabaseLogFormatter : IDbCommandInterceptor, IDbConnectionInterceptor
{
    private readonly Action<string> _writeAction;
    private readonly Stopwatch _stopwatch = new Stopwatch();

    /// <summary>
    /// Creates a formatter that will log every command from any context and also commands that do not originate from a context.
    /// </summary>
    /// <remarks>
    /// This constructor is not used when a delegate is set on <see cref="Database.Log" />. Instead it can be
    /// used by setting the formatter directly using <see cref="DbInterception.Add" />.
    /// </remarks>
    /// <param name="writeAction">The delegate to which output will be sent.</param>
    public CustomDatabaseLogFormatter(Action<string> writeAction)
    {
        Check.NotNull(writeAction, "writeAction");

        _writeAction = writeAction;
    }

    internal Action<string> WriteAction
    {
        get { return _writeAction; }
    }

    /// <summary>
    /// Writes the given string to the underlying write delegate.
    /// </summary>
    /// <param name="output">The string to write.</param>
    protected virtual void Write(string output)
    {
        _writeAction(output);
    }

    /// <summary>
    /// The stopwatch used to time executions. This stopwatch is started at the end of
    /// <see cref="NonQueryExecuting" />, <see cref="ScalarExecuting" />, and <see cref="ReaderExecuting" />
    /// methods and is stopped at the beginning of the <see cref="NonQueryExecuted" />, <see cref="ScalarExecuted" />,
    /// and <see cref="ReaderExecuted" /> methods. If these methods are overridden and the stopwatch is being used
    /// then the overrides should either call the base method or start/stop the stopwatch themselves.
    /// </summary>
    /// <returns>The stopwatch.</returns>
    protected internal Stopwatch Stopwatch
    {
        get { return _stopwatch; }
    }

    private void RestartStopwatch()
    {
        Stopwatch.Restart();
    }

    private void StopStopwatch()
    {
        Stopwatch.Stop();
    }

    #region IDbCommandInterceptor
    /// <summary>
    /// This method is called before a call to <see cref="DbCommand.ExecuteNonQuery" /> or
    /// one of its async counterparts is made.
    /// Starts the stopwatch returned from <see cref="Stopwatch"/>.
    /// </summary>
    /// <param name="command">The command being executed.</param>
    /// <param name="interceptionContext">Contextual information associated with the call.</param>
    public virtual void NonQueryExecuting(DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
    {
        Check.NotNull(command, "command");
        Check.NotNull(interceptionContext, "interceptionContext");

        RestartStopwatch();
    }

    /// <summary>
    /// This method is called after a call to <see cref="DbCommand.ExecuteNonQuery" /> or
    /// one of its async counterparts is made.
    /// Stops the stopwatch returned from <see cref="Stopwatch"/> and calls <see cref="Executed" />.
    /// </summary>
    /// <param name="command">The command being executed.</param>
    /// <param name="interceptionContext">Contextual information associated with the call.</param>
    public virtual void NonQueryExecuted(DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
    {
        Check.NotNull(command, "command");
        Check.NotNull(interceptionContext, "interceptionContext");

        StopStopwatch();
        Executed(command, interceptionContext);
    }

    /// <summary>
    /// This method is called before a call to <see cref="DbCommand.ExecuteReader(CommandBehavior)" /> or
    /// one of its async counterparts is made.
    /// Starts the stopwatch returned from <see cref="Stopwatch"/>.
    /// </summary>
    /// <param name="command">The command being executed.</param>
    /// <param name="interceptionContext">Contextual information associated with the call.</param>
    public virtual void ReaderExecuting(DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
    {
        Check.NotNull(command, "command");
        Check.NotNull(interceptionContext, "interceptionContext");

        RestartStopwatch();
    }

    /// <summary>
    /// This method is called after a call to <see cref="DbCommand.ExecuteReader(CommandBehavior)" /> or
    /// one of its async counterparts is made.
    /// Stops the stopwatch returned from <see cref="Stopwatch"/> and calls <see cref="Executed" />.
    /// </summary>
    /// <param name="command">The command being executed.</param>
    /// <param name="interceptionContext">Contextual information associated with the call.</param>
    public virtual void ReaderExecuted(DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
    {
        Check.NotNull(command, "command");
        Check.NotNull(interceptionContext, "interceptionContext");

        StopStopwatch();
        Executed(command, interceptionContext);
    }

    /// <summary>
    /// This method is called before a call to <see cref="DbCommand.ExecuteScalar" />  or
    /// one of its async counterparts is made.
    /// Starts the stopwatch returned from <see cref="Stopwatch"/>.
    /// </summary>
    /// <param name="command">The command being executed.</param>
    /// <param name="interceptionContext">Contextual information associated with the call.</param>
    public virtual void ScalarExecuting(DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
    {
        Check.NotNull(command, "command");
        Check.NotNull(interceptionContext, "interceptionContext");

        RestartStopwatch();
    }

    /// <summary>
    /// This method is called after a call to <see cref="DbCommand.ExecuteScalar" />  or
    /// one of its async counterparts is made.
    /// Stops the stopwatch returned from <see cref="Stopwatch"/> and calls
    /// <see cref="Executed" />.
    /// </summary>
    /// <param name="command">The command being executed.</param>
    /// <param name="interceptionContext">Contextual information associated with the call.</param>
    public virtual void ScalarExecuted(DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
    {
        Check.NotNull(command, "command");
        Check.NotNull(interceptionContext, "interceptionContext");

        StopStopwatch();
        Executed(command, interceptionContext);
    }

    /// <summary>
    /// Called whenever a command has completed executing. Calls <see cref="LogResult" />.
    /// </summary>
    /// <typeparam name="TResult">The type of the operation's results.</typeparam>
    /// <param name="command">The command that was executed.</param>
    /// <param name="interceptionContext">Contextual information associated with the command.</param>
    public virtual void Executed<TResult>(DbCommand command, DbCommandInterceptionContext<TResult> interceptionContext)
    {
        Check.NotNull(command, "command");
        Check.NotNull(interceptionContext, "interceptionContext");

        LogResult(command, interceptionContext);
    }

    /// <summary>
    /// Called to log the result of executing a command.
    /// </summary>
    /// <typeparam name="TResult">The type of the operation's results.</typeparam>
    /// <param name="command">The command being logged.</param>
    /// <param name="interceptionContext">Contextual information associated with the command.</param>
    public virtual void LogResult<TResult>(DbCommand command, DbCommandInterceptionContext<TResult> interceptionContext)
    {
        Check.NotNull(command, "command");
        Check.NotNull(interceptionContext, "interceptionContext");

        var stopwatch = Stopwatch;

        if (interceptionContext.Exception != null)
        {
            Write(
                String.Format(StringResources.CommandLogFailed, stopwatch.ElapsedMilliseconds, interceptionContext.Exception.Message)
                );
        }
        else if (interceptionContext.TaskStatus.HasFlag(TaskStatus.Canceled))
        {
            Write(String.Format(StringResources.CommandLogCanceled, stopwatch.ElapsedMilliseconds));
        }
        else
        {
            var result = interceptionContext.Result;
            var resultString = (object)result == null
                ? "null"
                : (result is DbDataReader)
                    ? result.GetType().Name
                    : result.ToString();
            Write(String.Format(StringResources.CommandLogComplete, stopwatch.ElapsedMilliseconds, resultString));
        }
    }
    #endregion

    #region IDbConnectionInterceptor
    public void BeginningTransaction(DbConnection connection, BeginTransactionInterceptionContext interceptionContext)
    { }

    public void BeganTransaction(DbConnection connection, BeginTransactionInterceptionContext interceptionContext)
    { }

    public void Closing(DbConnection connection, DbConnectionInterceptionContext interceptionContext)
    { }

    /// <summary>
    /// Called after <see cref="DbConnection.Close" /> is invoked.
    /// </summary>
    /// <param name="connection">The connection that was closed.</param>
    /// <param name="interceptionContext">Contextual information associated with the call.</param>
    public void Closed(DbConnection connection, DbConnectionInterceptionContext interceptionContext)
    {
        Check.NotNull(connection, "connection");
        Check.NotNull(interceptionContext, "interceptionContext");

        if (interceptionContext.Exception != null)
        {
            Write(String.Format(StringResources.ConnectionCloseErrorLog, DateTimeOffset.UtcNow, interceptionContext.Exception.Message));
        }
        else
        {
            Write(String.Format(StringResources.ConnectionClosedLog, DateTimeOffset.UtcNow));
        }
    }

    public void ConnectionStringGetting(DbConnection connection, DbConnectionInterceptionContext<string> interceptionContext)
    { }

    public void ConnectionStringGot(DbConnection connection, DbConnectionInterceptionContext<string> interceptionContext)
    { }

    public void ConnectionStringSetting(DbConnection connection, DbConnectionPropertyInterceptionContext<string> interceptionContext)
    { }

    public void ConnectionStringSet(DbConnection connection, DbConnectionPropertyInterceptionContext<string> interceptionContext)
    { }

    public void ConnectionTimeoutGetting(DbConnection connection, DbConnectionInterceptionContext<int> interceptionContext)
    { }

    public void ConnectionTimeoutGot(DbConnection connection, DbConnectionInterceptionContext<int> interceptionContext)
    { }

    public void DatabaseGetting(DbConnection connection, DbConnectionInterceptionContext<string> interceptionContext)
    { }

    public void DatabaseGot(DbConnection connection, DbConnectionInterceptionContext<string> interceptionContext)
    { }

    public void DataSourceGetting(DbConnection connection, DbConnectionInterceptionContext<string> interceptionContext)
    { }

    public void DataSourceGot(DbConnection connection, DbConnectionInterceptionContext<string> interceptionContext)
    { }

    public void Disposing(DbConnection connection, DbConnectionInterceptionContext interceptionContext)
    { }

    public void Disposed(DbConnection connection, DbConnectionInterceptionContext interceptionContext)
    { }

    public void EnlistingTransaction(DbConnection connection, EnlistTransactionInterceptionContext interceptionContext)
    { }

    public void EnlistedTransaction(DbConnection connection, EnlistTransactionInterceptionContext interceptionContext)
    { }

    public void Opening(DbConnection connection, DbConnectionInterceptionContext interceptionContext)
    { }

    /// <summary>
    /// Called after <see cref="DbConnection.Open" /> or its async counterpart is invoked.
    /// </summary>
    /// <param name="connection">The connection that was opened.</param>
    /// <param name="interceptionContext">Contextual information associated with the call.</param>
    public void Opened(DbConnection connection, DbConnectionInterceptionContext interceptionContext)
    {
        Check.NotNull(connection, "connection");
        Check.NotNull(interceptionContext, "interceptionContext");

        if (interceptionContext.Exception != null)
        {
            Write(
                interceptionContext.IsAsync
                    ? String.Format(StringResources.ConnectionOpenErrorLogAsync,
                        DateTimeOffset.UtcNow, interceptionContext.Exception.Message)
                    : String.Format(StringResources.ConnectionOpenErrorLog, DateTimeOffset.UtcNow, interceptionContext.Exception.Message));
        }
        else if (interceptionContext.TaskStatus.HasFlag(TaskStatus.Canceled))
        {
            Write(String.Format(StringResources.ConnectionOpenCanceledLog, DateTimeOffset.UtcNow));
        }
        else
        {
            Write(
                interceptionContext.IsAsync
                    ? String.Format(StringResources.ConnectionOpenedLogAsync, DateTimeOffset.UtcNow)
                    : String.Format(StringResources.ConnectionOpenedLog, DateTimeOffset.UtcNow));
        }
    }

    public void ServerVersionGetting(DbConnection connection, DbConnectionInterceptionContext<string> interceptionContext)
    { }

    public void ServerVersionGot(DbConnection connection, DbConnectionInterceptionContext<string> interceptionContext)
    { }

    public void StateGetting(DbConnection connection, DbConnectionInterceptionContext<ConnectionState> interceptionContext)
    { }

    public void StateGot(DbConnection connection, DbConnectionInterceptionContext<ConnectionState> interceptionContext)
    { } 
    #endregion
}

internal class Check
{
    public static T NotNull<T>(T value, string parameterName)
        where T : class
    {
        if (value == null)
        {
            throw new ArgumentNullException(parameterName);
        }

        return value;
    }
}

StringResources.resx:
CommandLogCanceled          Canceled in {0} ms{1}
CommandLogComplete          Completed in {0} ms with result: {1}
CommandLogFailed            Failed in {0} ms with error: {1}
ConnectionClosedLog         Closed connection at {0}
ConnectionCloseErrorLog     Failed to close connection at {0} with error: {1}
ConnectionOpenCanceledLog   Cancelled open connection at {0}
ConnectionOpenedLog         Opened connection at {0}
ConnectionOpenedLogAsync    Opened connection asynchronously at {0}
ConnectionOpenErrorLog      Failed to open connection at {0} with error: {1}
ConnectionOpenErrorLogAsync Failed to open connection asynchronously at {0} with error: {1}
0

这里还有另一种解决方案，可以从更高的层面来衡量查询 - 从数据访问层（DAL）方法级别。因此，您可以通过自定义属性标记每个数据库/数据访问层方法，该属性将收集有关方法执行时间的信息，并执行您想要的操作（记录日志）。

例如，您可以使用Fody库和Fody's MethodTimer扩展来实现。

以下是一些如何的句子：

例如，您有一个名为“UsersRepositry”的存储库，其中包含方法“GetAll”：

//semi-pseudo code
public class UsersRepository {
   ...
   public async Task<List<User>> GetAllAsync(){
      return await _efDbContext.Users.AllAsync();
   }   
}

使用 Fody，您可以通过 [Time] 属性进行标记：

[Time]
public async Task<List<User>> GetAllAsync(){
      return await _efDbContext.Users.AllAsync();
}

添加静态记录器，记录执行时间：

public static class MethodTimeLogger
    {
        public static void Log(MethodBase methodBase, TimeSpan elapsed, string message)
        {
            //Do some logging here, for example : 
            YourLogger.Info($"{methodBase.DeclaringType.Name}.{methodBase.Name} : {elapsed.TotalMilliseconds}ms");
        }
    }

工作原理：

Fody 将在编译时重写标记方法的 IL 级别，使其变为：

public class UsersRepository 
{
    public async Task<List<User>> GetAllAsync()
    {
        var stopwatch = Stopwatch.StartNew();
        try
        {
            //Some code u are curious how long it takes
            return await _efDbContext.Users.AllAsync();
        }
        finally
        {
            stopwatch.Stop();
            MethodTimeLogger.Log(methodof(GetAllAsync), stopwatch.Elapsed);
        }
    }
}
结论： 衡量数据访问层(DAL)方法执行时间的好方法。在这里你无法记录一些内部DbCommand信息(如SQL查询)或没有映射实体的原始执行时间，但总的来说-取决于你的需求。在我的情况下，仅记录方法/执行时间就足够了。

希望能对某些人有所帮助。祝您编码愉快！

0
相对简单，但你不能使用System.Timers.Timer对象吗？在EF代码之前调用start，在EF代码之后调用end。如果其中有异步代码，您可以调用.Result并删除awaits以同步运行代码并计时调用。除此之外，如果您使用SQL分析器并从另一个值中减去一个值（Timer-Profiler），则可以了解EF代码执行需要多长时间。
3
我希望有一个集中的解决方案，而不需要每次在任何地方使用Entity Framework时都要重复做同样的事情。 - Yogesh
我猜你可以为每个调用实体框架创建某种包装器，但我认为你试图实现的复杂性绝对超过了好处。我的首选方法是在必要时计时，在开发过程中进行改进，并将没有计时器等的代码放入生产环境。在你长时间运行的5+秒查询的特定情况下，我会尝试将其放入优化存储过程中，并查看是否能将时间缩短。 - MaxRev17
@MaxRev17 嗯，根据Jonathan Allen的回答，这似乎是一种比较通用的简单方法... - Zero3
网页内容由stack overflow 提供, 点击上面的
可以查看英文原文，
原文链接