为什么日志记录器建议每个类使用一个日志记录器?

根据 NLog 的文档:

大多数应用程序将为每个类使用一个日志记录器,其中日志记录器的名称与类的名称相同。

这和 log4net 的操作方式是一样的,为什么这是一个好的实践呢?

42113 次浏览

Probably because you want to be able to log methods that are only visible to the class without breaking encapsulation, this also makes it easy to use the class in another application without breaking the logging functionality.

Two reasons immediately spring to mind:

  1. Having a separate log for each class makes it easy to group together all log messages/errors pertaining to a given class.
  2. Having a log within a class allows you to log internal details which may not be accessible outside the class (e.g., private state, information dealing with a class's implementation, etc.).

I can see a few reasons for this choice.

  • You will always know where a particular log statement came from, if you include the name of the logger in your log output format.
  • You can control what log statements you see at a fine grained level by turning certain loggers on or off, or setting their level.

In most cases, the name of the class provides a good name for the logger. When scanning the log files, you can see the log message and associate it directly with a line of code.

A good example where this is not the best approach, is Hibernate's SQL logs. There is a shared logger named "Hibernate.SQL" or something like that, where a number of different classes write raw SQL out to a single logger category.

With log4net, using one logger per class makes it easy to capture the source of the log message (ie. the class writing to the log). If you don't have one logger per class, but instead have one logger for the entire app, you need to resort to more reflection tricks to know where the log messages are coming from.

Compare the following:

Log per class

using System.Reflection;
private static readonly ILog _logger =
LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType);


public void SomeMethod()
{
_logger.DebugFormat("File not found: {0}", _filename);
}

One logger per app (or similar)

Logger.DebugFormat("File not found: {0}", _filename); // Logger determines caller


-- or --


Logger.DebugFormat(this, "File not found: {0}", _filename); // Pass in the caller

Using the second example, the Logger would need to build a stack trace to see who was calling it or your code would always have to pass in the caller. With the logger-per-class style, you still do this, but you can do it once per class instead of once per call and eliminate a serious performance problem.

Makes it easy to configure appenders by namespace or class.

Advantage for using "logger per file" in NLog: you have possibility to manage/filter logs by namespace and class name. Example:

<logger name="A.NameSpace.MyClass"      minlevel="Debug" writeTo="ImportantLogs" />
<logger name="A.NameSpace.MyOtherClass" minlevel="Trace" writeTo="ImportantLogs" />
<logger name="StupidLibrary.*"          minlevel="Error" writeTo="StupidLibraryLogs" />


<!-- Hide other messages from StupidLibrary -->
<logger name="StupidLibrary.*" final="true" />


<!-- Log all but hidden messages -->
<logger name="*" writeTo="AllLogs" />

NLogger has a very useful code snippet to do this. The nlogger snippet will create the following code:

private static NLog.Logger logger = NLog.LogManager.GetCurrentClassLogger();

So only few keystrokes and you have logger per class. It will use namespace and class name as the name of the logger. To set different name to your class logger, you can use this:

private static NLog.Logger logger = NLog.LogManager.GetLogger("MyLib.MyName");

And, as @JeremyWiebe said, you don't have to use tricks to get the name of the class which is trying to log a message: Name of the logger (which is usually the name of the class) can be easy logged to file (or other target) by using ${logger} in layout.

There is also a performance benefit in the case of NLog. Most users will use

Logger logger = LogManager.GetCurrentClassLogger()

Looking up the current class from stack trace take some (but not much) performance.

From a development standpoint, it's easiest if you don't have to create a logger object each time. On the other hand, if you don't, but rather you create it dynamically using reflection, it'll slow down performance. To solve this, you can use the following code which creates the logger dynamically asynchronously:

using NLog;
using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Linq;
using System.Text;
using System.Threading.Tasks;


namespace WinForms
{
class log
{


public static async void Log(int severity, string message)
{
await Task.Run(() => LogIt(severity, message));
}


private static void LogIt(int severity, string message)
{
StackTrace st = new StackTrace();
StackFrame x = st.GetFrame(2);     //the third one goes back to the original caller
Type t = x.GetMethod().DeclaringType;
Logger theLogger = LogManager.GetLogger(t.FullName);


//https://github.com/NLog/NLog/wiki/Log-levels
string[] levels = { "Off", "Trace", "Debug", "Info", "Warn", "Error", "Fatal" };
int level = Math.Min(levels.Length, severity);
theLogger.Log(LogLevel.FromOrdinal(level), message);


}
}
}

If you are using NLOG you can specify the callsite in the config, this will record the class name and method where the logging statement was located.

<property name="CallSite" value="${callsite}" />

You could then use a constant for your logger name or the assembly name.

Disclaimer: I don't know how NLOG collects this information, my guess would be reflection so you may need to consider the performance. There are a few issues with Async methods if you are not using NLOG v4.4 or later.