Logging in Eclipse/OSGi plugins

Question

I am starting to develop an Eclipse plugin (technically, an OSGi plugin) and one of the first problems I've run into is that I can't seem to control the commons-logging output as I normally would.

I've included the commons-logging package in the plugin dependencies, and indeed, when I log something (at INFO or higher severity) it is logged to the console. However, I can't seem to log at any lower level (such as DEBUG or TRACE).

I have specified a log4j.properties file, and it is on the classpath (for the runtime, just as the commons-logging package is) but none of the settings in that properties file have any impact on the behavior of the logger.

Here's the log4j.properties file:

#  Log4j Logging levels, in order of decreasing importance are:
#   FATAL, ERROR, WARN, INFO, DEBUG, TRACE
#

# Root logger option
log4j.rootLogger=ERROR,stdout
#,LOGFILE

# Direct log messages to stdout
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.Target=System.out
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%d{ABSOLUTE} %5p %r (%l) %t%n - %m%n

What do I need to do so that I can actually control the output of the logger?

Here are some sample output messages, in the hopes that the formatting may coincide with a default for java.util.logging, or provide other hints to someone:

Oct 21, 2008 11:01:23 PM com.stottlerhenke.sentinel.client.Activator start
SEVERE: fatal_message
Oct 21, 2008 11:01:23 PM com.stottlerhenke.sentinel.client.Activator start
WARNING: warn_message
Oct 21, 2008 11:01:23 PM com.stottlerhenke.sentinel.client.Activator start
INFO: info_message

Update:

I have now tried various combinations of:

• org.osgi.service.log.LogService et al.
• slf4j
• Log4J
• Commons-logging
• java.util.logging

and I can only get DEBUG, or lower, level messages to appear if I am running OSGi manually from a prompt (which is impractical for what I am developing). Furthermore, I can't effect any other type of logging configuration via various properties files. Everything I try in that regard seems to be overridden by an eclipse setting.

I've also tried putting various config files for the above libraries in numerous places, including as plug-in fragments attached to their respective libraries as suggested here, and still, the same result happens.

I've implemented a custom LogListener, and traced the entire path of a log message (as well as I know how, anyway) with System.out.println's, and debug messages are present right up until they are output by whatever underlying logging API I'm using, then they disappear.

Answer 1

This is not an actual answer to your question, but you might find some clues in this set of articles by ekkes:

• Part 1: An overview
• Part 2: How to catch all log events from "classic" logging - frameworks
• Part 3: How to catch all log events from OSGI Log Services
• Part 4: How to start logging bundles the right way inside an OSGI Enterprise application

I suppose you read already "Using Log4J in Eclipse Equinox/OSGi":

Did you launch an osgi session in a console mode ?

java -jar org.eclipse.osgi_3.3.0.v20070530.jar -console -noExit -clean

That way, you may test log4j in a pure osgi environment and check if it works there.

Let use know if you find a solution (publish it as an answer), and I will vote it up ;)

Answer 2

3 days later...

I found the problem! There were two things I needed to do, first off, there was a problem with one MANIFEST.MF file:

I had the following in the MANIFEST.MF for one bundle:

Bundle-ClassPath: lib/jena.jar,
 .,
 org.apache.log4j-1.2.12.jar,
 lib/google-collect-snapshot.jar
Import-Package: com.acme.client.translation,
 com.acme.translation.interfaces,
 com.acme.shared.osgi,
 com.acme.utilities

That should have been this:

Bundle-ClassPath: lib/jena.jar,
 .,
 lib/google-collect-snapshot.jar
Import-Package: com.acme.client.translation,
 com.acme.client.translation.interfaces,
 com.acme.shared.osgi,
 com.acme.utilities,
 org.apache.log4j

The key difference is that the log4j was being used as a package, when it should have been used as a bundle. (I had a log4j jar in my lib dir from when I had expected Log4j to "just work" with OSGi.) The jar does work, sort-of. It evidently found some eclipse-level log4j configuration, and made use of that. Since it was just a jar (not a bundle) it didn't make use of any fragments that could specify a custom logging config, which leads us to the other thing that had to happen:

I needed to set up a bundle fragment to specify the logging config. This link from VonC gave me the info to do that. That entailed doing a number of things, unfortunately, the package with the incorrect MANIFEST.MF still had the log4j jar specified in the Bundle-ClassPath, and that seems to override the Import-Package list.

I finally figured out what was going on when I needed to log in another bundle (I had just given up at this point, and went back to using logs at the Warn level and higher.) This new bundle couldn't find a logging config! (so then I had three bundles running in the same OSGi environment, each with different log4j behavior -- one using my fragment settings, another using some random Eclipse logging settings, and finally the new bundle that didn't have any logging config.) Detailed comparisons of these three bundles revealed the difference in the Manifest.MF files, and now they all use the fragment bundle.

I owe a huge thanks to the authors of much of Eclipse Zone, [VonC], [Ekkes], and everyone in #eclipse on freenode for their help and patience :)