Wednesday, November 15, 2006

Using java.util.logging in BEA Weblogic

Some weeks ago I was making sure that the JMSJCA connector runs properly on BEA Weblogic 9.1. Of course I ran into some issues: never assume that your code is really portable until you try it out. I also found some issues in Weblogic. Now I don't want to make this into a bashing session of Weblogic: since I work for Sun Microsystems, and Weblogic can be considered a competitor or Glassfish, that would be in bad taste. However, there's one thing that bugged me a lot and for which I want to share a solution: logging.

Dude, where's my log output?

At SeeBeyond (and of course at Sun) we standardized on the use of java.util.logging. You could argue whether java.util.logging is technically the best solution, but since it's a standard it's a lot better if you use that package than it is to write your own or use other third party logging tools. Standardization gives portability! So, JMSJCA, STCMS, etc all use java.util.logging.

When I started to run my test suite on Weblogic, I was surprised that the log output from the tests did not end up in one of the Weblogic log files. Instead, output appeared on the console. Surely there was a configuration option somewhere in Weblogic to fix this, right? I couldn't find one. The problem became even more annoying when I tried to enable debug logging. In Glassfish you go to the logging configuration screen, and you simply type the name of the logging category that you want to change, select the level and that's it. Not so in Weblogic. What was going on? It was time to look a little deeper into this.

How Weblogic uses java.util.logging.

I must admit that the Weblogic documentation is good, and very easily accessible. I wish we had the same situation at SeeBeyond. Anyway, from the documentation it appeared that Weblogic fully supports java.util.logging: I quote from the documentation: To distribute messages, WebLogic Server supports Java based logging by default. The LoggingHelper class provides access to the java.util.logging.Logger object used for server logging. [snip] If your application is configured for Java Logging or Log4j, in order to publish application events using WebLogic logging services, create a custom handler or appender that relays the application events to WebLogic logging services using the message catalogs or Commons API.

Eh, what do you mean... LoggingHelper class? Can't I just use java.util.logging without depending on any Weblogic classes? Do I have to write custom code?

And how do I change log levels dynamically? Isn't there an option in the admin console to do that? An MBean perhaps? I was really surprised to find this recommendation: If you use the DEBUG severity level, BEA recommends that you create a "debug mode" for your application. For example, your application can create an object that contains a Boolean value. To enable or disable the debug mode, you toggle the value of the Boolean. Then, for each DEBUG message, you can create a wrapper that outputs the message only if your application's debug mode is enabled.

For example, the following code can produce a debug message:


private static boolean debug = Boolean.getBoolean("my.debug.enabled");
if (debug) {
   mylogger.debug("Something debuggy happened");
}
[snip]
To enable your application to print this message, you include the following Java option when you start the application's JVM:

-Dmy.debug.enabled=true

That was a good recommendation... TEN YEARS AGO!

A fix

Fortunately, things are not as grim as they look. It's quite easy to write a little bit of code that is deployed globally independently of your application, so that you can continue to use java.util.logging without sprinkling Weblogic dependencies all over your application. First of all, what's all this with this BEA logger? As it turns out, during startup, Weblogic instantiates a java.util.logging.Logger object and hooks a number of Handler objects to it. So if you log to that particular logger, your log output will appear in one of the Weblogic log files. Can't you get access to this Logger using Logger.getLogger(name)? No you cannot: Weblogic is not using the LogManager at all. That particular logger is not registered in the LogManager. That is the reason why you need to use the weblogic.logging.LoggingHelper.getServerLogger() method.

Once we have a reference to this special Logger object,  we can get a list of the Handler objects. Next, we can assign this list to the root logger object. As a result, whenever you use a Logger object obtained through Logger.getLogger(), the output will go to the Weblogic handlers. Problem solved!

Of course we want to centralize this code: afterall we don't want to introduce this dependency in our application code. There are two ways of doing this: we can write our own LogManager and set that as the JVM's LogManager singleton. We can do this because Weblogic doesn't set a LogManager. The other approach is to write a Weblogic startup class. An instance of this class is created at server startup and its startup() method is called. This is the approach I've taken:

package com.sun.bealog;

import java.util.Hashtable;
import java.util.logging.Handler;
import java.util.logging.Level;
import java.util.logging.LogManager;
import java.util.logging.Logger;
import javax.management.MBeanServer;
import javax.management.ObjectName;
import javax.naming.Context;
import javax.naming.InitialContext;
import javax.naming.NamingException;
import weblogic.common.T3ServicesDef;
import weblogic.common.T3StartupDef;
import weblogic.logging.LoggingHelper;

/\*\*
\* Allows logging by applications and components using the java.util.logging
\* package by sending output from java.util.logging.Logger-s to the
\* WebLogic trace file.
\*
\* @author fkieviet
\*/
public class BeaLog implements T3StartupDef {

public String startup(String string, Hashtable hashtable) throws Exception {
String result = "";
Logger wllogger = LoggingHelper.getServerLogger();
Handler[] wlhandlers = wllogger.getHandlers();

// Change log level on log file handler
for (int i = 0; i < wlhandlers.length; i++) {
if (wlhandlers[i].getLevel().intValue() >= 530) {
result += "log level changed of " + wlhandlers[i] + "; ";
wlhandlers[i].setLevel(Level.FINEST);
}
}

// Copy handlers from wllogger to rootlogger
Logger rootlogger = Logger. getLogger("");
Handler[] toremove = rootlogger.getHandlers();
for (int j = 0; j < toremove.length; j++) {
rootlogger.removeHandler(toremove[j]);
}
for (int i = 0; i < wlhandlers.length; i++) {
rootlogger.addHandler(wlhandlers[i]);
}
result += "root handler now has " + rootlogger.getHandlers().length + " handlers; ";

// Register wllogger so that it can be manipulated through the mbean
boolean alreadythere = !LogManager.getLogManager().addLogger(wllogger);

// Register mbean
InitialContext ctx = null;
String[] names = new String[] {"java:comp/jmx/runtime", "java:comp/env/jmx/runtime"};
for (int i = 0; i < names.length; i++) {
try {
ctx = new InitialContext();
MBeanServer mbeanServer = (MBeanServer) ctx.lookup(names[i]);
mbeanServer.registerMBean(LogManager.getLoggingMXBean(),
new ObjectName("java.util.logging:type=Logging"));
result += "mbean registered; ";
} catch (Exception e) {
// ignore
} finally {
safeClose(ctx);
}
}

// For Java CAPS: disable two commonly used loggers that are used to
// relay call context information
Logger.getLogger("com.stc.EnterContext").setLevel(Level.OFF);
Logger.getLogger("com.stc.ExitContext").setLevel(Level.OFF);

return this.getClass().getName() + result;
}

private void safeClose(Context ctx) {
if (ctx != null) {
try {
ctx.close();
} catch (NamingException ignore) {
// ignore
}
}
}

public void setServices(T3ServicesDef t3ServicesDef) {
}
}

As you may have noticed, there's another problem that's solved in the code snippet above: dynamice log level configuration. The JVM's logging package ships with an MBean that allows you to set the log levels dynamically. The only thing that needs to be done is to register this MBean in Weblogic's MBeanServer (Weblogic has an unusual way to access its MBeanServer as you can see in the code). From then on, you can use a tool like jmx-console to access the logging mbean and set the log levels.

Download a NetBeans project that contains the BeaLog code.

Post a Comment