Trustin
2005/12/28, Alex Karasulu <
[EMAIL PROTECTED]>:
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:
[EMAIL PROTECTED] 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
[EMAIL PROTECTED] 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
--
what we call human nature is actually human habit
--
http://gleamynode.net/
PGP Key ID: 0x854B996C
