Return-Path: Delivered-To: apmail-logging-general-archive@www.apache.org Received: (qmail 51973 invoked from network); 26 Jul 2007 06:43:22 -0000 Received: from hermes.apache.org (HELO mail.apache.org) (140.211.11.2) by minotaur.apache.org with SMTP; 26 Jul 2007 06:43:22 -0000 Received: (qmail 38590 invoked by uid 500); 26 Jul 2007 06:43:22 -0000 Delivered-To: apmail-logging-general-archive@logging.apache.org Received: (qmail 38533 invoked by uid 500); 26 Jul 2007 06:43:22 -0000 Mailing-List: contact general-help@logging.apache.org; run by ezmlm Precedence: bulk list-help: list-unsubscribe: List-Post: Reply-To: "Logging General" List-Id: Delivered-To: mailing list general@logging.apache.org Received: (qmail 38522 invoked by uid 99); 26 Jul 2007 06:43:22 -0000 Received: from herse.apache.org (HELO herse.apache.org) (140.211.11.133) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 25 Jul 2007 23:43:22 -0700 X-ASF-Spam-Status: No, hits=-98.6 required=10.0 tests=ALL_TRUSTED,INFO_TLD,NO_REAL_NAME X-Spam-Check-By: apache.org Received: from [140.211.11.3] (HELO eris.apache.org) (140.211.11.3) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 25 Jul 2007 23:43:19 -0700 Received: by eris.apache.org (Postfix, from userid 65534) id 04A7C1A9822; Wed, 25 Jul 2007 23:42:18 -0700 (PDT) Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit Subject: svn commit: r559716 [17/20] - in /logging/site/trunk/docs/log4net: ./ css/ images/ images/logos/ release/ release/howto/ release/manual/ src/ src/release/ src/release/howto/ src/release/manual/ src/stylesheets/ stylesheets/ Date: Thu, 26 Jul 2007 06:41:52 -0000 To: general@logging.apache.org From: carnold@apache.org X-Mailer: svnmailer-1.1.0 Message-Id: <20070726064218.04A7C1A9822@eris.apache.org> X-Virus-Checked: Checked by ClamAV on apache.org Added: logging/site/trunk/docs/log4net/src/release/manual/contexts.html URL: http://svn.apache.org/viewvc/logging/site/trunk/docs/log4net/src/release/manual/contexts.html?view=auto&rev=559716 ============================================================================== --- logging/site/trunk/docs/log4net/src/release/manual/contexts.html (added) +++ logging/site/trunk/docs/log4net/src/release/manual/contexts.html Wed Jul 25 23:41:40 2007 @@ -0,0 +1,419 @@ + + + + + + + + + + + + + + Apache log4net - + Apache log4net Manual: Contexts + + + + + + + + +
+ +
+
+
+ + + + + + + +

log4net Manual - Contexts

+ + +

+ Most real-world systems have to deal with multiple clients simultaneously. In a + typical multithreaded implementation of such a system, different threads will + handle different clients. Logging is especially well suited to trace and debug + complex distributed applications. An approach to differentiate the + logging output of one client from another is to instantiate a new separate + logger for each client. However this promotes the proliferation of loggers and + increases the management overhead of logging. +

+

+ A lighter technique is to uniquely stamp each log request initiated from the + same client interaction. +

+

+ Log4net supports different types of contextual logging and contexts with different scopes. +

+ +

Scopes

+

+ Contextual data can be set in different scopes. These contexts have progressively narrower visibility. + In the logging event itself the values from all of the contexts are combined together such that + values specified in a lower scoped context hide values from a higher context. +

+ +
+ + + + + + + + + + + + + + + + + + + + + + + + + + +
ScopeTypeDescription
Globallog4net.GlobalContext + The global context is shared by all threads in the current AppDomain. + This context is thread safe for use by multiple threads concurrently. +
Threadlog4net.ThreadContext + The thread context is visible only to the current managed thread. +
Logical Threadlog4net.ThreadLogicalContext + The logical thread context is visible to a logical thread. Logical + threads can jump from one managed thread to another. For more details + see the .NET API System.Runtime.Remoting.Messaging.CallContext. +
Eventlog4net.Core.LoggingEvent + Each event captures the current contextual state at the time the event + is generated. Contextual data can be set on the event itself. This context + is only visible to the code generating the event itself. +
+
+
+ +

