Wednesday, September 24, 2008

Logging in OSGI Enterprise Applications, Part 1



Logging is an important part of ERP Applications and should be easy using a modern logging framework ;-)

My actual work-in-progress (german ERP solution) contains: Equinox as OSGI Framework, Eclipse Riena for Remote Services + UI, EasyBeans as EJB3 Container + JPA (Hibernate) etc.

This means I have to integrate different logging - frameworks:

  • org.osgi.service.log
  • org.eclipse.equinox.log (Extended Log Services from 1.1.0.HEAD)
  • org.apache.commons.logging
  • org.apache.log4j
  • org.slf4j
  • java.util.logging (JSR47)

If you already followed some of my blogs, then you probably know that its not easy to design a clean OSGI architecture for a complex business application.

Actually I was confronted with the newest snapshot of EasyBeans containing a new Hibernate release (3.4) now using SLF4 as logging framework. This causes me to rethink my logging architecture.

The logging solution should make my OSGI client / server - application independent from logging frameworks. I'll explain all in detail later.  At first I'll give you an overview to see the differences between "classic" Java logging frameworks and OSGI Logging Services.

"Classic" Java Logging Frameworks


Usually logging works this way:

Logger definition:

Commons-Logging:
private static Log logger = LogFactory.getLog(MyClass.class);
Log4J:
private static Logger logger = Logger.getLogger(MyClass.class.getName());
SLF4J:
private static Logger logger = LoggerFactory.getLogger(MyClass.class);
JDK:
private static Logger logger = Logger.getLogger(MyClass.class.getName());

Logging a message:

logger.info(„my message“)

Because concatenating Strings is slowly we also find: 

if (logger.isDebugEnabled())
   logger.debug("message part 1" + aVar
   + "message part 2");

Remark: If you're using SLF4J (FAQ) in many cases you can simple use a parameterized message string:

logger.debug("message part 1 {} message part 2", aVar);


Configuring logging - frameworks:

Configuration can be made using Java code - but mostly you'll find a configuration file - wether in properties or XML format. 


Whats different if you're using these logging frameworks under OSGI ?

  • you need a bundle for each JAR. You can find bundles for Commons-Logging, LOG4J and SLF4J partly in Eclipse or get them from a bundle repository
  • logging itself is the same as in normal Java applications
  • you have to place the configuration file into a Fragment-Bundle


OSGI Logging Services

Under OSGI you can use Logging Services:

  • Standard OSGI : org.osgi.log (OSGI Logging, implemented by org.equinox.log)
  • Extended: org.equinox.log (1.1.0.HEAD Version from CVS or Riena download), extended Logging)

OSGI Logging uses Services and Listeners. Equinox implements OSGI Log Services as ManagementServices. 

  • LogService or ExtendedLogService - writes all log messages
  • LogReaderService or ExtendedLogReaderService - where you can read log messages from
  • LogListener - gets the messages from ReaderService and you can handle them

OSGI LogService can be compared with the Logger from "classic" Java logging. Its a good idea to place LogService Logger objects into the Activator of a bundle.

LogService logger = ...

Logging a message is nearly the same as logging in non - OSGI environments - of course we have to test if the service is available:

if (logger != null) {
     logger.log(LogService.LOG_INFO, „my message“);
}

The LogEvent can then be read using the LogReaderService. You can "track" this ReaderService  and add your own LogListener. This LogListener gets all messages and you can persist the messages or print to console or use one of the "classic" logging frameworks.

Equinox allows you to configure how many messages should be cached from LogReader Service and at which Log Level. But important to know: The LogReaderService sends always all messages to all registered LogListener independent from your configuration !

"Classic" Logging or OSGI Log Services ?

Lets look at the differences between "classic" Java - logging und OSGI - Log Services:

a) Which messages will be logged - and when ?

"Classic" Logging only creates log - messages if the Logger answers "yes" to „should I really log this message at those level for 'the.logger.name'“ ? It depends from the content of your configuration file, what you want to log at which level. If the Logger answers "no" - nothing will be logged.

OSGI Log Services always log ALL messages. The Log Reader Service gets them ALL. The Log Reader Service will inform all Log Listeners about all logged messages. Also the Log Reader Service will cache a configurable amount of messages.
The main task of a Log Listener is to filter the messages and to persist or print them.

b) What will be logged ? And whats the content of the Log Messages

Here you'll see the most important content of a Log Entry:



The different logging frameworks are also using different Log Levels, so they have to be mapped.
The logged Message is a String or will be created from myObject.toString().
MDC (Mapped Diagnostic Context) - a Thread - local Map where you can store context informations, per ex. user info of client sessions.
Marker - a tree of Strings you can mark messages with.

In an OSGI environment its very useful to log informations about the Bundle (and perhaps the Service Reference) where the logged message comes from.
Using OSGI Log Services you'll get this for free. If you're using SLF4J / LOGBack you can also store Bundle- and Service Names. (Using the Marker - more about this later)

c) Whats the best to use ? "Classic" Logging Frameworks or OSGI Log Services ?

Don't ask this question if you're developing an OSGI Enterprise - Application ;-)

Why not ? 

  • You'll never know in advance, which (foreign) projects you'll have to integrate while the whole life-cycle of your business application. 
  • You have to live with 3rdParty Bundles using all kind of logging - frameworks and -strategies. (Sometimes they change it as with Hibernate happened)

But you have to find the answer, HOW to combine and integrate them all without loosing flexibility. If you've solved this issue, then it also doesn't matter what you're using in your own bundles, because your logging architecture consumes it all :-)
Perhaps specific use cases can force you to use 'classic' logging and OSGI Log Services.

Integration of all Logging Frameworks and Log Services



