NLog is skipping log messages. .NET issue? Multi-thread issue?

Question

I have a multi-threaded C# .NET 4.5 application running.

Running on my local Windows 7 laptop, NLog logs all my messages. I publish the app using Visual Studio... copy the published app to a Windows Server 2008... and run the app on the server: this results in skipped log messages. Can someone help me understand WHY and how I can fix this or suggest an alternative to NLog?

My configuration file is as follows:

I have tried this without the "async = true"

<targets async="true">


    <target  xsi:type="ColoredConsole"
            name="ColoredConsole"
            layout="${date} ${level} ${message} ${event-context:item=AlgID} " />

    <target name="xmlfile" xsi:type="File"
            fileName="C:\QRT\Logs\LogEmiter.Nlog.xlog" keepFileOpen="true"
            layout="${log4jxmlevent}" />

    <target xsi:type="File"
            name ="LogFile" fileName="C:\QRT\Logs\QRTLog-${shortdate}.log"
            layout ="${date:format=yyyy-MM-dd HH\:mm\:ss.fff}|${level}|${threadid}|${threadname}|${event-properties:item=FromID}|${message}${exception:format=tostring} "/>

    <target xsi:type="File"
            name ="TapeLogFile" fileName="C:\QRT\Logs\QRTMarketLog.txt"
            layout ="${date:format=yyyy-MM-dd HH\:mm\:ss.fff}|${level}|${message}"/>

  </targets>
     <rules>
        <!-- add your logging rules here -->

        <logger name ="TapeLogFile" minlevel="Trace" writeTo="TapeLogFile" />
        <logger name ="TapeLogFile" minlevel="Trace" writeTo="ColoredConsole" final="true"/>
        <logger name="*" minlevel="Trace" writeTo="ColoredConsole" />
        <logger name="*" minlevel="Trace" writeTo="xmlfile" />
        <logger name="*" minlevel="Trace" writeTo="LogFile" />


        <!--
        Write all events with minimal level of Debug (So Debug, Info, Warn, Error and Fatal, but not Trace)  to "f"
        <logger name="*" minlevel="Debug" writeTo="f" />
        -->
      </rules>
    </nlog>

I log messages this way:

In my typical class, I would initialize my NLog helper class as such:

    private void InitliazlieLogger()
    {
        LogManager.ThrowExceptions = true;
        m_logger = new NLogHelper(LogManager.GetCurrentClassLogger());
        m_logger.Set("FromID", "Email"); // Class setting.
    }

private void DoSomething(int _x) 
{
    m_logger.Debug ("Print this statement: {0}", _x);
}

I have an NLog helper class...

public NLogHelper(Logger Logger)
{
    m_logger = Logger;
    m_properties = new Dictionary<string, object>();
}

public void Debug(string Message, params object[] Args)
        {
            m_logger.Debug()
                .Message(Message, Args)
                .Properties(m_properties)
                .Write();
            notify(Severity.Debug, Message);
        }

The issue is that some log messages are just skipped over. I added my own logging class which wrote to a file manually and inserted a call to is in NLogHelper.Debug and I found that the file I wrote manually had a complete set of log messages but the NLog output was missing some.

Again, this works on my laptop, but fails on Windows Server 2008. My Server has .NET 4.6.1 installed. I seem to only have 4.5.2 on my Windows 7 machine. Could that be it?

As a side note: If I upload all my source files the server and use Visual Studio on the server to compile the exact same code, NLog seems to work ?!?

-Confused.

Thanks -Ed

Answer 1

EDIT: This is not a complete answer. The answer below solved half the problem. What I had not noticed was that the missing messages were INFO and not DEBUG. Converting all my INFO logs to DEBUG logs fixed my issues. It seems that even though I can output INFO logs on my local machine, INFO would work on my server. Still not root-caused. :(

Well, I thought that the only difference between the working system (my laptop running Windows 7) and the server (running Window Server 2008) was the Windows version and the .NET version installed.

The issue was infact, thanks for Sibers for finding this, the fact that the server had multiple hardware CPUs and its multi-threading was closer to real multi-threading than was happening on my laptop. NLog was issuing error messages but I was not seeing them. It was trying to write over itself.

So I (Sibers) changed:

<target xsi:type="File"
        name ="LogFile" fileName="C:\QRT\Logs\QRTLog-${shortdate}.log"
        layout ="${date:format=yyyy-MM-dd HH\:mm\:ss.fff}|${level}|${threadid}|${threadname}|${event-properties:item=FromID}|${message}${exception:format=tostring} "/>

to

    <target name="asyncWrapper" xsi:Type="AsyncWrapper" queueLimit="20000">
        <target name="LogFile"
            xsi:type="File"
            fileName="C:\QRT\Logs\QRTLog-${shortdate}.log"
            layout="${date:format=yyyy-MM-dd HH\:mm\:ss.fff}|${level}|${threadid}|${threadname}|${event-properties:item=FromID}|${message}${exception:format=tostring} "
            concurrentWrites="true" />
   </target>

Problem fixed. Man... that took me a month! I was about to give up and write my own logger by hand.

-Ed