Context Properties

+

+ The log4net contexts store properties, i.e. name value pairs. The name is a string + the value is any object. A property can be set as follows: +

+
+log4net.GlobalContext.Properties["name"] = value;
+
+

+ If properties with the same name are set in more than one context scope then + the value in the narrowest scope (lower down in the list above) will hide the + other values. +

+

+ The property values are stored as objects within the LoggingEvent. + The PatternLayout supports rendering the value of a named + property using the %property{name} syntax. The value is + converted to a string by passing it to the log4net.ObjectRenderer.RendererMap + which will locate any custom renderer for the value type. The default behavior for + custom types is to call the object's ToString() method. +

+ +

Active Property Values

+

+ An active property value is one who's value changes over time. +

+

+ For example, imagine a custom type that implemented the + ToString() method to return the + number of bytes allocated by the runtime garbage collector. +

+
+public class GCAllocatedBytesHelper
+{
+    public override string ToString()
+    {
+        return GC.GetTotalMemory(true).ToString();
+    }
+}
+

+ An instance of this type can be added to the log4net.GlobalContext + during application startup: +

+
+log4net.GlobalContext.Properties["GCAllocatedBytes"] = new GCAllocatedBytesHelper();
+
+

+ Once this property is set in the context all subsequent logging events will have a property + called GCAllocatedBytes. The value of the property will be an instance of the + GCAllocatedBytesHelper type. When this value is rendered to a + string by calling the ToString method the current number of bytes + allocated by the garbage collector will be returned and included in the output. +

+ +
+ +
+ +

Context Stacks

+

+ Sometimes simple key value pairs are not the most convenient way of capturing contextual + information. A stack of information is a very convenient way of storing data especially + as our applications tend to be stack based. +

+

+ The ThreadContext and LogicalThreadContext + also support storing contextual data in a stack. The stack is stored in context property, + therefore stacks have names and more than one stack can exist in the same context. A property + value set in a narrower context would override a stack with the same property name set in a + wider scoped context. +

+

+ The stack supports Push and Pop methods. + As more contextual data is pushed onto the stack the stack grows. When the stack is rendered + all the data pushed onto the stack is output with the most recent data to the right hand + end of the string. +

+

+ As the stack is just an object stored in the context properties it is also rendered + using the same PatternLayout syntax: %property{name}. + Where name is the name of the stack. +

+

+ Calls the the stack's Push and Pop + methods must be matched up so that each push has a corresponding pop. The + Push method also returns an IDisposable + object that will perform the required pop operation when it is disposed. This allows + the C# using syntax to be used to automate the stack management. +

+
+using(log4net.ThreadContext.Stacks["NDC"].Push("context"))
+{
+    log.Info("Message");
+}
+
+

+ The INFO level log has a stack stored in its NDC property. The top item in the + stack is the string context. + The using syntax ensures that the value context is popped off the stack + at the end of the block. +

+

+ The using + syntax is recommended because it removes some work load from the developer and + reduces errors in matching up the Push and Pop calls, especially when exceptions + can occur. +

+
+ +

Nested Diagnostic Contexts

+

+ The NDC (Nested Diagnostic Context) exists for compatibility + with older versions of log4net. This helper class implements a stack which is stored + in the thread context property named NDC. +

+
+ +

Mapped Diagnostic Contexts

+

+ The MDC (MappedDiagnostic Context) exists for compatibility + with older versions of log4net. This helper class implements a properties map which is + mapped directly through to the thread context properties. +

+
+ +

