Reputation: 15907
We don't consider our app running properly if log4j2
isn't configured properly as specified in the config file. How do i reliably detect whether errors have occurred during log4j2
initialization and been printed on the console from java? There are (at least) two sources of bad configuration:
setConfiguration()
.This question is about the second point. It looks like log4j2
internally does try{...} catch(e) { LOGGER.error("bla bla", e) }
during initialization making it impossible to detect such problems.
Errors printed to the console that no human is ever going to see is bad. We'd rather have our app crash!
I'm surprised that I can't find a way to programmatically ask log4j2
: "Did I get the configuration I asked for?". Is there something I have overlooked? E.g. some way to detect whether anything has been logged yet?
Here is the console output we're seeing. Yes, there is permission denied to /path/to/file
- how do I detect that?
2015-10-15 17:43:50,539 main ERROR FileManager (/path/to/file) java.io.FileNotFoundException: /path/to/file (Permission denied)
2015-10-15 17:43:50,541 main ERROR Unable to invoke factory method in class class org.apache.logging.log4j.core.appender.FileAppender for element File. java.lang.reflect.InvocationTargetException
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:136)
at org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:794)
at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:734)
at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:726)
at org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:383)
at org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:161)
at org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:173)
at org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:422)
at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:494)
at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:510)
at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:199)
at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:146)
at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:41)
at org.apache.logging.log4j.LogManager.getContext(LogManager.java:177)
at org.apache.logging.log4j.LogManager.getLogger(LogManager.java:447)
at (our first call to org.apache.logging.log4j.LogManager.getLogger())
Looking in the code for LoggerContext.reconfigure()
, I see:
private void reconfigure(final URI configURI) {
<snip>
final Configuration instance = ConfigurationFactory.getInstance().getConfiguration(name, configURI, cl);
setConfiguration(instance);
<snip>
}
And during the call of setConfiguration()
, there is this in org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build
:
try {
<snip>
final Object plugin = factory.invoke(null, params);
<snip>
return plugin;
} catch (final Exception e) {
LOGGER.error("Unable to invoke factory method in class {} for element {}.", this.clazz, this.node.getName(),
e);
return null;
}
So the problem was not with getConfiguration()
from the ConfigurationFactory
, but with the subsequent setConfiguration()
, and there seems to be no way to detect that there was a problem... :-(
We're setting -Dlog4j.configurationFile=<file>
on the java command line, and there are already several posts on how to detect if <file>
is missing. One of which suggests to -Dlog4j.configurationFactory
with our own ConfigurationFactory
. But no amount of fiddling with our own ConfigurationFactory
is going to help during setConfiguration()
to detect the second point ("2." above) as far as I can reason.
We're running log4j2 version 2.4 on openjdk 8 on debian stable/jessie.
Upvotes: 2
Views: 1630
Reputation: 15907
It turns out the Log4j2
internals use a special StatusLogger
, that has a getStatusData()
method, so here's what to do:
import org.apache.logging.log4j.status.StatusData;
import org.apache.logging.log4j.status.StatusLogger;
...
StatusLogger statusLogger = StatusLogger.getLogger();
if (statusLogger.getStatusData().size() > 0) {
System.out.printf(
"Logged %d messages\n",
statusLogger.getStatusData().size()
);
// Investigate List<StatusData> if you want
for(StatusData data : statusLogger.getStatusData()) {
System.out.printf(
" Level %s message: %s\n",
data.getLevel(),
data.getMessage().getFormattedMessage()
);
}
System.err.println("exiting due to unexpected console status logs");
System.exit(1);
}
Upvotes: 2