Improving GeoServer logging.

Justin Deoliveira Saul Farber

Change to existing module

1.6.0

Complete. Functionality is complete and implemented on trunk (1.6.0). Functionality will not target 1.5.x branch at this time.

JIRA task:

Email discussion:

Other wiki discussions:

[http://docs.codehaus.org/display/GEOSDEV/Commons-Logging+in+Geoserver]

Justin Deoliveira +1 Jody Garnett +1 Rob Hranac +1 Chris Holmes +1

Logging support in GeoServer has a number of issues.

As people know geotools forces GeoServer to use java logging. This is problematic as applications that use geotools are then tied to java logging as well. For a toolkit to impose this kind of restriction on an application is unacceptable. I would imagine this is precisely why any java library that is taken seriously uses commons-logging which allows the application to choose.

Currently there is no way to change the logging level of a particular package. This is problematic as it means that we simply have to trust that a library that we use ( like geotools ) will log messages at appropriate levels for us. Unfortunatley this is not the case. For instance, geotools factory finder mechanism now logs at the CONFIG level which makes GeoServer startup look like a mess. Furthermore all the spring and struts logging at startup is really undesirable as well. Both java logging and log4j allow for a property file which enables users to control which level certain packages or loggers are logged at.

Currently, GeoServer is setup to allow the user to turn on file logging. The reason this is problematic is that the routines that setup the file logging are hacky ( and I am not ragging on anyone because I am the one who wrote them :-) ). But essentially they try to inspect the current logging handlers on the GeoServer logger and remove / add as neccessary. This falls apart miserably as soon as the environment wants to add its own file logger for instance. It is also very prone to other bugs like logging to two different files simultaneously, or logging to the same file twice, etc…

Since logging is done consistently and identically across geotools and geoserver, the fix must start in geotools and be ‘configured’ or ‘deployed’ by geoserver at run-time. All of geoserver and geotools use Java Logging, so by ‘redirecting’ all java-logging output into an appropriate common-logging logger, we can direct all geotools/geoserver logging transparently to a commons-logging framework.

In Geotools is a class called “CommonHandler” which can take a java.logging Logger and re-direct its output to an apache common-logging Logger. In this way all the code already written like this:

java.util.logger.Logger LOGGER = java.util.logger.Logger.getLogger("org.geotools.data");
LOGGER.fine("Here's a fine-level log message");
LOGGER.info("Here's an info-level log message");

will be transparently re-directed to a commons-logging implementation, without any fore-knowledge by the programmer, or changes in the code.

This CommonHandler class is configured by the Logging utility class (in the metadata module). To redirect a Logger to commons-logging, run the following code:

new Logging("org.geotools.data").redirectToCommonsLogging();

There is a suggestion that instead of doing this on a package-by-package basis, we could do all loggers in one fell swoop:

new Logging(Logging.ALL).redirectToCommonsLogging();

This seems undesirable because it would ‘hijack’ all loggers across the entire java logging spectrum. In a shared J2EE environment, there may be other loggers who we don’t want to apply our commons-logging redirection mechanism to.

This functionality is enabled by fixes for the following JIRA issues:

Geoserver must enable the redirection to commons logging, and then (of course) set up commons logging in order for this proces to work. This is done in two parts:

There is a ContextLoaderListener defined in geoserver’s web.xml which causes the LoggingStartupContextListener to begin redirection of all “org.geotools” “org.geoserver” and “org.vfny.geoserver” log streams to commons logging as soon as the geoserver context is loaded.

This ContextLoaderListener is specified in the web.xml file of a web application. ( This is the same way the spring context is loaded and initialized ):

<web-app>
…

<!-- intialize logging -->
<listener>

<listener-class>org.geoserver.logging.LoggingStartupContextListener</listener-class>
 </listener>

<!-- initialize spring -->
<listener>

<listener-class>org.springframework.web.context.ContextLoaderListener</listener-class>
 </listener>
…
</web-app>

A complete implementation of the LoggingStartupContextListener would also involve an implementation of contextDestroyed which would persist out the logging configuration.

See the initial implementation of LoggingStartupContextListener

Since relying on the servlet container to shut down cleanly is not always reliable this routine should probably also be invoked when the configuration is saved from the ui.

This functionality is enabled by fixes for the following JIRA issue:

Geoserver also includes a standard setup for commons-logging. There is a commons-logging.properties file which (by default) sends logging to the log4j logging system. There is also a log4j.properties file which configures log4j logging.

This proposal involves temporarily removing the configuration options to turn on and off logging from the ui.

Since the new logging system hands control off to the commons-logging system which has no a-priori control over its logging sub-system, how are we to provide the ability to change log cutoff levels on the fly, or to allow logging redirection to a file?

There is an open JIRA to handle these issues:

[http://jira.codehaus.org/browse/GEOS-1022]

One way we could handle integration logging control for geoserver with the UI would be to provide control for just the log4j commons-logging sub-system, and leave the rest to be configured by their administrators (hey, they changed the logging configuration to a new sub-system, they clearly know how to use it\!)

Logic to implement UI-based logging control:

\1. Determine the logging subsystem. Check in the commons-logging.properties file (it’s on the classpath). If the chosen logger is the log4jLogger then we handle each request in the appropriate way. If the logger is not one of those two, then we disable log control at the UI level (by greying out the appropriate web controls).

\2. For the supported subsystem (log4j) we could implement the “change the log level” and “choose which file to log to” in the following manner.

\1. Get a handle on the current configuration and check for a well-known file or console logger. If the well-known name isn’t present, disable the controls (someone has customized the file\!) 2. Provide a pull-down to select the default logging level of the file or console logger 3. For a file logger, provide a text-box for a filename to use for the file logger. 4. When the ‘save’ button is pressed by the UI, apply the selected UI control values to the Log4J configuration properties and reload the log4j system

An alternative way to handle UI integration would be to simply provide three or four ‘standard’ logging configurations. Here is a sample list:

• PRODUCTION ~~- Log to $DATA*DIR/logs/geoserver.log at Geoserver-INFO level, Geotools-WARN level and everything else WARN level.
• PRODUCTION*STDOUT~~- Log to stdout (letting the log stream go where the container wants it to) at at Geoserver-INFO level, Geotools-WARN level and everything else WARN level.
• DATASTOREDEBUGGING ~~- Log to $DATADIR/logs/geoserver.log with Geoserver at DEBUG level, Geotools datastores at DEBUG level the rest of Geotools at INFO level, and everything else at DEBUG level
• DEVELOPERDEBUGGING~~- Log to $DATADIR/logs/geoserver.log with Geoserver at DEBUG level, Geotools at DEBUG level, everything else at INFO level
• User-supplied logging configurations?