Home > Blockchain >  NLog Info Level outputs differently than Debug Level
NLog Info Level outputs differently than Debug Level

Time:10-11

I have a program using the following in-code configuration of NLog:

private static void SetupLogger()
        {
            var config = new NLog.Config.LoggingConfiguration();

            var consoleLog = new NLog.Targets.ConsoleTarget("consoleLog");
            var traceLog = new NLog.Targets.TraceTarget("traceLog");
            config.AddRule(LogLevel.Trace, LogLevel.Fatal, consoleLog);
            config.AddRule(LogLevel.Trace, LogLevel.Fatal, traceLog);
            NLog.LogManager.Configuration = config;
        }

Here is an example log call in code:

private void Send_Command(TransmitterProtocolDataCommand command)
        {
            CheckConnection();
            _logger.Info($"Sending: {command}");
            if(!_tracerModel.ComSendData(command.GetRawPacketBytes()))
                throw new FatalKeywordException($"Serial communication failed!");
            _logger.Debug(
                $"Sent Bytes: 0x{BitConverter.ToString(command.GetRawPacketBytes()).Replace("-", " 0x")}");
        }

Here is the output of the above example:

2022-10-07 15:05:00.6739|DEBUG|Testcenter.RobotFramework.Keyword.KeywordManager|Starting keyword invocation: Power_Roombus(powerOn=True) ...
Testcenter.RoombusService.exe Information: 0 : 2022-10-07 15:05:00.6739|INFO|Testcenter.RoombusService.KeywordLibrary.RoombusKeywords|Sending: TransmitterProtocol Command #0 (EnableCAN24VOut) => 0xA
2022-10-07 15:05:00.6739|DEBUG|Testcenter.RoombusService.KeywordLibrary.RoombusKeywords|Sent Bytes: 0x68 0x05 0x01 0x0A 0x03

The program is a remote-library-server, so it receives XML-RPC calls and invokes them. Output of those invocations is tracked using Trace. I don't think the error lies within the remote procedure call, since both log level entries are created within the same invocation.

I don't know why NLog is logging INFO with a preceding Testcenter.RoombusService.exe Information: 0 :

This is a problem for me since it ruins readability of the log, because there are breaks of format. Additionally, it ruins any sort of parsing that would be done on the log files later on, since I need to take these special "Prefix" into account.

Can anyone explain to me why it does that?

I'm new into using the NLog package and I couldn't find information on it in the documentation. (Maybe I overlooked something, don't know)

CodePudding user response:

Try updating your NLog TraceTarget to this:

var traceLog = new NLog.Targets.TraceTarget("traceLog") { RawWrite = true };

The additional prefix-output is appended by the Microsoft Trace Source Listener.

See also: https://github.com/NLog/NLog/wiki/Trace-target

  • Related