출처 : https://stackify.com/log4net-guide-dotnet-logging/
If you have been doing .NET programming very long, odds are, you have touched a few projects that used log4net. It has been around for a long time and is very similar to log4j which is for Java. Log4net is a tool I have used forever and I wanted to share a tutorial to use for .Net logging!
What is log4net and why should you use it, or any C# logging framework?
I still find it hard to believe how many people I talk to that don’t use any sort of C# logging framework. Personally, it would be one of the first things I add to any new project.
Logging frameworks are important because they make it easy to write your logs to different places by simply changing your configuration. You can write your .NET logs to a file on disk, a database, a log management system or potentially dozens of other places, all without changing your code.
Getting Started: How to Install log4net via Nuget
1. Add log4net Package
Starting with log4net is as easy as installing a Nuget package. You can use the Visual Studio UI to search for it and install it, or just run this quick command from the Package Manager Console.
PM> Install-Package log4net
2. Add log4net.config file
Add a new file to your project in Visual Studio called log4net.config and be sure to set a property for the file. Set “Copy to Output Directory” to “Copy Always”. This is important because we need the log4net.config file to be copied to the bin folder when you build and run your app.
To get you started quickly, copy this log4net config and put it in your new log4net.config file. This will log messages to the console and a log file both. We will discuss more about logging appenders further down.
<log4net> <root> <level value="ALL" /> <appender-ref ref="console" /> <appender-ref ref="file" /> </root> <appender name="console" type="log4net.Appender.ConsoleAppender"> <layout type="log4net.Layout.PatternLayout"> <conversionPattern value="%date %level %logger - %message%newline" /> </layout> </appender> <appender name="file" type="log4net.Appender.RollingFileAppender"> <file value="myapp.log" /> <appendToFile value="true" /> <rollingStyle value="Size" /> <maxSizeRollBackups value="5" /> <maximumFileSize value="10MB" /> <staticLogFileName value="true" /> <layout type="log4net.Layout.PatternLayout"> <conversionPattern value="%date [%thread] %level %logger - %message%newline" /> </layout> </appender> </log4net>
3. Tell log4net to Load Your Config
The next thing we need to do is tell log4net where to load it’s configuratin from so that it actually works. I suggest putting this in your AssemblyInfo.cs file. You can find it under the Properties section in your project.
Add this to the bottom of your AssemblyInfo file.
[assembly: log4net.Config.XmlConfigurator(ConfigFile = "log4net.config")]
4. Log Something!
Now you can modify your app to log something and try it out!
class Program { private static readonly log4net.ILog log = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType); static void Main(string[] args) { log.Info("Hello logging world!"); Console.WriteLine("Hit enter"); Console.ReadLine(); } }
Log Appenders: What They Are and Which Ones You Need to Know
Appenders are how you direct where you want your logs sent. The most popular of the standard appenders are most likely the RollingFileAppender and ConsoleAppender.
I would also try the DebugAppender if you want to see your log statements in the Visual Studio Debug window so you don’t have to open a log file.
If you are using a Console, checkout the ColoredConsoleAppender.
COLORED CONSOLE FOR LOG4NET
Make Good Use of Multiple Log Levels and Filter by Them
Be sure to use Debug, Info, Warning, Error, and Fatal logging levels as appropriate within your code. Don’t lot everything as Debug. Be sure to think about how you would be viewing the logs and what you want to see it later when coding your logging statements.
You can specify in your log4net config which log4net logging levels you want to log. This is really valuable if you want to specify only certain levels to be logged to a specific log appender or to reduce logging in production. This also you to log more or less data without changing your code.
log4net levels:
- All – Log everything
- Debug
- Info
- Warn
- Error
- Fatal
- Off – Don’t log anything
Advanced Topics & log4net Best Practices
1. Define Your LogManager Object as Static
Declaring any variable in your code has overhead. When I have been doing some profiling sessions in the past to optimize code, I have noticed that the constructors on the LogManager object can use a lot of CPU.
Declare it as static and use this little trick so you don’t have to hard code the class type.
private static readonly log4net.ILog log = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);
2. How to Enable log4net’s Own Internal Debug Logging
From time to time, you may have problems with a specific appender, or issues working with it.
To help resolve these issues, enable internal log4net logging via your web.config file.
<configuration> <appSettings> <add key="log4net.Internal.Debug" value="true"/> </appSettings> </configuration> You can then specify where the logging is written to. <configuration> ... <system.diagnostics> <trace autoflush="true"> <listeners> <add name="textWriterTraceListener" type="System.Diagnostics.TextWriterTraceListener" initializeData="C:\tmp\log4net.txt" /> </listeners> </trace> </system.diagnostics> ... </configuration>
3. Do Not Send Your Logs to a Database Table with the AdoAppender
Trying to query logs in SQL is very difficult if you log any real volume. You are much better off sending your logs to Elasticsearch or a log management service that can provide full-text indexing and more functionality with your logs.
4. Do Not Send Emails on Every Exception
The last thing you want to do is send any sort of emails from an appender. They either get ignored over time or something starts throwing a lot of exceptions and then your app starts sending thousands of errors. Although, there is an SmtpAppender if you really want to do this.
5. How to Send Alerts for Exceptions
If you want to send alerts about exceptions, send your exceptions to an error trackingproduct, like Retrace, which is designed for this. They can also de-dupe your errors so you can figure out when an error is truly new, track its history, and track error rates.
6. Send Your Logs to a Log Management System to View Them Across Servers
Capturing logs and logging them to a file on disk is great. But if you want to search your logs across multiple servers and applications, you need to send all of your logs to a central repository. There are a lot of log management solutions that can help you with this, or you can even setup your own elasticsearch cluster for it.
If you want to query all the files on disk, consider using VisualLogParser.
7. Use Filters to Suppress Certain Logging Statements
Filters can be configured to suppress specific log messages. Take a look at these examples.
Here’s how you can filter by the text on the log messages.
<filter type="log4net.Filter.StringMatchFilter"> <stringToMatch value="test" /> <!-- Can filter by string or regex --> </filter>
And here, you can filter by the log level.
<filter type="log4net.Filter.LevelRangeFilter"> <levelMin value="INFO" /> <levelMax value="FATAL" /> </filter>
8. You Can Make Your Own Custom log4net Appenders
If you want to do something that the standard appenders do not support, you can search online for one or write your own.
One example could be an appender for writing to Azure Storage. Once upon a time, we wrote one to send our logs to Azure Table storage to centralize them. We couldn’t really query them due to the lack of full-text indexing, but we could view them.
As an example of a custom appender, you can review the source code for our appender for sending logs to Retrace.
9. Customize Your Layout in Your Logs with log4net Pattern Layouts
You can modify your configuration to change what fields are outputting and in what format using pattern layouts.
<appender name="LogFileAppender" type="log4net.Appender.RollingFileAppender"> <param name="File" value="stackify.log" /> <param name="AppendToFile" value="true" /> <rollingStyle value="Size" /> <maxSizeRollBackups value="10" /> <maximumFileSize value="10MB" /> <staticLogFileName value="true" /> <layout type="log4net.Layout.PatternLayout"> <param name="ConversionPattern" value="%-5p %d{MM-dd hh:mm:ss.ffff} [%thread] %m%n" /> </layout> </appender>
Using the layout above, write the level (%p), current date time (%d), thread # (%thread), the message (%m) and a new line (%n). The “-5” in the “%-5p” is to set the width of the field to 5 characters.
Here are some other notable fields you can log, although they can have a big performance impact to your app and would not be recommended for high volume logging on a production application.
- %method – name of the method where the log message was written
- %stacktrace{level} – output a stack trace to show where the log message was written
- %type – type of the caller issuing the log request. Mostly likely your class name
- %line – the line number from where your logging statement was logged
A layout like this:
<layout type="log4net.Layout.PatternLayout"> <param name="ConversionPattern" value="%-5p%d{ yyyy-MM-dd HH:mm:ss} – [%thread] %m method:%method %n stacktrace:%stacktrace{5} %n type:%type %n line: %line %n" /> </layout>
Produces a log message like this:
ERROR 2017-02-06 09:38:10 – [10] Error downloading web request method:ThrowWebException stacktrace:Microsoft.VisualStudio.HostingProcess.HostProc.RunUsersAssembly > System.AppDomain.ExecuteAssembly > System.AppDomain._nExecuteAssembly > ConsoleApplication1.Program.Main > ConsoleApplication1.Class1.ThrowWebException type:ConsoleApplication1.Class1 line: 26
10. Use the Diagnostic Contexts to Log Additional Fields
You can also log custom fields to help give some more context about the user, customer or transaction related to the log statements.
The below example sets a custom property called “customer”. You can then modify your log4net pattern layout to include “%property{customer}” to output it in your logs.
log4net.ThreadContext.Properties["customer"] = "My Customer Name"; log.Debug("We are going to try and do a web request"); try { Class1.ThrowWebException(); } catch (Exception ex) { log.Error("Error trying to do something", ex); } log.Debug("We are done with the web request");
11. How to Correlate Log Messages by Web Request Transaction
Additionally, you can assign objects in contexts to use what it calls “active property values.” When the log message is written, the ToString() method will be called which can dynamically do something.
This can be used to write transaction IDs to help correlate messages to a web requestor transaction!
//Create our little helper class public class ActivityIdHelper { public override string ToString() { if (Trace.CorrelationManager.ActivityId == Guid.Empty) { Trace.CorrelationManager.ActivityId = Guid.NewGuid(); } return Trace.CorrelationManager.ActivityId.ToString(); } }
In your global.asax or Startup.cs class, subscribe to an event for when a request first starts.
public override void Init() { base.Init(); this.Error += WebApiApplication_Error; this.BeginRequest += WebApiApplication_BeginRequest; this.EndRequest += WebApiApplication_EndRequest; } void WebApiApplication_BeginRequest(object sender, EventArgs e) { //set the property to our new object log4net.LogicalThreadContext.Properties["activityid"] = new ActivityIdHelper(); log.Debug("WebApiApplication_BeginRequest"); }
If you add “%property{activity}” to your pattern layout, you can now see a transaction ID in your logs like so. Your log messages may still look like spaghetti, but at least you can easily see which ones go together.
DEBUG 02-06 02:51:58.6347 – a69640f7-d47d-4aa4-99c9-13cfd9ab93c2 WebApiApplication_BeginRequest DEBUG 02-06 02:51:58.6382 – a69640f7-d47d-4aa4-99c9-13cfd9ab93c2 Starting KitchenAsync - Call redis DEBUG 02-06 02:51:58.9315 – b8a3bcee-e82e-4298-b27f-6481b256b5ad Finished KitchenAsync DEBUG 02-06 02:51:59.1285 – a69640f7-d47d-4aa4-99c9-13cfd9ab93c2 Call Webclient DEBUG 02-06 02:51:59.1686 – 54218fab-bd1b-4c77-9ff8-ebef838dfb82 WebApiApplication_BeginRequest DEBUG 02-06 02:51:59.1746 – 54218fab-bd1b-4c77-9ff8-ebef838dfb82 Starting KitchenAsync - Call redis DEBUG 02-06 02:51:59.4378 – a69640f7-d47d-4aa4-99c9-13cfd9ab93c2 Finished KitchenAsync DEBUG 02-06 02:51:59.6450 – 54218fab-bd1b-4c77-9ff8-ebef838dfb82 Call Webclient DEBUG 02-06 02:51:59.9294 – 54218fab-bd1b-4c77-9ff8-ebef838dfb82 Finished KitchenAsync
12. How to Log ASP.NET Request Details
You could use the same strategy as above to dynamically grab ASP.NET request info to add to your log message.
public class WebRequestInfo { public override string ToString() { return HttpContext.Current?.Request?.RawUrl + ", " + HttpContext.Current?.Request?.UserAgent; } } void WebApiApplication_BeginRequest(object sender, EventArgs e) { log4net.LogicalThreadContext.Properties["activityid"] = new ActivityIdHelper(); log4net.LogicalThreadContext.Properties["requestinfo"] = new WebRequestInfo(); log.Debug("WebApiApplication_BeginRequest"); }
13. How to Do Structured Logging, or Log an Object or Properties with a Message
By default, you can log an object to it and it will serialize it with its default renderers.
log.Debug(new {color="red", int1 = 1});
Output:
DEBUG 2017-02-06 15:07:25 – [8] { color = red, int1 = 1 }
But what if you want to log your entire log message as JSON?
There are several nuget packages related to log4net and JSON, but the support and docs for all of them seem a little sketchy.
I would recommend just making your own JsonLayout class that does it. There is a good sample on GitHub. You could then control exactly how you log the JSON and which fields you log.
Output from the GitHub JsonLayout:
{ "processSessionId" : "225ba696-6607-4abc-95f6-df8e0438e898", "level" : "DEBUG", "messageObject" : "Finished KitchenAsync", "renderedMessage" : "Finished KitchenAsync", "timestampUtc" : "2017-02-06T21:20:07.5690494Z", "logger" : "WebApp2.Controllers.TestController", "thread" : "69", "exceptionObject" : null, "exceptionObjectString" : null, "userName" : "IIS APPPOOL\\WebApp2", "domain" : "/LM/W3SVC/1/ROOT/WebApp2-10-131308895921693643", "identity" : "", "location" : "WebApp2.Controllers.TestController+d__27.MoveNext(C:\\BitBucket\\PrefixTests\\WebApp2\\Controllers\\TestController.cs:477)", "pid" : 14428, "machineName" : "LAPTOP-1UJ70V4E", "workingSet" : 352481280, "osVersion" : "Microsoft Windows NT 10.0.14393.0", "is64bitOS" : true, "is64bitProcess" : true, "properties" : { "requestinfo" : {}, "activityid" : {}, "log4net:UserName" : "IIS APPPOOL\\WebApp2", "log4net:Identity" : "", "log4net:HostName" : "LAPTOP-1UJ70V4E" } }
If you want to really get the value of structured logging, you will want to send your logs to a log management tool that can index all the fields and enable powerful searching and analytics capabilities.
Learn more here: What is structured logging and why developers need it.
14. How to View log4net C# Logs by ASP.NET Web Request
Log files can quickly become a spaghetti mess of log messages. Especially with web apps that have lots of AJAX requests going on that all do logging.
I highly recommend using Prefix, Stackify’s FREE .NET Profiler to view your logs per web request, along with SQL queries, HTTP calls and much more.
