blob: f1bd42901d2b8b820ea03b3fe3f0cc1c52c15b17 [file] [log] [blame]
<html><head>
<meta http-equiv="Content-Type" content="text/html; charset=ISO-8859-1">
<title>11.2&nbsp;(Trace) Logging</title><link rel="stylesheet" href="css/stylesheet.css" type="text/css"><meta name="generator" content="DocBook XSL Stylesheets V1.74.0"><link rel="home" href="index.html" title="Virgo User Guide"><link rel="up" href="ch11.html" title="11.&nbsp;Serviceability and Diagnostics"><link rel="prev" href="ch11.html" title="11.&nbsp;Serviceability and Diagnostics"><link rel="next" href="ch11s03.html" title="11.3&nbsp;Service Dumps"><!--Begin Google Analytics code--><script type="text/javascript">
var gaJsHost = (("https:" == document.location.protocol) ? "https://ssl." : "http://www.");
document.write(unescape("%3Cscript src='" + gaJsHost + "google-analytics.com/ga.js' type='text/javascript'%3E%3C/script%3E"));
</script><script type="text/javascript">
var pageTracker = _gat._getTracker("UA-2728886-3");
pageTracker._setDomainName("none");
pageTracker._setAllowLinker(true);
pageTracker._trackPageview();
</script><!--End Google Analytics code--></head><body bgcolor="white" text="black" link="#0000FF" vlink="#840084" alink="#0000FF"><div class="navheader"><table width="100%" summary="Navigation header"><tr><th colspan="3" align="center">11.2&nbsp;(Trace) Logging</th></tr><tr><td width="20%" align="left"><a accesskey="p" href="ch11.html">Prev</a>&nbsp;</td><th width="60%" align="center">11.&nbsp;Serviceability and Diagnostics</th><td width="20%" align="right">&nbsp;<a accesskey="n" href="ch11s03.html">Next</a></td></tr></table><hr></div><div class="section" lang="en"><div class="titlepage"><div><div><h2 class="title" style="clear: both"><a name="serviceability-info-trace"></a>11.2&nbsp;(Trace) Logging</h2></div></div></div><p>
The Virgo&#8217;s (trace) logging support serves two main purposes:
</p><div class="itemizedlist"><ul type="disc"><li>
It provides global trace files that capture high-volume information regarding the Virgo&#8217;s internal events.
The files are intended for use by support personnel to diagnose runtime problems.
</li><li>
It provides application trace files that contain application-generated output. This includes output generated using popular logging and
tracing APIs including the OSGi LogService, as well as output generated by calls to <code class="literal">System.out</code> and <code class="literal">System.err</code>.
These files are intended for use by application developers and system administrators. An application is defined as a scope so a single bundle will
not get its own log file unless it is a Web application Bundle or is included in a scoped plan or a par file.
</li></ul></div><p>
</p><p>
By default, the Virgo trace file is called <code class="literal">$SERVER_HOME/serviceability/logs/log.log</code>,
and, again by default, the application trace files are called <code class="literal">$SERVER_HOME/serviceability/logs/</code><span class="emphasis"><em>application_name</em></span>
<code class="literal">/log.log</code>, where <span class="emphasis"><em>application_name</em></span> is automatically set by Virgo for each application artifact
installed and run (it is a combination of the artifact name and the version).
</p><p>
The default behaviour of these trace files is that, once <code class="literal">log.log</code> reaches a 10Mb limit, it rolls into a series of files named
<code class="literal">log_</code><span class="emphasis"><em>i</em></span><code class="literal">.log</code> where <span class="emphasis"><em>i</em></span> ranges from 1 to 4, and logging continues in
a new <code class="literal">log.log</code> file.
</p><p>
Entries in trace files are by default of the form &lt;timestamp&gt; &lt;thread-name&gt; &lt;source&gt; &lt;level&gt; &lt;entry-text&gt;. For example:
</p><pre class="screen">
[2008-05-15 09:09:46.940] server-dm-2 org.apache.coyote.http11.Http11Protocol I Initializing Coyote HTTP/1.1 on http-48080
</pre><p>
although this format is completely determined by the Logback configuration file <code class="literal">serviceability.xml</code>.
</p><div class="section" lang="en"><div class="titlepage"><div><div><h3 class="title"><a name="serviceability-info-trace-app"></a>Application Output</h3></div></div></div><p>
Virgo provides advanced support for capturing and tracing application-generated output by automatically separating trace output on a
per-application basis and will also capture any <code class="literal">System.out</code> and <code class="literal">System.err</code> output.
</p><div class="section" lang="en"><div class="titlepage"><div><div><h4 class="title"><a name="per-application-trace"></a>Per-application trace</h4></div></div></div><p>
Virgo uses SLF4J interfaces to Logback, and the root logger (by default) captures all logging output
and appends it to the application-specific trace files as described above.
To modify this, define application-specific loggers in the <code class="literal">serviceability.xml</code> file in the normal way.
</p></div><div class="section" lang="en"><div class="titlepage"><div><div><h4 class="title"><a name="sysout-and-syserr"></a>System.out and System.err</h4></div></div></div><p>
<code class="literal">System.out</code> and <code class="literal">System.err</code> output from applications is, by default, captured in the
application&#8217;s trace file.
This happens because the output streams are intercepted and written to the loggers named
<code class="literal">System.out</code> and <code class="literal">System.err</code> respectively.
Since there are no explicit loggers defined with these names in the <code class="literal">serviceability.xml</code> file,
this output is logged by the root logger (which captures <code class="literal">INFO</code> level and above).
</p><p>
The capture of <code class="literal">System.out</code> and <code class="literal">System.err</code> output is configured in the
<code class="literal">configuration/org.eclipse.virgo.medic.properties</code> file by the <code class="literal">log.wrapSysOut</code> and
<code class="literal">log.wrapSysErr</code> properties. By default the properties have a value of <code class="literal">true</code>
and capture is enabled. Capture can be disabled by configuring the properties with a value of <code class="literal">false</code>.
The third and last accepted value is <code class="literal">tee</code> which captures the System streams output in the logs
while at the same time allows printing output to the System streams. Thus this output will appear both in the logs
and in the System stream output - an example could be the Equinox console, launched with <code class="literal">-console</code> startup argument.
</p><div class="important" style="margin-left: 0.5in; margin-right: 0.5in;"><table border="0" summary="Important"><tr><td rowspan="2" align="center" valign="top" width="25"><img alt="[Important]" src="images/important.gif"></td><th align="left">Important</th></tr><tr><td align="left" valign="top">
If you provide value different than 'true | tee | false' then the server will default to 'tee' and print out a warning.
</td></tr></table></div><p>
The trace entries for <code class="literal">System.out</code> and <code class="literal">System.err</code>
output are of the form:
</p><pre class="screen">
[2008-05-16 09:28:45.874] server-tomcat-thread-1 System.out Hello world!
[2008-05-16 09:28:45.874] server-tomcat-thread-1 System.err Hello world!
</pre><p>
The third column indicates where the output came from (<code class="literal">System.out</code> or <code class="literal">System.err</code>).
</p><p>
To over-ride this behaviour, simply define explicit loggers named <code class="literal">System.out</code>
and/or <code class="literal">System.err</code> in the configuration file to send this output to an appender of your choice.
Be aware that all applications&#8217; output streams will be caught by these loggers, and that a sifting appender might be useful to separate them.
</p></div><div class="section" lang="en"><div class="titlepage"><div><div><h4 class="title"><a name="janino"></a>Janino</h4></div></div></div><p>
Janino can be used to define trace filters as Java expressions. This adds a significant overhead to tracing, so should be used with care.
</p><p>
For example, the addition of the following filter element to the sifting appender in <code class="literal">serviceability.xml</code>
suppresses per-application trace output that is not associated with a particular application and is normally written to
<code class="literal">serviceability/logs/virgo-kernel/log.log</code>.
</p><pre class="programlisting">&lt;<span class="hl-tag">appender</span> <span class="hl-attribute">name</span>=<span class="hl-value">"SIFTED_LOG_FILE"</span> <span class="hl-attribute">class</span>=<span class="hl-value">"ch.qos.logback.classic.sift.SiftingAppender"</span>&gt;
&lt;<span class="hl-tag">discriminator</span>&gt;
&lt;<span class="hl-tag">Key</span>&gt;applicationName&lt;<span class="hl-tag">/Key</span>&gt;
&lt;<span class="hl-tag">DefaultValue</span>&gt;virgo-kernel&lt;<span class="hl-tag">/DefaultValue</span>&gt;
&lt;<span class="hl-tag">/discriminator</span>&gt;
&lt;<span class="hl-tag">sift</span>&gt;
&lt;<span class="hl-tag">appender</span> <span class="hl-attribute">name</span>=<span class="hl-value">"${applicationName}_LOG_FILE"</span> <span class="hl-attribute">class</span>=<span class="hl-value">"ch.qos.logback.core.rolling.RollingFileAppender"</span>&gt;
&lt;<span class="hl-tag">filter</span> <span class="hl-attribute">class</span>=<span class="hl-value">"ch.qos.logback.core.filter.EvaluatorFilter"</span>&gt;
&lt;<span class="hl-tag">evaluator</span> <span class="hl-attribute">class</span>=<span class="hl-value">"ch.qos.logback.classic.boolex.JaninoEventEvaluator"</span>&gt;
&lt;<span class="hl-tag">expression</span>&gt;
(mdc == null) || (mdc.get("applicationName") == null)
&lt;<span class="hl-tag">/expression</span>&gt;
&lt;<span class="hl-tag">/evaluator</span>&gt;
&lt;<span class="hl-tag">OnMismatch</span>&gt;NEUTRAL&lt;<span class="hl-tag">/OnMismatch</span>&gt;
&lt;<span class="hl-tag">OnMatch</span>&gt;DENY&lt;<span class="hl-tag">/OnMatch</span>&gt;
&lt;<span class="hl-tag">/filter</span>&gt;
&lt;<span class="hl-tag">file</span>&gt;serviceability/logs/${applicationName}/log.log&lt;<span class="hl-tag">/file</span>&gt;
...
&lt;<span class="hl-tag">/appender</span>&gt;
&lt;<span class="hl-tag">/sift</span>&gt;
&lt;<span class="hl-tag">/appender</span>&gt;</pre><p>
</p><p>
To enable Janino in Virgo, place the Janino and commons compiler JARs, converted to OSGi bundles, in <code class="literal">plugins</code>.
For example these bundles are available at v2.6.1 from the SpringSource Enterprise Bundle Repository.
Then add the following lines to
<code class="literal">configuration/org.eclipse.equinox.simpleconfigurator/bundles.info</code>
(as described in <a class="link" href="ch13.html#configuring-framework-bundles" title="Configuring OSGi Framework Bundles">Configuring OSGi Framework Bundles</a>):
</p><pre class="programlisting">com.springsource.org.codehaus.janino,2.6.1,plugins/com.springsource.org.codehaus.janino-2.6.1.jar,4,false
com.springsource.org.codehaus.commons.compiler,2.6.1,plugins/com.springsource.org.codehaus.commons.compiler-2.6.1.jar,4,false</pre><p>
</p><div class="important" style="margin-left: 0.5in; margin-right: 0.5in;"><table border="0" summary="Important"><tr><td rowspan="2" align="center" valign="top" width="25"><img alt="[Important]" src="images/important.gif"></td><th align="left">Important</th></tr><tr><td align="left" valign="top">
Current versions of Logback, including 0.9.28 to 1.0, do not set Janino's "parent" class loader correctly.
This bug is covered by the Logback issue <a class="ulink" href="http://jira.qos.ch/browse/LBCORE-244" target="_top">LBCORE-244</a>.
With such versions, it is necessary to attach a fragment bundle to Janino. Place the fragment bundle in <code class="literal">plugins</code> and list it in
<code class="literal">configuration/org.eclipse.equinox.simpleconfigurator/bundles.info</code>.
The fragment's contents are described in <a class="ulink" href="https://bugs.eclipse.org/bugs/show_bug.cgi?id=333920#c15" target="_top">bug 333920</a>.
</td></tr></table></div></div></div></div><!--Begin LoopFuse code--><script src="http://loopfuse.net/webrecorder/js/listen.js" type="text/javascript"></script><script type="text/javascript">
_lf_cid = "LF_48be82fa";
_lf_remora();
</script><!--End LoopFuse code--><div class="navfooter"><hr><table width="100%" summary="Navigation footer"><tr><td width="40%" align="left"><a accesskey="p" href="ch11.html">Prev</a>&nbsp;</td><td width="20%" align="center"><a accesskey="u" href="ch11.html">Up</a></td><td width="40%" align="right">&nbsp;<a accesskey="n" href="ch11s03.html">Next</a></td></tr><tr><td width="40%" align="left" valign="top">11.&nbsp;Serviceability and Diagnostics&nbsp;</td><td width="20%" align="center"><a accesskey="h" href="index.html">Home</a></td><td width="40%" align="right" valign="top">&nbsp;11.3&nbsp;Service Dumps</td></tr></table></div></body></html>