18 December 2010

Glassfish Logging with slf4j (Part 2)

My previous post on the same subject is one of the most popular articles in this blog, and since Glassfish still does not officially support slf4j, this update may be helpful to anyone hitting my blog via Google trying to improve their logging experience with Glassfish.

To redirect (almost) all log messages from Glassfish and your applications to the same log file and/or console, follow this recipe:
  • Copy these JARs to [install-root]/lib/endorsed:
    • jul-to-slf4j.jar
    • slf4j-api.jar
    • logback-classic.jar
    • logback-core.jar
  • Build a JAR containing your logback.xml configuration at root level and put it in the same place. [Update 26 Jul 2011: Actually, this is no longer required: Simply create a logback configuration file somewhere in your local file system and add the system property -Dlogback.configurationFile=file:/path/to/my/logback.xml to your Glassfish configuration.]
  • Define a new system property in the jvm-options section of your domain.xml:
    -Djava.util.logging.config.file=${com.sun.aas.instanceRoot}/config/my_logging.properties
  • Create the corresponding file my_logging.properties with the following contents:
  • handlers = org.slf4j.bridge.SLF4JBridgeHandler
    com.sun.enterprise.server.logging.GFFileHandler.flushFrequency=1
    com.sun.enterprise.server.logging.GFFileHandler.file=${com.sun.aas.instanceRoot}/logs/server.log
    com.sun.enterprise.server.logging.GFFileHandler.rotationTimelimitInMinutes=0
    com.sun.enterprise.server.logging.GFFileHandler.logtoConsole=false
    com.sun.enterprise.server.logging.GFFileHandler.rotationLimitInBytes=2000000
    com.sun.enterprise.server.logging.GFFileHandler.alarms=false
    com.sun.enterprise.server.logging.GFFileHandler.formatter=com.sun.enterprise.server.logging.UniformLogFormatter
    com.sun.enterprise.server.logging.GFFileHandler.retainErrorsStasticsForHours=0
    
When you restart Glassfish, you should only see two log messages in the old java.util.logging format, all the rest goes via slf4j and logback to the appenders configured in your logback.xml. The two remaining log messages are issued before Glassfish reads the domain.xml configuration with the adapted configuration, so there is no easy way of avoiding them.

I have been using this approach on various Glassfish versions from 3.0.1 to 3.1-b33. It is rather ugly, but nonetheless effective.

All this may sound rather mysterious, so I'd better add some explanations:

jul-to-slf4j.jar is a bridge for redirecting java.util.logging via the slf4j API to any logging backend of your choice (logback in this case). To make the redirection work, the bridge has to be visible to the classloader evaluating the logging configuration. Since Glassfish starts logging very early in its bootstrapping phase, the lib/endorsed folder is the only place where the bridge has the desired effect.

Unfortunately, class file folders seem to be unsupported for endorsed libraries. Of course, it would be easier to simply put the logback.xml file in lib/endorsed/classes where you can directly edit it. But for a quick change to your logging configuration, you can always use an editor which supports editing ZIP/JAR file contents in place.

I created the contents of my_logging.properties by trial and error, starting with a one-liner containing only the handler. This caused a couple of exceptions as Glassfish seemed to be missing the GFFileHandler settings, so I copied them over from the original logging.properties.

The same procedure should also work for other slf4j backends, so you could replace the logback JARs by a log4j.jar.

12 comments:

Tan-Vinh said...

Thanks for this great information. I adjust it to log4j and it works like a charm. With the facade you easily switch to your logging solution.

cowwoc said...

See http://java.net/jira/browse/GLASSFISH-6666 for a related discussion.

Nicolas Heron said...

Hello,
I have a question, does it work with Glassfish 2 ?
Thanks

Harald Wellmann said...

Hi Nicolas,

no idea, I've never used Glassfish v2...

Amit said...

Is this all needed? i.e. placing the jul-to-slf4j.jar, defining a system property to specify the path to the configuration file etc.
If I just place the logback configuration file in the classpath and not use a console appender shouldn't be enough? As you mention all the console logs are redirected to a logger, if a consoleappender is not used in logback nothing will be logged to the glassfish server.log. The logback.xml can just have the required rolling file appenders.

Your thoughts on this would be appreciated

Harald Wellmann said...

Hi Amit,

it depends on what you're trying to do. If you just want to use slf4f/logback in your web app, it's enough to include them in your WAR.

The goal of my setup is broader: I'm trying to redirect all log messages both from my application and from Glassfish itself to the same location.

Amit said...

Thanks for the follow up. Just so that I understand it better - The advantage of redirecting all log messages both from the web-application and from Glassfish itself to the same location is to have glassfish manage the logs right?

and by manage I can think of the "collect-log-files" command which could be used when glassfish cluster is being setup.

Is there anything more that glassfish could log and it would be helpful for application troubleshooting/analysis/security?

Are there any other advantages?

Harald Wellmann said...

The answer is: It depends...

As a developer, I usually work with a single web app deployed to Glassfish directly from Eclipse. It is very useful to receive all diagnostic output from Glassfish and my app in the console and in a single log file. I just hate the default two-line output of java.util.logging to System.err instead of System.out, and there are many good reasons to prefer slf4j + logback over JUL, which I won't repeat here.

An administrator of a Glassfish instance used in production would have a different perspective: They can normally inspect the logs via the Glassfish admin console which AFAIK only supports the default JUL logs, so they would be blind with my approach.

Fortunately, with slf4j this is just a matter of configuration, so you can work with logback for development and revert to the default configuration for production.

I've never tried collect-log-files myself, so I can't comment on that.

Anyway, I think Glassfish is too rigid in forcing its own logging philosophy on its users.

In Glassfish JIRA, you find an enhancement request for supporting slf4j, which was raised for Glassfish v2 and does not seem to be on the agenda for 3.x currently.

But going by the number of visitors on this blog, I think better slf4j support is much wanted by many Glassfish users.

Cem Koc said...

Could you try with latest stable Glassfish 3.1.1 your solution? It is a pity that I could not be successful to log...

Gustavo said...

I'm using glassfish 3 and I was trying to implement this AND get simpledb-appender working. The catch was to put the jar files inside [domain_root]/lib/ext. Glassfish's classloader would not load a few files that were clearly inside the jars because of the way the jars would try to load them. Using this filder did the trick

Bern said...

This is a great tip. It also works fine on glassfish 3.1.1.
A variant config is to put the logback.xml file in the config of the glassfish domain. The command line for logback configuration can then be converted to -Dlogback.configurationFile=${com.sun.aas.instanceRoot}/config/logback.xml.

glh1309 said...

Hooray! Works perfectly with Glassfish 3.1.2 in Netbeans 7.1.2