You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mina.apache.org by "Luis Neves (JIRA)" <ji...@apache.org> on 2006/11/06 12:48:38 UTC

[jira] Commented: (DIRMINA-301) New Multi threaded SocketIOProcessor to improve fairness of socket reads/writes

    [ http://issues.apache.org/jira/browse/DIRMINA-301?page=comments#action_12447423 ] 
            
Luis Neves commented on DIRMINA-301:
------------------------------------

I tried the Multi Threaded SocketIOProcessor over the weekend and I come across some issues.

Environment:
- Mina-Head, using JUC instead of backport-util-concurrent and the ReadWriteThreadModel from QPid Project
- Linux CentOS 4.4
- Dual Xeon 3GHz, 2GB RAM
- JDK 6 VM (build 103) 
- Server and Message Producer on the same Machine, Message Consumer on a remote machine (both machines are identical in all aspects)
- Message size is ~3KB. Every Message has a length header and XML payload (Soap).
- I use un-pooled heap ByteBuffers.

The test is simple, every 5 seconds the Message Producer opens a thread/socket to the server, sends a batch of 25000 messages and closes the socket when it's done, on occasion there is some overlap in that a thread starts before the previous one finishes.
On the consumer side there is some basic accounting to check if every message of the batch is received.

There is a problem in the MultiThreadSocketIoProcessor.read(), it enters a endless loop after a client closes the connection, I "fixed it" bringing the  outer "try/catch" block out from the "for" loop. I may have introduced some bugs because the performance of this Multi Threaded SocketIOProcessor is much worse than the default, it goes down from 6500 msg/sec to 50 msg/sec. I can't complete the sending of a single batch of messages without errors of this kind:

java.nio.channels.CancelledKeyException
        at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:55)
        at sun.nio.ch.SelectionKeyImpl.readyOps(SelectionKeyImpl.java:69)
        at java.nio.channels.SelectionKey.isReadable(SelectionKey.java:271)
        at org.apache.mina.transport.socket.nio.MultiThreadSocketIoProcessor.processRead(MultiThreadSocketIoProcessor.java:368)
        at org.apache.mina.transport.socket.nio.MultiThreadSocketIoProcessor.access$15(MultiThreadSocketIoProcessor.java:359)
        at org.apache.mina.transport.socket.nio.MultiThreadSocketIoProcessor$ReadWorker.run(MultiThreadSocketIoProcessor.java:902)
        at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:43)
        at java.lang.Thread.run(Thread.java:619)

Is there anything that you guys want me to do to try to diagnose what's going wrong?

Regards

--
Luis Neves

