为什么nlog不能读取当前日期

Question

我正在使用Nlog将一些日志记录写入文本文件.部分nlog.config:

 <target name="file" xsi:type="File" fileName="${basedir}/MBWRunner_log.txt"
             layout="${date} (${level}): ${message}
Exception: ${exception:format=Method, ToString}"/>

日志文件中的行如下所示:

0001-01-01 00:00:00(追踪):MBWRunner开始了

如您所见,日期和时间都是0.我已经测试了{longdate}和{date:format = yyyyMMddHHmmss},结果相同.

该应用程序是一个控制台应用程序,从提升的命令行运行.

有线索吗？

[编辑]我在组织内的2台机器上测试了这个,结果相同.请帮忙!

使用的代码:

  static Logger _logger = LogManager.GetCurrentClassLogger();

public static void Log(string message, LogLevel priority)
    {
      LogEventInfo eventinfo = new LogEventInfo(); ;
      eventinfo.Message = message;
      eventinfo.Level = priority;
      Log(eventinfo);
    }

static void Log(LogEventInfo logentry)
{     
  _logger.Log(logentry);
}

Answer 1

更新:

@edosoft我认为问题是你使用LogEventInfo的默认构造函数.如果你在这里查看LogEventInfo的源代码

https://github.com/NLog/NLog/blob/master/src/NLog/LogEventInfo.cs

您将看到使用默认构造函数不会填充该.TimeStamp字段,因此该字段可能只是默认为DateTime的默认值,我假设是DateTime.MinValue.您应该使用其他构造函数之一或Create方法之一.由于您只设置了消息和级别字段,我建议:

var logEvent = new LogEventInfo(priority, "", message); //Second param is logger name.

要么

var logEvent = LogEventInfo.Create(priority, "", message);

从NLog源DateLayoutRenderer(从这里)我们可以看到,作为记录流的一部分写入的日期值计算如下:

    protected override void Append(StringBuilder builder, LogEventInfo logEvent)
    {
        var ts = logEvent.TimeStamp;
        if (this.UniversalTime)
        {
            ts = ts.ToUniversalTime();
        }

        builder.Append(ts.ToString(this.Format, this.Culture));
    }

这到底是怎么发生的是,DateLayoutRenderer是获得TimeStamp从值LogEventInfo对象(NLOG创建其中之一每次使用的时候Logger.Trace,Logger.Debug,Logger.Info等方法.你也可以创建LogEventInfo自己的对象,并与他们登录Logger.Log的方法).

默认情况下,LogEventInfo创建对象时,其TimeStamp字段设置如下(来自LogEventInfo 此处的源)(注意使用CurrentTimeGetter.Now):

    public LogEventInfo(LogLevel level, string loggerName, IFormatProvider formatProvider, [Localizable(false)] string message, object[] parameters, Exception exception)
    {
        this.TimeStamp = CurrentTimeGetter.Now;
        this.Level = level;
        this.LoggerName = loggerName;
        this.Message = message;
        this.Parameters = parameters;
        this.FormatProvider = formatProvider;
        this.Exception = exception;
        this.SequenceID = Interlocked.Increment(ref globalSequenceId);

        if (NeedToPreformatMessage(parameters))
        {
            this.CalcFormattedMessage();
        }
    }

使用属性TimeStamp在LogEventInfo构造函数中设置该字段TimeSource.Current.Now,其实现可在此处查看.

(更新 - 在某些时候,NLog从使用CurrentTimeGetter变为更通用的方法,TimeSource即拥有一种具有多种口味的对象(其中一种CachedTimeSource,基本上与之相同CurrentTimeGetter)).

为了省去导航链接的麻烦,以下是以下内容的来源CachedTimeSource:

public abstract class CachedTimeSource : TimeSource
{
    private int lastTicks = -1;
    private DateTime lastTime = DateTime.MinValue;

    /// <summary>
    /// Gets raw uncached time from derived time source.
    /// </summary>
    protected abstract DateTime FreshTime { get; }

    /// <summary>
    /// Gets current time cached for one system tick (15.6 milliseconds).
    /// </summary>
    public override DateTime Time
    {
        get
        {
            int tickCount = Environment.TickCount;
            if (tickCount == lastTicks)
                return lastTime;
            else
            {
                DateTime time = FreshTime;
                lastTicks = tickCount;
                lastTime = time;
                return time;
            }
        }
    }
}

这个类的目的是使用相对便宜的操作(Environment.Ticks)来限制对相对昂贵的操作(DateTime.Now)的访问.如果Ticks的值不随调用而变化(从一个记录的消息到下一个消息),那么此时DateTime.Now检索的值将与DateTime.Now的值相同,这次只检索,所以只需使用最后一个检索价值.

使用所有这些代码(并且日期/时间日志记录显然适用于大多数其他人),您的问题的一个可能的解释是您使用该Logger.Log方法来记录您的消息,并且您正在LogEventInfo自己构建对象.默认情况下,如果您只是新建一个LogEventInfo对象,则TimeStamp属性的自动设置应该可以正常工作.如果合适Environment.Ticks,它仅依赖于,DateTime.Now以及重用最后一个DateTime.Now值的逻辑.

您是否可能正在创建LogEventInfo对象然后将其TimeStamp属性设置为DateTime.MinValue？我问,因为记录的日期是DateTime.MinValue.

我能想到的唯一其他解释是,如果Environment.Ticks由于某种原因返回-1.如果是,则CurrentTimeGetter始终返回lastDateTime私有成员变量的初始值.我无法想象Environment.Ticks会返回-1 的场景.