Uploaded image for project: 'CDAP'
  1. CDAP
  2. CDAP-13988

Invalid message publish is indefinitely retried to TMS.

    XMLWordPrintableJSON

    Details

    • Release Notes:
      Fixed an error that where TMS publishing was retried indefinitely, if the first attempt failed.
    • Rank:
      1|i00fsf:

      Description

      I am seeing the following error message in the messaging service logs once every two seconds (repeatedly for hours). This indicates that some client is retrying it continuously, every two seconds.

      It is very likely a system component that is performing this operation, due to the consistency of the retry.

      2018-07-30 23:51:16,665 - ERROR [messaging.service-worker-thread-7:c.c.c.c.HttpExceptionHandler@70] - Unexpected error: request=POST /v1/namespaces/system/topics/metadata/publish user=<null>:
      java.lang.IllegalStateException: Invalid payload. Empty message is only allowed for transactional message
      	at co.cask.cdap.messaging.StoreRequest.computeNext(StoreRequest.java:65) ~[na:na]
      	at co.cask.cdap.messaging.StoreRequest.computeNext(StoreRequest.java:29) ~[na:na]
      	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:143) ~[com.google.guava.guava-13.0.1.jar:na]
      	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:138) ~[com.google.guava.guava-13.0.1.jar:na]
      	at co.cask.cdap.messaging.server.StoreHandler.publish(StoreHandler.java:83) ~[na:na]
      	at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source) ~[na:na]
      	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.invokeChannelRead(AbstractChannelHandlerContext.java:348) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at co.cask.cdap.common.http.AuthenticationChannelHandler.channelRead(AuthenticationChannelHandler.java:60) [na: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.invokeChannelRead(AbstractChannelHandlerContext.java:348) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	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.invokeChannelRead(AbstractChannelHandlerContext.java:348) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at co.cask.http.internal.RequestRouter.channelRead(RequestRouter.java:80) [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.invokeChannelRead(AbstractChannelHandlerContext.java:348) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.handler.codec.http.HttpServerKeepAliveHandler.channelRead(HttpServerKeepAliveHandler.java:64) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	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.invokeChannelRead(AbstractChannelHandlerContext.java:348) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	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.invokeChannelRead(AbstractChannelHandlerContext.java:348) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.handler.codec.MessageToMessageCodec.channelRead(MessageToMessageCodec.java:111) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	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.invokeChannelRead(AbstractChannelHandlerContext.java:348) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:438) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:310) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:284) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:253) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	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.invokeChannelRead(AbstractChannelHandlerContext.java:348) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1359) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	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.invokeChannelRead(AbstractChannelHandlerContext.java:348) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:935) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:134) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:645) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:580) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:497) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:459) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858) [io.netty.netty-all-4.1.16.Final.jar:4.1.16.Final]
      	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_161] 

      This also indicates poor error-handling code. This code (line 84 - https://github.com/caskdata/cdap/blob/release/5.0/cdap-tms/src/main/java/co/cask/cdap/messaging/server/StoreHandler.java#L84) will never execute, because the hasNext method on line 83 will itself throw an exception.

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                terence Terence Yim
                Reporter:
                ali.anwar Ali Anwar
              • Votes:
                0 Vote for this issue
                Watchers:
                2 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: