Hi,
Thanks for the quick response on this; sorry for my delay. In short, I get
that people don't want logging frameworks to fail, but in this case it is
failing (due to bad inputs) but not telling our application.
Here's a description of what our app does. When starting it, a "launcher"
program is started initially. This starts the actual long-running process,
then consumes output from it (which is where the stack trace is showing up)
until the main process decides that startup happened ok and sends a signal
(certain string in std out) telling the launcher it can exit. The main
process reads user settings from a properties file, including what kind of
logging to use, file logging and/or syslog.
What's happening is that it sees that file logging was specified (though
the same problem exists for errors in syslog properties), but a
non-writable directory may have been specified. Log4j2 then outputs a stack
trace but doesn't throw any exception to our code. So our code thinks
startup is ok, and right after signalling the launcher it replaces the
system err/out print streams with new ones that send any output to the
loggers. This is just in case any 3rd party libraries send something to sys
out/error; we want to redirect everything to the logs as the process is
meant to run for months and there is no other place for output.
Since the logger setup fails, I assume it's sending information to std
out/err as a default, but we've redirected that back to the logger and
don't see any output. I understand it might be a big change to not swallow
the exception and instead send it to the caller, but in the mean time is
there at least something we can check after this call returns to find out
that something didn't work?
Configurator.initialize(builder.build());
In case it helps, we have this file in our classpath at startup:
--- begin ---
<?xml version="1.0" encoding="UTF-8"?>
<!--
This dummy file is used only to keep log4j2 from outputting an error message
about "no configuration found" in the cases that [our app] exits before
logging
initialization can happen. Everything here is overridden at runtime when
an agent properly starts.
-->
<Configuration status="WARN">
<Appenders>
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level
%logger{36} - %msg%n"/>
</Console>
</Appenders>
<Loggers>
<Root level="error">
<AppenderRef ref="Console"/>
</Root>
</Loggers>
</Configuration>
--- end ---
I can share our configuration builder code also if it helps.
Thanks,
Bobby
On Wed, Nov 13, 2019 at 4:54 PM Ralph Goers <ralph.go...@dslextreme.com>
wrote:
> In general, our suggestion is to use the configuration file as a template
> and use dynamic components such as Lookups or Selectors. Choosing the log
> file directory could easily be handled by a Lookup, depending on what
> criteria you are using to determine it.
>
> In general, Logging Frameworks need not to fail. Most users really don’t
> like it if startup of the application fails due to logging issues. So when
> creation of a configuration fails Log4j logs the errors. In some cases it
> will just ignore the components that failed and in more serious cases it
> will ignore the created configuration, which would leave you with the
> default logging configuration.
>
> I am sure there are ways that we could detect that you want the exceptions
> propograted but I am sure it would take a bit of work.
>
> If you could provide more information on what you need to be dynamic I am
> sure we could help with that. Having said that though, there isn’t much
> that is going to help you with a Permission Denied exception trying to
> write to a log file except for providing a Fallback appender or enhancing
> the file appenders to support alternate locations.
>
> Ralph
>
> > On Nov 13, 2019, at 1:48 PM, Bobby Bissett <
> robert.biss...@enterprisedb.com> wrote:
> >
> > Hi all,
> >
> > We use log4j2, version 2.11.1, and have programmatic configuration
> because
> > we don't know until runtime what the logging settings are. For instance,
> > log directory for file logging, or syslog settings if that's used
> instead.
> >
> > I can provide the code we use to set things up if it helps, but don't
> know
> > if that's needed given description/exceptions below. Our problem is that
> > the Configurator.initialize(builder.build()) step doesn't throw
> exceptions
> > back to us. Our builder is:
> > ConfigurationBuilder<BuiltConfiguration> builder =
> > ConfigurationBuilderFactory.newConfigurationBuilder()
> >
> > Instead, it outputs stack traces to std err (or out), so we have large
> > stack traces at startup instead of a message what we would provide to the
> > end user. Worse, no exception is thrown back to our code, so we start up
> > anyway, except with no logging any more once we get to the point that std
> > out/err are supposed to go to our logs.
> >
> > The culprit is PluginBuilder#build, around line 128:
> > } catch (final Exception e) {
> > LOGGER.error("Could not create plugin of type {} for element
> > {}: {}",
> > this.clazz, node.getName(),
> > (e instanceof InvocationTargetException ?
> > ((InvocationTargetException) e).getCause() : e).toString(), e);
> > }
> >
> > The stacks output are below. Is there anything I can change to not have
> > log4j2 print stack traces, and more importantly find out that something
> > went wrong so we know to not keep running?
> >
> > Thanks,
> > Bobby
> >
> > Output at startup for a simple case like the log directory (for file
> > logging) not being writeable:
> >
> > 11/13/19 3:27:39 PM 2019-11-13 15:27:39,457 main ERROR FileManager
> > (/root/efm.log) java.io.FileNotFoundException: /root/efm.log (Permission
> > denied) java.io.FileNotFoundException: /root/efm.log (Permission denied)
> > 11/13/19 3:27:39 PM at java.io.FileOutputStream.open0(Native Method)
> > 11/13/19 3:27:39 PM at
> > java.io.FileOutputStream.open(FileOutputStream.java:270)
> > 11/13/19 3:27:39 PM at
> > java.io.FileOutputStream.<init>(FileOutputStream.java:213)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.appender.FileManager$FileManagerFactory.createManager(FileManager.java:422)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.appender.FileManager$FileManagerFactory.createManager(FileManager.java:406)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.appender.AbstractManager.getManager(AbstractManager.java:113)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.appender.OutputStreamManager.getManager(OutputStreamManager.java:114)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.appender.FileManager.getFileManager(FileManager.java:180)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.appender.FileAppender$Builder.build(FileAppender.java:95)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.appender.FileAppender$Builder.build(FileAppender.java:51)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:123)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:959)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:899)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:891)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:514)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:238)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.builder.impl.DefaultConfigurationBuilder.build(DefaultConfigurationBuilder.java:204)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.builder.impl.DefaultConfigurationBuilder.build(DefaultConfigurationBuilder.java:161)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.builder.impl.DefaultConfigurationBuilder.build(DefaultConfigurationBuilder.java:57)
> > 11/13/19 3:27:39 PM at [our code that is initializing the logging]
> > 11/13/19 3:27:39 PM
> > 11/13/19 3:27:39 PM 2019-11-13 15:27:39,469 main ERROR Could not create
> > plugin of type class org.apache.logging.log4j.core.appender.FileAppender
> > for element File: java.lang.IllegalStateException: ManagerFactory
> >
> [org.apache.logging.log4j.core.appender.FileManager$FileManagerFactory@7c83dc97
> ]
> > unable to create manager for [/root/efm.log] with data
> > [org.apache.logging.log4j.core.appender.FileManager$FactoryData@7748410a
> ]
> > java.lang.IllegalStateException: ManagerFactory
> >
> [org.apache.logging.log4j.core.appender.FileManager$FileManagerFactory@7c83dc97
> ]
> > unable to create manager for [/root/efm.log] with data
> > [org.apache.logging.log4j.core.appender.FileManager$FactoryData@7748410a
> ]
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.appender.AbstractManager.getManager(AbstractManager.java:115)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.appender.OutputStreamManager.getManager(OutputStreamManager.java:114)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.appender.FileManager.getFileManager(FileManager.java:180)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.appender.FileAppender$Builder.build(FileAppender.java:95)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.appender.FileAppender$Builder.build(FileAppender.java:51)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:123)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:959)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:899)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:891)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:514)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:238)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.builder.impl.DefaultConfigurationBuilder.build(DefaultConfigurationBuilder.java:204)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.builder.impl.DefaultConfigurationBuilder.build(DefaultConfigurationBuilder.java:161)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.builder.impl.DefaultConfigurationBuilder.build(DefaultConfigurationBuilder.java:57)
> > 11/13/19 3:27:39 PM at [our code that is initializing the logging]
> > 11/13/19 3:27:39 PM
> > 11/13/19 3:27:39 PM 2019-11-13 15:27:39,470 main ERROR Unable to invoke
> > factory method in class
> org.apache.logging.log4j.core.appender.FileAppender
> > for element File: java.lang.IllegalStateException: No factory method
> found
> > for class org.apache.logging.log4j.core.appender.FileAppender
> > java.lang.IllegalStateException: No factory method found for class
> > org.apache.logging.log4j.core.appender.FileAppender
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.findFactoryMethod(PluginBuilder.java:235)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:135)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:959)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:899)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:891)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:514)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:238)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.builder.impl.DefaultConfigurationBuilder.build(DefaultConfigurationBuilder.java:204)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.builder.impl.DefaultConfigurationBuilder.build(DefaultConfigurationBuilder.java:161)
> > 11/13/19 3:27:39 PM at
> >
> org.apache.logging.log4j.core.config.builder.impl.DefaultConfigurationBuilder.build(DefaultConfigurationBuilder.java:57)
> > 11/13/19 3:27:39 PM at [our code that is initializing the logging]
> > 11/13/19 3:27:39 PM
> > 11/13/19 3:27:39 PM 2019-11-13 15:27:39,470 main ERROR Null object
> returned
> > for File in Appenders.
> > 11/13/19 3:27:39 PM 2019-11-13 15:27:39,474 main ERROR Unable to locate
> > appender "file" for logger config "[our logger]"
> > 11/13/19 3:27:39 PM 2019-11-13 15:27:39,474 main ERROR Unable to locate
> > appender "file" for logger config "[other logger used in 3rd party lib]"
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-user-unsubscr...@logging.apache.org
> For additional commands, e-mail: log4j-user-h...@logging.apache.org
>
>
