[
https://issues.apache.org/jira/browse/BOOKKEEPER-689?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13787700#comment-13787700
]
Rakesh R commented on BOOKKEEPER-689:
-------------------------------------
Hi All, hope the following observation/anlysis will help us to understand more
on the issue:
>From the logs, 'mainWorkerPool#shutdown()' is waiting for the termination and
>the timeout period is 10seconds, by this time the test case is also waiting
>10seconds in latch. Since client#close is taking morethan 10seconds, the test
>case is failing.
step-1) at 13:10:55,508 made bookie shutdown
step-2) at 13:10:55,520 has created PerChannelBookieClient connections
step-3) after this it has invoked client#close(). But this call is not
completed quickly and enters into timed waiting(10seconds) for the
mainWorkerPool termination. Here I could see 'queued tasks = 1' in
'ThreadPoolExecutor@13ff0ab6' and I'm thinking this is the reason for spending
more time in 'mainWorkerPool.awaitTermination'. But I couldn't make it out the
reason for 'queued tasks = 1', I'd appreciate any help to finish the analysis.
step-4) At the same time our test case is also waiting in latch, here also
waiting period is 10seconds.
assertTrue("Close never completed", l.await(10, TimeUnit.SECONDS));
{code}
2013-10-03 13:10:55,508 - INFO - [Thread-219:Bookie@952] - Shutting down
Bookie-15233 with exitCode 0
2013-10-03 13:10:55,517 - INFO - [New I/O client worker
#211-2:PerChannelBookieClient$1@137] - Successfully connected to bookie: [id:
0x22ec7b20, /10.85.254.167:62636 => /10.85.254.167:15234]
2013-10-03 13:10:55,520 - INFO - [New I/O client worker
#211-3:PerChannelBookieClient$1@137] - Successfully connected to bookie: [id:
0x171995d6, /10.85.254.167:62637 => /10.85.254.167:15235]
2013-10-03 13:10:55,521 - ERROR - [New I/O client worker
#211-2:PerChannelBookieClient@549] - Unexpected exception caught by bookie
client channel handler
java.util.concurrent.RejectedExecutionException: Task
java.util.concurrent.FutureTask@4dc3b693 rejected from
java.util.concurrent.ThreadPoolExecutor@13ff0ab6[Shutting down, pool size = 0,
active threads = 0, queued tasks = 1, completed tasks = 0]
2013-10-03 13:11:05,521 - WARN - [Thread-219:BookKeeper@637] - The
mainWorkerPool did not shutdown cleanly
{code}
{code}
BookKeeper#close()
mainWorkerPool.shutdown();
if (!mainWorkerPool.awaitTermination(10, TimeUnit.SECONDS)) {
LOG.warn("The mainWorkerPool did not shutdown cleanly");
}
{code}
> BookKeeperTest failure
> ----------------------
>
> Key: BOOKKEEPER-689
> URL: https://issues.apache.org/jira/browse/BOOKKEEPER-689
> Project: Bookkeeper
> Issue Type: Bug
> Reporter: Flavio Junqueira
> Attachments: org.apache.bookkeeper.client.BookKeeperTest-output.txt,
> TEST-org.apache.bookkeeper.client.BookKeeperTest.xml
>
>
> Tests run: 12, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 49.385 sec
> <<< FAILURE!
> testCloseDuringOp[1](org.apache.bookkeeper.client.BookKeeperTest) Time
> elapsed: 14.74 sec <<< FAILURE!
> junit.framework.AssertionFailedError: Close never completed
> at junit.framework.Assert.fail(Assert.java:47)
> at junit.framework.Assert.assertTrue(Assert.java:20)
> at
> org.apache.bookkeeper.client.BookKeeperTest.testCloseDuringOp(BookKeeperTest.java:217)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:601)
> at
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
> at
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
> at
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
> at
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
> at
> org.junit.internal.runners.statements.FailOnTimeout$1.run(FailOnTimeout.java:28)
--
This message was sent by Atlassian JIRA
(v6.1#6144)