The heart of my solution is SLF4J with LOGBack as native implementation. 


SLF4J (Logback) has already bridges for all 'classic' logging frameworks: this enables you to use bundles logging to Commons-Logging (JCL), Log4J, JDK (java.util.logging) or SLF4J. All logged messages will be transparently routed to LOGBack.

Also all OSGI LogServices - wether Standard or Extended - will be catched from Log Listeners and delegated to SLF4J (LOGBack) delegiert.

So you have ONE place to handle all your logging :-) It depends only from your configuration, if LOGBack prints messages to Console or sends them to a socket (local or remote), to your filesystem, RDBMS or to a LogServer or ... 


(Logging) - Integration of Eclipse Riena


If you're using Eclipse Riena M4 there are currently two small problems to solve:

1. Log4J-over-SLF4J

The bridge Log4J-over-SLF4J only  provides the package org.apache.log4j, but  org.eclipse.riena.core has a dependency to org.apache.log4j.xml. Please change this to "optional" in the MANIFEST.MF:

Import-Package: org.apache.log4j,
org.apache.log4j.xml;resolution:=optional,
org.osgi.framework;version="1.3.0",
org.osgi.service.cm;version="1.2.0",
org.osgi.service.log;version="1.3.0"

2. multiple log entries

Starting with M5 Riena's logging can be configured and its promised that you can switch it all OFF. While using M4 you'll notice two extra messages printed from Rienas LogListener to Console. (Bugzilla 247680)


(Logging) - Integration of EasyBeans OSGI


EasyBeans logging is now transparently routed to LOGBack without any problems. Since some days the Snapshots of EasyBeans 1.1.0 includes Hibernate 3.4, which itself now is using SLF4J. This also causes no problems because LOGBack is native Implementation of SLF4J.


additional informations

This blog is only the first one of a serie about Logging and OSGI. Perhaps it makes sense that you also take a look at my (older) blogs to know the hard way I went ;-)


Links:
  • Simple Logging Facade for Java (SLF4J)
  • LOGBack - Loggingframework, native SLF4J implementation
  • Eclipse Riena (Remote Services, UI enhancements)
  • Eclipse Equinox (OSGI Framework)
  • EasyBeans OSGI (EJB3 Container as OSGI bundles)
  • Hibernate (JPA - integrated into EasyBeans)

How goes it on ?

This blog is only part 1 of the series „Logging in OSGI Enterprise Applications“ giving only a short overview - the following themes will be later discussed in detail with source codee examples - so stay tuned.

  • HowTo registrier OSGI Logging Services
  • Tracking (standard and extended) OSGI Logging Reader Services
  • Adding Log Listeners to LogReader Services
  • HowTo configure LOGBack for OSGI
  • Mapping of LogLevels
  • Details of used Bundles, Manifest - files, dependencies,...
  • Fragment-Bundles
  • OSGI Launch configurations
  • Testing the whole stuff
  • Use of EasyBeans JDBC Pooling to persist messages from LOGBack in RDBMS
  • Performance issues (frameworks, "classic" logging vs. OSGI LogServices)
  • HowTo migrate existing code
  • Useful Eclipse PlugIns (Log4E, LogBack Console)
  • Client-/Server Logging Strategy, Remote Services, MDC - Userinfo...
  • The „black hole“: how to log before the services are ready ?
  • Use of SLF4J Marker to put Bundle- und Service - informations into
  • What happens if other bundles are also using Log Listeners and log messages ?
  • ...

Remark: In my article I'm not covering PAX OSGI Logging. PAX uses Log4J as implementation and also integrates some logging frameworks (JCL, JDK, SLF4J, Avalon). Perhaps you should also take a look at PAX before deciding how to use logging in your OSGI application.

A more detailed complete article is already in work about Logging in OSGI Enterprise Applications“ - and I'll continue this blog series.

Examples with sourcecode will also follow - I'm jst preparing a sample of my  Equinox -based Riena-Easybeans-Server, where the logging of course is an important aspect.



Hopefully you can get some ideas from my experiences and ideas how to solve the logging problem. I promise: if you're developing OSGI enterprise applications - one day you'll run into logging problems, so its better you're prepared.


 in german.

8 comments:

Simon Kaegi said...

Your article is well timed. In the Equinox project we're adding a logging plan item for this years release and are in the process of figuring out how to best straighten out the 3rd party/OSGi logging mess we have.

AlBlue said...

Why not use PAX Logging, which sorts all this mess out? Gives you bindings for each of the logger types and filters them through a customisable back end.

ekke said...

there are some issues not so easy to solve using PAX Logging. ...please wait, I'll blog in detail soon in follow-ups.
ekke

Anonymous said...

Very interesting post! Looking forward to part 2.

By the way, the two Riena problems you mentioned are already fixed in HEAD :-). Thanks Stefan, if you're reading this.

Kind regards,
Elias.

Stefan said...

@Simon:
Is there already some ´link´ for the logging plan within equinox?

@ekke
Also waiting for Part 2.

@Elias:
Thanks!

Maralc said...

Hi Ekke,

Thanks for the good article.
It's not been easy to make all that logging living inside equinox.mara

Looking forward part 2.

Marcelo

William Drew said...

Ekke,

Is there any chance that you could fix the link to section #2 of the logging series? It would be greatly appreciated.

TIA.

ekke said...

william,
I moved my blog from blogger to wordpress -
and while importing I noticed the damaged part2 - its fixed at wordpress.
please visit my blog at
http://ekkescorner.wordpress.com
---
part2:
http://ekkescorner.wordpress.com/2008/10/03/logging-in-osgi-enterprise-applications-part-2/
---thx
ekke