directory-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Alex Karasulu <aok...@bellsouth.net>
Subject [MINA] ThreadPoolRegressionTest takes too long to run
Date Tue, 27 Dec 2005 22:32:52 GMT
After trying a command line run I saw this test taking forever (over 5 
minutes sometimes):

[surefire] Running org.apache.mina.filter.ThreadPoolFilterRegressionTest
[surefire] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 275.258 sec

Sometimes it blocked longer and I had to kill the process.  I got a 
thread dump just in case there was blocking even though I suspect the 
loops that iterate 1 million times to be the primary cause:

-------------------------- Thread Dump Start --------------------------

Full thread dump Java HotSpot(TM) Client VM (1.5.0_02-b09 mixed mode, 
sharing):

"IoThreadPool-5" prio=1 tid=0x0a1cd270 nid=0x7b9d in Object.wait() 
[0xb0aa0000..0xb0aa0f30]
        at java.lang.Object.wait(Native Method)
        at 
org.apache.mina.filter.ThreadPoolFilter$Worker.waitForPromotion(ThreadPoolFilter.java:493)
        - locked <0x89f57740> (a java.lang.Object)
        at 
org.apache.mina.filter.ThreadPoolFilter$Worker.run(ThreadPoolFilter.java:366)

"IoThreadPool-3" prio=1 tid=0x0a1c7030 nid=0x7b9c in Object.wait() 
[0xb1838000..0xb1838fb0]
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:474)
        at 
org.apache.mina.util.BlockingQueue.waitForNewItem(BlockingQueue.java:55)
        - locked <0x89f3d958> (a org.apache.mina.util.BlockingQueue)
        at 
org.apache.mina.filter.ThreadPoolFilter$Worker.fetchBuffer(ThreadPoolFilter.java:394)
        - locked <0x89f3d958> (a org.apache.mina.util.BlockingQueue)
        at 
org.apache.mina.filter.ThreadPoolFilter$Worker.run(ThreadPoolFilter.java:369)

"IoThreadPool-4" prio=1 tid=0x0a546d50 nid=0x7b9b in Object.wait() 
[0xb0a1f000..0xb0a1fe30]
        at java.lang.Object.wait(Native Method)
        at 
org.apache.mina.filter.ThreadPoolFilter$Worker.waitForPromotion(ThreadPoolFilter.java:493)
        - locked <0x89f3df00> (a java.lang.Object)
        at 
org.apache.mina.filter.ThreadPoolFilter$Worker.run(ThreadPoolFilter.java:366)

"IoThreadPool-2" prio=1 tid=0x0a4e5750 nid=0x7b9a runnable 
[0xb17b7000..0xb17b7eb0]
        at 
org.apache.mina.common.WriteFuture.setWritten(WriteFuture.java:102)
        at 
org.apache.mina.filter.ThreadPoolFilterRegressionTest$DummyNextFilter.messageReceived(ThreadPoolFilterRegressionTest.java:323)
        at 
org.apache.mina.filter.ThreadPoolFilter.processEvent(ThreadPoolFilter.java:665)
        at 
org.apache.mina.filter.ThreadPoolFilter$Worker.processEvents(ThreadPoolFilter.java:421)
        at 
org.apache.mina.filter.ThreadPoolFilter$Worker.run(ThreadPoolFilter.java:376)

"IoThreadPool-1" prio=1 tid=0x0a51f358 nid=0x7b99 in Object.wait() 
[0xb1f90000..0xb1f91130]
        at java.lang.Object.wait(Native Method)
        at 
org.apache.mina.filter.ThreadPoolFilter$Worker.waitForPromotion(ThreadPoolFilter.java:493)
        - locked <0x89f3db50> (a java.lang.Object)
        at 
org.apache.mina.filter.ThreadPoolFilter$Worker.run(ThreadPoolFilter.java:366)

"DatagramAcceptor-2" prio=1 tid=0x0a549cd8 nid=0x7b8a runnable 
[0xb1736000..0xb1736fb0]
        at sun.nio.ch.PollArrayWrapper.poll0(Native Method)
        at sun.nio.ch.PollArrayWrapper.poll(PollArrayWrapper.java:100)
        at sun.nio.ch.PollSelectorImpl.doSelect(PollSelectorImpl.java:56)
        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:69)
        - locked <0x8949ba98> (a sun.nio.ch.Util$1)
        - locked <0x8949ba88> (a java.util.Collections$UnmodifiableSet)
        - locked <0x8949b968> (a sun.nio.ch.PollSelectorImpl)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:80)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:84)
        at 
org.apache.mina.transport.socket.nio.support.DatagramAcceptorDelegate$Worker.run(DatagramAcceptorDelegate.java:258)

"Low Memory Detector" daemon prio=1 tid=0x0a01a870 nid=0x7b75 runnable 
[0x00000000..0x00000000]

"CompilerThread0" daemon prio=1 tid=0x0a019320 nid=0x7b74 waiting on 
condition [0x00000000..0xb2399a98]

"Signal Dispatcher" daemon prio=1 tid=0x0a0182d0 nid=0x7b73 runnable 
[0x00000000..0x00000000]

