Quieting JUL Warnings That Maven Tags as [ERROR]

In a headless MPS build driven by Maven with the maven-antrun-plugin, several loggers inside MPS emit informational messages at WARNING level. They are using java.util.logging — commonly abbreviated JUL — the logging framework built into the JDK. Examples include jetbrains.mps.classloading.ModulesWatcher, jetbrains.mps.persistence.ModelSourceRootWalker, and jetbrains.mps.persistence.DefaultModelRoot. Here is an excerpt from an actual CI run:

These messages are not errors. The build succeeds. However, they appear in the Maven output prefixed with [ERROR], which visually mixes them with actual build failures and makes real errors harder to locate. On a large CI log, a dozen mislabelled warnings can hide a single genuine failure.

The messages are logged as WARNING by MPS via java.util.logging. JUL’s default ConsoleHandler writes WARNING records to System.err. Somewhere in the pipeline between stderr and the final Maven output, stderr content gets tagged as [ERROR]. That is likely why a WARNING written to stderr shows up as an error in CI.

The tag depends on the stream, not on the JUL severity: bytes on stderr get [ERROR], bytes on stdout get [INFO]. Whatever assigns the tag looks at where the bytes came from, not at what they say.

Two intervention points are available: stop the message at the source (filter), or change the stream it uses (redirect).

A JUL configuration file raises the log level of the affected loggers to SEVERE:

The configuration file is passed to the JVM via -Djava.util.logging.config.file=/path/to/logging.properties. Once loaded, JUL drops all WARNING records from the listed loggers before they reach any handler.

Consequences. The messages are gone from the log. If one of these loggers later emits a new WARNING that would have been informative, it is dropped as well. This solution treats output from the affected loggers as irrelevant noise.

A custom JUL handler writes to System.out instead of System.err, while preserving System.err for SEVERE records:

StreamHandler buffers its output, so the explicit flush() after each publish() call is necessary; without it, records may appear late or interleave unexpectedly with output from other handlers.

The JUL properties file routes the affected loggers through this handler and detaches them from the root handler chain:

handlers registers ConsoleHandler on the root logger. .level sets the root logger’s own level, which every logger in the tree without its own explicit level inherits  — including the three MPS loggers redirected below, which have no explicit level of their own. ConsoleHandler.level sets the handler’s own, independent level. A handler filters separately from the logger it’s attached to, regardless of which of the two is stricter. And ConsoleHandler.formatter sets the formatter explicitly, matching ConsoleHandler own default. These properties and their defaults are documented in the ConsoleHandler class documentation ^[2] and ^[3].

The JUL properties file also routes the affected loggers through this handler and detaches them from the root handler chain:

The useParentHandlers = false line is required. Without it, each record goes both to the custom handler and to the root ConsoleHandler, appearing twice: once on stdout, once on stderr.

The compiled handler must be available to the JVM early in startup, before the first log call. In principle, adding the JAR to the regular classpath (-cp) would work, since JUL loads handler classes through the system classloader. In this setup, however, we pass the logging configuration via JAVA_TOOL_OPTIONS (see below), which propagates to any downstream forked JVMs. Placing the handler JAR on the bootclasspath guarantees availability regardless of the classpath configuration each fork ends up with:

Consequences. The WARNING records are kept visible in the log, but appear with an [INFO] prefix (because Maven tags stdout as [INFO]). Real SEVERE records still route through stderr and appear as [ERROR], preserving the ability to see genuine errors from the same loggers.

The two solutions differ in what happens to future, unexpected messages from the affected loggers.

Solution A minimises the moving parts. It is one properties file. It fits situations where the loggers are known to produce only irrelevant noise, and preserving that assumption is acceptable.

Solution B costs a Java class, a compile step, and a bootclasspath entry. It fits situations where the loggers may occasionally produce information worth seeing, and only the [ERROR] labelling is the problem, not the content.

The JVM arguments described above (-Xbootclasspath/a:…​ and -Djava.util.logging.config.file=…​) can be passed via either MAVEN_OPTS or JAVA_TOOL_OPTIONS. The two behave differently:

If the build has any forked JVMs downstream of Maven (test runners, generator tasks, RCP builds), those forks need the same logging configuration. In that case, JAVA_TOOL_OPTIONS is required. MAVEN_OPTS alone leaves the forked JVMs on their default JUL configuration, and the warnings reappear from those processes.

When JAVA_TOOL_OPTIONS is set, the JVM emits a startup notification:

This message is emitted by HotSpot itself, written to stderr at every JVM start, and consequently appears as [ERROR] in the CI log. It is not an actual error.

The message cannot be disabled through JVM flags. An OpenJDK bug requesting a suppression option was filed in 2014 and closed with resolution Won’t Fix ^[7]. The rationale given in the bug comments is brief: "This will not be implemented, as it may introduce a vulnerability."

Practical option: accept the single cosmetic line per JVM start and document it.

After the redirect, SimpleFormatter writes each log entry across two lines by default. In the CI log, each line receives its own [INFO] prefix, and the first line ends with the method name of the log call (warning), which visually resembles a severity tag and can be mistaken for a duplicate:

The fix is a format string in the JUL properties file:

The format tokens are documented in the java.util.logging.SimpleFormatter API ^[8]. %1$tF %1$tT is ISO date and time, %4$s is the level, %3$s is the logger name, %5$s is the message, %6$s is the stack trace if present, and %n is one newline. The same log entry now appears as a single line:

One entry per line, one prefix per line.

With Solution B in place, the CI log shows the affected warnings prefixed as [INFO] instead of [ERROR]. Real SEVERE events from the same loggers continue to appear as [ERROR]. The build itself is unchanged; only the log presentation is corrected.