Author: seb Date: Mon Jan 22 16:24:29 2007 New Revision: 1261 Modified: logback/trunk/logback-site/src/site/xdocTemplates/demo.xml Log: Improved documentation about the demo Modified: logback/trunk/logback-site/src/site/xdocTemplates/demo.xml ============================================================================== --- logback/trunk/logback-site/src/site/xdocTemplates/demo.xml (original) +++ logback/trunk/logback-site/src/site/xdocTemplates/demo.xml Mon Jan 22 16:24:29 2007 @@ -13,16 +13,18 @@ <p> Welcome to the logback demo! This document will take you to a tour - that will show you some of the most useful possibilities of logback. + that will show you some of the major possibilities of logback. </p> +<h3>Installation</h3> + <p> First, please download the logback demo. You will need to install a <a href="http://subversion.tigris.org/">Subversion</a> client - and issue the following command in a command/terminal window: + and issue the following line in a command/terminal window: </p> -<div class="source"><pre>svn co http://svn.qos.ch/repos/logback-demo logback-demo</pre></div> +<div class="source"><pre>svn co http://svn.qos.ch/repos/logback-demo/trunk logback-demo</pre></div> <p> This will checkout a copy of the logback demonstration web-app to a directory called @@ -46,6 +48,8 @@ <p>image main page</p> +<h3>Logback Classic</h3> + <p> For now, logback uses two components: one <code>ConsoleAppender</code> and one <code>RollingFileAppender</code>. The <code>RollingFileAppender</code> sends logging events @@ -53,7 +57,11 @@ the active file every minute. The old file will be renamed and compressed to <em>zip</em> file. The <code>ConsoleAppender</code> will output the logging requests to the console, and shorten the logger names to gain some space in the console window, without making the -names unreadable. You can study the configuration file that is used by editing the +names unreadable. For example, <code>ch.qos.logback.demo.prime.NumberCruncherImpl +</code> will be displayed as <code>c.q.l.d.prime.NumberCruncherImpl</code>. +</p> + +<p>You can study the configuration file that is used by editing the file called <em>logback.xml</em>, located in the <em>src/main/resources/</em> directory of the demo. You might want to keep this file in an editor window, since we will modify its content several times thoughout the demo. @@ -68,13 +76,15 @@ expected. </p> -<p>image statii page</p> - <p> -Visiting the <em>View logs</em> page does not impress much at the moment. Let us uncomment -the two parts of the config file that are below the <em>Part I: Cyclic buffer</em> comment. +After you're back to the main window, visiting the <em>View logs</em> page does +not impress much at the moment. Let us uncomment +the <strong>two</strong> parts of the config file that are below the <em>Cyclic buffer</em> comment. A <code>CyclicBuffer</code> is a class that keeps track of logging events and holds these -objects for immediate or differed display. +objects for immediate or differed display. The first element that you will need to uncomment +is the <em>appender</em> element. This element describes and configures the <code>CyclicBuffer</code>. +The second element, found at the end of the configuration file, is a <em>appender-ref</em> element. +It is used to link the appender to a given logger. Now reload the web-app by exiting the previous command with <em>CTRL-C</em> and issuing it again: <em>mvn package jetty:run</em>. </p> @@ -83,16 +93,17 @@ Now, the <em>View logs</em> page looks prettier. By virtue of the <code>CyclicBufferAppender</code>, this page can fetch the last events and present them through a servlet. We see that each 3 seconds a line is added to the logs. The formatting of this page is made with -a <code>HTMLLayout</code>. This component creates a nice readable table containing the logging +a <code>HTMLLayout</code>. This component creates a nice and readable table containing the logging events, based on a pattern that describes the information one wants to see in the table. </p> <p> -Having the logs that we see on the web page cluttered with scheduled messages +Having the logs that we see on the web page cluttered with scheduled +<em>Howdydy-diddly-ho</em> messages is not very comfortable. To get rid of these logs, now that we've verified that they work, we can add an <code>EvaluatorFilter</code> to the Appender. Uncomment the -parts named <em>PART II: Cyclic buffer with Evaluator</em>. You may then -comment or delete the first Basic Cyclic buffer elements. +part named <em>Cyclic buffer with Evaluator</em>. You may then +comment or delete the first Basic Cyclic buffer <em>appender</em> element. </p> <p> Let's take a look at the filter we've just added: @@ -125,15 +136,18 @@ <p> After a restart, the <em>Vew logs</em> page shows the -<em>Howdydy-diddly-ho</em> logs for the first 20 seconds only. +<em>Howdydy-diddly-ho</em> logs for the first 20 seconds only. Trying a prime calculations +on the <em>Prime number</em> page will add several lines to the <em>View logs</em> page. </p> +<h4>Turbo Filters</h4> + <p> Logback ships with a special category of filters: <code>TurboFilter</code> objects are ultra-fast, context-wide filters. They reveals themselves very useful to test MDC values, for examples and to add context-wide conditions to allow or deny logging events. Let's uncomment the part named -<em>PART III: TurboFilter: MDC value</em> in the <em>logback.xml</em> file. +<em>TurboFilter: MDC value</em> in the <em>logback.xml</em> file. </p> <p> This part adds a <code>TurboFilter</code> object to the context. It allows to @@ -164,6 +178,8 @@ demo, using the <em>logout</em> button on the left. </p> +<h4>Parametrized logging</h4> + <p> Parametrized logging is a feature that will be a great asset for any performance-critical system. Usually, a logging request is issued like this: @@ -176,7 +192,7 @@ log request is not processed. For example, using the <code>debug()</code> method when, as we've just done, the root level is any value higher that <em>DEBUG</em> will result in a loss of time because all calls to the <code>debug()</code> method will -be eventually dropped. +eventually be dropped. </p> <p> @@ -201,8 +217,8 @@ <p> Now let us edit the <code>NumberCruncherImpl</code> class, to switch the log methods. You will find this class in the <em>src/main/java/ch/qos/logback/demo/prime/</em> -directory. On line 54 and 55, just umcomment the parametrized logging line and -and comment out the other line. Restart the server with <em>mvn package jetty:run</em> +directory. On line 54 and 55, just uncomment the parametrized logging line and +comment out the other line. Restart the server with <em>mvn package jetty:run</em> and re-run the calculations you tried beforehand. </p> @@ -210,35 +226,39 @@ The durations should be obviously different. Remember that we had turned off all logging in the previous step of this demo. With the initial formatting method, we were constructing the logging message (<em>"Trying "+i+" as a factor."</em>) -a huge amount of time, actually each time a factor was tried for these big numbers. +a huge amount of times, actually each time a factor was tried for these big numbers. With the paramatrized logging, the construction of the message was postponed and, since logging was turned off, not processed. We see here that the cost of the <b>non-</b>logging was taken down to a very small figure, dividing the total cost of the calculation by a non-negligeable factor. </p> +<h4>Markers</h4> + <p> SLF4J allows the use of Marker objects. For example, one could use <em>TRACE</em> markers, to enrich some specific logging statements. On the other hand, one could want that such marked statements be dropped and not logged anywhere. <code>TurboFilter</code> objects can do that in an elegant and flexible way. Let us uncomment the -<em>PART V: TurboFilter: Marker value</em> section in the <em>logback.xml</em> file, +<em>TurboFilter: Marker value</em> section in the <em>logback.xml</em> file as +well as set the root logger's level back to <em>DEBUG</em>, and reload via the <em>Reload configuration</em> page. </p> <p> The logging statements that contained the <em>Howdydy-diddly-ho</em> do not appear anymore because they were associated with a <em>TRACE</em> marker. You -can check that by visiting the <em>View Logs</em> page. +can check that by visiting the <em>View Logs</em> page and reloading it every three +seconds for several times. </p> +<h3>Logback Access</h3> + <p> -Access logging is another important feature offered by logback. The first -step will be to simply read what appears on the console while +Access logging is another important feature offered by logback. Give a +look at what appears on the console while browsing the logback-demo website. Each access is logged to the console, -with some information about the access. To achieve this situation, we simply -used a <code>ConsoleAppender</code> and a <code>PatternLayout</code>, just like -we would do in a classic logging configuration. The configuration file +with some information about the event. The configuration file that we will edit in the next few steps is called <em>logback-access.xml</em> and is located in the <em>src/etc/</em> directory. The necessary configuration is listed below: @@ -258,6 +278,42 @@ </configuration></pre></div> <p> +To see more clearly the output produced by logback access, +you might want set the root logger's level to <em>OFF</em>, in the first +logback configuration file, called +<em>logback.xml</em> and located in <em>src/main/resources/</em>. It will clear +the console from the logs made by the demo application and only display those +that are generated by logback access. +</p> + +<p> +To see the logs produced by logback access, just visit a few pages and +look at your console. The information contained in each line has been +specified in the configuration file. The <code>ConsoleAppender</code> +named <em>STDOUT</em> contains a <code>PatternLayout</code> component. +This very component that one uses in logback classic to display either +the message, logger name or level of the request is used in logback +access to display the request method, requested page, status code and many others. +</p> + +<p>Here is a sample output of this appender.</p> + +<div class="source"><pre>127.0.0.1 - - 22/01/2007:14:35:40 +0100 GET /logback-demo/ViewStatii.do HTTP/1.1 200 3660 +127.0.0.1 - - 22/01/2007:14:35:41 +0100 GET /logback-demo/index.jsp HTTP/1.1 200 2389 +127.0.0.1 - - 22/01/2007:14:35:42 +0100 GET /logback-demo/lastLog/ HTTP/1.1 200 948 +127.0.0.1 - - 22/01/2007:14:35:42 +0100 GET /logback-demo/index.jsp HTTP/1.1 200 2389 +127.0.0.1 - - 22/01/2007:14:35:43 +0100 GET /logback-demo/prime.jsp HTTP/1.1 200 1296 +127.0.0.1 - - 22/01/2007:14:35:44 +0100 GET /logback-demo/index.jsp HTTP/1.1 200 2389 +127.0.0.1 - - 22/01/2007:14:35:45 +0100 GET /logback-demo/lottery.jsp HTTP/1.1 200 1209 +127.0.0.1 - - 22/01/2007:14:35:46 +0100 GET /logback-demo/index.jsp HTTP/1.1 200 2389 +127.0.0.1 - - 22/01/2007:14:35:48 +0100 GET /logback-demo/reload.jsp HTTP/1.1 200 1335 +127.0.0.1 - - 22/01/2007:14:35:49 +0100 GET /logback-demo/index.jsp HTTP/1.1 200 2389 +127.0.0.1 - - 22/01/2007:14:35:54 +0100 GET /logback-demo/login.jsp HTTP/1.1 200 1214 +127.0.0.1 - - 22/01/2007:14:35:55 +0100 GET /logback-demo/Logout.do HTTP/1.1 200 1000</pre></div> + +<h4>Filtering</h4> + +<p> In this next part, we are going to add some information to the console. Let us imagine that we want to log the numbers that are tried on the <em>Lottery</em> page. We will need a second <code>ConsoleAppender</code> @@ -275,10 +331,10 @@ <filter class="ch.qos.logback.core.filter.EvaluatorFilter"> <evaluator name="lotto_eval"> <Expression> - url.matches(request.getRequestURL().toString()) + url.matches(event.getRequestURL().toString()) </Expression> <matcher name="url"> - <regex>lotto.do</regex> + <regex>Lottery.do</regex> <caseSensitive>false</caseSensitive> </matcher> </evaluator> @@ -287,7 +343,7 @@ </filter> <layout class="ch.qos.logback.access.PatternLayout"> <Pattern> - LOTTO: %A [%r] Guess=%reqParameter{guessed_number} + LOTTERY: %A [%r] Guess=%reqParameter{guessed_number} </Pattern> </layout> </appender></pre></div> @@ -302,27 +358,48 @@ to display anything when the access' request url does not match the given expression. You can see that it is easy to specify a RegExp, name it and use it in the expression that will be evaluated. In that case, we only -entered the name of the <em>lotto.do</em> action. +entered the name of the <em>lottery.do</em> action. </p> <p> -Before shutting down the server and starting it again with the new configuration, -you might want to comment the appender named <em>STDOUT</em>, as well as its -<em>appender-ref</em> element, in the first logback configuration file, called -<em>logback.xml</em> and located in <em>src/main/resources/</em>. It will clear -the console from the logs made by the demo application and only display those -that are generated by logback access. +Let us uncomment the two elements with the <em>Lottery to Console</em> comments and +restart the server. Now, try to play the lottery. You will see more lines in the +Console that you've seen until now. At every try, logback will produce a log +as shown below: </p> +<div class="source"><pre>LOTTERY: 192.168.1.6 [POST /logback-demo/Lottery.do HTTP/1.1] Guess=321</pre></div> + +<h4>Sending emails</h4> +<p> +Logback access provides several components that are usually used by the classic +module. For example, a <code>SMTPAppender</code> can be used to send an email when +a specific event occurs. Here, we will contact the lottery administrator each time +a winner is detected. To achieve this, we will add a <code>SMTPAppender</code> to +the existing configuration. Please uncomment the part of <em>logback-access.xml</em> +named <em>Lottery to Email</em>. Do not forget to uncomment the +<em>appender-ref</em> element, at the end of the configuration file, referencing +the appender called <em>SMTP</em>. In the appender element, notice the use of a +<code>URLEvaluator</code>. This evaluator allows us to only specify one or more URLs +that have to be watched. When one of them are accessed, an email is sent. +</p> <p> - SMTP and +A reload of the configuration has to be done before we can test this new +component. Once done, try to play the lottery with the number <em>99</em>. +You should see a congratulation message but, most importantly, the +specified recipients should have a new mail in their mailbox. The content +of the email is a nicely formatted HTML table with informations about +the access that have occured before the triggering event. </p> +<h3>JMX</h3> + <p> Logback publishes several components via JMX. This allows you to see the status of certain objects, and change several configuration parameters. +Publishing logback's components via JMX is possible with Jetty and Tomcat. </p> <p> @@ -354,7 +431,7 @@ </p> <p> -By refreshing the loaded previously JMX page, you should see a new component, +By refreshing the previously loaded JMX page, you should see a new component, under the domain <em>ch.qos.logback.classic</em>. It is the <code>JMXConfigurator</code>. Clicking on it reveals its content. Its possibilities are listed below: </p> @@ -384,13 +461,37 @@ </p> <p> -Let us test the configurator. If you try to use the <em>Prime Number</em> page and -look at the <em>View logs</em> page after, you should see two types of logs. When the +Checking the level of a logger is an easy task. Enter the name of the logger in +the appropriate field and click the <em>Invoke</em> button. You should be able +to verify that the logger named <em>root</em> has its level set to <em>OFF</em>. +</p> + + +<p> +Let us test the level setting possibility of the configurator. +The <em>Prime Number</em> page requests two types of logs. When the calculation checks if a number is a factor, a <em>DEBUG</em> log is displayed. When -the calculation has found a factor, a <em>INFO</em> log is displayed. If you set the level -of the <em>ch.qos.logback.demo.prime</em> logger to <em>INFO</em>, and run a prime calculation +the calculation has found a factor, a <em>INFO</em> log is displayed. +</p> + +<p> +Let us first set the level of the logger named <em>ch.qos.logback.demo.prime</em> +to <em>DEBUG</em>. Run a prime calculation directly, without restarting the server. The +<em>View logs</em> page should show the <em>DEBUG</em> and <em>INFO</em> logs. +</p> + +<p> +Now, if you set the level of the <em>ch.qos.logback.demo.prime</em> logger to +<em>INFO</em>, and run a prime calculation again, you should not see the <em>DEBUG</em> level logs anymore. </p> +<p> +This demo of logback is now over. Do not hesitate to play around with the configuration files. +You might want to check the <a href="http://logback.qos.ch/documentation.html"> +logback documentation page</a> for more information about any component +you'd like to test. +</p> + </body> </document> \ No newline at end of file