Serilog日志记录中DateTime.UtcNow精度问题解析

在.NET Framework环境下使用Serilog进行日志记录时，开发者可能会遇到一个典型问题：当快速连续记录多条日志时，通过ForContext("AppGeneratedDateTime", DateTime.UtcNow)添加的时间戳会出现重复值。这种现象在循环日志记录场景中尤为明显。

问题本质

该问题的根源在于.NET Framework中DateTime.UtcNow属性的设计特性。与高精度的计时器不同，DateTime.UtcNow在.NET Framework中的时间分辨率通常为10-15毫秒级别。这意味着在极短时间间隔内（如循环快速记录时）获取的多个时间戳可能完全相同。

技术背景

Windows操作系统的时间API底层实现决定了DateTime.UtcNow的精度限制。传统Windows时间服务基于系统时钟中断周期，默认情况下约为15.6毫秒（64Hz）。虽然现代硬件支持更高精度，但.NET Framework的API设计保持了向后兼容性。

解决方案

方案一：引入延迟（不推荐）

通过在日志记录方法中强制添加Thread.Sleep(1)可以确保时间戳唯一性，但这种方法会显著影响性能，特别是在高频日志场景下。

方案二：高精度时间计算（推荐）

更优雅的解决方案是结合使用DateTime.UtcNow和Stopwatch类：

private static readonly DateTime _processStartTime = DateTime.UtcNow;
private static readonly Stopwatch _highPrecisionTimer = Stopwatch.StartNew();

public void LogInformation(string message)
{
    var preciseTimestamp = _processStartTime.AddTicks(_highPrecisionTimer.Elapsed.Ticks);
    
    _logger
        .ForContext("AppGeneratedDateTime", preciseTimestamp)
        .Information(message);
}

这种方案的工作原理：

1. 在程序启动时捕获基准时间点（_processStartTime）
2. 同时启动高精度计时器（Stopwatch）
3. 每次记录日志时，将计时器的增量加到基准时间上

方案对比

方案	精度	性能影响	适用场景
原始方案	15ms	无	非密集日志
延迟方案	1ms	高	不推荐
高精度方案	100ns	低	推荐方案

进阶建议

1. 对于需要严格时序分析的场景，建议直接记录Stopwatch的计时刻度（Ticks）
2. 考虑将时间戳生成逻辑封装为可配置的扩展方法
3. 在.NET Core/.NET 5+环境中，此问题已得到显著改善，但仍建议使用高精度方案保证一致性

总结

日志记录中的时间戳精度问题本质上是框架限制与业务需求的矛盾。通过理解底层机制并合理运用.NET提供的计时工具，开发者可以在不牺牲性能的前提下获得满足需求的时间精度。这种解决方案不仅适用于Serilog，也可推广到其他需要高精度时间记录的.NET应用场景中。