Details

    • Type: Bug
    • Status: Resolved
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 5.1.0
    • Component/s: Log
    • Rank:
      1|i00fnj:

      Description

      The following error can be seen in `metrics` service, where log handler resides.

      2018-07-27 21:24:54,200 - ERROR [metrics-executor-10:c.c.c.l.r.KafkaLogReader@108] - Got exception: 
      java.lang.ArrayIndexOutOfBoundsException: null
              at java.lang.System.arraycopy(Native Method) ~[na:1.8.0_161]
              at org.apache.avro.io.BinaryDecoder.doReadBytes(BinaryDecoder.java:329) ~[org.apache.avro.avro-1.6.2.jar:1.6.2]
              at org.apache.avro.io.BinaryDecoder.readString(BinaryDecoder.java:255) ~[org.apache.avro.avro-1.6.2.jar:1.6.2]
              at org.apache.avro.io.ValidatingDecoder.readString(ValidatingDecoder.java:107) ~[org.apache.avro.avro-1.6.2.jar:1.6.2]
              at org.apache.avro.generic.GenericDatumReader.readString(GenericDatumReader.java:336) ~[org.apache.avro.avro-1.6.2.jar:1.6.2]
              at org.apache.avro.generic.GenericDatumReader.readString(GenericDatumReader.java:329) ~[org.apache.avro.avro-1.6.2.jar:1.6.2]
              at org.apache.avro.generic.GenericDatumReader.read(GenericDatumReader.java:150) ~[org.apache.avro.avro-1.6.2.jar:1.6.2]
              at org.apache.avro.generic.GenericDatumReader.read(GenericDatumReader.java:148) ~[org.apache.avro.avro-1.6.2.jar:1.6.2]
              at org.apache.avro.generic.GenericDatumReader.readRecord(GenericDatumReader.java:173) ~[org.apache.avro.avro-1.6.2.jar:1.6.2]
              at org.apache.avro.generic.GenericDatumReader.read(GenericDatumReader.java:144) ~[org.apache.avro.avro-1.6.2.jar:1.6.2]
              at org.apache.avro.generic.GenericDatumReader.read(GenericDatumReader.java:135) ~[org.apache.avro.avro-1.6.2.jar:1.6.2]
              at co.cask.cdap.logging.serialize.LoggingEventSerializer.toGenericRecord(LoggingEventSerializer.java:130) ~[na:na]
              at co.cask.cdap.logging.serialize.LoggingEventSerializer.fromBytes(LoggingEventSerializer.java:83) ~[na:na]
              at co.cask.cdap.logging.read.KafkaLogReader$KafkaCallback.handle(KafkaLogReader.java:252) ~[na:na]
              at co.cask.cdap.logging.kafka.KafkaConsumer.fetchMessages(KafkaConsumer.java:90) ~[na:na]
              at co.cask.cdap.logging.read.KafkaLogReader.fetchLogEvents(KafkaLogReader.java:202) ~[na:na]
              at co.cask.cdap.logging.read.KafkaLogReader.getLogNext(KafkaLogReader.java:106) ~[na:na]
              at co.cask.cdap.logging.read.DistributedLogReader.getLogNext(DistributedLogReader.java:73) [na:na]
              at co.cask.cdap.logging.gateway.handlers.AbstractLogHandler.doNext(AbstractLogHandler.java:127) [na:na]
              at co.cask.cdap.logging.gateway.handlers.LogHandler.runIdNext(LogHandler.java:128) [na:na]
              at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_161]
              at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_161]
              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_161]
              at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_161]
              at co.cask.http.internal.HttpMethodInfo.invoke(HttpMethodInfo.java:82) [co.cask.http.netty-http-1.0.0.jar:na]
              at co.cask.http.internal.HttpDispatcher.channelRead(HttpDispatcher.java:45) [co.cask.http.netty-http-1.0.0.jar:na]
              at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
              at io.netty.channel.AbstractChannelHandlerContext.access$600(AbstractChannelHandlerContext.java:38) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
              at io.netty.channel.AbstractChannelHandlerContext$7.run(AbstractChannelHandlerContext.java:353) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
              at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
              at io.netty.util.concurrent.NonStickyEventExecutorGroup$NonStickyOrderedEventExecutor.run(NonStickyEventExecutorGroup.java:245) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
              at io.netty.util.concurrent.UnorderedThreadPoolEventExecutor$NonNotifyRunnable.run(UnorderedThreadPoolEventExecutor.java:277) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
              at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_161]
              at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_161]
              at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_161]
              at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [na:1.8.0_161]
              at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_161]
              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_161]
              at java.lang.Thread.run(Thread.java:748) [na:1.8.0_161]
      2018-07-27 21:24:54,200 - ERROR [metrics-executor-19:c.c.c.l.r.KafkaLogReader@108] - Got exception: 
      java.lang.ArrayIndexOutOfBoundsException: 23
              at org.apache.avro.io.parsing.Symbol$Alternative.getSymbol(Symbol.java:364) ~[org.apache.avro.avro-1.6.2.jar:1.6.2]
              at org.apache.avro.io.ResolvingDecoder.doAction(ResolvingDecoder.java:229) ~[org.apache.avro.avro-1.6.2.jar:1.6.2]
              at org.apache.avro.io.parsing.Parser.advance(Parser.java:88) ~[org.apache.avro.avro-1.6.2.jar:1.6.2]
              at org.apache.avro.io.ResolvingDecoder.readIndex(ResolvingDecoder.java:206) ~[org.apache.avro.avro-1.6.2.jar:1.6.2]
              at org.apache.avro.generic.GenericDatumReader.read(GenericDatumReader.java:148) ~[org.apache.avro.avro-1.6.2.jar:1.6.2]
              at org.apache.avro.generic.GenericDatumReader.readRecord(GenericDatumReader.java:173) ~[org.apache.avro.avro-1.6.2.jar:1.6.2]
              at org.apache.avro.generic.GenericDatumReader.read(GenericDatumReader.java:144) ~[org.apache.avro.avro-1.6.2.jar:1.6.2]
              at org.apache.avro.generic.GenericDatumReader.read(GenericDatumReader.java:135) ~[org.apache.avro.avro-1.6.2.jar:1.6.2]
              at co.cask.cdap.logging.serialize.LoggingEventSerializer.toGenericRecord(LoggingEventSerializer.java:130) ~[na:na]
              at co.cask.cdap.logging.serialize.LoggingEventSerializer.fromBytes(LoggingEventSerializer.java:83) ~[na:na]
              at co.cask.cdap.logging.read.KafkaLogReader$KafkaCallback.handle(KafkaLogReader.java:252) ~[na:na]
              at co.cask.cdap.logging.kafka.KafkaConsumer.fetchMessages(KafkaConsumer.java:90) ~[na:na]
              at co.cask.cdap.logging.read.KafkaLogReader.fetchLogEvents(KafkaLogReader.java:202) ~[na:na]
              at co.cask.cdap.logging.read.KafkaLogReader.getLogNext(KafkaLogReader.java:106) ~[na:na]
              at co.cask.cdap.logging.read.DistributedLogReader.getLogNext(DistributedLogReader.java:73) [na:na]
              at co.cask.cdap.logging.gateway.handlers.AbstractLogHandler.doNext(AbstractLogHandler.java:127) [na:na]
              at co.cask.cdap.logging.gateway.handlers.LogHandler.runIdNext(LogHandler.java:128) [na:na]
              at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_161]
              at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_161]
              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_161]
              at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_161]
              at co.cask.http.internal.HttpMethodInfo.invoke(HttpMethodInfo.java:82) [co.cask.http.netty-http-1.0.0.jar:na]
              at co.cask.http.internal.HttpDispatcher.channelRead(HttpDispatcher.java:45) [co.cask.http.netty-http-1.0.0.jar:na]
              at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
              at io.netty.channel.AbstractChannelHandlerContext.access$600(AbstractChannelHandlerContext.java:38) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
              at io.netty.channel.AbstractChannelHandlerContext$7.run(AbstractChannelHandlerContext.java:353) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
              at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
              at io.netty.util.concurrent.NonStickyEventExecutorGroup$NonStickyOrderedEventExecutor.run(NonStickyEventExecutorGroup.java:245) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
              at io.netty.util.concurrent.UnorderedThreadPoolEventExecutor$NonNotifyRunnable.run(UnorderedThreadPoolEventExecutor.java:277) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
              at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_161]
              at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_161]
              at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_161]
              at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [na:1.8.0_161]
              at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_161]
              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_161]
              at java.lang.Thread.run(Thread.java:748) [na:1.8.0_161] 

      The cause may be related to multi-threaded usage of LoggingEventSerializer, a class which is not ThreadSafe.

        Attachments

          Activity

            People

            • Assignee:
              yaojie Yaojie Feng
              Reporter:
              ali.anwar Ali Anwar
            • Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: