directory-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Norval Hope (JIRA)" <>
Subject [jira] Updated: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued
Date Thu, 10 Apr 2008 14:14:09 GMT


Norval Hope updated DIRSERVER-1161:

    Attachment: apacheds_1.5.1_streaming_log_output.txt

These attachments are linked with the previous attachments showing the problem against 1.5.1.
The first is the cutdown POM explained in previous attachment comment. The second is sample
logging output when perform a subtree search for all all DNs under ou=schema.

Note how the queue grows without any calls sending results until the first 

2008-04-10 23:40:12,718 14343 [pool-2-thread-4] (org.apache.mina.filter.executor.ExecutorFilter$ProcessEventsRunnable:276)
DEBUG  - About to process event for / size of queue is currently=1965

which occurs after the final response done message is written to the session. Only after this
occurs do the flood gates open and all the queued messages starting getting sent to the client.
It's looking like this code in ExecutorFilter.ProcessEventsRunnable is the problem:

        public void run() {
            while (true) {
                Event event;

                synchronized (buffer.eventQueue) {
                    event = buffer.eventQueue.poll();

                    if (event == null) {
                        buffer.processingCompleted = true;

                if ( logger.isDebugEnabled() ) {
                    logger.debug( "About to process event for " + buffer.session.getRemoteAddress()
+ " size of queue is currently="
                        + buffer.eventQueue.size());
                processEvent(event.getNextFilter(), buffer.session, event
                        .getType(), event.getData());

as it seems the loop if blocked (maybe in the poll?) indefinitely until all the results have
been written to the session, at which time the first processEvent () call is made and the
sending actually begins. I'll have to investigate further why this happens (the code looks
to me like it expects to go around the loop regularly as incremental search results become
available, which would seem to solve this JIRA issue provided that Events are actually cleared
properly from the queue in conjunction with the sending).

If any gurus out there have a few minutes to consider my findings / theories in their very
busy schedules, I would be very grateful indeed :-) I think I'm a least getting closer in
tracking down the root cause of the misbehaviour - I just hope it's possible to work out how
to resolve the issue once the forensics are clear.

> search results are not streamed to the client until final done response is queued
> ---------------------------------------------------------------------------------
>                 Key: DIRSERVER-1161
>                 URL:
>             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,
>   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.

View raw message