Java Client: Thread hangs after strange exception

Engel Sanchez engel at basho.com
Tue May 19 11:00:08 EDT 2015


Hi Henning. While Alex Moore in the clients team is looking at the client
side of this issue, I looked up the error messages you were getting in the
log and sent to him. Messages like this:

2015-05-08 14:12:18.103 [error] <0.937.0> gen_server <0.937.0>
terminated with reason: no function clause matching
riak_object:from_binary(<<"progress">>, <<"UploadServiceTest10">>,
{{ts,{1431,86330,742283}},<<53,1,0,0,0,34,131,108,0,0,0,1,
104,2,109,0,0,0,8,35,9,254,249,83,136,...>>})
line 633

Are caused by an issue that since has been fixed in +2.0, where internal
timestamps from the memory backend when using a TTL could be seen while
internal processes iterated over the key/values:
https://github.com/basho/riak_kv/pull/607

I agree with you in that I don't believe this is directly causing your
client hang issue.



On Tue, Apr 28, 2015 at 6:40 AM, Henning Verbeek <hankipanky at gmail.com>
wrote:

> For development, I have a single-node Riak 1.4 cluster that I'm
> connecting to with the Java client 2.0.1. Both client and server are
> running on the same node, connecting via localhost.
>
> Every now and then, an update operation ... hangs. On the console I
> see this strange error:
>
> 12:21:46.646 [nioEventLoopGroup-2-1] ERROR
> com.basho.riak.client.core.RiakNode - Operation onException() channel:
> id:-1348399652 localhost:8087 {}
> io.netty.util.concurrent.BlockingOperationException:
> DefaultChannelPromise at 63f65d07(incomplete)
> at
> io.netty.util.concurrent.DefaultPromise.checkDeadLock(DefaultPromise.java:396)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.DefaultChannelPromise.checkDeadLock(DefaultChannelPromise.java:157)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at io.netty.util.concurrent.DefaultPromise.await(DefaultPromise.java:257)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.DefaultChannelPromise.await(DefaultChannelPromise.java:129)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.DefaultChannelPromise.await(DefaultChannelPromise.java:28)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at com.basho.riak.client.core.RiakNode.doGetConnection(RiakNode.java:667)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at com.basho.riak.client.core.RiakNode.getConnection(RiakNode.java:636)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at com.basho.riak.client.core.RiakNode.execute(RiakNode.java:570)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> com.basho.riak.client.core.DefaultNodeManager.executeOnNode(DefaultNodeManager.java:90)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at com.basho.riak.client.core.RiakCluster.execute(RiakCluster.java:201)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at com.basho.riak.client.core.RiakCluster.execute(RiakCluster.java:195)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> com.basho.riak.client.api.commands.kv.StoreValue.executeAsync(StoreValue.java:117)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> com.basho.riak.client.api.commands.kv.UpdateValue$1.handle(UpdateValue.java:182)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> com.basho.riak.client.api.commands.ListenableFuture.notifyListeners(ListenableFuture.java:78)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> com.basho.riak.client.api.commands.CoreFutureAdapter.handle(CoreFutureAdapter.java:120)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> com.basho.riak.client.core.FutureOperation.fireListeners(FutureOperation.java:131)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> com.basho.riak.client.core.FutureOperation.setResponse(FutureOperation.java:170)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at com.basho.riak.client.core.RiakNode.onSuccess(RiakNode.java:824)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> com.basho.riak.client.core.netty.RiakResponseHandler.channelRead(RiakResponseHandler.java:58)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.DefaultChannelHandlerContext.invokeChannelRead(DefaultChannelHandlerContext.java:340)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.DefaultChannelHandlerContext.fireChannelRead(DefaultChannelHandlerContext.java:326)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:155)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.handler.codec.ByteToMessageCodec.channelRead(ByteToMessageCodec.java:108)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.DefaultChannelHandlerContext.invokeChannelRead(DefaultChannelHandlerContext.java:340)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.DefaultChannelHandlerContext.fireChannelRead(DefaultChannelHandlerContext.java:326)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:785)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:116)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:494)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:461)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:378)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:350)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:101)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at java.lang.Thread.run(Thread.java:745) [na:1.8.0_40]
>
> 12:21:46.653 [nioEventLoopGroup-2-1] WARN
> i.n.channel.DefaultChannelPipeline - An exception was thrown by a user
> handler's exceptionCaught() method while handling the following
> exception:
> io.netty.util.concurrent.BlockingOperationException:
> DefaultChannelPromise at 63f65d07(incomplete)
> at
> io.netty.util.concurrent.DefaultPromise.checkDeadLock(DefaultPromise.java:396)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.DefaultChannelPromise.checkDeadLock(DefaultChannelPromise.java:157)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at io.netty.util.concurrent.DefaultPromise.await(DefaultPromise.java:257)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.DefaultChannelPromise.await(DefaultChannelPromise.java:129)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.DefaultChannelPromise.await(DefaultChannelPromise.java:28)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at com.basho.riak.client.core.RiakNode.doGetConnection(RiakNode.java:667)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at com.basho.riak.client.core.RiakNode.getConnection(RiakNode.java:636)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at com.basho.riak.client.core.RiakNode.execute(RiakNode.java:570)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> com.basho.riak.client.core.DefaultNodeManager.executeOnNode(DefaultNodeManager.java:90)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at com.basho.riak.client.core.RiakCluster.execute(RiakCluster.java:201)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at com.basho.riak.client.core.RiakCluster.execute(RiakCluster.java:195)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> com.basho.riak.client.api.commands.kv.StoreValue.executeAsync(StoreValue.java:117)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> com.basho.riak.client.api.commands.kv.UpdateValue$1.handle(UpdateValue.java:182)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> com.basho.riak.client.api.commands.ListenableFuture.notifyListeners(ListenableFuture.java:78)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> com.basho.riak.client.api.commands.CoreFutureAdapter.handle(CoreFutureAdapter.java:120)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> com.basho.riak.client.core.FutureOperation.fireListeners(FutureOperation.java:131)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> com.basho.riak.client.core.FutureOperation.setResponse(FutureOperation.java:170)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at com.basho.riak.client.core.RiakNode.onSuccess(RiakNode.java:824)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> com.basho.riak.client.core.netty.RiakResponseHandler.channelRead(RiakResponseHandler.java:58)
> ~[storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.DefaultChannelHandlerContext.invokeChannelRead(DefaultChannelHandlerContext.java:340)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.DefaultChannelHandlerContext.fireChannelRead(DefaultChannelHandlerContext.java:326)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:155)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.handler.codec.ByteToMessageCodec.channelRead(ByteToMessageCodec.java:108)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.DefaultChannelHandlerContext.invokeChannelRead(DefaultChannelHandlerContext.java:340)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.DefaultChannelHandlerContext.fireChannelRead(DefaultChannelHandlerContext.java:326)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:785)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:116)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:494)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:461)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:378)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:350)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at
> io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:101)
> [storage-backend-2.1-SNAPSHOT.jar:2.1-SNAPSHOT]
> at java.lang.Thread.run(Thread.java:745) [na:1.8.0_40]
>
>
> VisualVM reports this for the hanging thread:
>
>    java.lang.Thread.State: WAITING
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for <4c34894c> (a
> java.util.concurrent.CountDownLatch$Sync)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
> at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
> at
> com.basho.riak.client.api.commands.kv.UpdateValue$UpdateValueFuture.await(UpdateValue.java:526)
> at com.basho.riak.client.api.RiakCommand.execute(RiakCommand.java:88)
> at com.basho.riak.client.api.RiakClient.execute(RiakClient.java:293)
> at
> com.skalio.skaliopush.services.ManifestFacade.updateMalware(ManifestFacade.java:222)
> at
> com.skalio.skaliopush.tasks.MalwareScanTask.call(MalwareScanTask.java:69)
> at
> com.skalio.skaliopush.tasks.MalwareScanTask.call(MalwareScanTask.java:35)
> 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)
>
>    Locked ownable synchronizers:
> - locked <617c74e5> (a java.util.concurrent.ThreadPoolExecutor$Worker)
>
> The call to RiakClient.execute() does not catch any Exceptions. There
> is absolutely no load on the box when this happens, and it's not
> reproducible.
>
> What is happening here? How can I fix it? How can I at least become
> aware of the Exception?
>
> Thanks for your help!
> Cheers,
> Henning
>
> _______________________________________________
> riak-users mailing list
> riak-users at lists.basho.com
> http://lists.basho.com/mailman/listinfo/riak-users_lists.basho.com
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.basho.com/pipermail/riak-users_lists.basho.com/attachments/20150519/54baac6d/attachment-0002.html>


More information about the riak-users mailing list