[DIRMINA-588] High CPU Usage in AprIoProcessor

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Abandoned
• Affects Version/s: 2.0.0-M2
• Fix Version/s: 2.0.14
• Component/s: Transport

Environment

Linux jellikit 2.6.24-16-generic #1 SMP Thu Apr 10 13:23:42 UTC 2008 i686 GNU/Linux

java version "1.6.0_06"
Java(TM) SE Runtime Environment (build 1.6.0_06-b02)
Java HotSpot(TM) Server VM (build 10.0-b22, mixed mode)

tomcat-native-1.1.13

apr-1.2.11

• Assignee: Unassigned
• Reporter: Geoff Cadien
• Created: 20/May/08 00:43
• Updated: 24/May/19 13:46
• Resolved: 24/May/19 13:46

Description

When running a simple test using the APR transport I see high cpu utilization that will continue which not active connections until the application is terminated.

Here is a thread dump:

2008-05-19 17:41:46
Full thread dump Java HotSpot(TM) Server VM (10.0-b22 mixed mode):

"AprIoProcessor-2" prio=10 tid=0x08399400 nid=0x5faa runnable [0xa0169000..0xa016a0c0]
java.lang.Thread.State: RUNNABLE
at java.util.concurrent.ConcurrentLinkedQueue.casHead(ConcurrentLinkedQueue.java:139)
at java.util.concurrent.ConcurrentLinkedQueue.poll(ConcurrentLinkedQueue.java:219)
at org.apache.mina.common.AbstractPollingIoProcessor.flush(AbstractPollingIoProcessor.java:471)
at org.apache.mina.common.AbstractPollingIoProcessor.access$9(AbstractPollingIoProcessor.java:465)
at org.apache.mina.common.AbstractPollingIoProcessor$Worker.run(AbstractPollingIoProcessor.java:707)
at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:619)

"AprIoProcessor-3" prio=10 tid=0x083c4000 nid=0x5fa9 runnable [0xa01ba000..0xa01bb040]
java.lang.Thread.State: RUNNABLE
at org.apache.tomcat.jni.Socket.recvb(Native Method)
at org.apache.mina.transport.socket.apr.AprIoProcessor.read(AprIoProcessor.java:332)
at org.apache.mina.transport.socket.apr.AprIoProcessor.read(AprIoProcessor.java:1)
at org.apache.mina.common.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:418)
at org.apache.mina.common.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:397)
at org.apache.mina.common.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:389)
at org.apache.mina.common.AbstractPollingIoProcessor.access$8(AbstractPollingIoProcessor.java:387)
at org.apache.mina.common.AbstractPollingIoProcessor$Worker.run(AbstractPollingIoProcessor.java:703)
at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:619)

"AprIoProcessor-1" prio=10 tid=0x083c3800 nid=0x5fa8 runnable [0xa020b000..0xa020bfc0]
java.lang.Thread.State: RUNNABLE
at org.apache.tomcat.jni.Poll.poll(Native Method)
at org.apache.mina.transport.socket.apr.AprIoProcessor.select(AprIoProcessor.java:130)
at org.apache.mina.common.AbstractPollingIoProcessor$Worker.run(AbstractPollingIoProcessor.java:697)
at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:619)

"DestroyJavaVM" prio=10 tid=0x0805a400 nid=0x5f88 waiting on condition [0x00000000..0xb7db1090]
java.lang.Thread.State: RUNNABLE

"AprSocketAcceptor-1" prio=10 tid=0x08318000 nid=0x5f9a runnable [0xa025c000..0xa025cf40]
java.lang.Thread.State: RUNNABLE
at org.apache.tomcat.jni.Poll.poll(Native Method)
at org.apache.mina.transport.socket.apr.AprSocketAcceptor.select(AprSocketAcceptor.java:189)
at org.apache.mina.common.AbstractPollingIoAcceptor$Worker.run(AbstractPollingIoAcceptor.java:203)
at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:619)

"AprSocketAcceptor-1-idleStatusChecker" prio=10 tid=0x082a1400 nid=0x5f99 waiting on condition [0xa02ad000..0xa02adec0]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at org.apache.mina.common.IdleStatusChecker$NotifyingTaskImpl.run(IdleStatusChecker.java:89)
at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:619)

"Low Memory Detector" daemon prio=10 tid=0x080ff400 nid=0x5f96 runnable [0x00000000..0x00000000]
java.lang.Thread.State: RUNNABLE

"CompilerThread1" daemon prio=10 tid=0x080fdc00 nid=0x5f95 waiting on condition [0x00000000..0xa05e1548]
java.lang.Thread.State: RUNNABLE

"CompilerThread0" daemon prio=10 tid=0x080fb000 nid=0x5f94 waiting on condition [0x00000000..0xa06624c8]
java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x080fa000 nid=0x5f93 waiting on condition [0x00000000..0x00000000]
java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=10 tid=0x080de800 nid=0x5f8e in Object.wait() [0xa074a000..0xa074afc0]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)

• waiting on <0xa4c607e0> (a java.lang.ref.ReferenceQueue$Lock)
  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
• locked <0xa4c607e0> (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=10 tid=0x080dd400 nid=0x5f8d in Object.wait() [0xa079b000..0xa079bf40]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)

• waiting on <0xa4c60380> (a java.lang.ref.Reference$Lock)
  at java.lang.Object.wait(Object.java:485)
  at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
• locked <0xa4c60380> (a java.lang.ref.Reference$Lock)

"VM Thread" prio=10 tid=0x080da400 nid=0x5f8c runnable

"GC task thread#0 (ParallelGC)" prio=10 tid=0x08061000 nid=0x5f89 runnable

"GC task thread#1 (ParallelGC)" prio=10 tid=0x08062000 nid=0x5f8a runnable

"VM Periodic Task Thread" prio=10 tid=0x08100c00 nid=0x5f97 waiting on condition

JNI global references: 981

Heap
PSYoungGen total 28736K, used 27996K [0xb2fa0000, 0xb4c10000, 0xb4c10000)
eden space 28352K, 97% used [0xb2fa0000,0xb4aab070,0xb4b50000)
from space 384K, 79% used [0xb4b50000,0xb4b9c000,0xb4bb0000)
to space 384K, 0% used [0xb4bb0000,0xb4bb0000,0xb4c10000)
PSOldGen total 233024K, used 137223K [0xa4c10000, 0xb2fa0000, 0xb2fa0000)
object space 233024K, 58% used [0xa4c10000,0xad211c20,0xb2fa0000)
PSPermGen total 16384K, used 3678K [0xa0c10000, 0xa1c10000, 0xa4c10000)
object space 16384K, 22% used [0xa0c10000,0xa0fa79a8,0xa1c10000)