> New Multi threaded SocketIOProcessor to improve fairness of socket reads/writes
> -------------------------------------------------------------------------------
>
>                 Key: DIRMINA-301
>                 URL: http://issues.apache.org/jira/browse/DIRMINA-301
>             Project: Directory MINA
>          Issue Type: Improvement
>          Components: Transport
>    Affects Versions: 1.0
>         Environment: Problem on all platforms, example test ran on a 8 Way Opteron
>            Reporter: Martin Ritchie
>         Attachments: Mina Multi Thread SocketIOProcessor(MinaHead).zip, Mina Multi Thread SocketIOProcessor.zip
>
>
> The current SocketIOProcessor uses a single thread to do both reads and socket flushes. During some testing of Apache Qpid (A messaging broker) which uses mina as a transport we ran in to two problems.
> The first was the client that produces lots of data failed with an OutOfMemoryException, as mentioned in DIRMINA-206.
> The second is that under constant load the broker cannot read and write from the same socket at the same time. I have created a MultiThreaded SocketIOProcessor that allows reads and writes to occur simultaneously. On low core boxes the performance is similar to the existing SocketIOProcessor. However, on higher core boxes the Multi threaded box can be more than twice the speed.
> The attached zip file is an attempt to resolve the second. 
> To run the test:
> run "ant " to build everything.
> The memory requirements for each process are shown in parenthesis, these were just the largest numbers shown in top as the processes ran.
> Then 
> "ant acceptor_mina"(1.2G) or "ant acceptor_multi"(250M) to run the listener process. 
> This process simply sends the received message back down the same socket.
> Then run the corresponding writer
> "ant writer_mina"(560M) or "ant writer_multi"(540M)
> The results from each of the writers I ran on an 8way Opteron are shown below.
> The out of memory issue on the writer can be demonstrated buy running:
> "ant writer_mina_mem" or "ant writer_multi_mem"
> The increased throughput on the Multi Threaded SocketIOProcessor should allow it survive the low memory setting.
> ~/dev/TempProjects/mina-2006-11-02-1056/Mina Multi Thread SocketIOProcessor$ ant writer_mina
> Buildfile: build.xml
> writer_mina:
>      [java] main 2006-11-02 10:57:36,932 INFO [apache.mina.SocketIOTest.WriterTest] Starting 2k test
>      [java] main 2006-11-02 10:57:36,933 WARN [apache.mina.SocketIOTest.WriterTest] Using MINA NIO
>      [java] main 2006-11-02 10:57:36,999 INFO [apache.mina.SocketIOTest.WriterTest] Attempting connection to localhost/127.0.0.1:9999
>      [java] main 2006-11-02 10:57:37,035 INFO [apache.mina.SocketIOTest.WriterTest] Connection completed
>      [java] Thread-2 2006-11-02 10:57:37,038 INFO [apache.mina.SocketIOTest.WriterTest] Starting to send 200000 buffers of 2048B
>      [java] Thread-2 2006-11-02 10:57:43,409 INFO [apache.mina.SocketIOTest.WriterTest] All buffers sent; waiting for receipt from server
>      [java] Thread-2 2006-11-02 10:57:58,652 INFO [apache.mina.SocketIOTest.WriterTest] Completed
>      [java] Thread-2 2006-11-02 10:57:58,652 INFO [apache.mina.SocketIOTest.WriterTest] Total time waiting for server after last write: 15243
>      [java] Thread-2 2006-11-02 10:57:58,652 INFO [apache.mina.SocketIOTest.WriterTest] Total time: 21613
>      [java] Thread-2 2006-11-02 10:57:58,652 INFO [apache.mina.SocketIOTest.WriterTest] MB per second: 18951
>      [java] Thread-2 2006-11-02 10:57:58,654 INFO [apache.mina.SocketIOTest.WriterTest] Average chunk time: 1.0000000000011369ms
>      [java] Thread-2 2006-11-02 10:57:58,654 INFO [apache.mina.SocketIOTest.WriterTest] Maximum WriteRequestQueue size: 171836
>      [java] Thread-2 2006-11-02 10:57:58,654 INFO [apache.mina.SocketIOTest.WriterTest] Closing session
> ~/dev/TempProjects/mina-2006-11-02-1056/Mina Multi Thread SocketIOProcessor$ ant writer_multi
> Buildfile: build.xml
> writer_multi:
>      [java] main 2006-11-02 10:58:10,544 INFO [apache.mina.SocketIOTest.WriterTest] Starting 2k test
>      [java] main 2006-11-02 10:58:10,546 WARN [apache.mina.SocketIOTest.WriterTest] Using MultiThread NIO
>      [java] main 2006-11-02 10:58:10,620 INFO [apache.mina.SocketIOTest.WriterTest] Attempting connection to localhost/127.0.0.1:9999
>      [java] main 2006-11-02 10:58:10,675 INFO [apache.mina.SocketIOTest.WriterTest] Connection completed
>      [java] Thread-3 2006-11-02 10:58:10,678 INFO [apache.mina.SocketIOTest.WriterTest] Starting to send 200000 buffers of 2048B
>      [java] Thread-3 2006-11-02 10:58:15,464 INFO [apache.mina.SocketIOTest.WriterTest] All buffers sent; waiting for receipt from server
>      [java] Thread-3 2006-11-02 10:58:20,214 INFO [apache.mina.SocketIOTest.WriterTest] Completed
>      [java] Thread-3 2006-11-02 10:58:20,215 INFO [apache.mina.SocketIOTest.WriterTest] Total time waiting for server after last write: 4750
>      [java] Thread-3 2006-11-02 10:58:20,215 INFO [apache.mina.SocketIOTest.WriterTest] Total time: 9537
>      [java] Thread-3 2006-11-02 10:58:20,215 INFO [apache.mina.SocketIOTest.WriterTest] MB per second: 42948
>      [java] Thread-3 2006-11-02 10:58:20,216 INFO [apache.mina.SocketIOTest.WriterTest] Average chunk time: 1.0ms
>      [java] Thread-3 2006-11-02 10:58:20,216 INFO [apache.mina.SocketIOTest.WriterTest] Maximum WriteRequestQueue size: 159054
>      [java] Thread-3 2006-11-02 10:58:20,216 INFO [apache.mina.SocketIOTest.WriterTest] Closing session

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

Re: [jira] Commented: (DIRMINA-301) New Multi threaded SocketIOProcessor to improve fairness of socket reads/writes

Posted by Martin Ritchie <ri...@apache.org>.
Is your test code available for us to have a look at? There shouldn't
be an endless loop. When the connection is closed then the read should
fail and cause the session to be removed. The only change we made to
the read(session) was to allow more than one ch.read(bytebuffer) per
session per call. Now up to a maximum of
MAX_BYTES_PER_SESSION_PER_READ (512K default) is read in one go.