+ To illustrate this point, let us take the example of a web service delivering + content to numerous clients. The web service can build the NDC at the very + beginning of the request before executing other code. The contextual + information can be the client's host name and other information inherent to the + request, typically information contained in cookies. Hence, even if the web + service is serving multiple clients simultaneously, the logs initiated by the + same code, i.e. belonging to the same logger, can still be distinguished + because each client request will have a different NDC stack. Contrast this with + the complexity of passing a freshly instantiated logger to all code exercised + during the client's request. +

+

+ Nevertheless, some sophisticated applications, such as virtual hosting web + servers, must log differently depending on the virtual host context and also + depending on the software component issuing the request. Log4net supports + multiple logger repositories. This would allow each virtual host to possess its own copy + of the logger hierarchy. Configuring multiple logger hierarchies is beyond the + scope of this document. +

+ +
+ + +
+
+
+
+
+ + + Propchange: logging/site/trunk/docs/log4net/src/release/manual/contexts.html ------------------------------------------------------------------------------ svn:mime-type = text/html Added: logging/site/trunk/docs/log4net/src/release/manual/internals.html URL: http://svn.apache.org/viewvc/logging/site/trunk/docs/log4net/src/release/manual/internals.html?view=auto&rev=559716 ============================================================================== --- logging/site/trunk/docs/log4net/src/release/manual/internals.html (added) +++ logging/site/trunk/docs/log4net/src/release/manual/internals.html Wed Jul 25 23:41:40 2007 @@ -0,0 +1,433 @@ + + + + + + + + + + + + + + Apache log4net - + Apache log4net Manual: Internals + + + + + + + + +
+ +
+
+
+ + + + + + + +

log4net Manual - Internals

+ + +

Performance

+

+ One of the often-cited arguments against logging is its computational cost. + This is a legitimate concern as even moderately sized applications can generate + thousands of log requests. Much effort was spent measuring and tweaking logging + performance. Log4net claims to be fast and flexible: speed first, flexibility + second. +

+

+ The user should be aware of the following performance issues. +

+
    +
  1. + Logging performance when logging is turned off. + + When logging is turned off entirely or just for a set of levels, the cost of a + log request consists of a method invocation plus an integer comparison. + +

    + However, The method invocation involves the "hidden" cost of parameter + construction. +

    +

    + For example, for some logger + log, writing, +

    +
    +log.Debug("Entry number: " + i + " is " + entry[i].ToString());
    +

    + incurs the cost of constructing the message parameter, i.e. converting both + integer + i + and + entry[i] + to strings, and concatenating intermediate strings, regardless of whether the + message will be logged or not. This cost of parameter construction can be quite + high and it depends on the number and type of the parameters involved. +

    +

    + To avoid the parameter construction cost write: +

    +
    +if(log.IsDebugEnabled)
    +{
    +    log.Debug("Entry number: " + i + " is " + entry[i].ToString());
    +}
    +

    + This will not incur the cost of parameter construction if debugging is + disabled. On the other hand, if the logger is debug-enabled, it will incur + twice the cost of evaluating whether the logger is enabled or not: once in + IsDebugEnabled + and once in + Debug. This is an insignificant overhead because + evaluating a logger takes about 1% of the time it takes to actually log. +

    +

    + Certain users resort to pre-processing or compile-time techniques to compile + out all log statements. This leads to perfect performance efficiency with + respect to logging. However, since the resulting application binary does not + contain any log statements, logging cannot be turned on for that binary. In + many people's opinion this is a disproportionate price to pay in exchange for a + small performance gain. +

    +
  2. +
  3. + The performance of deciding whether to log or not to log when logging is + turned on. + + This is essentially the performance of walking the logger hierarchy. When + logging is turned on, log4net still needs to compare the level of the log + request with the level of the request logger. However, loggers may not have an + assigned level; they can inherit them from the logger hierarchy. Thus, before + inheriting a level, the logger may need to search its ancestors. + +

    + There has been a serious effort to make this hierarchy walk to be as fast as + possible. For example, child loggers link only to their existing ancestors. In + the + BasicConfigurator + example shown earlier, the logger named + Com.Foo.Bar + is linked directly to the root logger, thereby circumventing the nonexistent + Com + or + Com.Foo + loggers. This significantly improves the speed of the walk, especially in + "sparse" hierarchies. +

    +

    + The typical cost of walking the hierarchy is typically 3 times slower than when + logging is turned off entirely. +

    +
  4. +
  5. + Actually outputting log messages + + This is the cost of formatting the log output and sending it to its target + destination. Here again, a serious effort was made to make layouts (formatters) + perform as quickly as possible. The same is true for appenders. + +
  6. +
