diff options
Diffstat (limited to 'slf4j-site/src/site/pages/extensions.html')
| -rwxr-xr-x | slf4j-site/src/site/pages/extensions.html | 886 |
1 files changed, 0 insertions, 886 deletions
diff --git a/slf4j-site/src/site/pages/extensions.html b/slf4j-site/src/site/pages/extensions.html deleted file mode 100755 index d4695810..00000000 --- a/slf4j-site/src/site/pages/extensions.html +++ /dev/null @@ -1,886 +0,0 @@ -<!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Transitional//EN" - "http://www.w3.org/TR/xhtml1/DTD/xhtml1-transitional.dtd"> - -<html xmlns="http://www.w3.org/1999/xhtml"> - <head> - <meta http-equiv="content-type" content="text/html; charset=iso-8859-1" /> - <title>SLF4J extensions</title> - - <link rel="stylesheet" type="text/css" media="screen" href="css/site.css" /> - <link rel="stylesheet" type="text/css" href="css/prettify.css" /> - </head> - <body onload="prettyPrint()"> - <script type="text/javascript">prefix='';</script> - <script type="text/javascript" src="js/prettify.js"></script> - <script src="templates/header.js" type="text/javascript"></script> - <div id="left"> - <script src="templates/left.js" type="text/javascript"></script> - </div> - <div id="content"> - - <h1>SLF4J extensions</h1> - - <p>SLF4J extensions are packaged within <em>slf4j-ext.jar</em> - which ships with SLF4J. </p> - - - <ul> - <li><a href="#profiler">Profiler</a></li> - <li><a href="#extended_logger">Extended logger</a></li> - <li><a href="#event_logger">Event Logging</a></li> - <li><a href="#javaagent">Logging added with Java agent (requires Java 5)</a></li> - </ul> - - <h2><a name="profiler"></a>Profilers</h2> - - <h3>What is a profiler?</h3> - - <p>According to wikipedia, <a - href="http://en.wikipedia.org/wiki/Profiler_%28computer_science%29">profiling</a> - is the investigation of a program's behavior using information - gathered as the program runs, i.e. it is a form of dynamic program - analysis, as opposed to static code analysis. The usual goal of - performance analysis is to determine which parts of a program to - optimize for speed or memory usage. - </p> - - <p>SLF4J profilers, a.k.a. poor man's profilers, will help the - developer gather performance data. Essentially, a profiler - consists of one or more stopwatches. Stopwatches are driven - (started/stopped) by statements in the <em>source code</em>. An - example should make the point clearer. - </p> - - <h3>Basic example</h3> - - - <em>Example: Using the profiler: <a - href="xref-test/org/slf4j/profiler/BasicProfilerDemo.html">BasicProfilerDemo</a></em> - - <pre class="prettyprint source">[omitted] -32 public class BasicProfilerDemo { -33 -34 public static void main(String[] args) { -35 // create a profiler called "BASIC" -36 <b>Profiler profiler = new Profiler("BASIC");</b> -37 <b>profiler.start("A");</b> -38 doA(); -39 -40 <b>profiler.start("B");</b> -41 doB(); -42 -43 <b>profiler.start("OTHER");</b> -44 doOther(); -45 <b>profiler.stop().print();</b> -46 } -[omitted]</pre> - - - <p>Running the above example will output the following output.</p> - - <p class="source">+ Profiler [BASIC] -|-- elapsed time [A] 220.487 milliseconds. -|-- elapsed time [B] 2499.866 milliseconds. -|-- elapsed time [OTHER] 3300.745 milliseconds. -|-- Total [BASIC] 6022.568 milliseconds.</p> - - <p>Instantiating a profiler starts a global stopwatch. Each call to - the start() method starts a new and named stopwatch. In addition to - starting a named stopwatch, the start() method also causes the - previous stopwatch to stop. Thus, the call to - <code>profiler.start("A")</code> starts a stopwatch named "A". The - subsequent call to <code>profiler.start("B")</code> starts - stopwatch "B" and simultaneously stops the stopwatch named - "A". Invoking the <code>stop()</code> on a profiler stops the last - stopwatch as well as the global stopwatch which was started when - the profiler was instantiated. - </p> - - - <h3>Profiler nesting</h3> - - <p>Profilers can also be nested. By nesting profilers, it is - possible to measure a task which itself has subtasks that need to - be timed and measured. - </p> - - <p>Starting a nested profiler will stop any previously started - stopwatch or nested profiler associated with the parent profiler. - </p> - - <p>Often times, the subtask is implemented by a different class as - the class hosting the parent profiler. Using the - <code>ProfilerRegistry</code> is a convenient way of passing a - nested profiler to an object outside the current object. Each - thread has its own profiler registry which can be retrieved by - invoking the <code>getThreadContextInstance()</code> method. - </p> - - <em>Example: <a - href="xref-test/org/slf4j/profiler/NestedProfilerDemo.html">NestedProfilerDemo</a> - </em> - - <pre class="prettyprint source">33 public class NestedProfilerDemo { -34 -35 public static void main(String[] args) { -36 // create a profiler called "DEMO" -37 Profiler profiler = new Profiler("DEMO"); -38 -39 // register this profiler in the thread context's profiler registry -40 <b>ProfilerRegistry profilerRegistry = ProfilerRegistry.getThreadContextInstance();</b> -41 <b>profiler.registerWith(profilerRegistry);</b> -42 -43 // start a stopwatch called "RANDOM" -44 profiler.start("RANDOM"); -45 RandomIntegerArrayGenerator riaGenerator = new RandomIntegerArrayGenerator(); -46 int n = 1000*1000; -47 int[] randomArray = riaGenerator.generate(n); -48 -49 // create and start a nested profiler called "SORT_AND_PRUNE" -50 // By virtue of its parent-child relationship with the "DEMO" -51 // profiler, and the previous registration of the parent profiler, -52 // this nested profiler will be automatically registered -53 // with the thread context's profiler registry -54 <b>profiler.startNested(SortAndPruneComposites.NESTED_PROFILER_NAME);</b> -55 -56 SortAndPruneComposites pruner = new SortAndPruneComposites(randomArray); -57 pruner.sortAndPruneComposites(); -58 -59 // stop and print the "DEMO" printer -60 profiler.stop().print(); -61 } -62 }</pre> - - <p>Here is the relevant excerpt from the <a - href="xref-test/org/slf4j/profiler/SortAndPruneComposites.html">SortAndPruneComposites</a> - class. - </p> - - <pre class="prettyprint source">[omitted] -6 public class SortAndPruneComposites { -7 -8 static String NESTED_PROFILER_NAME = "SORT_AND_PRUNE"; -9 -10 final int[] originalArray; -11 final int originalArrayLength; -12 -13 public SortAndPruneComposites(int[] randomArray) { -14 this.originalArray = randomArray; -15 this.originalArrayLength = randomArray.length; -16 -17 } -18 -19 public int[] sortAndPruneComposites() { -20 // retrieve previously registered profiler named "SORT_AND_PRUNE" -21 ProfilerRegistry profilerRegistry = ProfilerRegistry.getThreadContextInstance(); -22 <b>Profiler sortProfiler = profilerRegistry.get(NESTED_PROFILER_NAME);</b> -23 -24 // start a new stopwatch called SORT -25 sortProfiler.start("SORT"); -26 int[] sortedArray = sort(); -27 // start a new stopwatch called PRUNE_COMPOSITES -28 sortProfiler.start("PRUNE_COMPOSITES"); -29 int result[] = pruneComposites(sortedArray); -30 -31 return result; -32 } -[omitted] </pre> - - - <p>On a Dual-Core Intel CPU clocked at 3.2 GHz, running the - <code>ProfilerDemo</code> application yields the following output:</p> - - <p class="source">+ Profiler [DEMO] -|-- elapsed time [RANDOM] 70.524 milliseconds. -|---+ Profiler [SORT_AND_PRUNE] - |-- elapsed time [SORT] 665.281 milliseconds. - |-- elapsed time [PRUNE_COMPOSITES] 5695.515 milliseconds. - |-- Subtotal [SORT_AND_PRUNE] 6360.866 milliseconds. -|-- elapsed time [SORT_AND_PRUNE] 6360.866 milliseconds. -|-- Total [DEMO] 6433.922 milliseconds.</p> - - <p>From the above, we learn that generating 1'000'000 random - integers takes 70 ms, sorting them 665 ms, and pruning the composite - (non-prime) integers 5695 ms, for a grand total of 6433 ms. Given - that pruning composites takes most of the CPU effort, any future - optimizations efforts would be directed at the pruning part. - </p> - - <p>With just a few well-placed profiler calls we were able to - identify hot-spots in our application. Also note that passing a - profiler to a target class could be achieved by registering it in a - profiler registry and then retrieving it in the target class. - </p> - - <h3>Printing using a logger</h3> - - <p> Invoking <code>profiler.print</code> will always print the - output on the console. If you wish to leave the profiler code in - production, then you probably need more control over the output - destination. This can be accomplished by associating a logger of - your choice with a profiler. - </p> - - <p>After you have associated a logger with a profiler, you would - invoke the <code>log()</code> method instead of <code>print()</code> - previously, as the next example illustrates. - </p> - - <em>Profiler with a logger: <a - href="xref-test/org/slf4j/profiler/NestedProfilerDemo2.html">NestedProfilerDemo2</a> - </em> - - <pre class="prettyprint source">[omitted] -17 public class NestedProfilerDemo2 { -18 -19 static Logger logger = LoggerFactory.getLogger(NestedProfilerDemo2.class); -20 -21 public static void main(String[] args) { -22 Profiler profiler = new Profiler("DEMO"); -23 // associate a logger with the profiler -24 <b>profiler.setLogger(logger);</b> -25 -26 ProfilerRegistry profilerRegistry = ProfilerRegistry.getThreadContextInstance(); -27 profiler.registerWith(profilerRegistry); -28 -29 profiler.start("RANDOM"); -30 RandomIntegerArrayGenerator riaGenerator = new RandomIntegerArrayGenerator(); -31 int n = 10*1000; -32 int[] randomArray = riaGenerator.generate(n); -33 -34 profiler.startNested(SortAndPruneComposites.NESTED_PROFILER_NAME); -35 -36 SortAndPruneComposites pruner = new SortAndPruneComposites(randomArray); -37 pruner.sortAndPruneComposites(); -38 -39 // stop and log -40 profiler.stop().<b>log()</b>; -41 } -42 } </pre> - - <p>The output generated by this example will depend on the logging - environment, but should be very similar to the output generated by - the previous <code>NestedProfilerDemo</code> example. - </p> - - <p>The log() method logs at level DEBUG using a marker named - "PROFILER".</p> - - <p>If your logging system supports markers, e.g. logback, you could - specifically enable or disable output generated by SLF4J - profilers. Here is logback configuration file disabling output for - any logging event bearing the "PROFILER" marker, even if the logger - used by the profiler is enabled for the debug level. - </p> - - - <em>logback configuration disabling logging from profilers, and only - profilers</em> - - <pre class="prettyprint source"><configuration> - - <b><turboFilter class="ch.qos.logback.classic.turbo.MarkerFilter"> - <Marker>PROFILER</Marker> - <OnMatch>DENY</OnMatch> - </turboFilter></b> - - <appender name="STDOUT" - class="ch.qos.logback.core.ConsoleAppender"> - <layout class="ch.qos.logback.classic.PatternLayout"> - <Pattern>%-5level %logger{36} - %msg%n</Pattern> - </layout> - </appender> - - <root> - <level value="DEBUG" /> - <appender-ref ref="STDOUT" /> - </root> -</configuration> </pre> - - -<!-- .............................................................. --> - - <h2><a name="mdcStrLookup"></a>MDCStrLookup</h2> - - <p>StrLookup is a class defined in Apache Commons Lang. It is used - in conjunction with the StrSubstitutor class to allow Strings to - have tokens in the Strings dynamically replaced at run time. There - are many cases where it is desirable to merge the values for keys - in the SLF4J MDC into Strings. MDCStrLookup makes this possible. - </p> - <p> - Apache Commons Configuration provides a ConfigurationInterpolator - class. This class allows new StrLookups to be registered and the - values can then be used to merge with both the configuration of - Commons Configuration as well as the configuration files it manages. - </p> - <p> - StrLookup obviously has a dependency on Commons Lang. The Maven - pom.xml for slf4j-ext lists this dependency as optional so - that those wishing to use other extensions are not required to - unnecessarily package the commons lang jar. Therefore, when using - MDCStrLookup the dependency for commons-lang must be explicitly - declared along with slf4j-ext. - </p> - -<!-- .............................................................. --> - - <h2><a name="extended_logger"></a>Extended Logger</h2> - - <p>The <a - href="apidocs/org/slf4j/ext/XLogger.html"><code>XLogger</code></a> - class provides a few extra logging methods that are quite useful - for following the execution path of applications. These methods - generate logging events that can be filtered separately from other - debug logging. Liberal use of these methods is encouraged as the - output has been found to - </p> - - <ul> - <li>aid in problem diagnosis in development without requiring a - debug session</li> - - <li>aid in problem diagnosis in production where no debugging is - possible</li> - - <li>help educate new developers in learning the application.</li> - </ul> - - - <p>The two most used methods are the <code>entry()</code> and - <code>exit()</code> methods. <code>entry()</code> should be placed - at the beginning of methods, except perhaps for simple getters and - setters. <code>entry()</code> can be called passing from 0 to 4 - parameters. Typically these will be parameters passed to the - method. The <code>entry()</code> method logs with a level of TRACE - and uses a <code>Marker</code> with a name of "ENTER" which is also - a "FLOW" Marker. - </p> - - <p>The <code>exit()</code> method should be placed before any - return statement or as the last statement of methods without a - return. <code>exit()</code> can be called with or without a - parameter. Typically, methods that return void will use - <code>exit()</code> while methods that return an Object will use - exit(Object obj). The <code>entry()</code> method logs with a - level of TRACE and uses a Marker with a name of "EXIT" which is - also a "FLOW" Marker. - </p> - - <p>The throwing() method can be used by an application when it is - throwing an exception that is unlikely to be handled, such as a - RuntimeException. This will insure that proper diagnostics are - available if needed. The logging event generated will have a level - of ERROR and will have an associated Marker with a name of - "THROWING" which is also an "EXCEPTION" Marker. - </p> - - <p>The catching() method can be used by an application when it - catches an Exception that it is not going to rethrow, either - explicitly or attached to another Exception. The logging event - generated will have a level of ERROR and will have an associated - Marker with a name of "CATCHING" which is also an "EXCEPTION" - Marker. - </p> - - <p>By using these extended methods applications that standardize on - SLF4J can be assured that they will be able to perform diagnostic - logging in a standardized manner. - </p> - - <p>Note that XLogger instances are obtained to through the - <a - href="apidocs/org/slf4j/ext/XLoggerFactory.html"><code>XLoggerFactory</code></a> - utility class.</p> - - <p>The following example shows a simple application using these - methods in a fairly typical manner. The <code>throwing()</code> - method is not present since no Exceptions are explicitly thrown and - not handled. - </p> - - <pre class="prettyprint source">package com.test; - -import org.slf4j.ext.XLogger; -import org.slf4j.ext.XLoggerFactory; - -import java.util.Random; - -public class TestService { - private XLogger logger = XLoggerFactory.getXLogger(TestService.class - .getName()); - - private String[] messages = new String[] { "Hello, World", - "Goodbye Cruel World", "You had me at hello" }; - - private Random rand = new Random(1); - - public String retrieveMessage() { - logger.entry(); - - String testMsg = getMessage(getKey()); - - logger.exit(testMsg); - return testMsg; - } - - public void exampleException() { - logger.entry(); - try { - String msg = messages[messages.length]; - logger.error("An exception should have been thrown"); - } catch (Exception ex) { - logger.catching(ex); - } - logger.exit(); - } - - public String getMessage(int key) { - logger.entry(key); - - String value = messages[key]; - - logger.exit(value); - return value; - } - - private int getKey() { - logger.entry(); - int key = rand.nextInt(messages.length); - logger.exit(key); - return key; - } -}</pre> - - <p>This test application uses the preceding service to generate - logging events. - </p> - - <pre class="prettyprint source">package com.test; - -public class App { - public static void main( String[] args ) { - TestService service = new TestService(); - service.retrieveMessage(); - service.retrieveMessage(); - service.exampleException(); - } -} </pre> - - <p>The configuration below will cause all output to be routed to - target/test.log. The pattern for the FileAppender includes the - class name, line number and method name. Including these in the - pattern are critical for the log to be of value. - </p> - - <pre class="prettyprint source"><?xml version='1.0' encoding='UTF-8'?> -<configuration> - <appender name="console" class="ch.qos.logback.core.ConsoleAppender"> - <filter class="ch.qos.logback.classic.filter.LevelFilter"> - <level>ERROR</level> - <onMatch>ACCEPT</onMatch> - <onMismatch>DENY</onMismatch> - </filter> - <layout class="ch.qos.logback.classic.PatternLayout"> - <Pattern>%d{HH:mm:ss.SSS} %-5level %class{36}:%L %M - %msg%n</Pattern> - </layout> - </appender> - <appender name="log" class="ch.qos.logback.core.FileAppender"> - <File>target/test.log</File> - <Append>false</Append> - <layout class="ch.qos.logback.classic.PatternLayout"> - <Pattern>%d{HH:mm:ss.SSS} %-5level %class{36}:%L %M - %msg%n</Pattern> - </layout> - </appender> - - <root> - <level value="trace" /> - <appender-ref ref="log" /> - </root> -</configuration> -</pre> - <p> - Here is the output that results from the Java classes and configuration above. - </p> -<p class="source">00:07:57.725 TRACE com.test.TestService:22 retrieveMessage - entry -00:07:57.738 TRACE com.test.TestService:57 getKey - entry -00:07:57.739 TRACE com.test.TestService:59 getKey - exit with (0) -00:07:57.741 TRACE com.test.TestService:47 getMessage - entry with (0) -00:07:57.741 TRACE com.test.TestService:51 getMessage - exit with (Hello, World) -00:07:57.742 TRACE com.test.TestService:26 retrieveMessage - exit with (Hello, World) -00:07:57.742 TRACE com.test.TestService:22 retrieveMessage - entry -00:07:57.742 TRACE com.test.TestService:57 getKey - entry -00:07:57.743 TRACE com.test.TestService:59 getKey - exit with (1) -00:07:57.745 TRACE com.test.TestService:47 getMessage - entry with (1) -00:07:57.745 TRACE com.test.TestService:51 getMessage - exit with (Goodbye Cruel World) -00:07:57.746 TRACE com.test.TestService:26 retrieveMessage - exit with (Goodbye Cruel World) -00:07:57.746 TRACE com.test.TestService:32 exampleException - entry -00:07:57.750 ERROR com.test.TestService:40 exampleException - catching -java.lang.ArrayIndexOutOfBoundsException: 3 - at com.test.TestService.exampleException(TestService.java:35) - at com.test.AppTest.testApp(AppTest.java:39) - at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) - at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) - at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) - at java.lang.reflect.Method.invoke(Method.java:585) - at junit.framework.TestCase.runTest(TestCase.java:154) - at junit.framework.TestCase.runBare(TestCase.java:127) - at junit.framework.TestResult$1.protect(TestResult.java:106) - at junit.framework.TestResult.runProtected(TestResult.java:124) - at junit.framework.TestResult.run(TestResult.java:109) - at junit.framework.TestCase.run(TestCase.java:118) - at junit.framework.TestSuite.runTest(TestSuite.java:208) - at junit.framework.TestSuite.run(TestSuite.java:203) - at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) - at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) - at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) - at java.lang.reflect.Method.invoke(Method.java:585) - at org.apache.maven.surefire.junit.JUnitTestSet.execute(JUnitTestSet.java:213) - at org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.executeTestSet(AbstractDirectoryTestSuite.java:140) - at org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.execute(AbstractDirectoryTestSuite.java:127) - at org.apache.maven.surefire.Surefire.run(Surefire.java:177) - at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) - at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) - at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) - at java.lang.reflect.Method.invoke(Method.java:585) - at org.apache.maven.surefire.booter.SurefireBooter.runSuitesInProcess(SurefireBooter.java:338) - at org.apache.maven.surefire.booter.SurefireBooter.main(SurefireBooter.java:997) -00:07:57.750 TRACE com.test.TestService:42 exampleException - exit</p> - - <p>Simply changing the root logger level to DEBUG in the example - above will reduce the output considerably. - </p> - <p class="source">00:28:06.004 ERROR com.test.TestService:40 exampleException - catching -java.lang.ArrayIndexOutOfBoundsException: 3 - at com.test.TestService.exampleException(TestService.java:35) - at com.test.AppTest.testApp(AppTest.java:39) - at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) - at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) - at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) - at java.lang.reflect.Method.invoke(Method.java:585) - at junit.framework.TestCase.runTest(TestCase.java:154) - at junit.framework.TestCase.runBare(TestCase.java:127) - at junit.framework.TestResult$1.protect(TestResult.java:106) - at junit.framework.TestResult.runProtected(TestResult.java:124) - at junit.framework.TestResult.run(TestResult.java:109) - at junit.framework.TestCase.run(TestCase.java:118) - at junit.framework.TestSuite.runTest(TestSuite.java:208) - at junit.framework.TestSuite.run(TestSuite.java:203) - at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) - at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) - at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) - at java.lang.reflect.Method.invoke(Method.java:585) - at org.apache.maven.surefire.junit.JUnitTestSet.execute(JUnitTestSet.java:213) - at org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.executeTestSet(AbstractDirectoryTestSuite.java:140) - at org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.execute(AbstractDirectoryTestSuite.java:127) - at org.apache.maven.surefire.Surefire.run(Surefire.java:177) - at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) - at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) - at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) - at java.lang.reflect.Method.invoke(Method.java:585) - at org.apache.maven.surefire.booter.SurefireBooter.runSuitesInProcess(SurefireBooter.java:338) - at org.apache.maven.surefire.booter.SurefireBooter.main(SurefireBooter.java:997) </p> - - <!-- .............................................................. --> - - <h2><a name="event_logger"></a>Event Logging</h2> - - <p>The EventLogger class provides a simple mechanism for logging events that occur in an application. - While the EventLogger is useful as a way of initiating events that should be processed by an audit - Logging system, it does not implement any of the features an audit logging system would require - such as guaranteed delivery.</p> - - <p>The recommended way of using the EventLogger in a typical web application is to populate - the SLF4J MDC with data that is related to the entire lifespan of the request such as the user's id, - the user's ip address, the product name, etc. This can easily be done in a servlet filter where - the MDC can also be cleared at the end of the request. When an event that needs to be recorded - occurs an EventData object should be created and populated. Then call EventLogger.logEvent(data) - where data is a reference to the EventData object.</p> - - <pre class="prettyprint source">import org.slf4j.MDC; -import org.apache.commons.lang.time.DateUtils; - -import javax.servlet.Filter; -import javax.servlet.FilterConfig; -import javax.servlet.ServletException; -import javax.servlet.ServletRequest; -import javax.servlet.ServletResponse; -import javax.servlet.FilterChain; -import javax.servlet.http.HttpSession; -import javax.servlet.http.HttpServletRequest; -import javax.servlet.http.Cookie; -import javax.servlet.http.HttpServletResponse; -import java.io.IOException; -import java.util.TimeZone; - -public class RequestFilter implements Filter -{ - private FilterConfig filterConfig; - private static String TZ_NAME = "timezoneOffset"; - - public void init(FilterConfig filterConfig) throws ServletException { - this.filterConfig = filterConfig; - } - - /** - * Sample filter that populates the MDC on every request. - */ - public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, - FilterChain filterChain) throws IOException, ServletException { - HttpServletRequest request = (HttpServletRequest)servletRequest; - HttpServletResponse response = (HttpServletResponse)servletResponse; - MDC.put("ipAddress", request.getRemoteAddr()); - HttpSession session = request.getSession(false); - TimeZone timeZone = null; - if (session != null) { - // Something should set this after authentication completes - String loginId = (String)session.getAttribute("LoginId"); - if (loginId != null) { - MDC.put("loginId", loginId); - } - // This assumes there is some javascript on the user's page to create the cookie. - if (session.getAttribute(TZ_NAME) == null) { - if (request.getCookies() != null) { - for (Cookie cookie : request.getCookies()) { - if (TZ_NAME.equals(cookie.getName())) { - int tzOffsetMinutes = Integer.parseInt(cookie.getValue()); - timeZone = TimeZone.getTimeZone("GMT"); - timeZone.setRawOffset((int)(tzOffsetMinutes * DateUtils.MILLIS_PER_MINUTE)); - request.getSession().setAttribute(TZ_NAME, tzOffsetMinutes); - cookie.setMaxAge(0); - response.addCookie(cookie); - } - } - } - } - } - MDC.put("hostname", servletRequest.getServerName()); - MDC.put("productName", filterConfig.getInitParameter("ProductName")); - MDC.put("locale", servletRequest.getLocale().getDisplayName()); - if (timeZone == null) { - timeZone = TimeZone.getDefault(); - } - MDC.put("timezone", timeZone.getDisplayName()); - filterChain.doFilter(servletRequest, servletResponse); - MDC.clear(); - } - - public void destroy() { - } -} </pre> - - <p>Sample class that uses EventLogger.</p> - <pre class="prettyprint source">import org.slf4j.ext.EventData; -import org.slf4j.ext.EventLogger; - -import java.util.Date; -import java.util.UUID; - -public class MyApp { - - public String doFundsTransfer(Account toAccount, Account fromAccount, long amount) { - toAccount.deposit(amount); - fromAccount.withdraw(amount); - EventData data = new EventData(); - data.setEventDateTime(new Date()); - data.setEventType("transfer"); - String confirm = UUID.randomUUID().toString(); - data.setEventId(confirm); - data.put("toAccount", toAccount); - data.put("fromAccount", fromAccount); - data.put("amount", amount); - EventLogger.logEvent(data); - return confirm; - } -} </pre> - - <p>The EventLogger class uses a Logger named "EventLogger". EventLogger uses a logging level - of INFO. The following shows a configuration using Logback.</p> - <pre class="prettyprint source"><configuration> - <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> - <layout class="ch.qos.logback.classic.PatternLayout"> - <Pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</Pattern> - </layout> - </appender> - - <appender name="events" class="ch.qos.logback.core.ConsoleAppender"> - <layout class="ch.qos.logback.classic.PatternLayout"> - <Pattern>%d{HH:mm:ss.SSS} %X - %msg%n</Pattern> - </layout> - </appender> - - <logger name="EventLogger" additivity="false"> - <level value="INFO"/> - <appender appender-ref="events"/> - </logger> - - <root level="DEBUG"> - <appender-ref ref="STDOUT" /> - </root> - -</configuration> </pre> - - <!-- .............................................................. --> - - <h2><a name="javaagent"></a>Adding logging with Java agent</h2> - - <p><b>NOTE: BETA RELEASE, NOT PRODUCTION QUALITY</b> </p> - - <p>Quickstart for the impatient:</p> - - <ol> - <li>Use Java 5 or later.</li> - <li>Download slf4j-ext-${project.version}.jar and javassist.jar, and put them - both in the same directory.</li> - <li>Ensure your application is properly configured with - slf4j-api-${project.version}.jar and a suitable backend.</li> - - <li>Instead of "java ..." use "java --javaagent:PATH/slf4j-ext-${project.version}.jar=time,verbose,level=info ..." - <br/> - (replace PATH with the path to the jar) - </li> - <li>That's it!</li> - </ol> - - <p>In some applications logging is used to trace the actual - execution of the application as opposed to log an occasional event. - One approach is using the <a href="#extended_logger">extended - logger</a> to add statements as appropriately, but another is to use - a tool which modifies compiled bytecode to add these statements! - Many exist, and the one included in slf4j-ext is not intended to - compete with these, but merely provide a quick way to get very basic - trace information from a given application. - </p> - - <p>Java 5 added the Java Instrumentation mechanism, which allows you - to provide "Java agents" that can inspect and modify the byte code - of the classes as they are loaded. This allows the original class - files to remain unchanged, and the transformations done on the byte - codes depend on the needs at launch time. - </p> - - <p>Given the well-known "Hello World" example:</p> - - <pre class="prettyprint source">public class HelloWorld { - public static void main(String args[]) { - System.out.println("Hello World"); - } -}</pre> - - <p>a typical transformation would be similar to: (imports omitted)</p> - - <pre class="prettyprint source">public class LoggingHelloWorld { - final static Logger _log = LoggerFactory.getLogger(LoggingHelloWorld.class.getName()); - - public static void main(String args[]) { - if (_log.isInfoEnabled()) { - _log.info("> main(args=" + Arrays.asList(args) + ")"); - } - System.out.println("Hello World"); - if (_log.isInfoEnabled()) { - _log.info("< main()"); - } - } -}</pre> - - <p>which in turn produces the following result when run similar to - "java LoggingHelloWorld 1 2 3 4": - </p> - - <p class="source">1 [main] INFO LoggingHelloWorld - > main(args=[1, 2, 3, 4]) -Hello World -1 [main] INFO LoggingHelloWorld - < main()</p> - - <p>The same effect could have been had by using this command (with - the relative path to javassist.jar and - slf4j-ext-${project.version}.jar being ../jars):</p> - - <p class="source">java -javaagent:../jars/slf4j-ext-${project.version}.jar HelloWorld 1 2 3 4</p> - - <p></p> - - - <h3>How to use</h3> - <p>The javaagent may take one or more options separated by comma. The following options - are currently supported:</p> - - <dl> - <dt><b>level</b>=X</dt> - <dd>The log level to use for the generated log statements. X is - one of "info", "debug" or "trace". Default is "info".</dd> - - <dt><b>time</b></dt> - <dd>Print out the current date at program start, and again when - the program ends plus the execution time in milliseconds.</dd> - - <dt><b>verbose</b></dt> - <dd>Print out when a class is processed as part of being loaded</dd> - - <dt><b>ignore</b>=X:Y:...</dt> - <dd>(Advanced) Provide full list of colon separated prefixes of - class names NOT to add logging to. The default list is - "org/slf4j/:ch/qos/logback/:org/apache/log4j/". This does not override the fact that a class must be able to access the - slf4j-api classes in order to do logging, so if these classes are not visible to a given class it is not instrumented. - </dd> - </dl> - - - <p>Some classes may misbehave when being rendered with "object.toString()" so they may be explicitly disabled - in the logback configuration file permanently. For instance the ToStringBuilder in the Apache Jakarta commons lang - package is a prime candidate for this. For logback add this snippet to logback.xml: - <pre><logger name="org.apache.commons.lang.builder" level="OFF" /></pre> - </p> - - - - <p>Note: These are not finalized yet, and may change.</p> - - <h3>Locations of jar files</h3> - - <p>The javassist library is used for the actual byte code - manipulation and must be available to be able to add any logging - statements. slf4j-ext-${project.version} has been configured to - look for the following: - </p> - - <ul> - <li>"javassist-3.4.GA.jar" relatively to - slf4j-ext-${project.version}.jar as would be if Maven had downloaded - both from the repository and slf4j-ext-${project.version}.jar was - referenced directly in the Maven repository in the - "-javaagent"-argument.</li> - <li>"javassist-3.4.GA.jar" in the same directory as slf4j-ext</li> - <li>"javassist.jar" in the same directory as slf4j-ext</li> - </ul> - - <p>A warning message is printed if the javassist library was not - found by the agent, and options requiring byte code transformations will not work. - </p> - - - <h3>Misc notes</h3> - - <ul> - <li>A java agent is not invoked on any classes already loaded by the - class loader.</li> - <li>Exceptions in the java agent that would normally have been - printed, may be silently swallowed by the JVM.</li> - <li>The javaagent only logs to System.err.</li> - <li>The name of the logger variable is fixed (to a value unlikely to be used) so if that - name is already used, a failure occurs. This should be changed to determine - an unused name and use that instead.</li> - <li>Empty methods are not instrumented (an incorrect check for an interface). They should be</li> - - </ul> - - <p>(The agent is an adaption of the java.util.logging version - described in <a - href="http://today.java.net/pub/a/today/2008/04/24/add-logging-at-class-load-time-with-instrumentation.html" - >http://today.java.net/pub/a/today/2008/04/24/add-logging-at-class-load-time-with-instrumentation.html</a>) - </p> - - <script src="templates/footer.js" type="text/javascript"></script> -</div> -</body> -</html> - |