1 / 37

Making a logging approach work for your project… (log4net)

Making a logging approach work for your project… (log4net). Scott Colestock Trace Ventures, LLC. Agenda. Motivate tracing as a topic… Log4net background / key features Log4net concepts Tracing practices & viewers Log4net with DTS/COM+/BizTalk

mateja
Download Presentation

Making a logging approach work for your project… (log4net)

An Image/Link below is provided (as is) to download presentation Download Policy: Content on the Website is provided to you AS IS for your information and personal use and may not be sold / licensed / shared on other websites without getting consent from its author. Content is provided to you AS IS for your information and personal use only. Download presentation by click this link. While downloading, if for some reason you are not able to download a presentation, the publisher may have deleted the file from their server. During download, if you can't get a presentation, the file might be deleted by the publisher.

E N D

Presentation Transcript

  1. Making a logging approach work for your project…(log4net) Scott Colestock Trace Ventures, LLC

  2. Agenda • Motivate tracing as a topic… • Log4net background / key features • Log4net concepts • Tracing practices & viewers • Log4net with DTS/COM+/BizTalk • Compare (briefly) with the Microsoft Enterprise Library Logging Block

  3. Motivation… • We’ve always wanted a mechanism for diagnostic tracing in our code… • Especially before symbolic debuggers… • And whenever it isn’t convenient to attach one. • Production support or field diagnostics for ISV (“black box recorder”) • Early mechanisms… • stderr as the standard stream for error output fprintf(stderr,”Error: %s”,s); • OutputDebugString / DbgPrint • Observing behavior in real-time or in post-mortem can be extremely helpful… • Developers seem to like tackling logging solutions…

  4. Motivation (2) • Quickly, we realize that we can’t have all of our trace messages all of the time • We can’t diagnose a problem because we can’t see the relevant information or patterns in the noise • Performance problems can result • From preparing the messages • From sending messages to a destination • Early attempts at addressing this use severity levels • Verbose, Info, Warning, Error, etc. • Need common agreement among devs… • For non-trivial systems, this won’t cure the problem defined above…

  5. Motivation (3) – What we really want… Severity Level Verbose Info Warn Error UI Tier Business tier Data Access Calculation Engine Subsystems in your application

  6. What did .NET bring? • System.Diagnostics namespace • Trace/Debug classes for tracing • Extensible “listener” concept • Built-in: OutputDebugString, File, and Event Log • Verbose/Info/Warn/Error levels built into a TraceSwitch class • Trace.WriteLineIf(mySwitch.TraceError,…) • “Categories” simply acted as prepended text; no configuration implications • Unable to turn tracing on/off by category • Could maybe introduce Trace.WriteLineIf(severity.TraceError && myCategorySwitch.Enabled, …) • Unable to route different categories to different trace listeners • Also: ASP.NET TraceContext (“red”…or “not red”) 

  7. Closer to the ultimate… OutputDebugString Event Log Circular File Severity Level Verbose Info Warn Error Email UI Tier Business tier Data Access Calculation Engine Subsystems in your application

  8. Agenda • Motivate tracing as a topic… • Log4net background / key features • Log4net concepts • Tracing practices & viewers • Log4net with DTS/COM+/BizTalk • Compare (briefly) with the Microsoft Enterprise Library Logging Block

  9. Log4net Background • Apache-sponsored initiative within the “Apache Logging Services” project • http://logging.apache.org • Log4cxx, Log4j, Log4Perl, Log4PHP, Log4PLSQL • Log4net! • API consistency is a high priority for the overall project • Log4net initially created by NeoWorks as a branch from Log4j • Release 1: September 2001 • Release 1.2.0 beta 8: July 2003 • December 2003: Donated to Apache; now “incubating” • SourceForge CVS shows work is still active…

  10. Log4net Background (2) • Supported frameworks include: • .NET 1.0 / 1.1 • Compact Framework 1.0 • Mono .25 or higher • Microsoft Shared Source CLI 1.0 • Apache License • You can distribute copies of the work with or without source, in accordance with conditions in the license • Not burdensome at all, IMHO, but I’m not a lawyer…

  11. Log4net key features… • Hierarchical configuration of the logging space • Better than “categories”… • Multiple output targets (“appenders”) for trace information • Context that can be attached to a trace stream • Declarative formatting of trace output / Filtering • Reconfiguration on the fly (no process restart)

  12. Hierarchical Configuration • Suppose I have two classes with namespace-qualified names that look like: • MyCompany.MyDepartment.MyClassA • MyCompany.MyDepartment.MyClassB • Each class’ code can obtain a logger specific to that body of code using: private static readonly ILog log = LogManager.GetLogger(typeof(MyClassX));

  13. Hierarchical Configuration (2) • Each class (MyClassA/MyClassB) can now emit trace with statements such as log.Info(“hello world”) or log.Warn(“a potential problem…”) • What is significant is that log4net understands the hierarchy implied by the namespace-qualified names…

  14. Hierarchical Configuration (3) • Configuration Excerpt: <root> <level value="ERROR" /> </root> <logger name="MyCompany"> <level value="WARN" /> </logger> <logger name="MyCompany.MyDepartment.MyClassA"> <level value="DEBUG" /> </logger> By default, only output trace messages at the “error” level of severity But within the MyCompany namespace, output warnings AND errors Finally, for MyClassA, override what I’ve said for the namespace, and output ALL the trace information.

  15. Why is hierarchy important? • Important to note that log4net doesn’t insist that your tracing hierarchy maps to your namespace and type hierarchy – just recommended practice • Hierarchy is important because it allows the amount of trace information you are trying to digest to be controllable at the same level of granularity as your system partitions… • Most projects give a fair amount of thought to the .NET namespaces they use, and the boundaries for each • At very least, C# classes usually represent reasonable granularity • When all we work with is a static set of categories, we need take an initial guess at what the right granularity will be… • You might be wrong, because the subsystems associated with those categories grow at different rates • Do you really want to re-factor trace categories???

  16. Trace output at each level of hierarchy controlled by external configuration – defer the decision & reconfigure on the fly OutputDebugString Event Log Circular File Severity Level Verbose Info Warn Error Email UITier UITier.GridWrapper DataAccess DataAccess.CustomerDataSet Subsystems in your application

  17. Log4net key features… • Hierarchical configuration of the logging space • Better than “categories”… • Multiple output targets (“appenders”) for trace information • Context that can be attached to a trace stream • Declarative formatting of trace output / Filtering • Reconfiguration on the fly (no process restart)

  18. Log4net Appenders (Output targets) • ADONetAppender • Configurable batch size • Any IDBConnection (Sql, OleDb, etc.) • Supply connection string, command text (sproc or parameterized sql) • Supply a log4net “layout” for each parameter • ASPNetTraceAppender – uses ASP.NET trace facility <%@ Page Trace="true" %> or <system.web> <trace enabled="true" requestLimit="40" localOnly=“true"/> </system.web> • Trace messages are appended to browser page, and/or available via http://myserver/myapp/trace.axd • Using log4net instead of TraceContext…(always separate the API from the display technology…)

  19. Log4net Appenders (2) • ConsoleAppender / ColoredConsoleAppender • EventLogAppender (configurable ‘event source’) • FileAppender (watch out for multiple threads…) & RollingFileAppender • NetSendAppender • RemotingAppender – supply .NET remoting sink URI (IRemoteLoggingSink) • Can potentially use to consolidate logging events from multiple servers… • BufferingForwardingAppender – buffered batch in front of another appender • SmtpAppender / SmtpPickupDirAppender • UdpAppender • OutputDebugStringAppender

  20. Viewing OutputDebugString output • DBMon.exe as part of the Windows SDK see \Program Files\Microsoft Visual Studio .NET\Common7\Tools\Bin\winnt\Dbmon.Exe • Gives you a basic console view • Much better: DebugView from SysInternals • http://www.sysinternals.com/ntw2k/freeware/debugview.shtml

  21. Log4net key features… • Hierarchical configuration of the logging space • Better than “categories”… • Multiple output targets (“appenders”) for trace information • Context that can be attached to a trace stream • Declarative formatting of trace output / Filtering • Reconfiguration on the fly (no process restart)

  22. Log4net Classes / Core Concepts • LogManager – factory for loggers (ILog-derived class instances) • Loggers • Instance of a logger is specific to a subset of your code. • Typically “named” after namespace-qualified type name – i.e. private static readonly ILog log = LogManager.GetLogger(typeof(MyClassX)); • Used by the code to emit trace output at a particular severity level, using Debug/Info/Warn/Error/Fatal methods

  23. Log4net Classes / Core Concepts (2) • Logging level is generally inherited from the hierarchy, and be configured anywhere in the hierarchy. • Rule: logging level is equal to first non-null value working UP the tree. • Predefined levels: DEBUG, INFO, WARN, ERROR, FATAL, ALL, OFF • Default level for root in hierarchy is DEBUG

  24. Logging levels… • Configuration Excerpt: <root> <level value="ERROR" /> </root> <logger name="MyCompany"> <level value="WARN" /> </logger> <logger name="MyCompany.MyDepartment.MyClassA"> <level value="DEBUG" /> </logger> By default, only output trace messages at the “error” level of severity But within the MyCompany namespace, output warnings AND errors Finally, for MyClassA, override what I’ve said for the namespace, and output ALL the trace information.

  25. Log4net Classes / Core Concepts (3) • Appenders – an output destination for logging • Appenders are attached to a given level of the configured logging hierarchy • Root, or MyCompany, or MyCompany.MyDepartment.MyClassA • Log output will go to the first appender found moving up the hierarchy, as well as all appenders further up the hierarchy! • unless "additivity=false" at some level, in which case moving up hierarchy stops

  26. Appender Configuration <log4net> <appendername="OutputDebugStringAppender"type="log4net.Appender.OutputDebugStringAppender"/> <appendername="SMTPAppender"type="log4net.Appender.SMTPAppender"> <paramname="To"value="to@domain.com"/> <paramname="From"value="from@domain.com"/> <paramname="Subject"value="Logging messages"/> <paramname="SMTPHost"value="SMTPServer.domain.com"/> <evaluatortype="log4net.spi.LevelEvaluator"> <paramname="Threshold"value="ERROR"/> </evaluator> </appender> <root> <levelvalue="ERROR"/> <appender-refref="OutputDebugStringAppender"/> </root> <loggername="MyCompany"> <levelvalue="WARN"/> </logger> <loggername="MyCompany.MyDepartment.MyClassA"> <levelvalue="DEBUG"/> <appender-refref="SMTPAppender"/> </logger> </log4net>

  27. Log4net Classes / Core Concepts (4) • Layouts – Appenders can reference Layouts • Layouts format trace output in powerful ways • And, again, let you defer decisions • SimpleLayout / XmlLayout • PatternLayout • Lets you include details such as date, thread Id, logging level, name of logger, context information • Lets you include more expensive information such as the callers type-name, file name, method name, line number, windows identity (pay as you go…) <layouttype="log4net.Layout.PatternLayout"> <!-- The format specifiers let us add a wide variety of additional info --> <paramname="ConversionPattern"value="%d [%t] %-5p %c [%x] - %m%n"/> </layout>

  28. Log4net Classes / Core Concepts (5) • NDC – Nested Diagnostic Context • Allows you to distinguish log output that is interleaved from multiple clients, users, threads, requests, etc. • Functions as a Push/Pop style stack • NDC.Push(“somevalue”)/NDC.Pop or using(NDC.Push(“someval”)) { work(); } • Thread-relative • MDC – Mapped Diagnostic Context • Allows you to attach key-value pairs to a thread-relative context • Useful for business level identifiers or other info that isn’t nested • PatternLayout can output elements of “context”

  29. Log4net Classes / Core Concepts (6) • Filters – Appenders can have filters that determine what log events “make it through” • DenyAllFilter • LevelMatchFilter • LevelRangeFilter • MDCFilter / NDCFilter • Let’s just see events for this one user… • StringMatchFilter – including regex • I need this one event sent to my pager…

  30. Log4net Configuration • Configurators – classes that assist in configuring log4net in various ways • Assembly attributes can be used to specify a configuration file (read on first call!) • XmlConfiguratorAttribute • You can explicitly initialize, specifying config file location • XmlConfigurator.Configure • Can use standard .NET config file (app.config or web.config) or separate • Better to isolate!

  31. Logging practices • Create a standard configuration files with all the Appenders you might think you need • Start each project with this config file • Then reference Appenders by a particular point in the hierarchy when/if they are needed • Easier to change once in production… • Consider the cost of assembling a logging string • logger.Debug(String.Format(“Value foo is {0} and bar is {1} and baz is {3}”,foo,bar,baz)); • This can be quite expensive – guard with if(logger.IsDebugEnabled) {…}

  32. Trace Viewer Choices • Viewing trace logs in real time has always been a bit challenging • Tail utilities • SysInternal’s DebugView is pretty good… • Limited remote viewing story • Some filtering/highlighting • No multi-machine consolidation story • Not a bad way to go for simple scenarios

  33. Trace Viewer Choices (2) • Chainsaw v2 is part of the Apache logging project… • I haven’t used, but looks powerful. Log4j-focused; UI is java-based • Likely uses the XmlLayoutSchemaLog4j class • Attach to multiple servers, filter, sort, highlight, etc. • See http://logging.apache.org/log4j/docs/chainsaw.html

  34. Trace Viewer Choices (3) • Paul Bunyan from Diamond Sierra • http://www.diamondsierra.com/ • Server-side buffering service • Viewer is extremely powerful • Multiple server consolidation • Powerful filtering and sorting • Has own API; but trivial to write a log4net Appender (they have a .NET API) • Notion of context in log4net can map to context column in the viewer; logger can map to component column • Also: http://www.codeproject.com/csharp/TraceTool.asp (http://sourceforge.net/projects/tracetool)

  35. Log4net and BizTalk 2004 (or other “hosted” environments) • BizTalk 2004, COM+ applications, DTS packages, managed add-ins to Office, GAC-deployed components… • None of these can rely on explicit start-up sequence to do configuration • None of these can rely on finding a config file co-located with an assembly • Moreover, BizTalk/DTS environments make the thread-relative nature of log4net context break • Execution of a logic flow often occurs on multiple threads over time • BizTalk requires components to be serializable; built-in ILog implementations in log4net are not… • See “Diagnostic Tracing With BizTalk 2004” on www.traceofthought.net for more discussion and an extension library “log4net.Ext.Serializable” that addresses all of these issues

  36. Microsoft Enterprise Library Logging blockhttp://msdn.microsoft.com/library/default.asp?url=/library/en-us/dnpag2/html/entlib.asp • See http://weblogs.asp.net/lorenh • Pros • Graphical configuration tool in the box • Active development community • Integrated with the other blocks (but…) • Cons • No hierarchical configuration • Any change in config “touches” .net config (including web.config) • No short-circuit ala log.IsDebugEnabled • No standard priorities – just an int • Slower than log4net:

  37. Summary • Don’t tackle your own logging library… • Hierarchical configuration is huge… • Insist on separation of concerns: • The API you use versus the consumption strategy! • The immediate information you have in hand from accompanying context • Consider your trace viewing options for the real-time case

More Related