c# - 如何在 Log4Net 中记录运行时间

Question

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

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

2. 制作两份日志打印输出，一份刚进入 API 之后，另一份刚好在退出 API 之前。耗时将“存储”为两个日志时间戳之间的时间差。

您认为哪种方法最好？

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

Answer 1

我会选择第一个选项。 秒表 的创建成本非常低。有了一个好的包装器，每个 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 | DEBUG | ExecutionTimes | MyApiMethod() took 42 ms.

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

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

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

---

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