[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12777140#action_12777140 ] Oleg Kalnichevski commented on HTTPCORE-155: Marc, As a paying customer you may want to report this fact back to IBM. At least they seem to have acknowledged the existence of the problem. Oleg > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1-alpha1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > brush_up_1.09-03-20, HTTPCORE-155.patch, IOSessionImpl.diff, > IOSessionImpl.java, javacore.20081203.153723.32300.0001.txt, myoutput.txt, > patch.08-12-17.tar.gz, patch.08-12-18.tar.gz, patch.08-12-22.tar.gz, > patch.08-12-30.tar.gz, patch.09-03-18.tar.gz, summary_patch.09-03-18 > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client instances on this > single system... each with potentially 2 active connections simultaneously... > there is also virtually no CPU load (i.e. less then 5%) on this system... -- This message is automatically
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12777013#action_12777013 ] Marc Beyerle commented on HTTPCORE-155: --- Hi folks, unfortunately, I have to disappoint you a little bit about this. I just tested the IBM SDK for Java V5 on Intel 32-bit Linux and both SR9 and SR10 still run into timeouts when I use the "Message Mediation" example from the Apache Synapse Quick Start Guide. However, both of them run nicely with my patch enabled. Hence, I guess my patch is still relevant for the time being... Cheers, Marc > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1-alpha1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > brush_up_1.09-03-20, HTTPCORE-155.patch, IOSessionImpl.diff, > IOSessionImpl.java, javacore.20081203.153723.32300.0001.txt, myoutput.txt, > patch.08-12-17.tar.gz, patch.08-12-18.tar.gz, patch.08-12-22.tar.gz, > patch.08-12-30.tar.gz, patch.09-03-18.tar.gz, summary_patch.09-03-18 > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that w
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12776800#action_12776800 ] Asankha C. Perera commented on HTTPCORE-155: Hi Oleg I've updated the Synapse user on this new development and hopefully we will have confirmation on this in the near future thanks asankha > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1-alpha1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > brush_up_1.09-03-20, HTTPCORE-155.patch, IOSessionImpl.diff, > IOSessionImpl.java, javacore.20081203.153723.32300.0001.txt, myoutput.txt, > patch.08-12-17.tar.gz, patch.08-12-18.tar.gz, patch.08-12-22.tar.gz, > patch.08-12-30.tar.gz, patch.09-03-18.tar.gz, summary_patch.09-03-18 > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client instances on this > single system... each with potentially 2 active connections simultaneously... > there is also virtually no CPU load (i.e. less then 5%) on this system... -- This message is automatically gen
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12773629#action_12773629 ] Oleg Kalnichevski commented on HTTPCORE-155: It looks like IBM fixed the problem in its code, making this workaround less relevant. http://www-01.ibm.com/support/docview.wss?uid=swg1IZ31216 It would be great if someone could test HttpCore with IBM Java 5.0.0 SR9 or SR10 Oleg > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1-alpha1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > brush_up_1.09-03-20, HTTPCORE-155.patch, IOSessionImpl.diff, > IOSessionImpl.java, javacore.20081203.153723.32300.0001.txt, myoutput.txt, > patch.08-12-17.tar.gz, patch.08-12-18.tar.gz, patch.08-12-22.tar.gz, > patch.08-12-30.tar.gz, patch.09-03-18.tar.gz, summary_patch.09-03-18 > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client instances on this > single system... each with potentially 2 active connections simultaneously... > there is also virtuall
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12689413#action_12689413 ] Marc Beyerle commented on HTTPCORE-155: --- > Since ConcurrentLinkedQueue performs better, let's keep things as they are. Sounds good to me. And Thank You, Oleg, for your ideas and contributions! Cheers, Marc > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > brush_up_1.09-03-20, HTTPCORE-155.patch, IOSessionImpl.diff, > IOSessionImpl.java, javacore.20081203.153723.32300.0001.txt, myoutput.txt, > patch.08-12-17.tar.gz, patch.08-12-18.tar.gz, patch.08-12-22.tar.gz, > patch.08-12-30.tar.gz, patch.09-03-18.tar.gz, summary_patch.09-03-18 > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client instances on this > single system... each with potentially 2 active connections simultaneously... > there is also virtually no CPU load (i.e. less then 5%) on this system... -- This message is automatically
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12689211#action_12689211 ] Oleg Kalnichevski commented on HTTPCORE-155: > sorry for the delay, I was busy with a customer project. No problem. First things first. > The only thing I am not 100% sure about are the equals() and hashCode() > methods in InterestOpEntry. I would only > consider two InterestOpEntry instances equal if both the SelectionKey and the > event mask are equal. What do you think? #equals() and #hashCode() are only relevant if we used a Set to keep track of InterestOp changes. The whole idea was to record only the last event mask per any given SelectionKey, thus potentially reducing the overhead of InterestOp queueing. Since ConcurrentLinkedQueue performs better, let's keep things as they are. Oleg > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > brush_up_1.09-03-20, HTTPCORE-155.patch, IOSessionImpl.diff, > IOSessionImpl.java, javacore.20081203.153723.32300.0001.txt, myoutput.txt, > patch.08-12-17.tar.gz, patch.08-12-18.tar.gz, patch.08-12-22.tar.gz, > patch.08-12-30.tar.gz, patch.09-03-18.tar.gz, summary_patch.09-03-18 > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.ex
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12689106#action_12689106 ] Marc Beyerle commented on HTTPCORE-155: --- Hi Oleg, sorry for the delay, I was busy with a customer project. The Set related tests I conducted confirmed my assumption: The sequence of operations against the interest set is crucial. The more general Set implementations (HashSet and CopyOnWriteArraySet) don't work for my patch, since they return their elements in a more or less unpredictable order. The only Set implementation, which works properly, is the one that retains the order, in which elements are inserted (LinkedHashSet). However, it is a little slower than the currently used ConcurrentLinkedQueue. Therefore, my recommendation is to use ConcurrentLinkedQueue. I looked over your changes and I am fully okay with them. For example, in IOSessionImpl, I also thought about moving the checks for a CLOSED status at the beginning of setEvent() and the other methods, but my goal there was to keep the patch as close to the original code as possible. I also like your idea of getting rid of setEventMaskImpl() by using SelectionKey in InterestOpEntry and to use a callback mechanism for the enqueueing. The only thing I am not 100% sure about are the equals() and hashCode() methods in InterestOpEntry. I would only consider two InterestOpEntry instances equal if both the SelectionKey and the event mask are equal. What do you think? Last thing to mention is that the current ibm_compat_branch in SVN works fine with both the unit tests and my performance / stress tests (both IBM and Sun JVM). Cheers, Marc > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > brush_up_1.09-03-20, HTTPCORE-155.patch, IOSessionImpl.diff, > IOSessionImpl.java, javacore.20081203.153723.32300.0001.txt, myoutput.txt, > patch.08-12-17.tar.gz, patch.08-12-18.tar.gz, patch.08-12-22.tar.gz, > patch.08-12-30.tar.gz, patch.09-03-18.tar.gz, summary_patch.09-03-18 > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelector
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12688864#action_12688864 ] Oleg Kalnichevski commented on HTTPCORE-155: Cleaned things up a bit further. I think we are pretty much done here. If I hear no complaints, I'll merge the changes from the branch down to the trunk and close the issue. Oleg > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > brush_up_1.09-03-20, HTTPCORE-155.patch, IOSessionImpl.diff, > IOSessionImpl.java, javacore.20081203.153723.32300.0001.txt, myoutput.txt, > patch.08-12-17.tar.gz, patch.08-12-18.tar.gz, patch.08-12-22.tar.gz, > patch.08-12-30.tar.gz, patch.09-03-18.tar.gz, summary_patch.09-03-18 > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client instances on this > single system... each with potentially 2 active connections simultaneously... > there is also virtually no CPU load (i.e. less then 5%) on this system... -- This
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12688112#action_12688112 ] Oleg Kalnichevski commented on HTTPCORE-155: Scrap all that. I kept the InterestOpEntry but refactored it a bit. Please review. I think we are almost done. As the very last thing could you please experiment with using Set for keeping tract of InterestOpEntry instead of Queue and see if that makes any difference in terms of performance. Oleg > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > brush_up_1.09-03-20, HTTPCORE-155.patch, IOSessionImpl.diff, > IOSessionImpl.java, javacore.20081203.153723.32300.0001.txt, myoutput.txt, > patch.08-12-17.tar.gz, patch.08-12-18.tar.gz, patch.08-12-22.tar.gz, > patch.08-12-30.tar.gz, patch.09-03-18.tar.gz, summary_patch.09-03-18 > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client instances on this > single system... each with potentially 2 act
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12688072#action_12688072 ] Oleg Kalnichevski commented on HTTPCORE-155: That's much, much better! I checked in the patch with some minor tweaks. Many thanks, Marc. Now, do we really need to store the eventMask in the InterestOpEntry, since IOSessionImpl really has it? Do we really need InterestOpEntry at all? I do think there is still room for more clean-ups. Cheers Oleg > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > brush_up_1.09-03-20, HTTPCORE-155.patch, IOSessionImpl.diff, > IOSessionImpl.java, javacore.20081203.153723.32300.0001.txt, myoutput.txt, > patch.08-12-17.tar.gz, patch.08-12-18.tar.gz, patch.08-12-22.tar.gz, > patch.08-12-30.tar.gz, patch.09-03-18.tar.gz, summary_patch.09-03-18 > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client instances on this > single system... each with potentiall
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12683599#action_12683599 ] Oleg Kalnichevski commented on HTTPCORE-155: Just noticed another thing. We absolutely _have got_ to get rid of abstractIOReactor.processPendingInterestOps() calls from IOSessionImpl. IOSessions must be thread-safe when called from any thread. AbstractIOReactor.processPendingInterestOps() simply cannot be thread-safe unless called from the I/O dispatch thread. Oleg > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > HTTPCORE-155.patch, IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt, myoutput.txt, patch.08-12-17.tar.gz, > patch.08-12-18.tar.gz, patch.08-12-22.tar.gz, patch.08-12-30.tar.gz, > patch.09-03-18.tar.gz, summary_patch.09-03-18 > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client instances on this > single system... each with potentially 2
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12683595#action_12683595 ] Oleg Kalnichevski commented on HTTPCORE-155: > I'm pretty uncertain about the Set, however. I am not 100% sure either but I think it is an idea worth exploring. However, let's tackle one issue at a time. First, InterestOpEntry should be looked at. Cheers Oleg > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > HTTPCORE-155.patch, IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt, myoutput.txt, patch.08-12-17.tar.gz, > patch.08-12-18.tar.gz, patch.08-12-22.tar.gz, patch.08-12-30.tar.gz, > patch.09-03-18.tar.gz, summary_patch.09-03-18 > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client instances on this > single system... each with potentially 2 active connections simultaneously... > there is also virtually no CPU load (i.e. less then 5%) on this syst
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12683481#action_12683481 ] Marc Beyerle commented on HTTPCORE-155: --- Hi Oleg, sure, you can add my name to the list of contributors - thanks. I find the xyzImpl () methods not too ugly, but that's probably a matter of taste :-) Your solution sounds good to me, too. And I think it's quite easy to implement by simply adding an instance member to IOSessionImpl, which keeps track of the current event mask. The nice thing about this approach is that we not only get rid of two of the xyzImpl () methods, but also of the statics in InterestOpEntry and the two newly introduced if / else blocks in AbstractIOReactor. So overall, I think it's a good idea. I'll give it a try and let you know how it goes. I'm pretty uncertain about the Set, however. First, my assumption is that the sequence of operations against the interest set is important and second, a List is still the fastest means for a first in / first out queue. Maybe one could give LinkedList a try. What's your opinion? Cheers, Marc > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > HTTPCORE-155.patch, IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt, myoutput.txt, patch.08-12-17.tar.gz, > patch.08-12-18.tar.gz, patch.08-12-22.tar.gz, patch.08-12-30.tar.gz, > patch.09-03-18.tar.gz, summary_patch.09-03-18 > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.se
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12683126#action_12683126 ] Oleg Kalnichevski commented on HTTPCORE-155: Patch with minor code cleanups [1] checked in to a special branch [2] Many thanks, Marc! I would like to add your name to the list of contributors, if that is okay with you [1] http://svn.apache.org/viewvc?rev=755694&view=rev [2] https://svn.apache.org/repos/asf/httpcomponents/httpcore/branches/ibm_compat_branch Now, I see several areas where things can be cleaned up a little. How about this for a start? IOSessionImpl#*Impl methods are ugly. How about storing the complete interest op mask in the InterestOpEntry the instead of an individual operation? This we would need IOSessionImpl#*setEventMaskImpl only. InterestOpEntry would also become a bit simpler. This may also enable us to use Set for keeping track of interest ops instead of a list. What do you think? Oleg > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > HTTPCORE-155.patch, IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt, myoutput.txt, patch.08-12-17.tar.gz, > patch.08-12-18.tar.gz, patch.08-12-22.tar.gz, patch.08-12-30.tar.gz, > patch.09-03-18.tar.gz, summary_patch.09-03-18 > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(Abstra
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12683105#action_12683105 ] Marc Beyerle commented on HTTPCORE-155: --- Whoops, just noticed that in my "summary" patch, I switched on interest ops queueing, 'cause I was playing around after posting the regular patch, which has the queueing disabled. So better use Asankha's version. > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > HTTPCORE-155.patch, IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt, myoutput.txt, patch.08-12-17.tar.gz, > patch.08-12-18.tar.gz, patch.08-12-22.tar.gz, patch.08-12-30.tar.gz, > patch.09-03-18.tar.gz, summary_patch.09-03-18 > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client instances on this > single system... each with potentially 2 active connections simultaneously... > there is also virtually no CPU load (i.e. less then 5%) on this system... -- Thi
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12683072#action_12683072 ] Oleg Kalnichevski commented on HTTPCORE-155: Great! I'll happily commit the patch, but would it be a big deal for you to generate a single patch file in the udiff format? If you have a command based svn client, the following command will do the trick svn diff > my.patch Oleg > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt, myoutput.txt, patch.08-12-17.tar.gz, > patch.08-12-18.tar.gz, patch.08-12-22.tar.gz, patch.08-12-30.tar.gz, > patch.09-03-18.tar.gz > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client instances on this > single system... each with potentially 2 active connections simultaneously... > there is also virtually no CPU load (i.e. less then 5%) on this system... -- This message is a
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12683057#action_12683057 ] Marc Beyerle commented on HTTPCORE-155: --- Hi all, I adapted my patch to the latest SVN trunk. It consists of the previously described code changes, plus the possibility to switch interest ops queueing on and off (default is off). In order to be able to do so, I added the required static in NIOReactorPNames and the corresponding methods in NIOReactorParams. Furthermore, I had to slightly adapt AbstractMultiworkerIOReactor and BaseIOReactor. I ran the unit tests again in all combinations (interest ops queueing on and off, both with the Sun JVM and the IBM JVM) and the only test that failed - as expected, of course - was the combination IBM JVM + no queueing. For those, who started browsing through the comments just here: I expected this combination to fail, since the "no queueing" option behaves exactly as the original code, which was the reason why I wrote this patch: to make the IBM JVM work flawlessly with HttpCore NIO. In addition to that, I ran my performance tests again, and as before the patch has no impact on performance for the Sun JVM, and the IBM JVM performs quite nicely with queueing enabled. For applications using HttpCore NIO (such as Apache Synapse): In order to enable interest ops queueing, one has to call NIOReactorParams.setInterestOpsQueueing(params, true) before initializing the I/O reactors. Cheers, Marc > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt, myoutput.txt, patch.08-12-17.tar.gz, > patch.08-12-18.tar.gz, patch.08-12-22.tar.gz, patch.08-12-30.tar.gz, > patch.09-03-18.tar.gz > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelect
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12677457#action_12677457 ] Oleg Kalnichevski commented on HTTPCORE-155: The most important one would be making interest op queueing optional. Per default I/O reactors should handle interest ops as they do presently. One would have to explicitly enable interest op queueing by passing a parameter to the I/O reactor. All other issues can be dealt with incrementally. Oleg > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt, myoutput.txt, patch.08-12-17.tar.gz, > patch.08-12-18.tar.gz, patch.08-12-22.tar.gz, patch.08-12-30.tar.gz > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client instances on this > single system... each with potentially 2 active connections simultaneously... > there is also virtually no CPU load (i.e. less then 5%
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12677438#action_12677438 ] Marc Beyerle commented on HTTPCORE-155: --- Hi Oleg, Yes, I will adapt the patch to the latest SVN trunk. Due to legal issues, I cannot commit the code directly - I will attach it to this JIRA issue as soon as I find the time to make the changes. What brush-ups are you looking for? Cheers, Marc > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt, myoutput.txt, patch.08-12-17.tar.gz, > patch.08-12-18.tar.gz, patch.08-12-22.tar.gz, patch.08-12-30.tar.gz > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client instances on this > single system... each with potentially 2 active connections simultaneously... > there is also virtually no CPU load (i.e. less then 5%) on this system... -- This message is automatically ge
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12677313#action_12677313 ] Oleg Kalnichevski commented on HTTPCORE-155: Marc, Now that HttpCore 4.0 release is out we can start working on getting your patch into the official code line. Would you be willing to put more efforts into updating the patch against the latest SVN trunk and doing some additional brush-ups? Oleg > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt, myoutput.txt, patch.08-12-17.tar.gz, > patch.08-12-18.tar.gz, patch.08-12-22.tar.gz, patch.08-12-30.tar.gz > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client instances on this > single system... each with potentially 2 active connections simultaneously... > there is also virtually no CPU load (i.e. less then 5%) on this system... -- This message is automa
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12659942#action_12659942 ] Marc Beyerle commented on HTTPCORE-155: --- Hi all, First off, a big "Thank You" for all your comments / concerns. They are all valid, and I will try to address them as thoroughly as I can: - The root cause of the problem is not really related to performance per se, but to the fact that the IBM JVM fully blocks, when one thread is executing a select() operation and another thread tries to perform an interestOps() operation. This can be observed (for example) when running the Apache Synapse "Stock Quote" sample: It simply runs into a timeout after a while, so the issue really boils down to a "works / doesn't work" and not a "works faster / works slower" problem. We may now argue that the SelectionKey contract is improvable, but as a matter of fact the contract has been around for quite some time and we have to somehow address JVM implementations, which exhibit a runtime behavior like IBM's JVM. Although unlikely, even Sun could change its JVM's behavior in a future release. - The basic idea behind my patch is exactly as outlined by Sam. First, I replicate interestOps() operations and store them in a queue. Second, both select() and interestOps() operations are executed by one and the same thread, in order to "naturally" avoid blocking situations by mutual exclusion. Although this sounds like quite some overhead at first, you can verify that it actually isn't when you execute some performance tests. The Sun JVM performs exactly the same amount of I/O operations in exactly the same amount of time, regardless of whether either my patch or the original 4.0-beta1 code is used. - I originally changed the select() timeout down to 1ms, in order to process the interestOps() queue as quickly as possible and to avoid situations where a huge amount of interestOps() operations pile up. I also didn't like it, but couldn't think of any other way of achieving a timely processing of the queue. However, I changed the patch to include the idea outlined in one of the above comments: select() now has the original "selectTimeout" again, and I wakeup() the selector after enqueueing an interestOps() operation. Hence, when there is nothing to do, the I/O reactor sleeps. I performed my tests again, and it even slightly improved performance. Funny enough, although the 1ms loop seemed to be tight, it didn't consume CPU when I looked at my Linux system with "sadc". - An extra thanks goes to Asankha, whose tests pointed me to something I forgot (took me quite some time to figure out): Of course I have to flush the interestOps() queue before returning the current interest set. Otherwise, the interest set may still be changed by an operation waiting in the queue after the supposed current value has been returned. I changed the patch accordingly and now the unit tests run correctly with the IBM JVM again. Funny that it doesn't occur with the Sun JVM - this affirms the assumption that we're also dealing with thread timing issues here. Cheers, Marc > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt, myoutput.txt, patch.08-12-17.tar.gz, > patch.08-12-18.tar.gz, patch.08-12-22.tar.gz, patch.08-12-30.tar.gz > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2A
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12659941#action_12659941 ] Michael Clark commented on HTTPCORE-155: Hi Asankha, Sorry! I did not realize you were using the beta1 tag. I can indeed reproduce your test failures when using the beta1 tag. For whatever it's worth, when I run Marc's Dec 22 patch in the context of the trunk [as of yesterday], all tests are passing for me. regards, Mike > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt, myoutput.txt, patch.08-12-17.tar.gz, > patch.08-12-18.tar.gz, patch.08-12-22.tar.gz > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client instances on this > single system... each with potentially 2 active connections simultaneously... > there is also virtually no CPU load (i.e. less then 5%) on this system... -- This message is auto
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12659649#action_12659649 ] Michael Clark commented on HTTPCORE-155: Hi asankha, With the Dec 22 patch, I am not seeing any unit test failures. I ran with both Sun JRE 1.6.0_11 and Sun JRE 1.5.0_17. I ran ``mvn clean`` and then ``mvn test`` out of the /project/ dir to execute the tests. regards, Mike > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt, patch.08-12-17.tar.gz, > patch.08-12-18.tar.gz, patch.08-12-22.tar.gz > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client instances on this > single system... each with potentially 2 active connections simultaneously... > there is also virtually no CPU load (i.e. less then 5%) on this system... -- This message is automatically generated by JIRA. - You can reply to this email to ad
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12659562#action_12659562 ] Asankha C. Perera commented on HTTPCORE-155: Hi Marc I tested your 22-dec patch with Synapse, and for the same 20 user, 1 iteration test I got 249 & 263 TPS with the Sun JDK, and 281 & 290 TPS with the IBM JDK. However, I saw one out of the total 200,000 requests failing in one run of Synapse with the IBM JDK. Did you notice that some of the unit tests fails with the latest patch: Running org.apache.http.nio.TestAll Tests run: 97, Failures: 4, Errors: 0, Skipped: 0, Time elapsed: 47.652 sec <<< FAILURE! Results : Failed tests: testSimpleHttpGets(org.apache.http.nio.protocol.TestNIOSSLHttp) testSimpleBasicHttpEntityEnclosingRequestsWithContentLength(org.apache.http.nio.protocol.TestNIOSSLHttp) testSimpleBasicHttpEntityEnclosingRequestsChunked(org.apache.http.nio.protocol.TestNIOSSLHttp) testSimpleBasicHttpEntityEnclosingRequestsHTTP10(org.apache.http.nio.protocol.TestNIOSSLHttp) Tests run: 97, Failures: 4, Errors: 0, Skipped: 0 cheers asankha > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt, patch.08-12-17.tar.gz, > patch.08-12-18.tar.gz, patch.08-12-22.tar.gz > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/r
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12659198#action_12659198 ] Oleg Kalnichevski commented on HTTPCORE-155: > However, all this spinning in the reactor execution loop is inefficient. > Instead of spinning/polling in the reactor, would it work to > invoke Selector#wakeup immediately after enqueueing an interestOps queue > item? Yes, that is the way it is supposed to be. Would this allow the reactor to wake up in > a timely fashion when there are interestOps items in queue -- yet still allow > the reactor to sleep when there's nothing to do? Yes, sir. Oleg > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt, patch.08-12-17.tar.gz, > patch.08-12-18.tar.gz, patch.08-12-22.tar.gz > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client instances on this > single sys
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12659172#action_12659172 ] Michael Clark commented on HTTPCORE-155: Sam, Thanks for that explanation, it helped me a lot. I agree that a change in the VM implementation would be the cleanest resolution to this particular problem. That, combined with a tightening up of the SelectionKey contract to remove some of the "implementation dependent" ambiguity that the contract allows for. Unfortunately, we are probably stuck with that contract for a while, as it's been there for Java 1.4, 5 and now 6. A couple things that your message clarified for me: 1) I had not seen the doc comment about naive vs. high-performance implementations 1.1) And so, I did not realize that a reduction in the length of time that the #interestOps(int) method blocks, can be achieved by ensuring that #interestOps(int) is invoked only when no thread(s) are in #select(). Well, at least the docs hint fairly strongly at this. 2) It explains to me why Marc's patch relieves the symptoms of this particular problem: by making sure that #interestOps(int) is invoked only by the thread that is #select()ing, he can serialize the calls to #interestOps(int) and #select(), which ensures that their invocation is mutually exclusive. And so I think Marc's patch is getting close to the workaround you outlined, Sam? Now that I understand the problem more thoroughly (hopefully), I can perhaps offer some further review on his changes: As I mentioned before, Marc's patch is ignoring the selectTimeout member var of AbstractIOReactor -- this will need to be addressed somehow (probably by reintroducing its use.) But why did he make that change? The only reason I can see for such an aggressive selectTimeout as 1ms, is the need to have the reactor wake up, retrieve, and process pending interestOps queue items, even when the reactor has no reason to wake up out #select. Requests to change interestOps will not actually take effect until the reactor wakes up for some reason and processes the interestOps queue. Since enqueueing interestOps requests does not wake the reactor, it is possible for very many interestOps requests pile up and not be processed in a timely fashion -- if the reactor is asleep in #select(long), with no reason to wake up. So, Marc has set the select timeout very low, which guarantees that the reactor will give the selectionOps queue a great deal of attention, which helps get those interestOps requests processed in a timely manner. However, all this spinning in the reactor execution loop is inefficient. Instead of spinning/polling in the reactor, would it work to invoke Selector#wakeup immediately after enqueueing an interestOps queue item? That way the reactor could wake up in a timely fashion whenever there are interestOps items in queue, but be able stay asleep if there are none. regards, Mike > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt, patch.08-12-17.tar.gz, > patch.08-12-18.tar.gz, patch.08-12-22.tar.gz > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyIm
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12659137#action_12659137 ] Sam Berlin commented on HTTPCORE-155: - The issue stems from the fact the documentation of SelectionKey states that it is OK for a naive implementation of a SelectionKey read or write to block indefinitely if a selection operation is already in progress. The issue is not so much with the fact that an implementation blocks -- it has more to do with the fact that it can block if a selection is in progress. This documentation is counter to the most typical (and easiest) use of a SelectionKey. The average NIO program allows users to change the interestOps on any thread, and after changing the ops, wakes up the selector. On the Sun JVM this is allowed and works quite perfectly -- the ops change, the selector wakes up, the selector loops again and selects on the new interestOps. In my opinion, the documentation on SelectionKey that is is OK to block while a selection is in progress should be removed. It makes implementing a high-performance NIO program much more difficult to architect properly. If the code were to workaround the fact that this blocking is acceptable and "normal" behavior, the code would need to change such that code requesting a change in interestOps must: 1) Locally replicate the desired interestOps (including all prior interestOps changes). 2) Wakeup the Selector 3) The selector thread must retrieve the desire interestOps from each local replication and set the new interestOps on the actual SelectionKey. 4) Perform the select. In effect, this requires a duplication of SelectionKey's job. Each SelectionKey must have associated with it the newly desired ops that can only actually be set by the selector after it wakes up. > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt, patch.08-12-17.tar.gz, > patch.08-12-18.tar.gz, patch.08-12-22.tar.gz > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12659132#action_12659132 ] Michael Clark commented on HTTPCORE-155: Hi all, As I understand it, the root problem is that java.nio.channels.SelectionKey#interestOps(int) is allowed to block, and, in the IBM JDK, this allowance is taken to heart, and the method really does block for some time. In fact, it blocks for so much time that it is undesirable to invoke SelectionKey#interestOps(int) on the reactor thread, as this will delay the reactor thread from dispatching (potentially thousands of) other ready-to-distribute events, which ends up causing performance degradation for other, unrelated connections. I'm hoping I understand the problem correctly, as I have a couple questions/concerns about Marc's proposed changes. One is that it seems to me that the invocation of SelectionKey#interestOps(int) is still being done on the reactor thread -- it is just being done at a different stage within the reactor's execution loop. To me, it seems like this should not solve the core problem. The reactor thread is still invoking SelectionKey#interestOps(int), and presumably SelectionKey#interestOps(int) is still blocking, and if I am understanding things correctly, the reactor will still be choked during this block. My second question/concern is the hard-coding of the Selector#select(long) timeout parameter to 1 millisecond. At face value, this seems less than ideal. I am not knowledgeable enough yet about NIO and the HC non-blocking API to make a judgment call on this... architecturally. However, if the select timeout is going to be hard-coded, the member variable AbstractIOReactor#selectTimeout should be removed, renamed or re-purposed -- as it is no longer be honored as part of the selection process. Would perhaps a better solution to this problem, be to introduce or reuse an Executor thread pool (where? TBD), and hand off the task of setting interestOps to a non-reactor worker thread? Of course, this makes the setting of interestOps asynchronous to the reactor -- the impact of which must be evaluated and dealt with. I am not yet quite far enough along in researching NIO and the Reactor to determine how to properly manage any intermediate state, if this change were to be introduced. For example, it seems to me that certain operations should only proceed/occur after the interestOps have successfully been set. I need to determine what these operations are, how they are triggered, and how to make sure they happen at the right time, and on the right thread, even in the face of interestOps being set asynchronously. regards, Mike > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt, patch.08-12-17.tar.gz, > patch.08-12-18.tar.gz, patch.08-12-22.tar.gz > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnec
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12657832#action_12657832 ] Marc Beyerle commented on HTTPCORE-155: --- Hi Oleg, Thank you for your positive feedback. You are really tough to convince ;-) Following your suggestions, I changed a few things in the code itself, without changing the ideas behind the patch: The queue is a regular instance member now, and I don't exhibit the queue itself to the "outside world", but rather only offer an add()... method. In addition, I now changed the existing code as little as possible - for example, I moved the processing of the queue in an extra method, so that the amount of lines of code in the main loop in AbstractIOReactor grows as little as possible. Here's a bit more explanation of what I implemented, just to give you an idea about the decisions I had to take: Since the constructor of IOSessionImpl already depends on SelectionKey and contains exception handling, it's not much additional cost to add a reference to the calling AbstractIOReactor (plus check) there. The reason, why the loop in processPendingInterestOps() is entirely within the synchronized block, is to process all pending operations, which exist at the time of invocation, in one operation. If for example only the interestOpsQueue.remove() call was placed within the synchronized block, then this would allow the queue to grow while the processing is in progress. The only detail that I can think of right now, which one could implement differently, is to move the check for a valid operationType from addInterestOpsQueueElement() to the constructor of IOSessionQueueElement. But this would require exception handling there, which is more expensive than the if/else check in the method. Anyways, the queue elements are checked in detail in the add()... method, before they enter the queue. I ran some tests with both JVMs again, and the above changes didn't have a negative effect on throughput. Again, I couldn't observe any exceptions. Cheers, Marc > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt, patch.08-12-17.tar.gz > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12657334#action_12657334 ] Oleg Kalnichevski commented on HTTPCORE-155: Marc, This sounds great! Many thanks for such a thorough analysis of the problem. However, I still would like to release HttpCore 4.0 as is, and resolve this issue in the course of the 4.1 development. If everything goes well, HttpCore 4.0 should be released by the end of January 2009 I took a cursory look at patch. It looks fine conceptually but still could use some more work on the code level. For a start it would be great to make the selectorQueues non-static. Cheers, Oleg > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt, patch.08-12-17.tar.gz > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client instances on this > single system... each with potent
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[
https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12657317#action_12657317
]
Marc Beyerle commented on HTTPCORE-155:
---
Hi folks,
I received feedback from our customer: They tested my patch under Linux on
System z and it works. However, they also performed some tests under Windows,
where they discovered some - what they call - "dropouts". Therefore, I also
conducted some more tests and found that the Sun JVM produces intermittent
connection time-outs (with my patch enabled) under very heavy load. Funny
enough, I also saw a connection time-out when I tested the Sun JVM with the
original, un-modified code, but couldn't reproduce it reliably.
I am beginning to agree with our Java VM L3 support, that we are probably
facing a thread timing issue here. Why else would synchronization have an
influence on all this? Anyway, I completely re-wrote my patch (and had to go
through the entire IBM approval process again...) in such a way that it uses a
queueing mechanism, as proposed by Oleg. With this, I now achieve "natural"
synchronization: The I/O operations are carried out one after the other, in
order to avoid the blocking behavior, but now without Java monitor involvement.
I conducted quite extensive testing with the latest / greatest 1.5 JVM versions
now, and all scenarios worked just fine without any exceptions. I tested 50
concurrent threads hammering at Synapse ("Stock Quote"), with 400 requests each
(in addition, I performed each test several times):
- Intel Linux & Sun JVM
- Intel Linux & Sun JVM & patch
- Intel Linux & IBM JVM & patch
- Windows & Sun JVM
- Windows & Sun JVM & patch
- Windows & IBM JVM & patch
- Linux on System z & IBM JVM & patch
As a nice side-effect of the queueing implementation, the patch is ways faster
now :-) And it "future-proofs" HttpComponents, in case Sun decides to change
NIO behavior in a later release of the JDK.
@Asankha: I would really like to have your opinion - could you please perform
your tests also with the new patch?
Cheers,
Marc
> Performance issues with IBM JRE 6.0
> ---
>
> Key: HTTPCORE-155
> URL: https://issues.apache.org/jira/browse/HTTPCORE-155
> Project: HttpComponents HttpCore
> Issue Type: Bug
> Components: HttpCore NIO
>Affects Versions: 4.0-beta1
> Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore
> Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking
>Reporter: Tom McSorley
> Fix For: 4.1
>
> Attachments: AbstractIOReactor.diff, AbstractIOReactor.java,
> IOSessionImpl.diff, IOSessionImpl.java,
> javacore.20081203.153723.32300.0001.txt, patch.08-12-17.tar.gz
>
>
> I'm issuing a second HTTP Request on a connection that has very recently
> returned a null for the submitRequest() call... this 2nd request is being
> issued approximately 500ms after the submitRequest() null is returned... so
> the connection has just been established, an HTTP Request/Response-200 cycle
> has completed just prior to this 2nd request being issued. I'm seeing
> unusually long delays in the requestOutput() call (verified by surrounding
> timing prints)... that can range anywhere from a few milliseconds on up to 60
> seconds... It eventually unwinds, and then the submitRequest() is called...
> this 2nd request is dispatched and works fine... but, it is delayed
> considerably... Is this a known issue and is there a possible work-around?
> Here's the JVM related thread information:
> The thread being delayed and stuck in the requestOutput() call for a long
> time (mostly longer than 5 seconds):
> 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8,
> state:B, prio=5
> 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5,
> native policy:UNKNOWN)
> 4XESTACKTRACE at
> sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60)
> 4XESTACKTRACE at
> org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113)
> 4XESTACKTRACE at
> org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158)
> (non important stack information removed)
> 4XESTACKTRACE at
> java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919)
> 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735)
> Here's the monitor that this thread is blocked and waiting on:
> 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30:
> 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O
> dispatcher 7" (0x2A208E00), entry count 1
> 3LKWAITERQWaiting to enter:
> 3LKWAITER"pool-2-thread-5" (0x2AEECE00)
> And here's the thread that currently has this monitor locked:
> 3XMTHREADINFO "
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12656577#action_12656577 ] Marc Beyerle commented on HTTPCORE-155: --- Hi Asankha, No I didn't change the "Stock Quote" service itself, only the client side of it, in order to be able to simulate parallel users and to execute several requests in a row. Specifically, I only changed samples.userguide.StockQuoteClient. Cheers, Marc > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client instances on this > single system... each with potentially 2 active connections simultaneously... > there is also virtually no CPU load (i.e. less then 5%) on this system... -- This message is automatically generated by JIRA. - You can reply to this email to add a comment to the issue online. -
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12656053#action_12656053 ] Asankha C. Perera commented on HTTPCORE-155: Hi Marc My expectation from your patch was correct operation on the IBM JDK under load and not performance.. and I think its doing pretty well as a work around. I looked into the internals of the IBM JDK, and it seems like they bundle some of the sun.nio.ch classes.. but not the EPollSelectorProvider etc.. I wonder why IBM left this out - or is it available in the new JDKs, that are targeted for better NIO performance? I have also been trying out a queued approach as suggested by Oleg, but have been having some issues which needs some more time to overcome. For a simple test I use the Synapse sample #150, with the SimpleStockQuoteService (with the System.out.println commented out) and use an updated version of the HttpCore benchmark which I call the JavaBench :) .. to generate load. Typically for the above run I used 20 concurrent users, each iterating 10,000 iterations and ran this test thrice. The first was a warm up run which was ignored, and I just looked at the next two TPS results. I wonder why I didn't see a perf improvement with J9.. did you change the code of the stock quote service by any chance? cheers asankha > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTAC
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12656029#action_12656029 ] Marc Beyerle commented on HTTPCORE-155: --- Hi Asankha, My intention was never to write a patch to improve performance - I simply wanted to make Synapse work for our customer. Nevertheless, your TPS results puzzled me and so I also performed a few tests on my laptop. What I did was the following: I took the "Stock Quote" sample that comes with Synapse and turned it into a multi-threaded application. When I run this against both the latest / greatest 1.5 version of the Sun JVM and the IBM JVM, my results show the opposite ranking from yours. I used 50 threads and 200 "quote" requests per thread, in order to put my laptop under full load. How did you produce your numbers? Please don't get me wrong, I don't want to start a performance discussion here, I am only curious :-) Cheers, Marc > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/uti...@00b09208/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIORe
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12655561#action_12655561 ] Asankha C. Perera commented on HTTPCORE-155: Hi Marc I tested your patch against 4.0-beta1, and here are my numbers from two rounds of a 20,000 iteration simple test TPS on a laptop for simple proxying with Synapse IBM JDK + Patch: 241, 251 Sun JDK + Patch : 285, 285 Sun JDK : 291, 291 I have been following the recent updates on this from Oleg, but do agree with him that ideally this should be fixed in the JRE. Once again I thank you for sharing your patch and research on this issue. If you do hear from the IBM JRE team on any updates, do keep us informed thanks asankha > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > IOSessionImpl.diff, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/[EMAIL PROTECTED]/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client inst
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12653825#action_12653825 ] Marc Beyerle commented on HTTPCORE-155: --- Hi Oleg, I will attach the patch to this JIRA Issue in udiff format. Sorry, my editor was configured to remove EOL whitespace, so the patch is a bit bigger than expected. And yes, my concern was also performance. But when I monitor my system, I do not see a lot of CPU activity, even with this tight loop... If the underlying native implementation of Java NIO is based on polling, then this is simply expected behavior. I did experiment with polling under C a while ago, and this caused virtually no CPU at all. Your idea with using a queueing mechanism sounds very attractive to me :-) However, I have already spent quite a bit of time for all this, so I don't know if I can spent even more... And when I talked to the JVM support, they explained to me that the behavior, which is described above, is indeed needed just in the way it is. Thanks for your feedback & Cheers, Marc > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.diff, AbstractIOReactor.java, > IOSessionImpl.java, javacore.20081203.153723.32300.0001.txt > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/[EMAIL PROTECTED]/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12653773#action_12653773 ] Oleg Kalnichevski commented on HTTPCORE-155: Marc, I am very appreciative of the time and effort you have put into this patch. I understand it must be difficult for an IBM staffer to get permissions to contribute code developed internally to an open-source project. While I think the patch represents a feasible workaround, I have a number of concerns regarding the impact of the proposed changes on performance of the NIO transport. Firstly, reducing select interval to 1ms effectively makes I/O dispatch threads run in a tight loop this putting unnecessary high load on CPU(s). Secondly, I am concerned about over-synchronization in the IOSessionImpl. A better approach to solving this problem would be a queuing mechanism for modifications of interest ops similar to that for new sessions. The main idea is to ensure that any changes to the interest ops take place on the I/O dispatch thread after the I/O select operation. That would eliminate the need for synchronization altogether. Having said all that, I DO think the fix ought to be made where it is due, that is IBM JRE code. PS: Could you please submit the patch in udiff format? > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.java, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/[EMAIL PROTECTED]/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12653763#action_12653763 ] Asankha C. Perera commented on HTTPCORE-155: Hi Marc Its great to be able to get in touch with someone from IBM, since this is quite important to at least a few IBM customers. I assumed this to be fixable as well, but didn't have the time yet to dig deeper into this. I appreciate your patch and the work behind, and especially getting the approval to share this back with us. I will test this and get back to you. many thanks asankha > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: AbstractIOReactor.java, IOSessionImpl.java, > javacore.20081203.153723.32300.0001.txt > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/[EMAIL PROTECTED]/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client instances on this > single system... each with potentially 2 active connections simultaneously... > there is also virtually no CPU load (i.e. less then 5%) on this system... -- This message is automatically genera
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12653688#action_12653688 ] Marc Beyerle commented on HTTPCORE-155: --- Hi, folks! My name is Marc Beyerle and I am from IBM. I'm not from the JVM development, so please don't blame me :-) I am from an IBM System z (aka mainframe) customer center, and one of our customers is currently running into the above described problem. They also use Apache Synapse with the IBM JVM, like Asankha. I dug into this and found that the root cause is a "specification hole". If you read the Sun API here: http://java.sun.com/j2se/1.5.0/docs/api/java/nio/channels/SelectionKey.html you will find this: "... In a naive implementation, reading or writing the interest set may block indefinitely if a selection operation is already in progress". And exactly this is happening here. While org.apache.http.impl.nio.reactor.AbstractIOReactor does a select(), the IOSession cannot perform an interestOps(ops) operation. My suggestion is to synchronize around this, such that a deadlock does not occur. I wrote a fix for this against 4.0-beta1 and I will attach the files to this issue. I tested it with both the IBM JVM and the Sun JVM and it works just fine. You will notice that I had to reduce the timeout for the select() operation down to the minimum (1ms), in order to make things reactive. Also, before each select() operation, I check whether one of the IOSessions is waiting to perform an interestOps(ops) operation. In the loop around select(), I start looking for waiting IOSessions after the last waiting one, in order not to privilege the IOSessions at the beginning of the Iterator. I really hope you find this patch useful and you cannot imagine how much work it took me to get all the IBM approvals to post the patch to this issue here. Cheers, Marc > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.1 > > Attachments: javacore.20081203.153723.32300.0001.txt > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/[EMAIL PROTECTED]/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSel
[jira] Commented: (HTTPCORE-155) Performance issues with IBM JRE 6.0
[ https://issues.apache.org/jira/browse/HTTPCORE-155?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12580067#action_12580067 ] Tom McSorley commented on HTTPCORE-155: --- Oleg, I will run each version of the IBM JVM's I have access to and report on the results to you... I will try to get this done within the next day. Regards, - tom > Performance issues with IBM JRE 6.0 > --- > > Key: HTTPCORE-155 > URL: https://issues.apache.org/jira/browse/HTTPCORE-155 > Project: HttpComponents HttpCore > Issue Type: Bug > Components: HttpCore NIO >Affects Versions: 4.0-beta1 > Environment: Windows 2003 SP2 - IBM J2RE 1.6.0 build 2.4 - HTTPCore > Beta1 - Dual Core CPU 3.0Ghz - 1Gbps networking >Reporter: Tom McSorley > Fix For: 4.0-rc1 > > > I'm issuing a second HTTP Request on a connection that has very recently > returned a null for the submitRequest() call... this 2nd request is being > issued approximately 500ms after the submitRequest() null is returned... so > the connection has just been established, an HTTP Request/Response-200 cycle > has completed just prior to this 2nd request being issued. I'm seeing > unusually long delays in the requestOutput() call (verified by surrounding > timing prints)... that can range anywhere from a few milliseconds on up to 60 > seconds... It eventually unwinds, and then the submitRequest() is called... > this 2nd request is dispatched and works fine... but, it is delayed > considerably... Is this a known issue and is there a possible work-around? > Here's the JVM related thread information: > The thread being delayed and stuck in the requestOutput() call for a long > time (mostly longer than 5 seconds): > 3XMTHREADINFO "pool-2-thread-5" TID:0x2AEECE00, j9thread_t:0x2A7189A8, > state:B, prio=5 > 3XMTHREADINFO1(native thread ID:0x1B44, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/SelectionKeyImpl.interestOps(SelectionKeyImpl.java:60) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/IOSessionImpl.setEvent(IOSessionImpl.java:113) > 4XESTACKTRACE at > org/apache/http/impl/nio/NHttpConnectionBase.requestOutput(NHttpConnectionBase.java:158) > (non important stack information removed) > 4XESTACKTRACE at > java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > Here's the monitor that this thread is blocked and waiting on: > 2LKMONINUSE sys_mon_t:0x2A708AF8 infl_mon_t: 0x2A708B30: > 3LKMONOBJECT sun/nio/ch/[EMAIL PROTECTED]/00B09214: Flat locked by "I/O > dispatcher 7" (0x2A208E00), entry count 1 > 3LKWAITERQWaiting to enter: > 3LKWAITER"pool-2-thread-5" (0x2AEECE00) > And here's the thread that currently has this monitor locked: > 3XMTHREADINFO "I/O dispatcher 7" TID:0x2A208E00, j9thread_t:0x2A6EC73C, > state:R, prio=5 > 3XMTHREADINFO1(native thread ID:0x830, native priority:0x5, > native policy:UNKNOWN) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll0(Native Method) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:308(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl$SubSelector.access$500(WindowsSelectorImpl.java(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:162(Compiled > Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69(Compiled Code)) > 4XESTACKTRACE at > sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80(Compiled Code)) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractIOReactor.execute(AbstractIOReactor.java:121) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/BaseIOReactor.execute(BaseIOReactor.java:70) > 4XESTACKTRACE at > org/apache/http/impl/nio/reactor/AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:318) > 4XESTACKTRACE at java/lang/Thread.run(Thread.java:735) > I should also note that we're attempting to use 1000 client instances on this > single system... each with potentially 2 active connections simultaneously... > there is also virtually no CPU load (i.e. less then 5%) on this system... -- This message is automatically generated by JIRA. - You can reply to this email to add a comment to the issue online. - To unsubscribe, e-mail: [EMAIL PROTECTED] For additional commands, e-mail: [EMAIL PROTECTED]
