Local server iterator test fails and hangs randomly with NoSuchElementException ------------------------------------------------------------------------------- Key: HRJS-18 URL: https://issues.jboss.org/browse/HRJS-18 Project: Infinispan Javascript client Issue Type: Bug Affects Versions: 0.3.0 Reporter: Galder Zamarreño Assignee: Galder Zamarreño Fix For: 0.4.0 Attachments: server.log, tmp-tests.log Apart from the server returning {{NoSuchElementException}}, this is causing confusion in the client which results in the testsuite hanging completely. Here are snippets from client and server logs: {code} [2016-06-01 17:57:36.210] [DEBUG] client - Invoke putAll(msgId=323,pairs=[{"key":"local-it1","value":"v1","done":false},{"key":"local-it2","value":"v2","done":false},{"key":"local-it3","value":"v3","done":false}],opts=undefined) [2016-06-01 17:57:36.210] [TRACE] encoder - Encode operation with topology id 0 [2016-06-01 17:57:36.210] [TRACE] transport - Write buffer(msgId=323) to 127.0.0.1:11222: A0C302192D000003007703096C6F63616C2D697431027631096C6F63616C2D697432027632096C6F63616C2D697433027633 [2016-06-01 17:57:36.214] [TRACE] decoder - Read header(msgId=323): opCode=46, status=0, hasNewTopology=0 [2016-06-01 17:57:36.215] [TRACE] decoder - Call decode for request(msgId=323) [2016-06-01 17:57:36.215] [TRACE] connection - After decoding request(msgId=323), buffer size is 6, and offset 6 [2016-06-01 17:57:36.215] [TRACE] connection - Complete success for request(msgId=323) with undefined [2016-06-01 17:57:36.215] [DEBUG] client - Invoke iterator(msgId=324,batchSize=1,opts=undefined) [2016-06-01 17:57:36.215] [TRACE] encoder - Encode operation with topology id 0 [2016-06-01 17:57:36.215] [TRACE] transport - Write buffer(msgId=324) to 127.0.0.1:11222: A0C40219310000030001010100 [2016-06-01 17:57:36.230] [TRACE] decoder - Read header(msgId=324): opCode=50, status=0, hasNewTopology=0 [2016-06-01 17:57:36.230] [TRACE] decoder - Call decode for request(msgId=324) [2016-06-01 17:57:36.230] [TRACE] connection - After decoding request(msgId=324), buffer size is 43, and offset 43 [2016-06-01 17:57:36.230] [TRACE] connection - Complete success for request(msgId=324) with {"iterId":"28cab848-73ac-47c5-ad68-f518b89c5ba4","conn":{}} [2016-06-01 17:57:36.230] [TRACE] client - Invoke iterator.next(msgId=325,iteratorId=28cab848-73ac-47c5-ad68-f518b89c5ba4) on 127.0.0.1:11222 [2016-06-01 17:57:36.230] [TRACE] encoder - Encode operation with topology id 0 [2016-06-01 17:57:36.231] [TRACE] transport - Write buffer(msgId=325) to 127.0.0.1:11222: A0C5021933000003002432386361623834382D373361632D343763352D616436382D663531386238396335626134 [2016-06-01 17:57:36.231] [TRACE] client - Invoke iterator.next(msgId=326,iteratorId=28cab848-73ac-47c5-ad68-f518b89c5ba4) on 127.0.0.1:11222 [2016-06-01 17:57:36.231] [TRACE] encoder - Encode operation with topology id 0 [2016-06-01 17:57:36.231] [TRACE] transport - Write buffer(msgId=326) to 127.0.0.1:11222: A0C6021933000003002432386361623834382D373361632D343763352D616436382D663531386238396335626134 [2016-06-01 17:57:36.231] [TRACE] client - Invoke iterator.next(msgId=327,iteratorId=28cab848-73ac-47c5-ad68-f518b89c5ba4) on 127.0.0.1:11222 [2016-06-01 17:57:36.231] [TRACE] encoder - Encode operation with topology id 0 [2016-06-01 17:57:36.231] [TRACE] transport - Write buffer(msgId=327) to 127.0.0.1:11222: A0C7021933000003002432386361623834382D373361632D343763352D616436382D663531386238396335626134 [2016-06-01 17:57:36.244] [TRACE] decoder - Read header(msgId=327): opCode=80, status=133, hasNewTopology=0 [2016-06-01 17:57:36.244] [ERROR] decoder - Error decoding body of request(msgId=327): java.util.NoSuchElementException [2016-06-01 17:57:36.244] [TRACE] connection - After decoding request(msgId=327), buffer size is 39, and offset 39 [2016-06-01 17:57:36.244] [TRACE] connection - Complete failure for request(msgId=327) with java.util.NoSuchElementException [2016-06-01 17:57:36.249] [TRACE] decoder - Read header(msgId=327): opCode=52, status=0, hasNewTopology=0 {code} {code} 2016-06-01 17:57:36,216 TRACE [org.infinispan.server.hotrod.HotRodDecoder] (HotRodServerWorker-8-2) Decoded header HotRodHeader{op=IterationStartRequest, version=25, messageId=324, cacheName=, flag=0, clientIntelligence=3, topologyId=0} 2016-06-01 17:57:36,222 TRACE [org.infinispan.interceptors.impl.InvocationContextInterceptor] (HotRodServerHandler-6-115) Invoked with command EntrySetCommand{cache=default} and InvocationContext [org.infinispan.context.impl.NonTxInvocationContext@7bc2d6d3] 2016-06-01 17:57:36,222 TRACE [org.infinispan.interceptors.impl.CallInterceptor] (HotRodServerHandler-6-115) Executing command: EntrySetCommand{cache=default}. 2016-06-01 17:57:36,229 TRACE [org.infinispan.server.hotrod.ContextHandler] (HotRodServerHandler-6-115) Write response IterationStartResponse{version=25, messageId=324, cacheName=, operation=IterationStartResponse, status=Success, iterationId=28cab848-73ac-47c5-ad68-f518b89c5ba4} 2016-06-01 17:57:36,229 TRACE [org.infinispan.server.hotrod.HotRodEncoder] (HotRodServerWorker-8-2) Encode msg IterationStartResponse{version=25, messageId=324, cacheName=, operation=IterationStartResponse, status=Success, iterationId=28cab848-73ac-47c5-ad68-f518b89c5ba4} 2016-06-01 17:57:36,229 TRACE [org.infinispan.server.hotrod.Encoder2x$] (HotRodServerWorker-8-2) Write topology response header with no change 2016-06-01 17:57:36,229 TRACE [org.infinispan.server.hotrod.HotRodEncoder] (HotRodServerWorker-8-2) Write buffer contents A1C4023200002432386361623834382D373361632D343763352D616436382D663531386238396335626134 to channel [id: 0xd8959d2b, L:/127.0.0.1:11222 - R:/127.0.0.1:52367] 2016-06-01 17:57:36,231 TRACE [org.infinispan.server.hotrod.HotRodDecoder] (HotRodServerWorker-8-2) Decode using instance @54abd903 2016-06-01 17:57:36,231 TRACE [org.infinispan.server.hotrod.HotRodDecoder] (HotRodServerWorker-8-2) Decoded header HotRodHeader{op=IterationNextRequest, version=25, messageId=325, cacheName=, flag=0, clientIntelligence=3, topologyId=0} 2016-06-01 17:57:36,231 TRACE [org.infinispan.server.hotrod.HotRodDecoder] (HotRodServerWorker-8-2) Decode using instance @54abd903 2016-06-01 17:57:36,231 TRACE [org.infinispan.server.hotrod.HotRodDecoder] (HotRodServerWorker-8-2) Decoded header HotRodHeader{op=IterationNextRequest, version=25, messageId=326, cacheName=, flag=0, clientIntelligence=3, topologyId=0} 2016-06-01 17:57:36,231 TRACE [org.infinispan.server.hotrod.HotRodDecoder] (HotRodServerWorker-8-2) Decode using instance @54abd903 2016-06-01 17:57:36,231 TRACE [org.infinispan.server.hotrod.HotRodDecoder] (HotRodServerWorker-8-2) Decoded header HotRodHeader{op=IterationNextRequest, version=25, messageId=327, cacheName=, flag=0, clientIntelligence=3, topologyId=0} 2016-06-01 17:57:36,239 DEBUG [org.infinispan.server.hotrod.HotRodExceptionHandler] (HotRodServerWorker-8-2) Exception caught: java.util.NoSuchElementException at org.infinispan.stream.impl.RemovableIterator.next(RemovableIterator.java:49) at scala.collection.convert.Wrappers$JIteratorWrapper.next(Wrappers.scala:43) at org.infinispan.server.hotrod.iteration.DefaultIterationManager$$anonfun$next$1$$anonfun$6.apply(IterationManager.scala:142) at org.infinispan.server.hotrod.iteration.DefaultIterationManager$$anonfun$next$1$$anonfun$6.apply(IterationManager.scala:142) at scala.collection.TraversableLike$WithFilter$$anonfun$map$2.apply(TraversableLike.scala:728) at scala.collection.immutable.Range.foreach(Range.scala:166) at scala.collection.TraversableLike$WithFilter.map(TraversableLike.scala:727) at org.infinispan.server.hotrod.iteration.DefaultIterationManager$$anonfun$next$1.apply(IterationManager.scala:142) at org.infinispan.server.hotrod.iteration.DefaultIterationManager$$anonfun$next$1.apply(IterationManager.scala:138) at scala.Option.map(Option.scala:146) at org.infinispan.server.hotrod.iteration.DefaultIterationManager.next(IterationManager.scala:138) at org.infinispan.server.hotrod.ContextHandler.realRead(ContextHandler.java:182) at org.infinispan.server.hotrod.ContextHandler.lambda$channelRead0$1(ContextHandler.java:56) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:145) at java.lang.Thread.run(Thread.java:745) 2016-06-01 17:57:36,244 TRACE [org.infinispan.server.hotrod.HotRodEncoder] (HotRodServerWorker-8-2) Encode msg ErrorResponse{version=25, messageId=327, operation=ErrorResponse, status=ServerError, msg=java.util.NoSuchElementException} {code}