11.2 (Trace) Logging

The Virgo’s (trace) logging support serves two main purposes:

By default, the Virgo trace file is called $SERVER_HOME/serviceability/logs/log.log, and, again by default, the application trace files are called $SERVER_HOME/serviceability/logs/application_name /log.log, where application_name is automatically set by Virgo for each application artifact installed and run (it is a combination of the artifact name and the version).

The default behaviour of these trace files is that, once log.log reaches a 10Mb limit, it rolls into a series of files named log_i.log where i ranges from 1 to 4, and logging continues in a new log.log file.

Entries in trace files are by default of the form <timestamp> <thread-name> <source> <level> <entry-text>. For example:

[2008-05-15 09:09:46.940] server-dm-2 org.apache.coyote.http11.Http11Protocol I Initializing Coyote HTTP/1.1 on http-48080
	    

although this format is completely determined by the Logback configuration file serviceability.xml.

Application Output

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 System.out and System.err output.

Per-application trace

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 serviceability.xml file in the normal way.

System.out and System.err

System.out and System.err output from applications is, by default, captured in the application’s trace file. This happens because the output streams are intercepted and written to the loggers named System.out and System.err respectively. Since there are no explicit loggers defined with these names in the serviceability.xml file, this output is logged by the root logger (which captures INFO level and above).

The capture of System.out and System.err output is configured in the configuration/org.eclipse.virgo.medic.properties file by the log.wrapSysOut and log.wrapSysErr properties. By default the properties have a value of true and capture is enabled. Capture can be disabled by configuring the properties with a value of false. The third and last accepted value is tee 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 -console startup argument.

[Important]Important
If you provide value different than 'true | tee | false' then the server will default to 'tee' and print out a warning.

The trace entries for System.out and System.err output are of the form:

[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!
			

The third column indicates where the output came from (System.out or System.err).

To over-ride this behaviour, simply define explicit loggers named System.out and/or System.err in the configuration file to send this output to an appender of your choice. Be aware that all applications’ output streams will be caught by these loggers, and that a sifting appender might be useful to separate them.

Janino

Janino can be used to define trace filters as Java expressions. This adds a significant overhead to tracing, so should be used with care.

For example, the addition of the following filter element to the sifting appender in serviceability.xml suppresses per-application trace output that is not associated with a particular application and is normally written to serviceability/logs/virgo-kernel/log.log.

<appender name="SIFTED_LOG_FILE" class="ch.qos.logback.classic.sift.SiftingAppender">
    <discriminator>
        <Key>applicationName</Key>
        <DefaultValue>virgo-kernel</DefaultValue>
    </discriminator>
    <sift>
        <appender name="${applicationName}_LOG_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
            <filter class="ch.qos.logback.core.filter.EvaluatorFilter">
                <evaluator class="ch.qos.logback.classic.boolex.JaninoEventEvaluator">
                    <expression>
                        (mdc == null) || (mdc.get("applicationName") == null)
                    </expression>
                </evaluator>
                <OnMismatch>NEUTRAL</OnMismatch>
                <OnMatch>DENY</OnMatch>
            </filter>
            <file>serviceability/logs/${applicationName}/log.log</file>
            ...
        </appender>
    </sift>
</appender>

To enable Janino in Virgo, place the Janino and commons compiler JARs, converted to OSGi bundles, in plugins. For example these bundles are available at v2.6.1 from the SpringSource Enterprise Bundle Repository. Then add the following lines to configuration/org.eclipse.equinox.simpleconfigurator/bundles.info (as described in Configuring OSGi Framework Bundles):

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

[Important]Important
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 LBCORE-244. With such versions, it is necessary to attach a fragment bundle to Janino. Place the fragment bundle in plugins and list it in configuration/org.eclipse.equinox.simpleconfigurator/bundles.info. The fragment's contents are described in bug 333920.