Log4net logging with custom parameters

Question

I have database maintenance in place using AdoNetAppender. What I would like to do is write a user id to each log statement. However, I do not want to use the standard log4net% identifier for two reasons:

• log4net warns that it is very slow as it should look for the context identifier.
• In some components of the service, standard authentication is a service account, but we have already fixed the user ID in a variable, and I would like to use this.

I saw code in which some people use log4net.ThreadContext to add additional properties, but I understand that this is “unsafe” due to thread rotation (and this is also a performance leak).

My approach was to extend the AdoNetAppenderParameter class like this:

public class UserAdoNetAppenderParameter : AdoNetAppenderParameter { public UserAdoNetAppenderParameter() { DbType = DbType.String; PatternLayout layout = new PatternLayout(); Layout2RawLayoutAdapter converter = new Layout2RawLayoutAdapter(layout); Layout = converter; ParameterName = "@username"; Size = 255; } public override void Prepare(IDbCommand command) { command.Parameters.Add(this); } public override void FormatValue(IDbCommand command, LoggingEvent loggingEvent) { string[] data = loggingEvent.RenderedMessage.Split('~'); string username = data[0]; command.Parameters["@username"] = username; } } 

and then programmatically add this to the current application like this:

 ILog myLog = LogManager.GetLogger("ConnectionService"); IAppender[] appenders = myLog.Logger.Repository.GetAppenders(); AdoNetAppender appender = (AdoNetAppender)appenders[0]; appender.AddParameter(new UserAdoNetAppenderParameter()); myLog.InfoFormat("{0}~{1}~{2}~{3}", userName, "ClassName", "Class Method", "Message"); 

The goal is to use a standard format for messages and parse the first part of the string, which should always be the username. The FormatValue () method of the appender custom parameter must use only that part of the string so that it can be written to a separate field in the log database.

My problem is that no log statements are written to the database. Oddly enough, when debugging, the breakpoint in the FormatValue () method only hits when the service stops.

I made my way through many things related to this, but have not yet found the answers. Someone was able to do this, or I'm wrong. Postscript I also tried to extend AdoNetAppender, but it does not give you access to setting parameter values.

Answer 1

After some experimentation, I finally got this to work. Ensuring that the log4net log helps identify errors and downloads the source code of log4net, as well as an overview of the AdoNetAppenderParameter class, show how to use the FormatValue () method. So here the user parameter appender is changed:

 public class UserAdoNetAppenderParameter : AdoNetAppenderParameter { public override void FormatValue(IDbCommand command, LoggingEvent loggingEvent) { string[] data = loggingEvent.RenderedMessage.Split('~'); string username = string.Empty; if (data != null && data.Length >= 1) username = data[0]; // Lookup the parameter IDbDataParameter param = (IDbDataParameter)command.Parameters[ParameterName]; // Format the value object formattedValue = username; // If the value is null then convert to a DBNull if (formattedValue == null) { formattedValue = DBNull.Value; } param.Value = formattedValue; } } 

And to use this, I add it to the log4net configuration file as follows:

 <parameter type="MyAssembly.Logging.UserAdoNetAppenderParameter, MyAssembly"> <parameterName value="@username" /> <dbType value="String" /> <size value="255" /> <layout type="log4net.Layout.PatternLayout" value="%message" /> </parameter> 

And by convention, my log statements will be something like this:

 if (log.IsDebugEnabled) log.DebugFormat("{0}~{1}~{2}", username, someOtherParameter, message); 

If you look at the class, it uses the data [0] as the username, so it depends on compliance with the agreement. However, it gets the username in its own parameter and in a separate field in the log database table, without resorting to temporarily putting it on an unsafe ThreadContext.

Answer 2

I also needed to write structured data and liked to use the logging interface as follows:

 log.Debug( new { SomeProperty: "some value", OtherProperty: 123 }) 

Therefore, I also wrote my own AdoNetAppenderParameter class to do the job:

 public class CustomAdoNetAppenderParameter : AdoNetAppenderParameter { public override void FormatValue(IDbCommand command, LoggingEvent loggingEvent) { // Try to get property value object propertyValue = null; var propertyName = ParameterName.Replace("@", ""); var messageObject = loggingEvent.MessageObject; if (messageObject != null) { var property = messageObject.GetType().GetProperty(propertyName); if (property != null) { propertyValue = property.GetValue(messageObject, null); } } // Insert property value (or db null) into parameter var dataParameter = (IDbDataParameter)command.Parameters[ParameterName]; dataParameter.Value = propertyValue ?? DBNull.Value; } } 

Now the log4net configuration can be used to register any property of this object:

 <?xml version="1.0" encoding="utf-8"?> <log4net> <appender name="MyAdoNetAppender" type="log4net.Appender.AdoNetAppender"> <connectionType value="System.Data.SqlClient.SqlConnection, System.Data, Version=1.0.3300.0, Culture=neutral, PublicKeyToken=b77a5c561934e089" /> <connectionString value="... your connection string ..." /> <commandText value="INSERT INTO mylog ([level],[someProperty]) VALUES (@log_level,@SomeProperty)" /> <parameter> <parameterName value="@log_level" /> <dbType value="String" /> <size value="50" /> <layout type="log4net.Layout.PatternLayout"> <conversionPattern value="%level" /> </layout> </parameter> <parameter type="yourNamespace.CustomAdoNetAppenderParameter, yourAssemblyName"> <parameterName value="@SomeProperty" /> <dbType value="String" /> <size value="255" /> </parameter> </appender> <root> <level value="DEBUG" /> <appender-ref ref="MyAdoNetAppender" /> </root> </log4net> 

Answer 3

Yes, stream flexibility means you cannot return the correct data. For log4net, you will want to insert it into the HttpContext Items collection .

The problem is that you need to do some work to get it back when it is time to write these values ​​in the database, because of this I always used the Marek Adaptive Property Provider class to do the hard work for me. This is a very simple use, since all you have to do is the following:

 log4net.ThreadContext.Properties["UserName"] = AdaptivePropertyProvider.Create("UserName", Thread.CurrentPrincipal.Identity.Name); 

The adaptive property will know the appropriate place to retrieve the value when log4net requests it.

Alternative option

If you're not stuck with log4net, NLog makes the logging process for ASP.NET websites easier because they natively support ASP.NET applications. Usage and even configuration are almost identical to log4net!