can I pass a custom property to NLOG and output to file?

Question

EDIT 4: "From" seems to be a reserved word in NLog. Changing it "FromID" worked. this is an awesome way to pass variables to NLog and still keep your code clean !!!! THANK MIKE!!!

EDIT 3. I really like this idea.:

Implemented a helper class as Mike suggested below:

public class NLogHelper
{
    //
    // Class Properties
    //
    private Logger m_logger;
    private Dictionary<string, object> m_properties;


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

    //
    // Setting Logger properties per instancce
    //
    public void Set(string key, object value)
    {
        m_properties.Add(key, value);
    }

    //
    // Loggers
    //
    public void Debug(string format, params object[] args)
    {
        m_logger.Debug()
            .Message(format, args)
            .Properties(m_properties)
            .Write();
    }

and in my main code, I have:

    private NLogHelper m_logger;
    public void Start() 
    {
        m_logger = new NLogHelper(LogManager.GetCurrentClassLogger());
        m_logger.Set("From", "QRT123");  // Class setting.
        m_logger.Debug("Hello ");
    }

And the target set in the config file as follows:

<target xsi:type="File"
    name ="LogFile" fileName="C:\QRT\Logs\QRTLog-${shortdate}.log"
    layout ="${date}|${level}|${event-properties:item=From}|${message} "/>

But the output has a BLANK in the place of the 'from' property ???

So I'm ALMOST THERE... but it does not seem to work??

EDIT 2: I am now trying to create my own version of the NLog call:

private void Log_Debug (string Message) 
{
   LogEventInfo theEvent = new LogEventInfo(LogLevel.Debug, "What is this?", Message);
   theEvent.Properties["EmployeeID"] = m_employeeID;
   m_logger.Log(theEvent);
}

The issue is that I have to format the string for the calls (but a huge performance deal)... but this seems like a hack??

Ideally, I would declare properties in the custom layout renderer and instead of setting those properties in the configuration file, each instance of my class would have the property set... something like [ID = m_ID] for the whole class. This way whenever a NLog is called from that class, the ID property is set and NLog's custom layout renderer can use this property to output it. Am I making sense??

I'm new to NLog and have been looking at custom renderers. Basically, my goal is to have my log statements be: _logger.Debug ("My Name is {0}", "Ed", ID=87);

and I'd like my rendered to be something like: layout = ${ID} ${date} ${Level} ${Message}

That's it. ${ID} can have a default value of 0. fine. But ideally, I'd like every call to have the ability to specify an ID without needing to have 3 lines everytime I want to log.

I've seen custom renderers allowing me to customize what I output but i'm not sure how I can customize the properties I pass to it without

https://github.com/NLog/NLog/wiki/Extending%20NLog shows how I can add properties but I don't know how to call them.

Also, https://github.com/NLog/NLog/wiki/Event-Context-Layout-Renderer shows how I can set custom properties but that involved the creation of a LogEventInfo object every time I want to log something.

Nlog Custom layoutrenderer shows how to customize the output.. again... not how to customize the inputs.

This is for a Console app in C# targeting .NET 4.0 using VS2013

Thanks -Ed

Foot

Answer 1

Event properties (used to be called event-context) would be the built-in way to do what you want. If you are using NLog 3.2+ you can use the fluent api, which may be a bit more appealing than creating LogEventInfo objects. You can access this api by by using the namespace NLog.Fluent.

Your layout would then be defined like this:

${event-properties:item=ID} ${date} ${Level} ${Message}

Then using the fluent api, log like this:

_logger.Debug()
    .Message("My name is {0}", "Ed")
    .Property("ID", 87)
    .Write();

Other than setting properties per event as above, the only other option would be to set properties per thread using MDC or MDLS.

NLog dosen't have a way (that I have found) of setting per-logger properties. Internally, NLog caches Logger instances by logger name, but does not guarantee that the same instance of Logger will always be returned for a given logger name. So for example if you call LogManager.GetCurrentClassLogger() in the constructor of your class, most of the time you will get back the same instance of Logger for all instances of your class. In which case, you would not be able to have separate values on your logger, per instance of your class.

Perhaps you could create a logging helper class that you can instantiate in your class. The helper class can be initialized with per-instance property values to be logged with every message. The helper class would also provide convenience methods to log messages as above, but with one line of code. Something like this:

// Example of a class that needs to use logging
public class MyClass
{
    private LoggerHelper _logger;

    public MyClass(int id)
    {
        _logger = new LoggerHelper(LogManager.GetCurrentClassLogger());

        // Per-instance values
        _logger.Set("ID", id);
    }

    public void DoStuff()
    {
        _logger.Debug("My name is {0}", "Ed");
    }
}


// Example of a "stateful" logger
public class LoggerHelper
{
    private Logger _logger;
    private Dictionary<string, object> _properties;


    public LoggerHelper(Logger logger)
    {
        _logger = logger;
        _properties = new Dictionary<string, object>();
    }

    public void Set(string key, object value)
    {
        _properties.Add(key, value);
    }

