[ https://issues.apache.org/jira/browse/KAFKA-5226?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16008885#comment-16008885 ]
Ian Springer commented on KAFKA-5226: ------------------------------------- That's not how I read the stack trace. If my code was causing the NPE, the line immediately after "Caused by: java.lang.NullPointerException: null" (i.e. the first line of the root cause stack trace) would be a line from one of my classes. I read it as either sourceNode or rawRecord being null. I suppose it's also possible something is truncating the stack trace. My uncaught exception handler is simply logging the error using Logback. {code} @Override public void uncaughtException(Thread t, Throwable e) { log.error("Uncaught exception in thread [{}]", t.getName(), e); } {code} I don't think the JDK is trimming the stack trace at all, since the exception only occurred twice. > NullPointerException (NPE) in SourceNodeRecordDeserializer.deserialize > ---------------------------------------------------------------------- > > Key: KAFKA-5226 > URL: https://issues.apache.org/jira/browse/KAFKA-5226 > Project: Kafka > Issue Type: Bug > Components: streams > Affects Versions: 0.10.2.1 > Environment: 64-bit Amazon Linux, JDK8 > Reporter: Ian Springer > > I saw the following NPE in our Kafka Streams app, which has 3 nodes running > on 3 separate machines.. Out of hundreds of messages processed, the NPE only > occurred twice. I are not sure of the cause, so I am unable to reproduce it. > I'm hoping the Kafka Streams team can guess the cause based on the stack > trace. If I can provide any additional details about our app, please let me > know. > > {code} > INFO 2017-05-10 02:58:26,021 org.apache.kafka.common.utils.AppInfoParser > Kafka version : 0.10.2.1 > INFO 2017-05-10 02:58:26,021 org.apache.kafka.common.utils.AppInfoParser > Kafka commitId : e89bffd6b2eff799 > INFO 2017-05-10 02:58:26,031 o.s.context.support.DefaultLifecycleProcessor > Starting beans in phase 0 > INFO 2017-05-10 02:58:26,075 org.apache.kafka.streams.KafkaStreams > stream-client [evergage-app-bd9c9868-4b9b-4d2e-850f-9b5bec1fc0a9] State > transition from CREATED to RUNNING. > INFO 2017-05-10 02:58:26,075 org.apache.kafka.streams.KafkaStreams > stream-client [evergage-app-bd9c9868-4b9b-4d2e-850f-9b5bec1fc0a9] Started > Kafka Stream process > INFO 2017-05-10 02:58:26,086 o.a.k.c.consumer.internals.AbstractCoordinator > Discovered coordinator p1kaf1.prod.apptegic.com:9092 (id: 2147482646 rack: > null) for group evergage-app. > INFO 2017-05-10 02:58:26,126 o.a.k.c.consumer.internals.ConsumerCoordinator > Revoking previously assigned partitions [] for group evergage-app > INFO 2017-05-10 02:58:26,126 org.apache.kafka.streams.KafkaStreams > stream-client [evergage-app-bd9c9868-4b9b-4d2e-850f-9b5bec1fc0a9] State > transition from RUNNING to REBALANCING. > INFO 2017-05-10 02:58:26,127 o.a.k.c.consumer.internals.AbstractCoordinator > (Re-)joining group evergage-app > INFO 2017-05-10 02:58:27,712 o.a.k.c.consumer.internals.AbstractCoordinator > Successfully joined group evergage-app with generation 18 > INFO 2017-05-10 02:58:27,716 o.a.k.c.consumer.internals.ConsumerCoordinator > Setting newly assigned partitions [us.app.Trigger-0] for group evergage-app > INFO 2017-05-10 02:58:27,716 org.apache.kafka.streams.KafkaStreams > stream-client [evergage-app-bd9c9868-4b9b-4d2e-850f-9b5bec1fc0a9] State > transition from REBALANCING to REBALANCING. > INFO 2017-05-10 02:58:27,729 > o.a.kafka.streams.processor.internals.StreamTask task [0_0] Initializing > state stores > INFO 2017-05-10 02:58:27,731 > o.a.kafka.streams.processor.internals.StreamTask task [0_0] Initializing > processor nodes of the topology > INFO 2017-05-10 02:58:27,742 org.apache.kafka.streams.KafkaStreams > stream-client [evergage-app-bd9c9868-4b9b-4d2e-850f-9b5bec1fc0a9] State > transition from REBALANCING to RUNNING. > [14 hours pass...] > INFO 2017-05-10 16:21:27,476 o.a.k.c.consumer.internals.ConsumerCoordinator > Revoking previously assigned partitions [us.app.Trigger-0] for group > evergage-app > INFO 2017-05-10 16:21:27,477 org.apache.kafka.streams.KafkaStreams > stream-client [evergage-app-bd9c9868-4b9b-4d2e-850f-9b5bec1fc0a9] State > transition from RUNNING to REBALANCING. > INFO 2017-05-10 16:21:27,482 o.a.k.c.consumer.internals.AbstractCoordinator > (Re-)joining group evergage-app > INFO 2017-05-10 16:21:27,489 o.a.k.c.consumer.internals.AbstractCoordinator > Successfully joined group evergage-app with generation 19 > INFO 2017-05-10 16:21:27,489 o.a.k.c.consumer.internals.ConsumerCoordinator > Setting newly assigned partitions [us.app.Trigger-0] for group evergage-app > INFO 2017-05-10 16:21:27,489 org.apache.kafka.streams.KafkaStreams > stream-client [evergage-app-bd9c9868-4b9b-4d2e-850f-9b5bec1fc0a9] State > transition from REBALANCING to REBALANCING. > INFO 2017-05-10 16:21:27,489 > o.a.kafka.streams.processor.internals.StreamTask task [0_0] Initializing > processor nodes of the topology > INFO 2017-05-10 16:21:27,493 org.apache.kafka.streams.KafkaStreams > stream-client [evergage-app-bd9c9868-4b9b-4d2e-850f-9b5bec1fc0a9] State > transition from REBALANCING to RUNNING. > INFO 2017-05-10 16:21:30,584 o.a.k.c.consumer.internals.ConsumerCoordinator > Revoking previously assigned partitions [us.app.Trigger-0] for group > evergage-app > INFO 2017-05-10 16:21:30,584 org.apache.kafka.streams.KafkaStreams > stream-client [evergage-app-bd9c9868-4b9b-4d2e-850f-9b5bec1fc0a9] State > transition from RUNNING to REBALANCING. > INFO 2017-05-10 16:21:30,588 o.a.k.c.consumer.internals.AbstractCoordinator > (Re-)joining group evergage-app > INFO 2017-05-10 16:21:30,593 o.a.k.c.consumer.internals.AbstractCoordinator > Successfully joined group evergage-app with generation 20 > INFO 2017-05-10 16:21:30,594 o.a.k.c.consumer.internals.ConsumerCoordinator > Setting newly assigned partitions [demo.retail.Trigger-0, us.app.Trigger-0] > for group evergage-app > INFO 2017-05-10 16:21:30,594 org.apache.kafka.streams.KafkaStreams > stream-client [evergage-app-bd9c9868-4b9b-4d2e-850f-9b5bec1fc0a9] State > transition from REBALANCING to REBALANCING. > INFO 2017-05-10 16:21:30,595 > o.a.kafka.streams.processor.internals.StreamTask task [0_0] Initializing > state stores > INFO 2017-05-10 16:21:30,596 > o.a.kafka.streams.processor.internals.StreamTask task [0_0] Initializing > processor nodes of the topology > INFO 2017-05-10 16:21:30,602 org.apache.kafka.streams.KafkaStreams > stream-client [evergage-app-bd9c9868-4b9b-4d2e-850f-9b5bec1fc0a9] State > transition from REBALANCING to RUNNING. > INFO 2017-05-10 16:21:30,698 org.apache.kafka.clients.producer.KafkaProducer > Closing the Kafka producer with timeoutMillis = 9223372036854775807 ms. > WARN 2017-05-10 16:21:30,703 > o.a.kafka.streams.processor.internals.StreamThread stream-thread > [StreamThread-1] Unexpected state transition from RUNNING to NOT_RUNNING. > ERROR 2017-05-10 16:21:30,704 > c.a.a.web.server.UncaughtExceptionLoggingListener Uncaught exception in > thread [StreamThread-1] > org.apache.kafka.streams.errors.StreamsException: Failed to deserialize key > for record. topic=demo.retail.Trigger, partition=0, offset=0 > at > org.apache.kafka.streams.processor.internals.SourceNodeRecordDeserializer.deserialize(SourceNodeRecordDeserializer.java:38) > at > org.apache.kafka.streams.processor.internals.RecordQueue.addRawRecords(RecordQueue.java:85) > at > org.apache.kafka.streams.processor.internals.PartitionGroup.addRawRecords(PartitionGroup.java:117) > at > org.apache.kafka.streams.processor.internals.StreamTask.addRecords(StreamTask.java:158) > at > org.apache.kafka.streams.processor.internals.StreamThread.runLoop(StreamThread.java:605) > at > org.apache.kafka.streams.processor.internals.StreamThread.run(StreamThread.java:361) > Caused by: java.lang.NullPointerException: null > at > org.apache.kafka.streams.processor.internals.SourceNodeRecordDeserializer.deserialize(SourceNodeRecordDeserializer.java:36) > ... 5 common frames omitted > {code} -- This message was sent by Atlassian JIRA (v6.3.15#6346)