Hello Bill,
What you could do is start the whole thing in a debugger and put a
breakpoint
in org.apache.kafka.clients.producer.KafkaProducer.KafkaProducer(ProducerConfig,
Serializer<K>, Serializer<V>) here:
} catch (Throwable t) {
// call close methods if internal objects are already
constructed
// this is to prevent resource leak. see KAFKA-2121
---> BREAKPOINT close(0, TimeUnit.MILLISECONDS, true);
// now propagate the exception
throw new KafkaException("Failed to construct kafka producer",
t);
}
This line 333 in the latest client.
Then you can dump the exception on the console and tell us what it is
because we are not seeing it in the log since the close method causes its
own NPE.
Finding what the Throwable is will be a lot.
Gary
On Thu, Aug 18, 2016 at 11:30 PM, Bill Okara <billok...@gmail.com> wrote:
> Thanks, Gary,
>
> you're probably right, the log in log.info seems to be the culprit.
>
> By doing the 'trace' in log4j2.xml, it seems that the initialization
> for the WebappClassLoader actually finished OK, but when initializing
> for the Parent Classloader, it's when the NullPointerException
> happened. Any idea why? or did the config in the previously attached
> src look legit?
>
> Thanks!
> Bill
>
> -------
> 2016-08-19 00:00:28,569 localhost-startStop-1 DEBUG Configuration
> XmlConfiguration[location=jndi:/localhost/log4j-appender/WEB-INF/classes/
> log4j2.xml]
> initialized
> 2016-08-19 00:00:28,570 localhost-startStop-1 DEBUG Starting
> configuration XmlConfiguration[location=jndi:/localhost/log4j-
> appender/WEB-INF/classes/log4j2.xml]
> 2016-08-19 00:00:28,579 localhost-startStop-1 DEBUG PluginManager
> 'Converter' found 41 plugins
> 2016-08-19 00:00:28,579 localhost-startStop-1 DEBUG Starting
> OutputStreamManager SYSTEM_OUT.false.false-3
> 2016-08-19 00:00:28,579 localhost-startStop-1 DEBUG Starting
> LoggerContext[name=1f32e575,
> org.apache.logging.log4j.core.LoggerContext@28b2955f]...
> 2016-08-19 00:00:28,580 localhost-startStop-1 DEBUG Reconfiguration
> started for context[name=1f32e575] at URI null
> (org.apache.logging.log4j.core.LoggerContext@28b2955f) with optional
> ClassLoader: null
> 2016-08-19 00:00:28,580 localhost-startStop-1 DEBUG Using
> configurationFactory
> org.apache.logging.log4j.core.config.ConfigurationFactory$Factory@42223c17
> 2016-08-19 00:00:28,580 localhost-startStop-1 TRACE Trying to find
> [log4j2-test1f32e575.properties] using context class loader
> WebappClassLoader
> context: /log4j-appender
> delegate: false
> repositories:
> /WEB-INF/classes/
> ----------> Parent Classloader:
> java.net.URLClassLoader@1f32e575
> class loader.
> 2016-08-19 00:00:28,598 localhost-startStop-1 TRACE Trying to find
> [log4j2.jsn] using ClassLoader.getSystemResource().
> 2016-08-19 00:00:28,599 localhost-startStop-1 TRACE Trying to find
> [log4j2.xml] using context class loader WebappClassLoader
> context: /log4j-appender
> delegate: false
> repositories:
> /WEB-INF/classes/
> ----------> Parent Classloader:
> java.net.URLClassLoader@1f32e575
> .
> 2016-08-19 00:00:28,602 localhost-startStop-1 DEBUG Initializing
> configuration XmlConfiguration[location=/opt/java/apache/apache-tomcat-
> 7.0.70/webapps/log4j-appender/WEB-INF/classes/log4j2.xml]
> 2016-08-19 00:00:28,603 localhost-startStop-1 DEBUG Installed script
> engines
> ...
> 016-08-19 00:00:28,619 localhost-startStop-1 DEBUG Configuration
> XmlConfiguration[location=/opt/java/apache/apache-tomcat-
> 7.0.70/webapps/log4j-appender/WEB-INF/classes/log4j2.xml]
> initialized
> 2016-08-19 00:00:28,619 localhost-startStop-1 DEBUG Starting
> configuration XmlConfiguration[location=/opt/java/apache/apache-tomcat-
> 7.0.70/webapps/log4j-appender/WEB-INF/classes/log4j2.xml]
> Aug 19, 2016 12:00:28 AM org.apache.catalina.core.ContainerBase
> addChildInternal
> SEVERE: ContainerBase.addChild: start:
> org.apache.catalina.LifecycleException: Failed to start component
> [StandardEngine[Catalina].StandardHost[localhost].StandardContext[/log4j-
> appender]]
> at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:153)
> at org.apache.catalina.core.ContainerBase.addChildInternal(
> ContainerBase.java:899)
> at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:875)
> at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:652)
> at org.apache.catalina.startup.HostConfig.deployDirectory(
> HostConfig.java:1260)
> at org.apache.catalina.startup.HostConfig$DeployDirectory.
> run(HostConfig.java:2002)
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(
> ThreadPoolExecutor.java:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(
> ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> Caused by: java.lang.ExceptionInInitializerError
> at org.apache.logging.log4j.core.appender.mom.kafka.
> DefaultKafkaProducerFactory.newKafkaProducer(DefaultKafkaProducerFactory.
> java:29)
> at org.apache.logging.log4j.core.appender.mom.kafka.KafkaManager.startup(
> KafkaManager.java:86)
> at org.apache.logging.log4j.core.appender.mom.kafka.KafkaAppender.start(
> KafkaAppender.java:96)
> at org.apache.logging.log4j.core.config.AbstractConfiguration.
> start(AbstractConfiguration.java:247)
> at org.apache.logging.log4j.core.LoggerContext.setConfiguration(
> LoggerContext.java:496)
> at org.apache.logging.log4j.core.LoggerContext.start(
> LoggerContext.java:249)
> at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(
> Log4jContextFactory.java:239)
> at org.apache.logging.log4j.core.config.Configurator.
> initialize(Configurator.java:157)
> at org.apache.logging.log4j.web.Log4jWebInitializerImpl.initializeNonJndi(
> Log4jWebInitializerImpl.java:167)
> at org.apache.logging.log4j.web.Log4jWebInitializerImpl.start(
> Log4jWebInitializerImpl.java:109)
> at org.apache.logging.log4j.web.Log4jServletContainerInitializ
> er.onStartup(Log4jServletContainerInitializer.java:57)
> at org.apache.catalina.core.StandardContext.startInternal(
> StandardContext.java:5604)
> at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:147)
> ... 10 more
> Caused by: java.lang.NullPointerException
> at org.apache.kafka.clients.producer.KafkaProducer.close(
> KafkaProducer.java:658)
> at org.apache.kafka.clients.producer.KafkaProducer.<init>(
> KafkaProducer.java:333)
> at org.apache.kafka.clients.producer.KafkaProducer.<init>(
> KafkaProducer.java:188)
> -------------
>
> On Thu, Aug 18, 2016 at 5:40 PM, Gary Gregory <garydgreg...@gmail.com>
> wrote:
> > Based on the stack trace, it looks like the Slf4j logger in KafkaProducer
> > is null:
> >
> > log.info("Closing the Kafka producer with timeoutMillis = {}
> ms.",
> > timeUnit.toMillis(timeout));
> >
> > It does not look like timeUnit can be null, so it must be log.
> >
> > The root problem of course if that we have an exception thrown in the
> > KafkaProducer
> > ctor.
> >
> > Gary
> >
> > On Thu, Aug 18, 2016 at 3:44 PM, Bill Okara <billok...@gmail.com> wrote:
> >
> >> tried again, seemed like the .out extension got filtered out by mail
> >> server...
> >>
> >> On Thu, Aug 18, 2016 at 4:41 PM, Bill Okara <billok...@gmail.com>
> wrote:
> >> > attach the catalina.out again, didn't seem to go through last time...
> >> >
> >> >
> >> > On Thu, Aug 18, 2016 at 4:33 PM, Bill Okara <billok...@gmail.com>
> wrote:
> >> >> Hi,
> >> >>
> >> >> When trying out the log4j2 Kafka appender, it works ok if all the
> >> >> log4j2/kafka-client related jars are packaged in the webapp's
> >> >> WEB-INF/lib, like:
> >> >>
> >> >>>ls WEB-INF/lib/
> >> >> jackson-core-2.8.1.jar
> >> >> log4j-core-2.6.2.jar
> >> >> lz4-1.3.0.jar
> >> >> kafka-clients-0.10.0.1.jar
> >> >> log4j-slf4j-impl-2.6.2.jar
> >> >> slf4j-api-1.7.21.jar
> >> >> log4j-api-2.6.2.jar
> >> >> log4j-web-2.6.2.jar
> >> >> snappy-java-1.1.2.6.jar
> >> >>
> >> >>
> >> >> But if the jars are provided in tomcat/lib (for all webapps), and
> each
> >> >> webapp will have its own log4j2.xml (as in attached war), then when
> >> >> launching the webapp, will encounter:
> >> >>
> >> >> -----
> >> >> Caused by: java.lang.NullPointerException
> >> >> at org.apache.kafka.clients.producer.KafkaProducer.close(
> >> KafkaProducer.java:658)
> >> >> at org.apache.kafka.clients.producer.KafkaProducer.<init>(
> >> KafkaProducer.java:333)
> >> >> at org.apache.kafka.clients.producer.KafkaProducer.<init>(
> >> KafkaProducer.java:188)
> >> >> at org.apache.logging.log4j.core.appender.mom.kafka.
> >> DefaultKafkaProducerFactory.newKafkaProducer(
> DefaultKafkaProducerFactory.
> >> java:29)
> >> >> at org.apache.logging.log4j.core.appender.mom.kafka.
> >> KafkaManager.startup(KafkaManager.java:86)
> >> >> at org.apache.logging.log4j.core.appender.mom.kafka.
> >> KafkaAppender.start(KafkaAppender.java:96)
> >> >> at org.apache.logging.log4j.core.
> config.AbstractConfiguration.
> >> start(AbstractConfiguration.java:247)
> >> >> at org.apache.logging.log4j.core.LoggerContext.
> >> setConfiguration(LoggerContext.java:496)
> >> >> at org.apache.logging.log4j.core.LoggerContext.reconfigure(
> >> LoggerContext.java:566)
> >> >> ---------
> >> >>
> >> >> (full stack trace as in attached catalina.out)
> >> >>
> >> >>
> >> >> To reproduce the error, simply:
> >> >> 1) build the attached webapp, and deploy the output to tomcat/webapps
> >> >> 2) move the WEB-INF/lib/*.jar to tomcat/lib (make sure WEB-INF/lib is
> >> >> empty after move)
> >> >> 3) start tomcat
> >> >>
> >> >> Tested with tomcat 7.0.70
> >> >>
> >> >> Anyone encounter similar problem? or is this a bug? (log4j2 or
> >> >> kafka-client bug?)
> >> >>
> >> >>
> >> >> Thanks,
> >> >> Bill
> >>
> >>
> >> ---------------------------------------------------------------------
> >> To unsubscribe, e-mail: log4j-user-unsubscr...@logging.apache.org
> >> For additional commands, e-mail: log4j-user-h...@logging.apache.org
> >>
> >
> >
> >
> > --
> > E-Mail: garydgreg...@gmail.com | ggreg...@apache.org
> > Java Persistence with Hibernate, Second Edition
> > <http://www.manning.com/bauer3/>
> > JUnit in Action, Second Edition <http://www.manning.com/tahchiev/>
> > Spring Batch in Action <http://www.manning.com/templier/>
> > Blog: http://garygregory.wordpress.com
> > Home: http://garygregory.com/
> > Tweet! http://twitter.com/GaryGregory
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-user-unsubscr...@logging.apache.org
> For additional commands, e-mail: log4j-user-h...@logging.apache.org
>
>
--
E-Mail: garydgreg...@gmail.com | ggreg...@apache.org
Java Persistence with Hibernate, Second Edition
<http://www.manning.com/bauer3/>
JUnit in Action, Second Edition <http://www.manning.com/tahchiev/>
Spring Batch in Action <http://www.manning.com/templier/>
Blog: http://garygregory.wordpress.com
Home: http://garygregory.com/
Tweet! http://twitter.com/GaryGregory