    public void Debug(string format, params object[] args)
    {
        _logger.Debug()
            .Message(format, args)
            .Properties(_properties)
            .Write();
    }
}

This would work with the same layout as above.

Hostility

thank you ! I will try implementing the helper so I can keep my code readable. do you think this will impact performance? Because of all the calls to a helper class? – Foot

Hi Mike: I implemented your suggestion but it does not seem to work? I get a blank in the spot I'd expect the new property. I've provided my code above in "EDIT 3". i made sure I spelled the property correctly... 'not sure what's going on here. No compile issued etc. – Foot

Got it to work. "From" seems to be a reserved word. I changed it to FromID and it worked! – Foot

There wouldn't be a noticeable decrease in performance from using a helper class in this way. However, there is a potential for some different performance characteristics in using NLog's fluent API vs. the standard API. – Hostility

The example above DOES use the fluent API (or at least, that's the only way I got the syntax above to work). – Foot

Right. And thats the only part of the solution that I would have concerns about performance. I havent noticed any issues in my use of it however. – Hostility

Answer 2

NLog v4.5 supports structured logging using message templates:

logger.Info("Logon by {user} from {ip_address}", "Kenny", "127.0.0.1");

NLog v4.6.3 supports injecting properties using WithProperty:

logger.WithProperty("user", "kenny").Info("User logon");

NLog v5 introduces new fluent API:

logger.ForInfoEvent().Property("user", "kenny").Message("User logon").Log();

See also https://github.com/NLog/NLog/wiki/How-to-use-structured-logging

See also https://github.com/NLog/NLog.Extensions.Logging/wiki/NLog-properties-with-Microsoft-Extension-Logging

Colligan

use string interpolation in C# 6.0 logger.Info($"Logon by {"Kenny"} from ${"127.0.0.1"}"); – Querulous

@Querulous The idea is not to use string-interpolation but message-templates: messagetemplates.org – Colligan

Answer 3

Use MDLC Layout Renderer

MappedDiagnosticsLogicalContext.Set("PropertyName", "PropertyValue"); MappedDiagnosticsLogicalContext.Set("PropertyName2", "AnotherPropertyValue");

In your nlog config:

${mdlc:item=PropertyName} ${mdlc:item=PropertyName2}

https://github.com/NLog/NLog/wiki/MDLC-Layout-Renderer

Pteranodon

Answer 4

I had 6 variables I wanted to send to structured logging in multiple places (so when I get a user report I can search the log database on our key id fields). I created a logging scope class that leverages the MDLC. So it should be thread safe, work with async/await code and be 3 lines of code for 6 variables everywhere used.

public class MyClassLoggingScope : IDisposable
{
    private readonly List<IDisposable> context;

    public MyClassLoggingScope(MyClass varSource)
    {
        this.context = new List<IDisposable> 
        { 
            MappedDiagnosticsLogicalContext.SetScoped("Var1", varSource.Var1)
            // list all scoped logging context variables
        }
    } 

    public void Dispose()
    {
        foreach (IDisposable disposable in this.context)
        {
            disposable.Dispose();
        }
    }
}

Usage:

using (new MyClassLoggingScope(this))
{
    // do the things that may cause logging somewhere in the stack
}

Then as flux earlier suggested, in the logging config you can use ${mdlc:item=Var1}

Shewmaker

Answer 5

I noticed that in the meantime the API must have changed, as the accepted answer doesn't work for me.

My use case assumes I want to have one logger for a dedicated task, which requires the property. All the other loggers shouldn't be affected.

So what did work for me was:

logger.Properties["MyProperty"] = "SetItTheValueHere";

Then I can just call the logging functions as usual:

logger.Info("My Log");

and the logs contain the property set.

Civism

Modifying the Logger.Properties directly can give unwanted side-effects (for others using the same logger-instance). It is recommended to use Logger.WithProperty if wanting to mutate the Logger-property-injection. – Colligan

@RolfKristensen Good to know, thanks for the warning. In my case there'll be nobody else using this logger - at least for now - but it's always good to avoid problematic solutions from the beginning. – Civism

Answer 6

This is propably not the best way to do this and not even thread safe but a quick and dirty solution: You could use Environment variables:

Environment.SetEnvironmentVariable("NLogOptionID", "87");
logger.Debug("My Name id Ed");
Environment.SetEnvironmentVariable("NLogOptionID", null);

In your layout, you can use environment variables.

${environment:variable=NLogOptionID}

Lukasz

Wow. Interesting. I love the idea because I can set the Env Variable once. Right now, I was working with a LogEventInfo (I edited the question above to add this)... but this is very messy... I do need thread-safe though... – Foot

I have no idea why it was rated low. Honestly with the nlog unable to log {aspnet-user-identity} as it currently logs as empty value, in asp.netcore 2.2 web api, this is the solution i was able to achieve. I have no clue why the HttpContext.User.Identity is not being rendered by that layout property but this trick works for me. – Toniatonic

@Toniatonic It might look like this works for you. However, since this sets the variable on a process level, it could happen that, between a call to Environment.SetEnvironmentVariable and the actual logger.Debug(...) call another thread already updated the value and you log the wrong user. For a simple console or windows app this can be really helpful, but use it with caution in web projects. – Restate

Thread safe is increasingly important the more users are on your site, this might work perfectly fine in the dev environment, but would be useless in production. You could get away with it if you put it inside a subfunction with a lock statement, but then you could have performance issues when every log statement is waiting on other log statements. – Shewmaker

@DeniseSkidmore True, that's why you shouldn't use this approach in a webapp. I use this in a bootstrapper application that has no reference to nlog but loads the real application via reflection and it is guaranteed that at this moment the app only runs a single thread. This way I can extend my logging with usefull information. – Restate