You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@directory.apache.org by "Norval Hope (JIRA)" <ji...@apache.org> on 2008/04/09 10:01:26 UTC

[jira] Created: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

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


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.


[jira] Updated: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Norval Hope (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Norval Hope updated DIRSERVER-1161:
-----------------------------------

    Attachment: mina_1.1.2_streaming.patch
                installers_1.5.1_streaming.patch
                apacheds_1.5.1_streaming.patch

Unfortunately the problem persists against the 1.5.1 tagged release too, the attached files are patches to the top-level component after which they are named, with my source tree as follows:

<top>/
   apacheds/ (checked out from http://svn.apache.org/repos/asf/directory/apacheds/releases/1.5.1)
   installers/ (checked out from  http://svn.apache.org/repos/asf/directory/installers/releases/1.5.1)
   mina/ (checked out from http://svn.apache.org/repos/asf/mina/tags/1.1.2)

I'll include the top-level POM I used (cut-down version of the on one from the trunk) and sample logging output in next attachments.

> 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, installers_1.5.1_streaming.patch, mina_1.1.2_streaming.patch, 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.


[jira] Commented: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Norval Hope (JIRA)" <ji...@apache.org>.
    [ 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.


[jira] Updated: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Emmanuel Lecharny (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Emmanuel Lecharny updated DIRSERVER-1161:
-----------------------------------------

    Priority: Blocker  (was: Major)

Raised the status to Blocker in order to get it fixed in the next release

> 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
>            Priority: Blocker
>         Attachments: apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming_log_output.txt, installers_1.5.1_streaming.patch, installers_1.5.1_streaming.patch, mina_1.1.2_streaming.patch, mina_1.1_trunk_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.


[jira] Commented: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Norval Hope (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12588450#action_12588450 ] 

Norval Hope commented on DIRSERVER-1161:
----------------------------------------

Trustin was also kindly helping me sound out my theories etc re this issue. I'm including his responses to the issue too for completeness:

===> re spawning thread (in my view the critical immediate fix)


Hi Norval,

I think you figured the cause of the problem by yourself.  It seems like
SearchHandler is writing the search results inside the ExecutorFilter's
thread.  Any response messages from the client will not be processed by
IoHandler because ExecutorFilter doesn't allow the execution of more
than one event for one session.  That's why Executor's queue size
increases.  Your solution (i.e. writing the search result from other
thread) will fix the problem.  I think ApacheDS is also designed to be
thread safe so it should be fine.  It's also fine with MINA to do so.

HTH,

====> re blocking queue (also important, but once the separate thread is spawned above it only becomes a problem when client and server are running at markedly different speeds - but when this is so we can end up back at the same "OutOfMemory" problem for big searches).


Hi again,

MINA 2 has a mechanism that copes with too fast client without using
BlockingQueue.  You might want to backport it to MINA 1.1 and include it
into ApacheDS codebase.  Writing too fast from the server side is a
different problem.  You will have to check scheduledWriteBytes property
of the session and wait a little bit if it's too big.

HTH,

===> I also pinged Trustin about why he felt the blocking queue wasn't a good idea, but haven't heard back as yet.

> 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.patch, apacheds_1.5.1_streaming_log_output.txt, installers_1.5.1_streaming.patch, installers_1.5.1_streaming.patch, mina_1.1.2_streaming.patch, mina_1.1_trunk_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.


[jira] Commented: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Norval Hope (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12587463#action_12587463 ] 

Norval Hope commented on DIRSERVER-1161:
----------------------------------------

On futher investigation my comments 1 and 3 above are spurious. We're doing work on 2. to see how much peak memory use that saves us, as a work-around.

My gut feeling is that the lack of streaming is due to two threads interacting with the same underlying session, where we have the pool-3-thread-4 which got the messageReceived() and is therefore invoking SearchHandler and a SocketAcceptorIoProcessor-0.0 thread which is writing data that never seems to be sent to the client despite being written and flushed. It's like somehow the "result response" message causes the underlying session to change for a reading state to a state where the buffered output data can finally be sent off to the client, although through all my stepping through the MINA filter chains etc in the debugger I can't see the magic moment where this state transition occurs. It doesn't seem to relate to the state of the thread invoking the SearchHandler  as best I can see (i.e. like a lock being held onto), but rather to something that happens due to it writing the final response done message to the session which triggers some change in the  SocketAcceptorIoProcessor-0.0 thread.

> 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: 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.


[jira] Updated: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Norval Hope (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Norval Hope updated DIRSERVER-1161:
-----------------------------------

    Attachment: apacheds_1.5.1_streaming_log_output.txt
                pom.xml

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 /127.0.0.1:3453 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;
                        break;
                    }
                }

                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: 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.


[jira] Commented: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Norval Hope (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12587092#action_12587092 ] 

Norval Hope commented on DIRSERVER-1161:
----------------------------------------

Other things I've noticed in analysing this issue (these may or may not be knock-on problems which tie back to the lack of streaming):
  1. MINA's ProtocolCodecFilter has the following inner class where there are no accessors for "message" which leaves me thinking this object is for debugging only in which case it maybe needs to be made conditional

   private static class MessageByteBuffer extends ByteBufferProxy
    {
        private final Object message;
  2. In general when I look at memory usage I see a ton of strings which are RDN and LdapDN instances that it seems to me could be better handled better using String.intern()
  3. In SearchResponseIterator I see this code and wonder why the LdapDN needs to be created at @@@@@ for each search result (if this is just testing for validity does it make sense to make this behaviour configurable via server.xml):

if ( !isReferral || req.getControls().containsKey( ManageDsaITControl.CONTROL_OID ) )
        {
            SearchResponseEntry respEntry = new SearchResponseEntryImpl( req.getMessageId() );
            respEntry.setAttributes( result.getAttributes() );
            
            try
            {
                respEntry.setObjectName( new LdapDN( result.getName() ) ); // @@@@@@
            }
            catch ( InvalidNameException ine )
            {
                log.error( "Invalid object name : " + result.getName(), ine);
                throw new RuntimeException( ine );
            }
            
            prefetched = respEntry;
        }

   4. Even if incremental streaming is achieved I'm worried that the architecture doesn't seem to cope with the case where SearchHandler generates results quicker then the JNDI client consumes them, so that an unbounded amount of encoded results can build up on the server waiting to be transmitted, or does NIO take care of this (assuming the current streaming bug is fixed) by blocking the server in some way?

> 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: 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.


[jira] Commented: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Norval Hope (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12588476#action_12588476 ] 

Norval Hope commented on DIRSERVER-1161:
----------------------------------------

Just wanted to comment that the upside to fixing this issue in terms of throughput of the ApacheDS server is likely to very considerable, as my testing shows that my level (software built on top of AD) large searches are now running up to 500% faster for me due to the much, much smaller heap. I hope the benefits are also as significant when there is vanilla AD persistence behind the SearchResponseIterator instead of my custom extensions.

> 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.patch, apacheds_1.5.1_streaming_log_output.txt, installers_1.5.1_streaming.patch, installers_1.5.1_streaming.patch, mina_1.1.2_streaming.patch, mina_1.1_trunk_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.


[jira] Commented: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Emmanuel Lecharny (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12624602#action_12624602 ] 

Emmanuel Lecharny commented on DIRSERVER-1161:
----------------------------------------------

We have discussed the issue further with Alex this week, and we think that the problem should be fixed on ADS, not in MINA.

However, the fix won't be a quick and easy one. Here is what we discussed about :
- considering that if the client is slow, we may create as many Message stored in memory as we have entries to send back
- and that we don't want to block a thread waiting for a blocking queue, as we have a limited number of thread to process LDAP requests
- we have to find a way to be informed when the socket is ready to accept a new write, and then pick a thread in an executor to get the next entry to write (maybe the next N entries, to avoid some expensive calls to the executor)
- that also mean we must be able to push the cursor we have just created into a session container, and free the thread used to create this cursor

We have to think more about the details, now.

> 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
>            Assignee: Emmanuel Lecharny
>            Priority: Blocker
>             Fix For: 1.5.4
>
>         Attachments: apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming_log_output.txt, installers_1.5.1_streaming.patch, installers_1.5.1_streaming.patch, mina_1.1.2_streaming.patch, mina_1.1_trunk_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.


[jira] Commented: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Norval Hope (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12587952#action_12587952 ] 

Norval Hope commented on DIRSERVER-1161:
----------------------------------------

Pretty sure this solution is going to fly now.

Also think that the SessionBuffer should use a BlockingQueue with fixed size to stop the same unbounded growth problem is the case that the JNDI client is slow reading search results compared to the speed that the server produces them. A possible problem s that I think I saw evidence of an assumption that a null event can be written to the queue, which Blocking Queue doesn't allow, but I need to investigate further. Note this would be a fix to MINA.

> 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.


[jira] Closed: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Norval Hope (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Norval Hope closed DIRSERVER-1161.
----------------------------------


> 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
>            Assignee: Emmanuel Lecharny
>            Priority: Blocker
>             Fix For: 1.5.5
>
>         Attachments: apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming_log_output.txt, installers_1.5.1_streaming.patch, installers_1.5.1_streaming.patch, mina_1.1.2_streaming.patch, mina_1.1_trunk_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.


[jira] Commented: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Emmanuel Lecharny (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12649527#action_12649527 ] 

Emmanuel Lecharny commented on DIRSERVER-1161:
----------------------------------------------

I think I have all the responses flushed one by one by adding an ExecutorFilter on the WRITE EventType :

...
        // Inject the codec into the chain
        ((DefaultIoFilterChainBuilder)chain).addLast( "codec", 
                new ProtocolCodecFilter( this.getProtocolCodecFactory() ) );
        
        // Now inject an ExecutorFilter for the write operations
        ((DefaultIoFilterChainBuilder)chain).addLast( "executor", 
        		new ExecutorFilter( new OrderedThreadPoolExecutor( 10 ), 
        			IoEventType.WRITE ) );
...

I have no idea about what should be the number of threads in the pool, so I just set it to 10 atm. Integration tests are passing

(This is on the ads-mina2.0 branch)
 

> 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
>            Assignee: Emmanuel Lecharny
>            Priority: Blocker
>             Fix For: 1.5.5
>
>         Attachments: apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming_log_output.txt, installers_1.5.1_streaming.patch, installers_1.5.1_streaming.patch, mina_1.1.2_streaming.patch, mina_1.1_trunk_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.


[jira] Updated: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Emmanuel Lecharny (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Emmanuel Lecharny updated DIRSERVER-1161:
-----------------------------------------

    Fix Version/s:     (was: 1.5.3)
                   1.5.4

let's apply the patch in 1.5.4

> 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
>            Assignee: Emmanuel Lecharny
>            Priority: Blocker
>             Fix For: 1.5.4
>
>         Attachments: apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming_log_output.txt, installers_1.5.1_streaming.patch, installers_1.5.1_streaming.patch, mina_1.1.2_streaming.patch, mina_1.1_trunk_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.


[jira] Commented: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Alex Karasulu (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12606051#action_12606051 ] 

Alex Karasulu commented on DIRSERVER-1161:
------------------------------------------

Emmanuel did you want to take this on since you've been working on this.  if not let me know I can knock this out after getting back up to speed with this issue.  We probably should fix this in 1.5.3.

> 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
>            Priority: Blocker
>             Fix For: 1.5.3
>
>         Attachments: apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming_log_output.txt, installers_1.5.1_streaming.patch, installers_1.5.1_streaming.patch, mina_1.1.2_streaming.patch, mina_1.1_trunk_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.


[jira] Commented: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Emmanuel Lecharny (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12588158#action_12588158 ] 

Emmanuel Lecharny commented on DIRSERVER-1161:
----------------------------------------------

Hi Norval,

I read all this thread in the train while coming back from  Amsterdam, and what I saw (and what I went through while debugging the server) was quite scary ...

I'm not sure that MINA in the current version still hold the data in a queue before sending them, but anyway, if it's not the case, the slow JNDI client is already a perfect example of what we should protect the server from !

Ok, after some minimal investigation, I found that MINA was calling the encoder in the ProtocoalEncoderFilter and flush the resulting bytes directly to the client, but then try to send the message again, which has obviously already been sent. Here is the code :

ProtocolCodecFilter.filterWrite() {
    ...
        ProtocolEncoder encoder = getEncoder(session);
        ProtocolEncoderOutputImpl encoderOut = getEncoderOut(session,
                nextFilter, writeRequest);

        try {
            encoder.encode(session, message, encoderOut);

            // Here, the encoded message is sent.
            encoderOut.flush();

            // Here an empty message is sent...
            nextFilter.filterWrite(session, new WriteRequest(
                    new MessageByteBuffer(writeRequest.getMessage()),
                    writeRequest.getFuture(), writeRequest.getDestination()));

I don't know if this last empty message sent is related to the issue you mentionned in your previous comment, as I haven't yet thoroughly tested the code, but it might be a problem.

I think we might went to wait until the data are _really_ read by the client just after the encoderOut.flush() call before sending the next result, and this would protect the server from the issue you mentioned before.



Side remark : MINA migth have a cool API, but when it comes to debug it and getting into the guts of it, this is a nightmare. I just think that many part of it is just over-complicated, defeating the moto : "Write code for the Average Programmer"

> 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.


[jira] Assigned: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Emmanuel Lecharny (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Emmanuel Lecharny reassigned DIRSERVER-1161:
--------------------------------------------

    Assignee: Emmanuel Lecharny

> 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
>            Assignee: Emmanuel Lecharny
>            Priority: Blocker
>             Fix For: 1.5.3
>
>         Attachments: apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming_log_output.txt, installers_1.5.1_streaming.patch, installers_1.5.1_streaming.patch, mina_1.1.2_streaming.patch, mina_1.1_trunk_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.


[jira] Updated: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Norval Hope (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Norval Hope updated DIRSERVER-1161:
-----------------------------------

    Attachment: streaming_log_output.txt
                streaming_logging.patch

The .patch attached adds some extra logging to SearchHandler and ExecutorFilter (in MINA) to make the problem apparent, and adds some extra settings in apacheds/server-main/log4j.properties to ensure the new messages are logged.

I checked out http://svn.apache.org/repos/asf/directory/apacheds/branches/1.0-with-dependencies to a directory called "ad" and then checked out http://svn.apache.org/repos/asf/mina/tags/1.0.3 to a directory called "mina" under the top-level "ad", so the patch also includes building of this custom MINA 1.0.3 in the top-level pom.xml. 

Finally I've attached some log output for a search triggered from JXplorer for all DNs under ou=system. Note how in attached .txt file we see "size of queue is currently=17" without any writing being attempted until the final response done is queued, at which time all results are written. I have verified when running an LDAP client in the debugger (JMeter) that it sees no search results until the done has been written to the session and the NIO structures are flushed (and the synchronized block exited). I have also verified this lack of streaming applies to searches returning 100k results, so it's not a simple timing issue or anything simple like that.

> 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: 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.


[jira] Updated: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Norval Hope (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Norval Hope updated DIRSERVER-1161:
-----------------------------------

    Attachment: installers_1.5.1_streaming.patch
                mina_1.1_trunk_streaming.patch
                apacheds_1.5.1_streaming.patch

Ok, these attached files represent  a patch to ApacheDS 1.5.1 (release tag http://svn.apache.org/repos/asf/directory/apacheds/releases/1.5.1) and latest MINA 1.1 trunk (http://svn.apache.org/repos/asf/mina/branches/1.1 at 647053) which passes the "mvn -Dintegration test" on AD and as well my own test suites working at a higher level).

The changes are discussed in early comments / attachments this issue but are summarized again here:
 1. The major problem is that no data is streamed to the JNDI client
(and consequently the queue on the ExecutorFilter.SessionBuffer grows
in an unbounded fashion) until SearchHandler.messageRecieved()
returns. Hence it needs to return as soon as a NamingEnumeration over
the results to be returned is available, meaning a separate thread
needs to be used to drain the SearchResponseIterator asynchronously. Another solution mentioned by Emmanuel would be to force the session to be drained by the client for each result, but I think forcing the server and client to move in such strict lock-step would not be the best approach scalability-wise (and would be harder to implement too).
   2. The next problem is the potential for a difference in the client
/ server speed. My patch uses a
LinkedBlockingQueue and this approach worked fine. The problems / notes are:
     a. I did my patching against MINA 1.1 trunk (1.1.7-SNAPSHOT) so I
could get Trustin's feedback, but I gather you guys are aiming at
1.1.6 for your upcoming AD 1.5.2 release
     b. given Trustin's feedback I'm not sure how "onboard" he is going
to be this the blocking queue approach, but it seems a simple and
clean solution to me
     c. configuring the size of the blocking queue (or using a
non-blocking queue if this needs be kept as an
option for other MINA usages) is difficult as SessionBuffer is a static class in
ExecutorFilter and therefore can't be configured via ExecutorFilter's
constructor. I have used a system property as the best solution I can
think of at this stage.

> 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.patch, apacheds_1.5.1_streaming_log_output.txt, installers_1.5.1_streaming.patch, installers_1.5.1_streaming.patch, mina_1.1.2_streaming.patch, mina_1.1_trunk_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.


[jira] Resolved: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Emmanuel Lecharny (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Emmanuel Lecharny resolved DIRSERVER-1161.
------------------------------------------

    Resolution: Fixed

I think that the issue is solved with the ExecutorFilter trick.

> 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
>            Assignee: Emmanuel Lecharny
>            Priority: Blocker
>             Fix For: 1.5.5
>
>         Attachments: apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming_log_output.txt, installers_1.5.1_streaming.patch, installers_1.5.1_streaming.patch, mina_1.1.2_streaming.patch, mina_1.1_trunk_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.


[jira] Updated: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Alex Karasulu (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Alex Karasulu updated DIRSERVER-1161:
-------------------------------------

    Fix Version/s:     (was: 1.5.4)
                   1.5.5

Moving to 1.5.5.  We need to move to MINA 2.0 where we have more leverage to fix this issue.  I'm confident though that we'll have a solid solution to this problem for 1.5.5 since we've already added the needed structures in ApacheDS to handle this properly.

> 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
>            Assignee: Emmanuel Lecharny
>            Priority: Blocker
>             Fix For: 1.5.5
>
>         Attachments: apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming_log_output.txt, installers_1.5.1_streaming.patch, installers_1.5.1_streaming.patch, mina_1.1.2_streaming.patch, mina_1.1_trunk_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.


[jira] Commented: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Emmanuel Lecharny (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12606053#action_12606053 ] 

Emmanuel Lecharny commented on DIRSERVER-1161:
----------------------------------------------

I take this on my plate. I have spent quite an good amount of time on MINA since Norval pointed out the problem, in order to be able to get a grip on MINA.

> 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
>            Assignee: Emmanuel Lecharny
>            Priority: Blocker
>             Fix For: 1.5.3
>
>         Attachments: apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming_log_output.txt, installers_1.5.1_streaming.patch, installers_1.5.1_streaming.patch, mina_1.1.2_streaming.patch, mina_1.1_trunk_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.


[jira] Commented: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Norval Hope (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12587882#action_12587882 ] 

Norval Hope commented on DIRSERVER-1161:
----------------------------------------

So far my testing of the "spawn a thread to iterate through the search results" approach looks very promising. I'll do further testing before tidying up (probably use an Executor etc) and submitting a patch against 1.5.1 and any other releases of interest.

> 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.


[jira] Updated: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Emmanuel Lecharny (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Emmanuel Lecharny updated DIRSERVER-1161:
-----------------------------------------

    Fix Version/s: 1.5.3

Affected to 1.5.3

> 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
>            Priority: Blocker
>             Fix For: 1.5.3
>
>         Attachments: apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming.patch, apacheds_1.5.1_streaming_log_output.txt, installers_1.5.1_streaming.patch, installers_1.5.1_streaming.patch, mina_1.1.2_streaming.patch, mina_1.1_trunk_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.


[jira] Issue Comment Edited: (DIRSERVER-1161) search results are not streamed to the client until final done response is queued

Posted by "Norval Hope (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRSERVER-1161?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12588377#action_12588377 ] 

nrhope edited comment on DIRSERVER-1161 at 4/13/08 8:58 PM:
-----------------------------------------------------------------

Ok, these attached files represent  a patch to ApacheDS 1.5.1 (release tag http://svn.apache.org/repos/asf/directory/apacheds/releases/1.5.1) and latest MINA 1.1 trunk (http://svn.apache.org/repos/asf/mina/branches/1.1 at 647053) which passes the "mvn -Dintegration test" on AD and as well my own test suites working at a higher level).

Note this patch also cover another leak I noticed in SearchHandler when a search returns no results (refer to these lines):

                // stop leak of message for each search returning no results
                SessionRegistry.getSingleton().removeOutstandingRequest( session, req.getMessageId() );

The changes are discussed in early comments / attachments this issue but are summarized again here:
 1. The major problem is that no data is streamed to the JNDI client
(and consequently the queue on the ExecutorFilter.SessionBuffer grows
in an unbounded fashion) until SearchHandler.messageRecieved()
returns. Hence it needs to return as soon as a NamingEnumeration over
the results to be returned is available, meaning a separate thread
needs to be used to drain the SearchResponseIterator asynchronously. Another solution mentioned by Emmanuel would be to force the session to be drained by the client for each result, but I think forcing the server and client to move in such strict lock-step would not be the best approach scalability-wise (and would be harder to implement too).
   2. The next problem is the potential for a difference in the client
/ server speed. My patch uses a
LinkedBlockingQueue and this approach worked fine. The problems / notes are:
     a. I did my patching against MINA 1.1 trunk (1.1.7-SNAPSHOT) so I
could get Trustin's feedback, but I gather you guys are aiming at
1.1.6 for your upcoming AD 1.5.2 release
     b. given Trustin's feedback I'm not sure how "onboard" he is going
to be this the blocking queue approach, but it seems a simple and
clean solution to me
     c. configuring the size of the blocking queue (or using a
non-blocking queue if this needs be kept as an
option for other MINA usages) is difficult as SessionBuffer is a static class in
ExecutorFilter and therefore can't be configured via ExecutorFilter's
constructor. I have used a system property as the best solution I can
think of at this stage.

      was (Author: nrhope):
    Ok, these attached files represent  a patch to ApacheDS 1.5.1 (release tag http://svn.apache.org/repos/asf/directory/apacheds/releases/1.5.1) and latest MINA 1.1 trunk (http://svn.apache.org/repos/asf/mina/branches/1.1 at 647053) which passes the "mvn -Dintegration test" on AD and as well my own test suites working at a higher level).

The changes are discussed in early comments / attachments this issue but are summarized again here:
 1. The major problem is that no data is streamed to the JNDI client
(and consequently the queue on the ExecutorFilter.SessionBuffer grows
in an unbounded fashion) until SearchHandler.messageRecieved()
returns. Hence it needs to return as soon as a NamingEnumeration over
the results to be returned is available, meaning a separate thread
needs to be used to drain the SearchResponseIterator asynchronously. Another solution mentioned by Emmanuel would be to force the session to be drained by the client for each result, but I think forcing the server and client to move in such strict lock-step would not be the best approach scalability-wise (and would be harder to implement too).
   2. The next problem is the potential for a difference in the client
/ server speed. My patch uses a
LinkedBlockingQueue and this approach worked fine. The problems / notes are:
     a. I did my patching against MINA 1.1 trunk (1.1.7-SNAPSHOT) so I
could get Trustin's feedback, but I gather you guys are aiming at
1.1.6 for your upcoming AD 1.5.2 release
     b. given Trustin's feedback I'm not sure how "onboard" he is going
to be this the blocking queue approach, but it seems a simple and
clean solution to me
     c. configuring the size of the blocking queue (or using a
non-blocking queue if this needs be kept as an
option for other MINA usages) is difficult as SessionBuffer is a static class in
ExecutorFilter and therefore can't be configured via ExecutorFilter's
constructor. I have used a system property as the best solution I can
think of at this stage.
  
> 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.patch, apacheds_1.5.1_streaming_log_output.txt, installers_1.5.1_streaming.patch, installers_1.5.1_streaming.patch, mina_1.1.2_streaming.patch, mina_1.1_trunk_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.