+

+ Although log4net has many features, its first design goal was speed. Some + log4net components have been rewritten many times to improve performance. + Nevertheless, contributors frequently come up with new optimizations. You + should be pleased to know that when configured with the + SimpleLayout + performance tests have shown log4net to log within an order of magnitude of + System.Console.WriteLine. +

+
+ +

Logging Event Flow

+

+ The following is the series of steps and checks that a messages goes through while being logged. + For the purposes of this example we will document an INFO level + message being logged on logger ConsoleApp.LoggingExample. This logger is configured + to use the log4net.Appender.ConsoleAppender. The repository used + in this example is a log4net.Repository.Hierarchy object. +

+
    +
  1. + + The user logs a message using the ILog.Info method on the logger + obtained using a call to log4net.LogManager.GetLogger("ConsoleApp.LoggingExample"). + For example: log4net.LogManager.GetLogger("ConsoleApp.LoggingExample").Info("Application Start"); + The ILog interface is actually an extension to log4net that provides level + specific logging methods (i.e. Debug, Info, Warn, Error, and Fatal). + +
  2. +
  3. + + The message is then logged through to the ILogger.Log method on the + appropriate log4net.Repository.Hierarchy.Logger object. The + ILogger.Log method takes the Level to + log at as a parameter and therefore works for all levels. + +
  4. +
  5. + + The repository threshold level is compared to the message level to determine if the message + can be logged. If the message level is below the threshold level the message is not logged. + In this case the repository is a log4net.Repository.Hierarchy object. + +
  6. +
  7. + + The Logger level is compared to the message level to determine if the + message can be logged. Note that the Logger level is inherited from a + parent Logger if not specified explicitly for this Logger. + If the message level is below the Logger level the message is not logged. + +
  8. +
  9. + + A LoggingEvent instance is created to encapsulate the message being logged. + +
  10. +
  11. + + The list of appenders for the Logger is built. This includes appenders + attached to parent Loggers except where excluded by the + Logger.Additivity property. + +
  12. +
  13. + + The LoggingEvent object is passed to the + IAppender.DoAppend method for each appender. + +
  14. +
+

+ For Each Appender that the LoggingEvent is delivered to the following + actions take place: +

+
    +
  1. + + The appender threshold level is compared to the message level to determine if the message + can be logged. If the message level is below the threshold level the message is not logged. + +
  2. +
  3. + + If the appender has a filter chain the LoggingEvent is passed down the + filter chain which can decide if the message can be logged or not. + +
  4. +
  5. + + Next an appender specific check is performed. Usually this check will verify that all the + required properties are set for the appender (e.g. a Layout is set if required). + +
  6. +
  7. + + The LoggingEvent is passed to the appender specific + Append method. What happens now is specific to the appender. + +
  8. +
+

+ The following actions take place in the ConsoleAppender.Append method: +

+
    +
  1. + + The ConsoleAppender uses a Layout to + format the message as a string for display. + +
  2. +
  3. + + The Layout uses the LoggingEvent.RenderedMessage + property to get the string for the message object. This uses the registered + IObjectRenderer for the type of the message object. + +
  4. +
  5. + + The message text is displayed on the console using the Console.WriteLine method. + +
  6. +
+
+ +
+ + +
+
+
+
+
+ + + Propchange: logging/site/trunk/docs/log4net/src/release/manual/internals.html ------------------------------------------------------------------------------ svn:mime-type = text/html