"Finalizer" daemon prio=1 tid=0x0a0135d0 nid=0x7b72 in Object.wait() 
[0xb269b000..0xb269bfb0]
        at java.lang.Object.wait(Native Method)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
        - locked <0x89180df0> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=1 tid=0x0a012898 nid=0x7b71 in 
Object.wait() [0xb271c000..0xb271ce30]
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:474)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
        - locked <0x89180e70> (a java.lang.ref.Reference$Lock)

"main" prio=1 tid=0x09fd59b8 nid=0x7b6e in Object.wait() 
[0xbf87f000..0xbf880d38]
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:474)
        at org.apache.mina.common.IoFuture.join(IoFuture.java:90)
        - locked <0x88d42990> (a org.apache.mina.common.WriteFuture)
        at 
org.apache.mina.filter.ThreadPoolFilterRegressionTest.testShutdown(ThreadPoolFilterRegressionTest.java:124)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at junit.framework.TestCase.runTest(TestCase.java:154)
        at junit.framework.TestCase.runBare(TestCase.java:127)
        at junit.framework.TestResult$1.protect(TestResult.java:106)
        at junit.framework.TestResult.runProtected(TestResult.java:124)
        at junit.framework.TestResult.run(TestResult.java:109)
        at junit.framework.TestCase.run(TestCase.java:118)
        at junit.framework.TestSuite.runTest(TestSuite.java:208)
        at junit.framework.TestSuite.run(TestSuite.java:203)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at 
org.apache.maven.surefire.battery.JUnitBattery.executeJUnit(JUnitBattery.java:230)
        at 
org.apache.maven.surefire.battery.JUnitBattery.execute(JUnitBattery.java:204)
        at 
org.apache.maven.surefire.Surefire.executeBattery(Surefire.java:218)
        at org.apache.maven.surefire.Surefire.run(Surefire.java:166)
        at org.apache.maven.surefire.Surefire.run(Surefire.java:90)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at 
org.apache.maven.surefire.SurefireBooter.runTestsInProcess(SurefireBooter.java:246)
        at 
org.apache.maven.surefire.SurefireBooter.run(SurefireBooter.java:195)
        at 
org.apache.maven.test.SurefirePlugin.execute(SurefirePlugin.java:366)
        at 
org.apache.maven.plugin.DefaultPluginManager.executeMojo(DefaultPluginManager.java:399)
        at 
org.apache.maven.lifecycle.DefaultLifecycleExecutor.executeGoals(DefaultLifecycleExecutor.java:519)
        at 
org.apache.maven.lifecycle.DefaultLifecycleExecutor.executeGoalWithLifecycle(DefaultLifecycleExecutor.java:469)
        at 
org.apache.maven.lifecycle.DefaultLifecycleExecutor.executeGoal(DefaultLifecycleExecutor.java:448)
        at 
org.apache.maven.lifecycle.DefaultLifecycleExecutor.executeGoalAndHandleFailures(DefaultLifecycleExecutor.java:301)
        at 
org.apache.maven.lifecycle.DefaultLifecycleExecutor.executeTaskSegments(DefaultLifecycleExecutor.java:268)
        at 
org.apache.maven.lifecycle.DefaultLifecycleExecutor.execute(DefaultLifecycleExecutor.java:137)
        at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:316)
        at org.apache.maven.DefaultMaven.execute(DefaultMaven.java:113)
        at org.apache.maven.cli.MavenCli.main(MavenCli.java:249)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at 
org.codehaus.classworlds.Launcher.launchEnhanced(Launcher.java:315)
        at org.codehaus.classworlds.Launcher.launch(Launcher.java:255)
        at 
org.codehaus.classworlds.Launcher.mainWithExitCode(Launcher.java:430)
        at org.codehaus.classworlds.Launcher.main(Launcher.java:375)

"VM Thread" prio=1 tid=0x0a00fdd8 nid=0x7b70 runnable

"VM Periodic Task Thread" prio=1 tid=0x0a01bd00 nid=0x7b76 waiting on 
condition

-------------------------- Thread Dump End --------------------------

I'm working in the new trunk region with m2.  I'm just trying to get the 
tests to pass for mina after removing all the spring and ssl deps out 
into separate subprojects.  I'm getting very unusual results.  Some 
tests are blowing chunks when they did not before.  Here's my setup 
which has been constant:

[akarasulu@newton org.apache.mina]$ uname -a
Linux newton 2.6.12-1.1381_FC3 #1 Fri Oct 21 03:46:55 EDT 2005 i686 
athlon i386 GNU/Linux

[akarasulu@newton org.apache.mina]$ java -version
java version "1.5.0_02"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_02-b09)
Java HotSpot(TM) Client VM (build 1.5.0_02-b09, mixed mode, sharing)

For now I seem to get better results obviously when I reduce the number 
of iterations the tests do in these loops.  I will commit this for now 
in the new area just to get tests to finish in a timely fashion.  We can 
revert this back later or find a better place for these regression 
tests.  Also I will upgrade my JVM and my version of m2 which seems to 
have a 2.0.2 release out now.

Alex


Mime
View raw message