如何在 Log4Net 中记录经过的时间

本文关键字：经过 时间 记录 Log4Net | 更新日期: 2023-09-27 18:35:48

我想记录我的API的运行时间。我在这里看到两种不同的方法：

  1. 使用stopwatch .在进入 API 后创建一个新的秒表，然后在退出之前调用stop()（在日志本身上打印经过的时间）。

  2. 制作两个日志打印输出，一个在进入 API 后，另一个在退出 API 之前。经过的时间将被"存储"为两个日志时间戳之间的时间差。

您认为哪种方法最好？

第一个看起来不错，但我需要在任何地方创建一个新的秒表。第二个更干净，但在读回日志时必须做一些数学运算

如何在 Log4Net 中记录经过的时间

我会选择第一个选项。创建Stopwatch非常便宜。使用良好的包装器，每个 API 方法中所需的代码可以像以下一样简单：

public int MyApiMethod()
{
    using (new ExecutionTimeLogger())
    {
        // All API functionality goes inside this using block.
        var theResultValue = 23;
        return theResultValue;
    }
}

类ExecutionTimeLogger如下所示：

using System;
using System.Diagnostics;
using System.Runtime.CompilerServices;
using log4net;
public class ExecutionTimeLogger : IDisposable
{
    private readonly ILog log = LogManager.GetLogger("ExecutionTimes");
    private readonly string methodName;
    private readonly Stopwatch stopwatch;
    public ExecutionTimeLogger([CallerMemberName] string methodName = "")
    {
        this.methodName = methodName;
        stopwatch = Stopwatch.StartNew();
    }
    public void Dispose()
    {
        log.Debug(methodName + "() took " + stopwatch.ElapsedMilliseconds + " ms.");
        GC.SuppressFinalize(this);
    }
}

根据您的记录器实现，输出可能如下所示：

15：04：23.4477 |调试 |执行时间 |MyApiMethod（） 花了 42 毫秒。

请注意，当 API 方法在using内抛出异常时，也会生成日志输出，因为ExecutionTimeLogger实例将被无所事事地释放。

methodName参数将由编译器自动填充，因为它具有 [CallerMemberName] 属性。您不需要每次创建ExecutionTimeLogger时都传递它。

第 GC.SuppressFinalize(this) 行告诉垃圾回收器不必计划对 ExecutionTimeLogger 实例终结器的调用，因为我们知道它从未创建过非托管资源。

如果使用 Unity 作为 DI 框架，还可以编写一个UnityContainerExtension，将具有特定自定义属性（例如LogExecutionTimeAttribute）的每个方法包装为所需的测量和日志记录代码。不过，这要复杂得多。

我更喜欢第一种方法（使用stopwatch）。
如果您的方法称为同步，则不必为每个 API 调用创建新的Stopwatch对象。您可以定义 Stopwatch 的全局实例，并在调用 Stop() 后调用Reset() ，或Restart()从头开始计数。

相关文章：