A wonder-slim application logs through slf4j, like most Java code today, and a separate module decides where the output goes. This guide covers choosing that module, configuring it in keys that work with any of them, how that combines with the configuration a Project Wonder application already has, and changing levels while the application runs.

It describes wonder-slim as of 8.0.12. Most applications never need more than the first three sections: pick a backend, and set a level or two.

1. Choosing a backend

ERExtensions logs through slf4j and depends on no logging implementation. The application adds exactly one of two modules, and that module brings the implementation:

• ERLoggingReload4j: log4j 1.x, in its maintained form reload4j. What Project Wonder applications have always used, and the one to keep if your configuration relies on log4j's appenders.
• ERLoggingLogback: logback, log4j's modern successor from the same author.

<dependency>
    <groupId>is.rebbi.slim</groupId>
    <artifactId>ERLoggingLogback</artifactId>
    <version>${wonder.version}</version>
</dependency>

Only one may be on the classpath. With two, the application stops at launch and names both, so if a framework you use brings ERLoggingReload4j along, exclude it from that dependency when you switch:

<dependency>
    <groupId>com.example</groupId>
    <artifactId>SomeFramework</artifactId>
    <version>1.0.0</version>
    <exclusions>
        <exclusion>
            <groupId>is.rebbi.slim</groupId>
            <artifactId>ERLoggingReload4j</artifactId>
        </exclusion>
    </exclusions>
</dependency>

A module's backend is found through Java's ServiceLoader, so there is nothing to register. Without either module, the application still runs, says once on the console that no logging backend is present, and leaves logging to slf4j's defaults.

