[ https://issues.apache.org/jira/browse/KUDU-1521?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16626763#comment-16626763 ]
Alexey Serbin commented on KUDU-1521: ------------------------------------- Still flaky, with 3 attempts failed in a row. The first attempt failed with: {noformat} com.stumbleupon.async.TimeoutException: Timed out after 50000ms when joining Deferred@147093588(state=PENDING, result=null, callback=wakeup thread Time-limited test, errback=wakeup thread Time-limited test) at com.stumbleupon.async.Deferred.doJoin(Deferred.java:1183) at com.stumbleupon.async.Deferred.join(Deferred.java:1042) at org.apache.kudu.client.TestAsyncKuduSession.test(TestAsyncKuduSession.java:299) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:483) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:298) at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:292) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.lang.Thread.run(Thread.java:745) [^org.apache.kudu.client.TestAsyncKuduSession.test.log.xz] {noformat} I attached full log of the failed scenario (the first failed run out of three failed). > Flakiness in TestAsyncKuduSession > --------------------------------- > > Key: KUDU-1521 > URL: https://issues.apache.org/jira/browse/KUDU-1521 > Project: Kudu > Issue Type: Bug > Components: client > Affects Versions: 0.9.1 > Reporter: Adar Dembo > Assignee: Todd Lipcon > Priority: Major > Attachments: > org.apache.kudu.client.TestAsyncKuduSession-TableIsDeleted-output.txt, > org.apache.kudu.client.TestAsyncKuduSession-output.txt, > org.apache.kudu.client.TestAsyncKuduSession.test.log.xz > > > I've been trying to parse the various failures in > http://104.196.14.100/job/kudu-gerrit/2270/BUILD_TYPE=RELEASE. Here's what I > see in the test: > The way test() tests AUTO_FLUSH_BACKGROUND is inherently flaky; a delay while > running test code will give the background flush task a chance to fire when > the test code doesn't expect it. I've seen this cause lead to no > PleaseThrottleException, but I suspect the first block of test code dealing > with background flushes is flaky too (since it's testing elapsed time). > There's also some test failures that I can't figure out. I've pasted them > below for posterity: > {noformat} > 03:52:14 > testGetTableLocationsErrorCauseSessionStuck(org.kududb.client.TestAsyncKuduSession) > Time elapsed: 100.009 sec <<< ERROR! > 03:52:14 java.lang.Exception: test timed out after 100000 milliseconds > 03:52:14 at java.lang.Object.wait(Native Method) > 03:52:14 at java.lang.Object.wait(Object.java:503) > 03:52:14 at com.stumbleupon.async.Deferred.doJoin(Deferred.java:1136) > 03:52:14 at com.stumbleupon.async.Deferred.join(Deferred.java:1019) > 03:52:14 at > org.kududb.client.TestAsyncKuduSession.testGetTableLocationsErrorCauseSessionStuck(TestAsyncKuduSession.java:133) > 03:52:14 > 03:52:14 > testBatchErrorCauseSessionStuck(org.kududb.client.TestAsyncKuduSession) Time > elapsed: 0.199 sec <<< ERROR! > 03:52:14 org.kududb.client.MasterErrorException: Server[Kudu Master - > 127.13.215.1:64030] NOT_FOUND[code 1]: The table was deleted: Table deleted > at 2016-07-09 03:50:24 UTC > 03:52:14 at > org.kududb.client.TabletClient.dispatchMasterErrorOrReturnException(TabletClient.java:533) > 03:52:14 at org.kududb.client.TabletClient.decode(TabletClient.java:463) > 03:52:14 at org.kududb.client.TabletClient.decode(TabletClient.java:83) > 03:52:14 at > org.jboss.netty.handler.codec.replay.ReplayingDecoder.callDecode(ReplayingDecoder.java:500) > 03:52:14 at > org.jboss.netty.handler.codec.replay.ReplayingDecoder.messageReceived(ReplayingDecoder.java:435) > 03:52:14 at > org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) > 03:52:14 at > org.kududb.client.TabletClient.handleUpstream(TabletClient.java:638) > 03:52:14 at > org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) > 03:52:14 at > org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) > 03:52:14 at > org.jboss.netty.handler.timeout.ReadTimeoutHandler.messageReceived(ReadTimeoutHandler.java:184) > 03:52:14 at > org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) > 03:52:14 at > org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) > 03:52:14 at > org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559) > 03:52:14 at > org.kududb.client.AsyncKuduClient$TabletClientPipeline.sendUpstream(AsyncKuduClient.java:1877) > 03:52:14 at > org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:268) > 03:52:14 at > org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:255) > 03:52:14 at > org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:88) > 03:52:14 at > org.jboss.netty.channel.socket.nio.AbstractNioWorker.process(AbstractNioWorker.java:108) > 03:52:14 at > org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:337) > 03:52:14 at > org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) > 03:52:14 at > org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) > 03:52:14 at > org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) > 03:52:14 at > org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) > 03:52:14 at > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) > 03:52:14 at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) > 03:52:14 at java.lang.Thread.run(Thread.java:745) > 03:52:14 > 03:52:14 org.kududb.client.TestAsyncKuduSession Time elapsed: 0.23 sec <<< > ERROR! > 03:52:14 java.lang.Exception: Can't recover from error, see previous WARN > 03:52:14 at org.kududb.client.BaseKuduTest$2.call(BaseKuduTest.java:290) > 03:52:14 at com.stumbleupon.async.Deferred.doCall(Deferred.java:1280) > 03:52:14 at > com.stumbleupon.async.Deferred.runCallbacks(Deferred.java:1259) > 03:52:14 at com.stumbleupon.async.Deferred.callback(Deferred.java:1002) > 03:52:14 at > com.stumbleupon.async.DeferredGroup.done(DeferredGroup.java:169) > 03:52:14 at > com.stumbleupon.async.DeferredGroup.recordCompletion(DeferredGroup.java:142) > 03:52:14 at > com.stumbleupon.async.DeferredGroup.access$000(DeferredGroup.java:36) > 03:52:14 at > com.stumbleupon.async.DeferredGroup$1Notify.call(DeferredGroup.java:82) > 03:52:14 at com.stumbleupon.async.Deferred.doCall(Deferred.java:1280) > 03:52:14 at > com.stumbleupon.async.Deferred.runCallbacks(Deferred.java:1259) > 03:52:14 at com.stumbleupon.async.Deferred.access$300(Deferred.java:427) > 03:52:14 at > com.stumbleupon.async.Deferred$Continue.call(Deferred.java:1368) > 03:52:14 at com.stumbleupon.async.Deferred.doCall(Deferred.java:1280) > 03:52:14 at > com.stumbleupon.async.Deferred.runCallbacks(Deferred.java:1259) > 03:52:14 at com.stumbleupon.async.Deferred.callback(Deferred.java:1002) > 03:52:14 at > org.kududb.client.AsyncKuduSession$TabletLookupCB$1.call(AsyncKuduSession.java:382) > 03:52:14 at > org.kududb.client.AsyncKuduSession$TabletLookupCB$1.call(AsyncKuduSession.java:378) > 03:52:14 at com.stumbleupon.async.Deferred.doCall(Deferred.java:1280) > 03:52:14 at > com.stumbleupon.async.Deferred.runCallbacks(Deferred.java:1259) > 03:52:14 at com.stumbleupon.async.Deferred.callback(Deferred.java:1002) > 03:52:14 at > com.stumbleupon.async.DeferredGroup.done(DeferredGroup.java:169) > 03:52:14 at > com.stumbleupon.async.DeferredGroup.recordCompletion(DeferredGroup.java:142) > 03:52:14 at > com.stumbleupon.async.DeferredGroup.access$000(DeferredGroup.java:36) > 03:52:14 at > com.stumbleupon.async.DeferredGroup$1Notify.call(DeferredGroup.java:82) > 03:52:14 at com.stumbleupon.async.Deferred.doCall(Deferred.java:1280) > 03:52:14 at > com.stumbleupon.async.Deferred.runCallbacks(Deferred.java:1259) > 03:52:14 at > com.stumbleupon.async.Deferred.handleContinuation(Deferred.java:1315) > 03:52:14 at com.stumbleupon.async.Deferred.doCall(Deferred.java:1286) > 03:52:14 at > com.stumbleupon.async.Deferred.runCallbacks(Deferred.java:1259) > 03:52:14 at com.stumbleupon.async.Deferred.callback(Deferred.java:1002) > 03:52:14 at org.kududb.client.KuduRpc.handleCallback(KuduRpc.java:195) > 03:52:14 at org.kududb.client.KuduRpc.errback(KuduRpc.java:215) > 03:52:14 at org.kududb.client.TabletClient.decode(TabletClient.java:484) > 03:52:14 at org.kududb.client.TabletClient.decode(TabletClient.java:83) > 03:52:14 at > org.jboss.netty.handler.codec.replay.ReplayingDecoder.callDecode(ReplayingDecoder.java:500) > 03:52:14 at > org.jboss.netty.handler.codec.replay.ReplayingDecoder.messageReceived(ReplayingDecoder.java:435) > 03:52:14 at > org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) > 03:52:14 at > org.kududb.client.TabletClient.handleUpstream(TabletClient.java:638) > 03:52:14 at > org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) > 03:52:14 at > org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) > 03:52:14 at > org.jboss.netty.handler.timeout.ReadTimeoutHandler.messageReceived(ReadTimeoutHandler.java:184) > 03:52:14 at > org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) > 03:52:14 at > org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) > 03:52:14 at > org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559) > 03:52:14 at > org.kududb.client.AsyncKuduClient$TabletClientPipeline.sendUpstream(AsyncKuduClient.java:1877) > 03:52:14 at > org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:268) > 03:52:14 at > org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:255) > 03:52:14 at > org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:88) > 03:52:14 at > org.jboss.netty.channel.socket.nio.AbstractNioWorker.process(AbstractNioWorker.java:108) > 03:52:14 at > org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:337) > 03:52:14 at > org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) > 03:52:14 at > org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) > 03:52:14 at > org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) > 03:52:14 at > org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) > 03:52:14 at > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) > 03:52:14 at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) > 03:52:14 at java.lang.Thread.run(Thread.java:745) > {noformat} -- This message was sent by Atlassian JIRA (v7.6.3#76005)