On 06/11/06, Luis Neves (JIRA) <ji...@apache.org> wrote:
>    [ http://issues.apache.org/jira/browse/DIRMINA-301?page=comments#action_12447423 ]
>
> Luis Neves commented on DIRMINA-301:
> ------------------------------------
>
> I tried the Multi Threaded SocketIOProcessor over the weekend and I come across some issues.
>
> Environment:
> - Mina-Head, using JUC instead of backport-util-concurrent and the ReadWriteThreadModel from QPid Project
> - Linux CentOS 4.4
> - Dual Xeon 3GHz, 2GB RAM
> - JDK 6 VM (build 103)
> - Server and Message Producer on the same Machine, Message Consumer on a remote machine (both machines are identical in all aspects)
> - Message size is ~3KB. Every Message has a length header and XML payload (Soap).
> - I use un-pooled heap ByteBuffers.
>
> The test is simple, every 5 seconds the Message Producer opens a thread/socket to the server, sends a batch of 25000 messages and closes the socket when it's done, on occasion there is some overlap in that a thread starts before the previous one finishes.
> On the consumer side there is some basic accounting to check if every message of the batch is received.
>
> There is a problem in the MultiThreadSocketIoProcessor.read(), it enters a endless loop after a client closes the connection, I "fixed it" bringing the  outer "try/catch" block out from the "for" loop. I may have introduced some bugs because the performance of this Multi Threaded SocketIOProcessor is much worse than the default, it goes down from 6500 msg/sec to 50 msg/sec. I can't complete the sending of a single batch of messages without errors of this kind:
>
> java.nio.channels.CancelledKeyException
>        at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:55)
>        at sun.nio.ch.SelectionKeyImpl.readyOps(SelectionKeyImpl.java:69)
>        at java.nio.channels.SelectionKey.isReadable(SelectionKey.java:271)
>        at org.apache.mina.transport.socket.nio.MultiThreadSocketIoProcessor.processRead(MultiThreadSocketIoProcessor.java:368)
>        at org.apache.mina.transport.socket.nio.MultiThreadSocketIoProcessor.access$15(MultiThreadSocketIoProcessor.java:359)
>        at org.apache.mina.transport.socket.nio.MultiThreadSocketIoProcessor$ReadWorker.run(MultiThreadSocketIoProcessor.java:902)
>        at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:43)
>        at java.lang.Thread.run(Thread.java:619)
>
> Is there anything that you guys want me to do to try to diagnose what's going wrong?
>
> Regards
>
> --
> Luis Neves
>
> > New Multi threaded SocketIOProcessor to improve fairness of socket reads/writes
> > -------------------------------------------------------------------------------
> >
> >                 Key: DIRMINA-301
> >                 URL: http://issues.apache.org/jira/browse/DIRMINA-301
> >             Project: Directory MINA
> >          Issue Type: Improvement
> >          Components: Transport
> >    Affects Versions: 1.0
> >         Environment: Problem on all platforms, example test ran on a 8 Way Opteron
> >            Reporter: Martin Ritchie
> >         Attachments: Mina Multi Thread SocketIOProcessor(MinaHead).zip, Mina Multi Thread SocketIOProcessor.zip
> >
> >
> > The current SocketIOProcessor uses a single thread to do both reads and socket flushes. During some testing of Apache Qpid (A messaging broker) which uses mina as a transport we ran in to two problems.
> > The first was the client that produces lots of data failed with an OutOfMemoryException, as mentioned in DIRMINA-206.
> > The second is that under constant load the broker cannot read and write from the same socket at the same time. I have created a MultiThreaded SocketIOProcessor that allows reads and writes to occur simultaneously. On low core boxes the performance is similar to the existing SocketIOProcessor. However, on higher core boxes the Multi threaded box can be more than twice the speed.
> > The attached zip file is an attempt to resolve the second.
> > To run the test:
> > run "ant " to build everything.
> > The memory requirements for each process are shown in parenthesis, these were just the largest numbers shown in top as the processes ran.
> > Then
> > "ant acceptor_mina"(1.2G) or "ant acceptor_multi"(250M) to run the listener process.
> > This process simply sends the received message back down the same socket.
> > Then run the corresponding writer
> > "ant writer_mina"(560M) or "ant writer_multi"(540M)
> > The results from each of the writers I ran on an 8way Opteron are shown below.
> > The out of memory issue on the writer can be demonstrated buy running:
> > "ant writer_mina_mem" or "ant writer_multi_mem"
> > The increased throughput on the Multi Threaded SocketIOProcessor should allow it survive the low memory setting.
> > ~/dev/TempProjects/mina-2006-11-02-1056/Mina Multi Thread SocketIOProcessor$ ant writer_mina
> > Buildfile: build.xml
> > writer_mina:
> >      [java] main 2006-11-02 10:57:36,932 INFO [apache.mina.SocketIOTest.WriterTest] Starting 2k test
> >      [java] main 2006-11-02 10:57:36,933 WARN [apache.mina.SocketIOTest.WriterTest] Using MINA NIO
> >      [java] main 2006-11-02 10:57:36,999 INFO [apache.mina.SocketIOTest.WriterTest] Attempting connection to localhost/127.0.0.1:9999
> >      [java] main 2006-11-02 10:57:37,035 INFO [apache.mina.SocketIOTest.WriterTest] Connection completed
> >      [java] Thread-2 2006-11-02 10:57:37,038 INFO [apache.mina.SocketIOTest.WriterTest] Starting to send 200000 buffers of 2048B
> >      [java] Thread-2 2006-11-02 10:57:43,409 INFO [apache.mina.SocketIOTest.WriterTest] All buffers sent; waiting for receipt from server
> >      [java] Thread-2 2006-11-02 10:57:58,652 INFO [apache.mina.SocketIOTest.WriterTest] Completed
> >      [java] Thread-2 2006-11-02 10:57:58,652 INFO [apache.mina.SocketIOTest.WriterTest] Total time waiting for server after last write: 15243
> >      [java] Thread-2 2006-11-02 10:57:58,652 INFO [apache.mina.SocketIOTest.WriterTest] Total time: 21613
> >      [java] Thread-2 2006-11-02 10:57:58,652 INFO [apache.mina.SocketIOTest.WriterTest] MB per second: 18951
> >      [java] Thread-2 2006-11-02 10:57:58,654 INFO [apache.mina.SocketIOTest.WriterTest] Average chunk time: 1.0000000000011369ms
> >      [java] Thread-2 2006-11-02 10:57:58,654 INFO [apache.mina.SocketIOTest.WriterTest] Maximum WriteRequestQueue size: 171836
> >      [java] Thread-2 2006-11-02 10:57:58,654 INFO [apache.mina.SocketIOTest.WriterTest] Closing session
> > ~/dev/TempProjects/mina-2006-11-02-1056/Mina Multi Thread SocketIOProcessor$ ant writer_multi
> > Buildfile: build.xml
> > writer_multi:
> >      [java] main 2006-11-02 10:58:10,544 INFO [apache.mina.SocketIOTest.WriterTest] Starting 2k test
> >      [java] main 2006-11-02 10:58:10,546 WARN [apache.mina.SocketIOTest.WriterTest] Using MultiThread NIO
> >      [java] main 2006-11-02 10:58:10,620 INFO [apache.mina.SocketIOTest.WriterTest] Attempting connection to localhost/127.0.0.1:9999
> >      [java] main 2006-11-02 10:58:10,675 INFO [apache.mina.SocketIOTest.WriterTest] Connection completed
> >      [java] Thread-3 2006-11-02 10:58:10,678 INFO [apache.mina.SocketIOTest.WriterTest] Starting to send 200000 buffers of 2048B
> >      [java] Thread-3 2006-11-02 10:58:15,464 INFO [apache.mina.SocketIOTest.WriterTest] All buffers sent; waiting for receipt from server
> >      [java] Thread-3 2006-11-02 10:58:20,214 INFO [apache.mina.SocketIOTest.WriterTest] Completed
> >      [java] Thread-3 2006-11-02 10:58:20,215 INFO [apache.mina.SocketIOTest.WriterTest] Total time waiting for server after last write: 4750
> >      [java] Thread-3 2006-11-02 10:58:20,215 INFO [apache.mina.SocketIOTest.WriterTest] Total time: 9537
> >      [java] Thread-3 2006-11-02 10:58:20,215 INFO [apache.mina.SocketIOTest.WriterTest] MB per second: 42948
> >      [java] Thread-3 2006-11-02 10:58:20,216 INFO [apache.mina.SocketIOTest.WriterTest] Average chunk time: 1.0ms
> >      [java] Thread-3 2006-11-02 10:58:20,216 INFO [apache.mina.SocketIOTest.WriterTest] Maximum WriteRequestQueue size: 159054
> >      [java] Thread-3 2006-11-02 10:58:20,216 INFO [apache.mina.SocketIOTest.WriterTest] Closing session
>
> --
> This message is automatically generated by JIRA.
> -
> If you think it was sent incorrectly contact one of the administrators: http://issues.apache.org/jira/secure/Administrators.jspa
> -
> For more information on JIRA, see: http://www.atlassian.com/software/jira
>
>
>


-- 
Martin Ritchie