Why can't nlog read the current date

date, formatting, nlog

Solution

UPDATE:

@edosoft I think the problem is your use of the default constructor for LogEventInfo. If you look at the source for LogEventInfo here

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

You will see that using the default constructor does not populate the `.TimeStamp` field, so the field will probably just default to the default value for DateTime, which I assume is `DateTime.MinValue`. You should use one of the other constructors or one of the Create methods. Since you are setting only the Message and Level fields, I would suggest either:

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

Or

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

From the NLog source for `DateLayoutRenderer` (from here) we can see that the date value that gets written as part of the logging stream is calculated like this:

    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));
    }

What is happening here is that the `DateLayoutRenderer` is getting the `TimeStamp` value from the `LogEventInfo` object (NLog creates one of these each time you use the `Logger.Trace`, `Logger.Debug`, `Logger.Info`, etc methods. You can also create `LogEventInfo` objects yourself and log them with the `Logger.Log` method).

By default, when a `LogEventInfo` object is created, its `TimeStamp` field is set like this (from the source for `LogEventInfo` here) (note the use of `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();
        }
    }

The `TimeStamp` field is set in the `LogEventInfo` constructor using the `TimeSource.Current.Now` property, whose implementation can be seen here.

(UPDATE - At some point NLog changed from using `CurrentTimeGetter` to a more generic approach of having a `TimeSource` object that has several flavors (one of which, `CachedTimeSource`, is essentially the same as `CurrentTimeGetter`)).

To save the trouble of navigating the link, here is the source for `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;
            }
        }
    }
}

The purpose of this class is to use a relatively cheap operation (`Environment.Ticks`) to limit access to a relatively expensive operation (`DateTime.Now`). If the value of Ticks does not change from call to call (from one logged message to the next), then the value of `DateTime.Now` retrieved the this time will be the same as the value of DateTime.Now retrieved this time, so just use the last retrieved value.

With all of this code in play (and with Date/Time logging apparently working for most other people), one possible explanation of your problem is that you are using the `Logger.Log` method to log your messages and you are building the `LogEventInfo` objects yourself. By default, if you just new a `LogEventInfo` object, the automatic setting of the `TimeStamp` property should work fine. It is only dependent on `Environment.Ticks`, `DateTime.Now`, and the logic that reuses the last `DateTime.Now` value, if appropriate.

Is it possible that you are creating a `LogEventInfo` object and then setting its `TimeStamp` property to `DateTime.MinValue`? I ask because the date that is being logged is `DateTime.MinValue`.

The only other explanation that I can think of would be if `Environment.Ticks` returns -1 for some reason. If it did, then `CurrentTimeGetter` would always return the initial value of the lastDateTime private member variable. I can't imagine a scenario where `Environment.Ticks` would return -1.

Problem

Original source