如何使用 NLog 正确测量多线程 C# 应用程序中操作和指令所需的时间？

Question

我有 UNIX 服务器编程背景，速度分析非常简单：只需添加日志并验证后续条目之间的差异即可。

然而，这种工作方式在我当前的应用程序中似乎是假的：基于

NLog

的 C# 多线程应用程序（后者用于日志记录目的）。

我正在测试的来源如下：

foreach (var missionpart in mission.missionParts)
{
    _logger.Debug($"GetmissionsTelegram : currently dealing with missionPart with Id=[{missionpart.Id}]");
    if (missionpart.ProductId != null)
    {
        if (products.Where(o => o.Id == missionpart.ProductId).FirstOrDefault() == null)
        {
            add_mission = false;
        }
    }
    _logger.Debug($"GetmissionsTelegram : missionPart with Id=[{missionpart.Id}] is dealt with.");
}

_logger.Debug($"GetmissionsTelegram : will be added=[{addmission}]");

从这段代码中，您可以很容易地看到包含“is dealt with”的行应该立即跟在“currently dealt”或“will be add”行之后。事实并非如此，您可以从以下日志文件摘录中看到：

...
2024-10-17 16:58:13.2446 | GetJobsTelegram : jobPart with Id=[37370] is dealt with.
2024-10-17 16:58:24.1662 | GetJobsTelegram : currently dealing with jobPart with Id=[37371]
...
2024-10-17 17:02:31.9896 | GetJobsTelegram : jobPart with Id=[37320] is dealt with.
2024-10-17 17:02:44.9066 | GetJobsTelegram : currently dealing with jobPart with Id=[37321]
...
2024-10-17 17:04:44.1077 | GetJobsTelegram : jobPart with Id=[37305] is dealt with.
2024-10-17 17:04:55.9323 | GetJobsTelegram : currently dealing with jobPart with Id=[37306]

如您所见，时间戳长达九秒甚至更长！

我可以确认我的应用程序确实需要很长时间才能完成所有工作，因此万一

NLog

做了一些缓冲（这在Windows技术中似乎很正常），这只会将问题转移到日志的无用性上，但是问题依然存在。

...或者也许有一种方法可以立即跳到问题的根源：有没有办法对多线程 C# 应用程序说：

在此任务完成之前，您不能继续其他线程。

有人有一些关于如何帮助我的信息吗？

提前致谢

Answer 1

NLog 默认以本地时间输出时间戳，因为这是大多数初次用户所期望的。从机器时间到区域本地时间的转换会产生开销，因此 NLog 默认情况下使用缓存时间源 (

FastLocal

)，每 15 毫秒刷新一次（遵循 Environment.TickCount）

您可以将 timesource 更改为更高精度，如下所示：

<nlog>
    <time type="AccurateUTC" />
    <!-- Rest of Configuration -->
</nlog>

请注意，如果您计划对亚毫秒级的内容进行基准测试，那么我强烈建议您查看BenchmarkDotNet

另请参阅：https://blog.machinezoo.com/how-to-configure-nlog-time-source

另请参阅：https://blog.machinezoo.com/nlog-timestamps-with-millisecond

另请参阅：https://caraulean.com/2016/timestamp-accuracy-and-resolution-in-nlog/