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

Invalid message publish is indefinitely retried to TMS.

    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: