On Fri, Aug 19, 2016 at 8:56 AM, Bill Okara <billok...@gmail.com> wrote:
> Hi Gary,
>
> it turned out that the first NullPointerException is caused by the
> same reason, that is, in:
>
> private KafkaProducer(ProducerConfig config, Serializer<K>
> keySerializer, Serializer<V> valueSerializer) {
> try {
> log.trace("Starting the Kafka producer");
>
>
> the log in log.trace(...) is NULL
>
> So I guess the question is why it (the log) is null when trying to
> initialize the Parent Classloader (which is the tomcat common
> classloader)? And this only happened is all the log4j* jars are put in
> tomcat/lib vs packaged in WEB-INF/lib.
>
Good question, does this happen if Log4j is out of the picture? IOW, does
the Slf4j log static get initialized properly?
private static final Logger log =
LoggerFactory.getLogger(KafkaProducer.class);
Gary
>
> Thanks!
> Bill
>
>
> On Fri, Aug 19, 2016 at 1:46 AM, Gary Gregory <garydgreg...@gmail.com>
> wrote:
> > 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
>
> ---------------------------------------------------------------------
> 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
