High System CPU Time
hamilrk1 Oct 3, 2007 1:48 PMOn our production app servers I'm seeing high system cpu time as compared with user cpu time. The ration is 1:1 which I feel can be improved upon ... Yes?/No?
We're running apache and JBoss on the same server with mod_jk connector and have narrowed the high system cpu time down to the JBoss process (JVM). I'm just starting to take a look inside JBoss and the JVM to see what's up and figured I'd drop a quick line in the forums too...
The System/User load increases evenly @ 1:1 directly related to load. The server is pushing around 4 Mbps. Apache is snoozing...
Looking for suggestions on where/how to look at what is going on.
Server is dual proc with 2 Gig
OS is REL4.5 with latest patches
JVM is:
java version "1.5.0_11"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_11-b03)
Java HotSpot(TM) Server VM (build 1.5.0_11-b03, mixed mode)
JBoss version 4.0.4GA(build: CVSTag=JBoss_4_0_4_GA date=200605151000)
Snapshot of the heap from one of the app servers below:
[root@app3 ~]# jmap -heap 20166
Attaching to process ID 20166, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 1.5.0_11-b03
using thread-local object allocation.
Parallel GC with 4 thread(s)
Heap Configuration:
MinHeapFreeRatio = 40
MaxHeapFreeRatio = 70
MaxHeapSize = 536870912 (512.0MB)
NewSize = 655360 (0.625MB)
MaxNewSize = 4294901760 (4095.9375MB)
OldSize = 1441792 (1.375MB)
NewRatio = 8
SurvivorRatio = 8
PermSize = 16777216 (16.0MB)
MaxPermSize = 67108864 (64.0MB)
Heap Usage:
PS Young Generation
Eden Space:
capacity = 58458112 (55.75MB)
used = 6423064 (6.125511169433594MB)
free = 52035048 (49.624488830566406MB)
10.987463981046805% used
From Space:
capacity = 524288 (0.5MB)
used = 98304 (0.09375MB)
free = 425984 (0.40625MB)
18.75% used
To Space:
capacity = 524288 (0.5MB)
used = 0 (0.0MB)
free = 524288 (0.5MB)
0.0% used
PS Old Generation
capacity = 313262080 (298.75MB)
used = 118485440 (112.99652099609375MB)
free = 194776640 (185.75347900390625MB)
37.82310326229079% used
PS Perm Generation
capacity = 40894464 (39.0MB)
used = 29614816 (28.242889404296875MB)
free = 11279648 (10.757110595703125MB)
72.41766513922276% used
[root@app3 ~]#
From JMX Console - listThreadCpuUtilization() shows TP-Processorxxx at the top of the list.
TP-Processor26 86810
TP-Processor71 86160
TP-Processor15 85450
TP-Processor9 85390
TP-Processor49 85370
TP-Processor78 85230
TP-Processor158 85000
TP-Processor14 84670
TP-Processor27 84590
TP-Processor53 84440
TP-Processor93 84310
TP-Processor58 84290
TP-Processor47 83700
TP-Processor75 83670
TP-Processor126 83410
TP-Processor135 83380
TP-Processor149 83020
TP-Processor122 82960
TP-Processor89 82920
TP-Processor163 82670
TP-Processor175 82440
TP-Processor63 82240
TP-Processor164 82000
TP-Processor37 81750
TP-Processor150 81700
TP-Processor100 81680
TP-Processor96 81640
TP-Processor174 81630
TP-Processor86 81520
...
about 200 or so threads total
These threads all have the same makeup:
Thread: TP-Processor26 : priority:5, demon:true, threadId:75, threadState:RUNNABLE, threadLockName:null
java.net.SocketInputStream.socketRead0(Native Method)
java.net.SocketInputStream.read(SocketInputStream.java:129)
java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
java.io.BufferedInputStream.read1(BufferedInputStream.java:256)
java.io.BufferedInputStream.read(BufferedInputStream.java:313)
org.apache.jk.common.ChannelSocket.read(ChannelSocket.java:607)
org.apache.jk.common.ChannelSocket.receive(ChannelSocket.java:545)
org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:672)
org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:876)
org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
java.lang.Thread.run(Thread.java:595)
Thanks,
-Rob