Logging Manager in 2.2

Glenn Golden

I've put in two logging controls that will help us control our Sakai's logging. This lets us set specific logging levels in sakai.properties, and lets us filter out specific messages from code that we know we don't want to see.

The logging controls are part of the new LogConfigurationManager, implemented as a component, the Log4jConfigurationManager, in the util module. This component works only if the log4j configuration has a "sakai" appender (which ours does). It can also be disabled, if we really don't want it to do anything, with an entry in our sakai.properties:

enabled@org.sakaiproject.log.api.LogConfigurationManager = false

The API can also be called at runtime to dynamically alter the log levels.

Logging Levels

Logging levels are first established in the log4j configuration file we deploy from Sakai. The source for this file is in:

sakai/util/util-impl/log/src/conf/log4j.properties

This is made into a jar and deployed to common (this is a requirement of log4j configuration in Tomcat).

We can set logging levels in this file. For example:

1. Application logging options
   log4j.logger.org.sakaiproject=INFO

1. Ignore erroneous MyFaces variable resolver warnings
   log4j.logger.org.apache.myfaces.el.VariableResolverImpl=ERROR

This sets any logger with "org.sakaiproject.*" to INFO level, and the "org.apache.myfaces.el.VariableResolverImpl" to ERROR level.

The problem is it is not so easy for us to change this on a case-by- case basis. We have to change the Sakai source and re-deploy.

Now, we can specify logging levels in our sakai.properties. This augments and overrides the levels set in our config file. Example:

log.config.count=3
log.config.1 = ALL.org.sakaiproject.log.impl
log.config.2 = OFF.org.sakaiproject
log.config.3 = DEBUG.org.sakaiproject.db.impl

This uses the established (but awkard) method of having a name.count followed by name.1, name,2, etc. to form an array of strings for the value "name". In this case, the name is "log.config".

The values are of the form

LEVEL.logger

Levels are OFF TRACE DEBUG INFO WARN ERROR FATAL ALL

Ignoring Messages

Some of our third party code has the unfortunate side effect of sending out ominous sounding ERROR and WARN messages that are reporting normal cases that need no attention on the developer or administrator's part. In short, these should be missing.

We used to have to get used to all these bogus messages, which makes it hard for the entire community to read Sakai logs and watch out for conditions that do need our attention.

Now, we can block the known cases of these errors.

This is configured as a complex spring bean configuration, a map of sets, in the components.xml of util-pack where the LogConfigurationManager is hosted. Here's an example:

<property name="ignore">
<map>
<entry>
<!-- from this logger -->
<key><value>org.apache.myfaces.webapp.webxml.WebXmlParser</ value></key>
<set>
<!-- messages starting with these strings will be ignored -->
<value>Ignored element 'init-param' as child of 'servlet'.</value>
</set>
</entry>
<entry>
<key><value>org.apache.commons.digester.Digester</value></key>
<set>
<value>[NavigationRuleRule]{faces-config/navigation-rule}  Merge</value>
</set>
</entry>
<entry>
<key><value>org.hibernate.cache.EhCacheProvider</value></key>
<set>
<value>Could not find configuration</value>
</set>
</entry>
<entry>
<key><value>net.sf.ehcache.config.Configurator</value></key>
<set>
<value>No configuration found. Configuring ehcache from</value>
</set>
</entry>
<entry>
<key><value>org.apache.myfaces.util.LocaleUtils</value></key>
<set>
<value>Locale name null or empty, ignoring</value>
</set>
</entry>
</map>
</property>

The keys are logger names, and the set of values are partial messages. Any message that the logger attempts to log that starts with any of our set of strings will be ignored.

These are, by the way, the set of messages we will be ignoring for 2.2, so far.

In the future, we can figure out a way to augment and override this list from sakai.properties. This is difficult because sakai.properties is a flat properties file, while this is a complex data structure. But I'm not expecting case-by-case disabling of messages. I'm expecting instead that the community will find the bogus log messages from our enabling technologies and we can just disable them OOTB.

Runtime Control

Although not yet done, we can write an admin tool that uses the api to change log levels dynamically at runtime while the server is running. A webservices call might also be interesting for this. In these ways, if a situation arises in a production or running Sakai, the administrator can enable selective loggers to a more verbose logging level to get a better clue about what is happening, and then revert it to normal levels after the test, all without interrupting the service.

The API controls only the app server on which it is running - in a cluster, the other app servers' logging levels will be unaffected.