[
https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12587843#action_12587843
]
Norval Hope commented on DIRSERVER-1161:
----------------------------------------
I should reiterate if it isn't clear - that the 1.0 and 1.5 patch attachments
for this issue add some extra debug log output to two classes only, the
software is vanilla 1.0 and 5.1.
Here a dump of the stack when I stop at a breakpoint in SearchHandler as it
does a session.write() on the first search result and I now see exactly why the
problem occurs:
-------------------------
UberjarMain [Java Application]
org.apache.directory.server.UberjarMain at localhost:1066
Thread [SocketAcceptor-0] (Running)
Thread [DestroyJavaVM] (Running)
Thread [SynchWorkerThread] (Running)
Thread [SocketAcceptorIoProcessor-0.0] (Running)
Thread [pool-2-thread-1] (Running)
Thread [pool-2-thread-2] (Running)
Thread [pool-2-thread-3] (Running)
Thread [pool-2-thread-4] (Suspended (breakpoint at line 393 in
SearchHandler))
SearchHandler.messageReceived(IoSession, Object) line: 393
LdapProtocolProvider$LdapProtocolHandler(DemuxingIoHandler).messageReceived(IoSession,
Object) line: 141
LdapProtocolProvider$LdapProtocolHandler.messageReceived(IoSession,
Object) line: 428
AbstractIoFilterChain$TailFilter.messageReceived(IoFilter$NextFilter,
IoSession, Object) line: 570
SocketFilterChain(AbstractIoFilterChain).callNextMessageReceived(IoFilterChain$Entry,
IoSession, Object) line: 299
AbstractIoFilterChain.access$5(AbstractIoFilterChain,
IoFilterChain$Entry, IoSession, Object) line: 296
AbstractIoFilterChain$EntryImpl$1.messageReceived(IoSession,
Object) line: 648
SimpleProtocolDecoderOutput.flush() line: 58
ProtocolCodecFilter.messageReceived(IoFilter$NextFilter, IoSession,
Object) line: 180
SocketFilterChain(AbstractIoFilterChain).callNextMessageReceived(IoFilterChain$Entry,
IoSession, Object) line: 299
AbstractIoFilterChain.access$5(AbstractIoFilterChain,
IoFilterChain$Entry, IoSession, Object) line: 296
AbstractIoFilterChain$EntryImpl$1.messageReceived(IoSession,
Object) line: 648
ExecutorFilter.processEvent(IoFilter$NextFilter, IoSession,
ExecutorFilter$EventType, Object) line: 228
ExecutorFilter$ProcessEventsRunnable.run() line: 280
ThreadPoolExecutor$Worker.runTask(Runnable) line: 650
ThreadPoolExecutor$Worker.run() line: 675
Thread.run() line: 595
C:\jdk1.5.0_11\bin\javaw.exe (11/04/2008 1:56:36 PM)
------------------------------
The problem is that SearchHandler is called via
AbstractIoFilterChain$EntryImpl$1.messageReceived(IoSession, Object)
line: 648
and after submitting the search to the underlying framework, it synchronously
steps through all of the the results submitting session.write()s for each one.
However, none of the queued events are flushed to the JNDI client until
SearchHandler has completely drained the SearchResponseIterator over the
results of the search and exited, at which point the stack unwinds back to
ExecutorFilter$ProcessEventsRunnable.run() line: 280
which results in the outputting of a log message like this:
2008-04-11 14:49:06,984 3130859 [pool-2-thread-6]
(org.apache.mina.filter.executor.ExecutorFilter$ProcessEventsRunnable:276)
DEBUG - About to process event for /127.0.0.1:1090 size of queue is
currently=1973
and then all the queued output SENT messages actually get flushed out to the
JNDI client via this call:
processEvent(event.getNextFilter(), buffer.session, event
.getType(), event.getData());
So my immediate thought is to change SearchHandler so that it spawns a thread
to take care of iterating through the search results asynchronously and then
returns immediately. With some luck this will result in the desired streaming
behaviour, but of course I don't know the relevant bits of the code well enough
to know if this approach is too simplistic and will violate any implicit or
explicit assumptions in the ApacheDS / MINA architecures. I'm going to try it
out anyway ...
> search results are not streamed to the client until final done response is
> queued
> ---------------------------------------------------------------------------------
>
> Key: DIRSERVER-1161
> URL: https://issues.apache.org/jira/browse/DIRSERVER-1161
> Project: Directory ApacheDS
> Issue Type: Bug
> Components: core
> Affects Versions: 1.0
> Environment: JDK 1.5.0_11
> Reporter: Norval Hope
> Attachments: apacheds_1.5.1_streaming.patch,
> apacheds_1.5.1_streaming_log_output.txt, installers_1.5.1_streaming.patch,
> mina_1.1.2_streaming.patch, pom.xml, streaming_log_output.txt,
> streaming_logging.patch
>
> Original Estimate: 120h
> Remaining Estimate: 120h
>
> Search results accumulate in Events on the SessionBuffer.eventQueue within
> ExecutorFilter.fireEvent() until final done response for the search is
> written to the session and then all results for the search (possibly millions
> depending on the search and state of the directory) are written out at once.
> This is a big problem for scalability and I gather from previous
> correspondence with Alex that this behaviour is unexpected.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
