Here is a thread dump of when it is stuck. It is the client side that
is deadlocking on a write.
I can reproduce it 100% of the time now. By adding a print statement
just before the session.write(...) it starts to work just fine, with out
it and it locks up. Also adding a 50ms delay does the trick till the
server gets bogged down (after about 2250 connections are going).
This is the one trying to write out that is blocked: Thread
[AnonymousIoService-2] (Suspended)
-Scott
org.eclipse.jdt.internal.junit.runner.RemoteTestRunner at localhost:1972
(Suspended)
System Thread [Finalizer] (Suspended)
Object.wait(long) line: not available [native method]
ReferenceQueue<T>.remove(long) line: not available
ReferenceQueue<T>.remove() line: not available
Finalizer$FinalizerThread.run() line: not available
System Thread [Reference Handler] (Suspended)
Object.wait(long) line: not available [native method]
Reference$Lock(Object).wait() line: not available
Reference$ReferenceHandler.run() line: not available
Thread [main] (Suspended)
Thread.sleep(long) line: not available [native method]
Utility.safe_sleep(long) line: 32
ConnectorTest.setupManyConnection(int, int, boolean) line:
214
ConnectorTest.test_ZZ__SSLManyConnectionData() line: 179
NativeMethodAccessorImpl.invoke0(Method, Object, Object[])
line: not available [native method]
NativeMethodAccessorImpl.invoke(Object, Object[]) line: not
available
DelegatingMethodAccessorImpl.invoke(Object, Object[]) line:
not available
Method.invoke(Object, Object...) line: not available
ConnectorTest(TestCase).runTest() line: 164
ConnectorTest(TestCase).runBare() line: 130
TestResult$1.protect() line: 110
TestResult.runProtected(Test, Protectable) line: 128
TestResult.run(TestCase) line: 113
ConnectorTest(TestCase).run(TestResult) line: 120
TestSuite.runTest(Test, TestResult) line: 228
TestSuite.run(TestResult) line: 223
RemoteTestRunner.runTests(String[], String) line: 478
RemoteTestRunner.run() line: 344
RemoteTestRunner.main(String[]) line: 196
System Thread [Signal Dispatcher] (Suspended)
Thread [ReaderThread] (Suspended)
SocketInputStream.socketRead0(FileDescriptor, byte[], int,
int, int) line: not available [native method]
SocketInputStream.read(byte[], int, int) line: not available
StreamDecoder$CharsetSD.readBytes() line: not available
StreamDecoder$CharsetSD.implRead(char[], int, int) line: not
available
StreamDecoder$CharsetSD(StreamDecoder).read(char[], int,
int) line: not available
InputStreamReader.read(char[], int, int) line: not available
BufferedReader.fill() line: not available
BufferedReader.readLine(boolean) line: not available
BufferedReader.readLine() line: not available
RemoteTestRunner$ReaderThread.run() line: 149
Thread [SocketAcceptor-0] (Suspended)
WindowsSelectorImpl$SubSelector.poll0(long, int, int[],
int[], int[], long) line: not available [native method]
WindowsSelectorImpl$SubSelector.poll() line: not available
WindowsSelectorImpl$SubSelector.access$400(WindowsSelectorImpl$SubSelect
or) line: not available
WindowsSelectorImpl.doSelect(long) line: not available
WindowsSelectorImpl(SelectorImpl).lockAndDoSelect(long)
line: not available
WindowsSelectorImpl(SelectorImpl).select(long) line: not
available
WindowsSelectorImpl(SelectorImpl).select() line: not
available
SocketAcceptor$Worker.run() line: 260
NamePreservingRunnable.run() line: 43
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 990
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
Thread [pool-4-thread-1] (Suspended)
Unsafe.park(boolean, long) line: not available [native
method]
LockSupport.parkNanos(long) line: not available
SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue$TransferSta
ck$SNode, boolean, long) line: 427
SynchronousQueue$TransferStack.transfer(Object, boolean,
long) line: 326
SynchronousQueue.poll(long, TimeUnit) line: 877
ThreadPoolExecutor.getTask() line: 924
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 983
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
Thread [SocketConnectorIoProcessor-0.0] (Suspended)
WindowsSelectorImpl$SubSelector.poll0(long, int, int[],
int[], int[], long) line: not available [native method]
WindowsSelectorImpl$SubSelector.poll() line: not available
WindowsSelectorImpl$SubSelector.access$400(WindowsSelectorImpl$SubSelect
or) line: not available
WindowsSelectorImpl.doSelect(long) line: not available
WindowsSelectorImpl(SelectorImpl).lockAndDoSelect(long)
line: not available
WindowsSelectorImpl(SelectorImpl).select(long) line: not
available
SocketIoProcessor$Worker.run() line: 557
NamePreservingRunnable.run() line: 43
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 990
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
Thread [SocketAcceptorIoProcessor-0.0] (Suspended)
WindowsSelectorImpl$SubSelector.poll0(long, int, int[],
int[], int[], long) line: not available [native method]
WindowsSelectorImpl$SubSelector.poll() line: not available
WindowsSelectorImpl$SubSelector.access$400(WindowsSelectorImpl$SubSelect
or) line: not available
WindowsSelectorImpl.doSelect(long) line: not available
WindowsSelectorImpl(SelectorImpl).lockAndDoSelect(long)
line: not available
WindowsSelectorImpl(SelectorImpl).select(long) line: not
available
SocketIoProcessor$Worker.run() line: 557
NamePreservingRunnable.run() line: 43
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 990
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
Thread [AnonymousIoService-1] (Suspended)
Unsafe.park(boolean, long) line: not available [native
method]
LockSupport.park() line: not available
AbstractQueuedSynchronizer$ConditionObject.await() line: not
available
ConditionObjectWrapper.await() line: 40
LinkedBlockingQueue.take() line: 363
ThreadPoolExecutor.getTask() line: 924
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 983
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
Thread [PooledByteBufferExpirer-0] (Suspended)
Thread.sleep(long) line: not available [native method]
PooledByteBufferAllocator$Expirer.run() line: 277
Thread [AnonymousIoService-2] (Suspended)
Object.wait(long) line: not available [native method]
DefaultWriteFuture(Object).wait() line: not available
DefaultWriteFuture(DefaultIoFuture).join() line: 86
ClientEchoTestProtocolHandler(ClientProtocolHandler).messageSend(ByteBuf
fer) line: 275
ClientEchoTestProtocolHandler.sessionOpened() line: 67
ClientEchoTestProtocolHandler(ClientProtocolHandler).sessionOpened(IoSes
sion) line: 75
ClientEchoTestProtocolHandler.sessionOpened(IoSession) line:
114
AbstractIoFilterChain$TailFilter.sessionOpened(IoFilter$NextFilter,
IoSession) line: 659
SocketFilterChain(AbstractIoFilterChain).callNextSessionOpened(IoFilterC
hain$Entry, IoSession) line: 291
AbstractIoFilterChain.access$800(AbstractIoFilterChain,
IoFilterChain$Entry, IoSession) line: 54
AbstractIoFilterChain$EntryImpl$1.sessionOpened(IoSession)
line: 775
ExecutorFilter.processEvent(IoFilter$NextFilter, IoSession,
ExecutorFilter$EventType, Object) line: 261
ExecutorFilter$ProcessEventsRunnable.run() line: 305
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 990
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
Thread [AnonymousIoService-4] (Suspended)
Unsafe.park(boolean, long) line: not available [native
method]
LockSupport.park() line: not available
AbstractQueuedSynchronizer$ConditionObject.await() line: not
available
ConditionObjectWrapper.await() line: 40
LinkedBlockingQueue.take() line: 363
ThreadPoolExecutor.getTask() line: 924
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 983
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
Thread [AnonymousIoService-3] (Suspended)
Unsafe.park(boolean, long) line: not available [native
method]
LockSupport.park() line: not available
AbstractQueuedSynchronizer$ConditionObject.await() line: not
available
ConditionObjectWrapper.await() line: 40
LinkedBlockingQueue.take() line: 363
ThreadPoolExecutor.getTask() line: 924
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 983
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
Thread [SocketConnectorIoProcessor-0.2] (Suspended)
WindowsSelectorImpl$SubSelector.poll0(long, int, int[],
int[], int[], long) line: not available [native method]
WindowsSelectorImpl$SubSelector.poll() line: not available
WindowsSelectorImpl$SubSelector.access$400(WindowsSelectorImpl$SubSelect
or) line: not available
WindowsSelectorImpl.doSelect(long) line: not available
WindowsSelectorImpl(SelectorImpl).lockAndDoSelect(long)
line: not available
WindowsSelectorImpl(SelectorImpl).select(long) line: not
available
SocketIoProcessor$Worker.run() line: 557
NamePreservingRunnable.run() line: 43
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 990
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
Thread [AnonymousIoService-5] (Suspended)
Unsafe.park(boolean, long) line: not available [native
method]
LockSupport.park() line: not available
AbstractQueuedSynchronizer$ConditionObject.await() line: not
available
ConditionObjectWrapper.await() line: 40
LinkedBlockingQueue.take() line: 363
ThreadPoolExecutor.getTask() line: 924
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 983
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
Thread [AnonymousIoService-6] (Suspended)
Unsafe.park(boolean, long) line: not available [native
method]
LockSupport.park() line: not available
AbstractQueuedSynchronizer$ConditionObject.await() line: not
available
ConditionObjectWrapper.await() line: 40
LinkedBlockingQueue.take() line: 363
ThreadPoolExecutor.getTask() line: 924
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 983
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
Thread [AnonymousIoService-7] (Suspended)
Unsafe.park(boolean, long) line: not available [native
method]
LockSupport.park() line: not available
AbstractQueuedSynchronizer$ConditionObject.await() line: not
available
ConditionObjectWrapper.await() line: 40
LinkedBlockingQueue.take() line: 363
ThreadPoolExecutor.getTask() line: 924
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 983
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
Thread [SocketAcceptorIoProcessor-0.2] (Suspended)
Thread [AnonymousIoService-8] (Suspended)
Unsafe.park(boolean, long) line: not available [native
method]
LockSupport.park() line: not available
AbstractQueuedSynchronizer$ConditionObject.await() line: not
available
ConditionObjectWrapper.await() line: 40
LinkedBlockingQueue.take() line: 363
ThreadPoolExecutor.getTask() line: 924
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 983
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
Thread [AnonymousIoService-10] (Suspended)
Unsafe.park(boolean, long) line: not available [native
method]
LockSupport.park() line: not available
AbstractQueuedSynchronizer$ConditionObject.await() line: not
available
ConditionObjectWrapper.await() line: 40
LinkedBlockingQueue.take() line: 363
ThreadPoolExecutor.getTask() line: 924
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 983
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
Thread [AnonymousIoService-9] (Suspended)
Unsafe.park(boolean, long) line: not available [native
method]
LockSupport.park() line: not available
AbstractQueuedSynchronizer$ConditionObject.await() line: not
available
ConditionObjectWrapper.await() line: 40
LinkedBlockingQueue.take() line: 363
ThreadPoolExecutor.getTask() line: 924
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 983
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
Thread [AnonymousIoService-11] (Suspended)
Unsafe.park(boolean, long) line: not available [native
method]
LockSupport.park() line: not available
AbstractQueuedSynchronizer$ConditionObject.await() line: not
available
ConditionObjectWrapper.await() line: 40
LinkedBlockingQueue.take() line: 363
ThreadPoolExecutor.getTask() line: 924
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 983
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
Thread [AnonymousIoService-12] (Suspended)
Unsafe.park(boolean, long) line: not available [native
method]
LockSupport.park() line: not available
AbstractQueuedSynchronizer$ConditionObject.await() line: not
available
ConditionObjectWrapper.await() line: 40
LinkedBlockingQueue.take() line: 363
ThreadPoolExecutor.getTask() line: 924
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 983
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
Thread [AnonymousIoService-13] (Suspended)
Unsafe.park(boolean, long) line: not available [native
method]
LockSupport.park() line: not available
AbstractQueuedSynchronizer$ConditionObject.await() line: not
available
ConditionObjectWrapper.await() line: 40
LinkedBlockingQueue.take() line: 363
ThreadPoolExecutor.getTask() line: 924
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 983
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
Thread [AnonymousIoService-14] (Suspended)
Unsafe.park(boolean, long) line: not available [native
method]
LockSupport.park() line: not available
AbstractQueuedSynchronizer$ConditionObject.await() line: not
available
ConditionObjectWrapper.await() line: 40
LinkedBlockingQueue.take() line: 363
ThreadPoolExecutor.getTask() line: 924
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 983
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
Thread [AnonymousIoService-15] (Suspended)
Unsafe.park(boolean, long) line: not available [native
method]
LockSupport.park() line: not available
AbstractQueuedSynchronizer$ConditionObject.await() line: not
available
ConditionObjectWrapper.await() line: 40
LinkedBlockingQueue.take() line: 363
ThreadPoolExecutor.getTask() line: 924
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 983
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
Thread [AnonymousIoService-16] (Suspended)
Object.wait(long) line: not available [native method]
DefaultWriteFuture(Object).wait() line: not available
DefaultWriteFuture(DefaultIoFuture).join() line: 86
ClientEchoTestProtocolHandler(ClientProtocolHandler).messageSend(ByteBuf
fer) line: 275
ClientEchoTestProtocolHandler.sessionOpened() line: 67
ClientEchoTestProtocolHandler(ClientProtocolHandler).sessionOpened(IoSes
sion) line: 75
ClientEchoTestProtocolHandler.sessionOpened(IoSession) line:
114
AbstractIoFilterChain$TailFilter.sessionOpened(IoFilter$NextFilter,
IoSession) line: 659
SocketFilterChain(AbstractIoFilterChain).callNextSessionOpened(IoFilterC
hain$Entry, IoSession) line: 291
AbstractIoFilterChain.access$800(AbstractIoFilterChain,
IoFilterChain$Entry, IoSession) line: 54
AbstractIoFilterChain$EntryImpl$1.sessionOpened(IoSession)
line: 775
ExecutorFilter.processEvent(IoFilter$NextFilter, IoSession,
ExecutorFilter$EventType, Object) line: 261
ExecutorFilter$ProcessEventsRunnable.run() line: 305
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 990
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
Thread [SocketAcceptor-1] (Suspended)
WindowsSelectorImpl$SubSelector.poll0(long, int, int[],
int[], int[], long) line: not available [native method]
WindowsSelectorImpl$SubSelector.poll() line: not available
WindowsSelectorImpl$SubSelector.access$400(WindowsSelectorImpl$SubSelect
or) line: not available
WindowsSelectorImpl.doSelect(long) line: not available
WindowsSelectorImpl(SelectorImpl).lockAndDoSelect(long)
line: not available
WindowsSelectorImpl(SelectorImpl).select(long) line: not
available
WindowsSelectorImpl(SelectorImpl).select() line: not
available
SocketAcceptor$Worker.run() line: 260
NamePreservingRunnable.run() line: 43
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
line: 990
ThreadPoolExecutor$Worker.run() line: 531
Thread.run() line: not available
-----Original Message-----
From: Trustin Lee [mailto:[EMAIL PROTECTED]
Sent: Tuesday, April 10, 2007 2:00 AM
To: [email protected]
Subject: Re: Question on SSL connections
Scott,
On 4/10/07, Scott Peters <[EMAIL PROTECTED]> wrote:
> I am seeing this with the 1.0.3 snapshot. Before that with 1.0.1,
1.0.2
> or 1.1 I was not able to get even this amount of regularity in the SSL
> connnections, they locked up even more often due to that known
> deadlock. I believe there is still a race condition still since the
> non-SSL work 100% of the time. From what I can determine it is around
> the when a new ssl filter is added on an existing session. I have yet
to
> spend much time digging into the MINA layer. Adding a new SSLFilter
> object on an existing IoHandler object that had been previously
> connected during the sessionOpened(...) callback there is a chance
that
> it won't be seutp correctly. As I'm more knowledable of the high
level
> MINA architecure now I will start to dig deeper into the guts to see
if i
> can determine where the problem is. If you have any idea as to where
to
> look that would be great. Otherwise I'll just keep looking around and
> see what I can figure out. I will keep you posted on what I find.
You could post your thread dump here so we can track down the problem
more easily?
Trustin
--
what we call human nature is actually human habit
--
http://gleamynode.net/
--
PGP Key ID: 0x0255ECA6
