user-guide/src/docs/asciidoc/serviceability.adoc

:virgo-name: Virgo
:version: 3.7.0.RELEASE

:umbrella-virgo-name: Eclipse Virgo
:tomcat-product-name: Virgo for Apache Tomcat
:tomcat-product-name-short: VTS
:jetty-product-name: Virgo Jetty Server
:jetty-product-name-short: VJS
:kernel-product-name: Virgo Kernel
:kernel-product-name-short: VK
:nano-product-name: Virgo Nano
:nano-product-name-short: VN
:user-guide: link:../../virgo-user-guide/html/index.html[User Guide]
:tooling-guide: link:../../virgo-tooling-guide/html/index.html[Tooling Guide]

:gemini-blueprint-guide: https://www.eclipse.org/gemini/blueprint/documentation/reference/2.0.0.RELEASE/html/index.html[Eclipse Gemini Blueprint Reference Guide]

:spring-framework-version: 4.2.9.RELEASE

:homepage: https://www.eclipse.org/virgo
:ebr: http://www.eclipse.org/ebr[EBR]

:imagesdir: assets/images

anchor:serviceability[Serviceability and Diagnostics]

== Serviceability and Diagnostics

{virgo-name} supports two kinds of logging: *Event Logging* and *Trace logging* which is usually referred
to simply as *Logging*. The difference between Event Logging and Logging is explained below, but both are configured in the
`serviceability.xml` file in the `configuration` directory. This file takes the form of a Logback configuration, {virgo-name}
uses a Logback implementation behind the SLF4J logging interface.

For a description of the syntax and facilities provided by `serviceability.xml`
see the *Logback* documentation (referenced in xref:furtherreading[]).

anchor:serviceability-info-log[]

=== Event Logging

Event logging records important events in {virgo-name}. Each event is logged to
an event log file and is accompanied by a code enclosed in angle brackets.
An example is shown below:

....
[2010-10-25 16:20:45.897] system-artifacts             <TC0010I> Creating HTTP/1.1 connector with scheme http on port 8080.
....

(For a description of the log code syntax, see xref:log-codes[].)
The format of event log messages is fully configurable.

By default, event log messages are stored in `$SERVER_HOME/serviceability/eventlogs/eventlog.log`.

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

anchor:serviceability-info-trace[]

=== (Trace) Logging

The {virgo-name}'s (trace) logging support serves two main purposes:

* It provides global trace files that capture high-volume information regarding the {virgo-name}'s internal events.
The files are intended for use by support personnel to diagnose runtime problems.
* 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 `System.out` and `System.err`.
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.

By default, the {virgo-name} 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-name} 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`.

anchor:serviceability-info-trace-app[]

==== Application Output

{virgo-name} 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.

anchor:per-application-trace[]

==== Per-application trace

{virgo-name} 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.

anchor:sysout-and-syserr[]

=== 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]
--
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.

anchor:janino[]

==== 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`.

[source,xml]
----
<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-name}, 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 xref:configuring-framework-bundles[Configuring OSGi Framework Bundles]):

[source,txt]
----
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]]></programlisting> 
----

[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 http://jira.qos.ch/browse/LBCORE-244[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 https://bugs.eclipse.org/bugs/show_bug.cgi?id=333920#c15[bug 333920].
--

anchor:serviceability-info-dump[]

=== Service Dumps

A service dump is triggered when one of the following events
occurs:

. A failure is detected in the {virgo-name} code, or
. a thread deadlock is detected.

A service dump contains a snapshot of all the important state from
the running {virgo-name} instance. This snapshot is not intended
for end user consumption but is useful for service personnel.


By default, service dumps are created in `$SERVER_HOME/serviceability/dump`.