Difference between revisions of "Virgo/Diagnostics"

From Eclipsepedia

Jump to: navigation, search
m (Add section on Entry and Exit tracing)
(Entry and Exit tracing on the diagnostics page)
Line 62: Line 62:
 
The <code lang="text">'''serviceability.xml'''</code> file is just a logback configuration file, and all the Logback functionality is available. For more information see the [http://logback.qos.ch/manual/configuration.html Logback configuration] on-line documentation.
 
The <code lang="text">'''serviceability.xml'''</code> file is just a logback configuration file, and all the Logback functionality is available. For more information see the [http://logback.qos.ch/manual/configuration.html Logback configuration] on-line documentation.
  
== Entry Exit tracing ==
+
== Entry and Exit tracing ==
  
 +
In the default '''<code lang="text">serviceability.xml</code>''' file the root logging level is '''<code lang="text">INFO</code>'''. This is reasonable: if a log entry is made at <b><code lang="text">INFO</code></b> level, one expects this to appear in the log under normal circumstances.
 +
 +
<code lang="text">Medic</code> (one of the Virgo repositories) is designed to set up logging, tracing and dumping, for use by the rest of the code, and achieves this partly by weaving in aspects that perform tracing at the entry and exit  points of methods. These aspects are woven into the rest of the code so that they don't have to code them themselves.
 +
 +
The entry and exit level tracing aspects are carefully woven into the <code lang="text">kernel</code> and the server code (<code lang="text">web</code>) to avoid the logging code itself (recursion) and the low-level utility functions (<code lang="text">util</code> and <code lang="text">osgi-extensions</code>).
 +
 +
It traces entry and exit points at two levels: <b><code lang="text">DEBUG</code></b> for all <code lang="java">public</code> methods and <b><code lang="text">TRACE</code></b> for all other methods (package private and private).  'Getter' and 'Setter' methods (those beginning with <code lang="text">get</code> and <code lang="text">set</code>) are not traced at any level.
 +
 +
So, to see these entries you need to set the logging level to <b><code lang="text">DEBUG</code></b> or higher for the areas you are interested in.
 +
 +
You will see entries in the <b><code lang="text">serviceability/log/log*.log</code></b> files like this:<pre>[2010-07-29 16:40:31.342] main  > public static boolean org.eclipse.virgo.kernel.core.BundleUtils.isFragmentBundle(org.osgi.framework.Bundle)
 +
[2010-07-29 16:40:31.342] main  < public static boolean org.eclipse.virgo.kernel.core.BundleUtils.isFragmentBundle(org.osgi.framework.Bundle)
 +
[2010-07-29 16:40:31.342] main  > public void org.eclipse.virgo.kernel.core.internal.BundleStartTracker.trackStart(org.osgi.framework.Bundle, org.eclipse.virgo.kernel.core.Signal)
 +
[2010-07-29 16:40:31.342] main  > public static boolean org.eclipse.virgo.kernel.core.BundleUtils.isFragmentBundle(org.osgi.framework.Bundle)
 +
[2010-07-29 16:40:31.343] main  < public static boolean org.eclipse.virgo.kernel.core.BundleUtils.isFragmentBundle(org.osgi.framework.Bundle)
 +
[2010-07-29 16:40:31.343] main  Adding signal 'org.eclipse.virgo.kernel.install.artifact.internal.AbstractInstallArtifact$StateMonitorSignal@210c507' for bundle 'com.springsource.platform.apps.explicit_bundle_imports_1.0.0 [54]'
 +
[2010-07-29 16:40:31.343] main  < public void org.eclipse.virgo.kernel.core.internal.BundleStartTracker.trackStart(org.osgi.framework.Bundle, org.eclipse.virgo.kernel.core.Signal)</pre>
 +
 +
where the entry and exit points are marked with <b><code lang="text">></code></b> and <b><code lang="text"><</code></b> respectively, with the full class names of the method and its parameters supplied.
 +
 +
It is arranged that <i>any</i> exit from a method will be traced if its entry is, even if that was the result of an exception, so the entry and exit lines should always pair.
  
 
[[Category:Virgo]] [[Category:EclipseRT]]
 
[[Category:Virgo]] [[Category:EclipseRT]]

Revision as of 05:43, 30 July 2010


This page contains hints and tips for diagnosing problems with Virgo and Virgo applications.

Equinox Console

The Equinox Console is useful for examining either the kernel framework or the user region framework.

Virgo offers shell commands to the user region Equinox Console for slightly more friendly inspection of user region artefacts.

To enable an Equinox console, you need to set a framework property, like this:

osgi.console=2402
identifying the port to use.

In the case of the user region, add this property to the file config/org.eclipse.virgo.kernel.userregion.properties. In the case of the kernel region, add this property to the file lib/org.eclipse.virgo.kernel.launch.properties.

You can even enable an Equinox console in both regions at once, using two different ports of course.

To use the console, telnet in:

> telnet localhost 2402

The most useful commands are ss to list all bundles, bundle <n> to display information about the bundle with bundle id <n>, and help to see other commands.

When running in the user region, the Virgo shell commands are offered via the vsh command. Type vsh help to see a list of the shell commands available.

Precision Debug logging

It is possible to turn on logging at various levels for specific classes (loggers) in Virgo. We illustrate this with a FileSystemChecker debug trace, which is part of the HotDeployer system.

In serviceability.xml in the config directory simply add the following:
<logger level="DEBUG" additivity="false" name="org.eclipse.virgo.kernel.deployer.hot.HotDeployer">
    <appender-ref ref="SIFTED_LOG_FILE" />
</logger>

after the other logger specifications and before the root tag.

This puts debug information in the log.log file in serviceability/logs/virgo-kernel directory.

Alternatively, set appender-ref ref="LOG_FILE" and the debug information goes in the general log.log file in the serviceability/logs directory.

In this case the sort of output you might see is (actual paths have been replaced):
[2010-07-23 12:27:44.599] fs-watcher                   org.eclipse.virgo.kernel.deployer.hot.HotDeployer                 pickup - before check:
	FileList():  [test.configuration.properties]
	Known files: [/path-to-server-home/pickup/test.configuration.properties]
	Monitored:   [/path-to-server-home/pickup/test.configuration.properties] 
[2010-07-23 12:27:44.660] fs-watcher                   org.eclipse.virgo.kernel.deployer.hot.HotDeployer                 pickup - after check:
	Known files: [/path-to-server-home/pickup/test.configuration.properties]
	Monitored:   [] 
[2010-07-23 12:27:45.661] fs-watcher                   org.eclipse.virgo.kernel.deployer.hot.HotDeployer                 pickup - before check:
	FileList():  [test.configuration.properties]
	Known files: [/path-to-server-home/pickup/test.configuration.properties]
	Monitored:   [] 
[2010-07-23 12:27:45.661] fs-watcher                   org.eclipse.virgo.kernel.deployer.hot.HotDeployer                 pickup - after check:
	Known files: [/path-to-server-home/pickup/test.configuration.properties]
	Monitored:   [] 
[2010-07-23 12:27:46.661] fs-watcher                   org.eclipse.virgo.kernel.deployer.hot.HotDeployer                 pickup - before check:
	FileList():  [test.configuration.properties]
	Known files: [/path-to-server-home/pickup/test.configuration.properties]
	Monitored:   [] 
[2010-07-23 12:27:46.662] fs-watcher                   org.eclipse.virgo.kernel.deployer.hot.HotDeployer                 pickup - after check:
	Known files: [/path-to-server-home/pickup/test.configuration.properties]
	Monitored:   [] 

which is pretty verbose, so be aware that the log file may become quite large very quickly. In the standard serviceability.xml file the appenders used here write to "rolling log files" which are based upon size; so the total amount of logged information is bounded, though the log you choose can be swamped with information from one source.

The serviceability.xml file is just a logback configuration file, and all the Logback functionality is available. For more information see the Logback configuration on-line documentation.

Entry and Exit tracing

In the default serviceability.xml file the root logging level is INFO. This is reasonable: if a log entry is made at INFO level, one expects this to appear in the log under normal circumstances.

Medic (one of the Virgo repositories) is designed to set up logging, tracing and dumping, for use by the rest of the code, and achieves this partly by weaving in aspects that perform tracing at the entry and exit points of methods. These aspects are woven into the rest of the code so that they don't have to code them themselves.

The entry and exit level tracing aspects are carefully woven into the kernel and the server code (web) to avoid the logging code itself (recursion) and the low-level utility functions (util and osgi-extensions).

It traces entry and exit points at two levels: DEBUG for all public methods and TRACE for all other methods (package private and private). 'Getter' and 'Setter' methods (those beginning with get and set) are not traced at any level.

So, to see these entries you need to set the logging level to DEBUG or higher for the areas you are interested in.

You will see entries in the serviceability/log/log*.log files like this:
[2010-07-29 16:40:31.342] main   > public static boolean org.eclipse.virgo.kernel.core.BundleUtils.isFragmentBundle(org.osgi.framework.Bundle) 
[2010-07-29 16:40:31.342] main   < public static boolean org.eclipse.virgo.kernel.core.BundleUtils.isFragmentBundle(org.osgi.framework.Bundle) 
[2010-07-29 16:40:31.342] main   > public void org.eclipse.virgo.kernel.core.internal.BundleStartTracker.trackStart(org.osgi.framework.Bundle, org.eclipse.virgo.kernel.core.Signal) 
[2010-07-29 16:40:31.342] main   > public static boolean org.eclipse.virgo.kernel.core.BundleUtils.isFragmentBundle(org.osgi.framework.Bundle) 
[2010-07-29 16:40:31.343] main   < public static boolean org.eclipse.virgo.kernel.core.BundleUtils.isFragmentBundle(org.osgi.framework.Bundle) 
[2010-07-29 16:40:31.343] main   Adding signal 'org.eclipse.virgo.kernel.install.artifact.internal.AbstractInstallArtifact$StateMonitorSignal@210c507' for bundle 'com.springsource.platform.apps.explicit_bundle_imports_1.0.0 [54]' 
[2010-07-29 16:40:31.343] main   < public void org.eclipse.virgo.kernel.core.internal.BundleStartTracker.trackStart(org.osgi.framework.Bundle, org.eclipse.virgo.kernel.core.Signal)

where the entry and exit points are marked with > and < respectively, with the full class names of the method and its parameters supplied.

It is arranged that any exit from a method will be traced if its entry is, even if that was the result of an exception, so the entry and exit lines should always pair.