One detail explains a dependency you might otherwise wonder about: WebObjects itself calls the log4j API in a place or two (encoding a direct action's query parameters is one), so some log4j API has to be on the classpath whichever backend you choose. ERLoggingReload4j has the real one; ERLoggingLogback brings log4j-over-slf4j, which hands those calls to slf4j and so to logback. The two can't be on the classpath together, which is one more reason for choosing exactly one module.

2. Levels and the layout

Logging is configured in the application's Properties, in keys every backend understands:

# A logger's level: TRACE, DEBUG, INFO, WARN, ERROR or OFF
er.logging.level.com.example.billing=DEBUG
er.logging.level.cayenne-sql=WARN

# The root logger's
er.logging.level.root=INFO

# The layout of the console output
er.logging.pattern=%d{MMM dd HH:mm:ss} %-5p %c - %m%n

A level applies to the logger named and everything beneath it, so er.logging.level.er.extensions covers all of ERExtensions. The level names are the same in every backend, and WARNING is read as WARN.

ERExtensions' own Properties sets the defaults: the root at INFO, and the layout above. Most applications need nothing more than a level or two of their own. The environment variants work as they do for any property, so Properties.dev is the place for what you want to see only in development:

# Properties: quiet in production
er.logging.level.cayenne-sql=WARN

# Properties.dev: every SQL statement while developing
er.logging.level.cayenne-sql=INFO

In your own code, log through slf4j as you would anywhere else:

private static final Logger log = LoggerFactory.getLogger( InvoicePage.class );

log.debug( "Rendering invoice {}", invoice.number() );

3. When configuration meets configuration

A backend can do far more than levels and a layout: files, rotation, remote targets, filters. That configuration stays available, in the backend's own form, and takes precedence where it overlaps. The whole picture is four layers, a later one winning over an earlier one where both name the same logger:

1. Project Wonder style log4j levels: log4j.logger.X, log4j.rootLogger and log4j.rootCategory. Only for logback, which reads the levels from them (reload4j reads all of log4j.* itself, at layer 3).
2. The keys above, er.logging.*, from wherever they're set: ERExtensions' defaults, the application's Properties, Properties.dev, the command line.
3. The backend's own configuration: log4j.* properties for reload4j, read exactly as log4j always read them; for logback, the file the logback.configurationFile property names, or logback.xml on the classpath. If logback's configuration gives the root logger output of its own, the console output from layer 2 steps aside.
4. Levels set on the running instance, from the admin console or in code (section 4). These win over everything, until they're unset.

When a logger ends up at a level you didn't expect, the startup report and the admin console's Configuration page (/wonder/admin/configuration) show each property with the source it came from, and which sources it overrides.

4. Changing levels while the application runs

Logging follows the configuration: whenever a logging property changes (er.logging.*, log4j.* or logback.configurationFile), logging is configured again, and nothing else is needed. A logging property changes in three ways:

• In development, edit the application's Properties or Properties.dev and save. The files the configuration was read from are watched, and a change is picked up within a second.
• In deployment, files aren't watched, since much of the configuration is only read at startup. A touch file can be: set er.extensions.ERXConfigurationManager.PropertiesTouchFile to a path, and touching that file makes the application read its configuration again.
• On a running instance, from the admin console's Configuration page ("Set a property on this instance"), or in code:

ERXConfigurationManager.setProperty( "er.logging.level.com.example.billing", "DEBUG" );

// …and back to what the configuration says
ERXConfigurationManager.unsetProperty( "er.logging.level.com.example.billing" );

A level set on the running instance wins over every other layer, the backend's own configuration included, until it's unset or the instance stops; the Configuration page marks it as set on this instance, with a button to unset it. Setting a level through the log4j API (Logger.getLogger( … ).setLevel( … )) works on reload4j only: with logback, those calls go through log4j-over-slf4j, which can't set levels. The property works with both.

5. Existing log4j configuration

A Project Wonder application usually carries a block of log4j configuration in its Properties:

log4j.loggerFactory=er.extensions.logging.ERXLogger$Factory
log4j.rootCategory=INFO, A1
log4j.appender.A1=org.apache.log4j.ConsoleAppender
log4j.appender.A1.layout=er.extensions.logging.ERXPatternLayout
log4j.appender.A1.layout.ConversionPattern=%d{MMM dd HH:mm:ss} %$[%#] (%F:%L) %-5p %c %x - %t - %m%n
log4j.logger.er=INFO
log4j.logger.cayenne-sql=WARN

With ERLoggingReload4j, it keeps working unchanged: it's the backend's own configuration, layer 3.

With ERLoggingLogback, the levels are used (log4j.logger.* and the root's), but logback can't read log4j's appenders and layouts. It names those keys in one warning at startup, and uses er.logging.pattern for its console output instead.

Converted, most of such a block turns out to repeat the defaults. The block above comes down to:

er.logging.level.cayenne-sql=WARN
er.logging.pattern=%d{MMM dd HH:mm:ss} (%F:%L) %-5p %c - %t - %m%n

The root at INFO is the default, and so is er beneath it; log4j.loggerFactory only applies to reload4j. Once converted, the configuration works with either backend. Leave the layout out entirely if the default suits you.

6. WebObjects' own output

WebObjects writes through its own NSLog. wonder-slim sends that to slf4j too, from the first line of main(), so it lands in the same log, in the same layout, with whichever backend: NSLog.out to the logger NSLog at INFO, NSLog.err at WARN, NSLog.debug at DEBUG.

WebObjects writes a good deal of debug output while it starts (every one of its properties, its URLs, "Waiting for requests…"), and the startup report already says what matters of it, so it's held back: NSLog.debug reaches the log only from WebObjects' informational debug level up, and that level is capped at critical by default, whatever WebObjects' own properties say. To see the debug output, raise the cap with a JVM option (it's read before the configuration exists):

-Der.extensions.NSLog.debugLevel=2

Set er.extensions.ERXNSLogLog4jBridge.ignoreNSLogSettings=true to hand all of NSLog.debug to slf4j and decide with the NSLog logger's level instead.

7. When logging starts

Logging works from the first line of ERXApplication.main(), first to the console in the default layout, since the configuration doesn't exist yet. As soon as the configuration is composed, still in main(), logging is configured from it, before any framework initializes and before the application object is constructed. From there on, everything logged reaches the configured log: framework plugins, WebObjects' own startup, your application's constructor. The startup guide goes through the order in full.

In deployment, WebObjects sends the console to the WOOutputPath file while it constructs the application, and the console output follows it there: logback by itself, reload4j because wonder-slim tells it to.

8. The layout

er.logging.pattern is handed to whichever backend is in use, so write it in the conversions both understand:

Literal parentheses, as in (%F:%L), stay literal with both. Project Wonder's own additions to log4j's layout, %$ for the application's name and %# for its port, exist only in reload4j's ERXPatternLayout.

The classes behind all this are few: ERXLoggingBackend and ERXLoggingConfiguration in ERExtensions, and one backend in each logging module. The wonder-slim repository has them, and its docs/LOGGING.md goes into the details.