JVM optimization
This is a note of jvm optimization of a production service.
Linux system tool
top
Use top to view process status:
$ top
top - 10:55:37 up 1234 days, 20:33, 1 user, load average: 26.61, 31.80, 35.25
Tasks: 485 total, 2 running, 483 sleeping, 0 stopped, 0 zombie
%Cpu(s): 82.8 us, 9.4 sy, 0.0 ni, 5.6 id, 0.0 wa, 0.0 hi, 2.2 si, 0.0 st
KiB Mem : 26359952+total, 10300115+free, 79046432 used, 81551928 buff/cache
KiB Swap: 0 total, 0 free, 0 used. 17903020+avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
35253 work 20 0 27.3g 10.6g 11532 S 817.5 4.2 795248:54 java
38200 work 20 0 27.2g 10.4g 11480 S 774.6 4.1 782100:51 java
33196 work 20 0 27.2g 10.5g 11496 S 663.0 4.2 767660:17 java
38110 work 20 0 27.2g 10.4g 11496 S 368.3 4.2 717635:28 java
38489 work 20 0 27.2g 10.5g 11516 S 286.1 4.2 797625:38 java
198487 work 20 0 134384 18352 888 R 64.0 0.0 0:03.06 netstat
120786 work 20 0 21.7g 4.8g 7032 S 15.5 1.9 410952:23 java
120732 work 20 0 21.7g 4.8g 6996 S 11.2 1.9 346910:48 java
120726 work 20 0 21.7g 4.8g 6980 S 10.2 1.9 355160:19 java
120838 work 20 0 21.7g 4.9g 7244 S 5.6 1.9 407095:04 java
198488 work 20 0 113540 976 820 S 2.3 0.0 0:00.13 awk
197696 root 20 0 0 0 0 S 0.7 0.0 0:00.34 kworker/15:2
10 root 20 0 0 0 0 S 0.3 0.0 10342:55 rcu_sched
161 root 20 0 0 0 0 S 0.3 0.0 947:20.63 ksoftirqd/30
18515 root 20 0 573816 14272 2968 S 0.3 0.0 250:14.40 tuned
View a specific process:
$ top -Hp 35253
top - 10:58:20 up 1234 days, 20:35, 1 user, load average: 28.47, 31.40, 34.61
Threads: 968 total, 3 running, 965 sleeping, 0 stopped, 0 zombie
%Cpu(s): 57.2 us, 6.7 sy, 0.0 ni, 33.8 id, 0.0 wa, 0.0 hi, 2.3 si, 0.0 st
KiB Mem : 26359952+total, 10287185+free, 79023616 used, 81704048 buff/cache
KiB Swap: 0 total, 0 free, 0 used. 17905331+avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
35309 work 20 0 27.3g 10.6g 11532 S 71.6 4.2 8159:47 G1 Conc#5
35306 work 20 0 27.3g 10.6g 11532 S 69.3 4.2 8159:23 G1 Conc#2
35308 work 20 0 27.3g 10.6g 11532 S 69.3 4.2 8160:05 G1 Conc#4
35307 work 20 0 27.3g 10.6g 11532 S 69.0 4.2 8160:03 G1 Conc#3
35257 work 20 0 27.3g 10.6g 11532 S 68.3 4.2 8160:12 G1 Conc#0
35305 work 20 0 27.3g 10.6g 11532 S 68.3 4.2 8159:48 G1 Conc#1
35375 work 20 0 27.3g 10.6g 11532 S 13.9 4.2 589:09.39 http-nio-0.0.0.
35469 work 20 0 27.3g 10.6g 11532 S 7.9 4.2 29171:28 http-nio-8442-P
35470 work 20 0 27.3g 10.6g 11532 S 6.3 4.2 27653:44 http-nio-8442-A
189160 work 20 0 27.3g 10.6g 11532 R 6.3 4.2 587:47.64 http-nio-0.0.0.
35457 work 20 0 27.3g 10.6g 11532 S 5.0 4.2 17071:54 http-nio-0.0.0.
35458 work 20 0 27.3g 10.6g 11532 S 4.0 4.2 14972:14 http-nio-0.0.0.
11726 work 20 0 27.3g 10.6g 11532 S 2.0 4.2 487:53.72 http-nio-0.0.0.
35348 work 20 0 27.3g 10.6g 11532 S 1.7 4.2 12352:21 pulsar-timer-5-
35288 work 20 0 27.3g 10.6g 11532 S 1.3 4.2 805:44.45 GC Thread#6
35304 work 20 0 27.3g 10.6g 11532 S 1.3 4.2 804:14.37 GC Thread#22
35284 work 20 0 27.3g 10.6g 11532 S 1.0 4.2 806:37.70 GC Thread#2
35285 work 20 0 27.3g 10.6g 11532 S 1.0 4.2 806:05.20 GC Thread#3
35286 work 20 0 27.3g 10.6g 11532 S 1.0 4.2 805:39.92 GC Thread#4
35287 work 20 0 27.3g 10.6g 11532 S 1.0 4.2 804:21.61 GC Thread#5
35290 work 20 0 27.3g 10.6g 11532 S 1.0 4.2 806:57.15 GC Thread#8
35293 work 20 0 27.3g 10.6g 11532 S 1.0 4.2 807:10.16 GC Thread#11
35294 work 20 0 27.3g 10.6g 11532 S 1.0 4.2 804:48.06 GC Thread#12
35297 work 20 0 27.3g 10.6g 11532 S 1.0 4.2 806:14.76 GC Thread#15
35299 work 20 0 27.3g 10.6g 11532 S 1.0 4.2 806:53.58 GC Thread#17
ps
Use ps:
$ ps -ef | grep java
work 33196 1 99 2023 ? 533-03:00:51 /home/work/dynamic-raft/jdk-11/bin/java -Xms8192m -Xmx8192m -Dspring.profiles.active=prod-x9 -Dserver.port=8081 -Dserver.httpsPort=8441 -Draft.id=10.19.24.7-6001 -Dmanagement.server.port=9441 -jar dynamic-service-1.1.1.jar
work 35253 1 99 2023 ? 552-06:53:20 /home/work/dynamic-raft/jdk-11/bin/java -Xms8192m -Xmx8192m -Dspring.profiles.active=prod-x9 -Dserver.port=8082 -Dserver.httpsPort=8442 -Draft.id=10.19.24.7-6002 -Dmanagement.server.port=9442 -jar dynamic-service-1.1.1.jar
...
Or use jps:
$ jps
35253 jar
38200 jar
201882 Jps
38489 jar
33196 jar
38110 jar
$ ps -mp 35253 -o THREAD,tid,time | sort -rn
work 5.7 19 - ep_pol - - 35469 20-06:12:44
work 5.4 19 - - - - 35470 19-04:54:46
work 3.3 19 - ep_pol - - 35457 11-20:32:40
work 2.9 19 - inet_c - - 35458 10-09:32:49
work 2.4 19 - futex_ - - 35348 8-13:52:37
work 155 - - - - - - 552-07:28:01
work 1.5 19 - futex_ - - 35309 5-16:02:00
work 1.5 19 - futex_ - - 35308 5-16:02:18
work 1.5 19 - futex_ - - 35307 5-16:02:17
work 1.5 19 - futex_ - - 35306 5-16:01:36
work 1.5 19 - futex_ - - 35305 5-16:02:02
work 1.5 19 - futex_ - - 35257 5-16:02:24
work 0.4 19 - futex_ - - 90755 1-07:46:12
work 0.4 19 - futex_ - - 73007 1-10:15:56
work 0.4 19 - futex_ - - 73006 1-10:16:16
work 0.4 19 - futex_ - - 73005 1-10:16:29
work 0.4 19 - futex_ - - 73004 1-10:14:13
work 0.4 19 - futex_ - - 73003 1-10:15:21
work 0.4 19 - futex_ - - 72981 1-10:17:19
work 0.4 19 - futex_ - - 72980 1-10:17:15
work 0.4 19 - futex_ - - 72974 1-10:18:23
Memory & GC analysis
Jinfo: View process startup detail
$ jinfo 35253
Java System Properties:
...
VM Flags:
-XX:CICompilerCount=15 -XX:ConcGCThreads=6 -XX:G1ConcRefinementThreads=23 -XX:G1HeapRegionSize=4194304 -XX:GCDrainStackTargetSize=64 -XX:InitialHeapSize=8589934592 -XX:MarkStackSize=4194304 -XX:MaxHeapSize=8589934592 -XX:MaxNewSize=5150605312 -XX:MinHeapDeltaBytes=4194304 -XX:NonNMethodCodeHeapSize=8178940 -XX:NonProfiledCodeHeapSize=121739650 -XX:ProfiledCodeHeapSize=121739650 -XX:ReservedCodeCacheSize=251658240 -XX:+SegmentedCodeCache -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseFastUnorderedTimeStamps -XX:+UseG1GC
VM Arguments:
jvm_args: -Xms8192m -Xmx8192m -Dspring.profiles.active=prod-x9 -Dserver.port=8082 -Dserver.httpsPort=8442 -Draft.id=10.19.24.7-6002 -Dmanagement.server.port=9442
java_command: dynamic-service-1.1.1.jar
java_class_path (initial): dynamic-service-1.1.1.jar
Launcher Type: SUN_STANDARD
JMap: View memory layout
$ jmap -histo:live 35253| head -n 10
num #instances #bytes class name (module)
-------------------------------------------------------
1: 38351692 1298970832 [B (java.base@11)
2: 37661022 903864528 java.lang.String (java.base@11)
3: 17207496 412979904 com.kingsoft.dw.dynamic.domain.dwevent.EventProperty
4: 3431252 221917408 [Ljava.lang.Object; (java.base@11)
5: 2207352 207421824 [Ljava.util.HashMap$Node; (java.base@11)
6: 5579222 133901328 java.lang.Long (java.base@11)
7: 2220304 124337024 java.util.LinkedHashMap (java.base@11)
8: 5670892 90734272 java.lang.Integer (java.base@11)
其中：
- [C is a char[]
- [S is a short[]
- [I is a int[]
- [B is a byte[]
- [[I is a int[][]
jstat: View GC status
$ jstat -gcutil 35253 1000
S0 S1 E O M CCS YGC YGCT FGC FGCT GCT
0.00 100.00 13.98 78.28 97.30 91.11 595624 22540.714 3 5.341 22546.055
0.00 100.00 18.64 78.28 97.30 91.11 595624 22540.714 3 5.341 22546.055
0.00 100.00 8.98 78.88 97.30 91.11 595625 22540.837 3 5.341 22546.177
0.00 100.00 12.99 78.79 97.30 91.11 595625 22540.837 3 5.341 22546.177
0.00 100.00 17.63 78.79 97.30 91.11 595625 22540.837 3 5.341 22546.177
0.00 100.00 22.70 78.79 97.30 91.11 595625 22540.837 3 5.341 22546.177
0.00 100.00 35.69 78.79 97.30 91.11 595625 22540.837 3 5.341 22546.177
0.00 100.00 95.04 78.79 97.30 91.11 595626 22540.837 3 5.341 22546.177
0.00 100.00 5.90 71.19 97.30 91.11 595627 22541.470 3 5.341 22546.811
0.00 100.00 19.78 71.19 97.30 91.11 595627 22541.470 3 5.341 22546.811
0.00 100.00 59.97 70.23 97.30 91.11 595627 22541.470 3 5.341 22546.811
0.00 100.00 21.34 71.44 97.30 91.11 595628 22541.658 3 5.341 22546.998
0.00 100.00 39.07 71.37 97.30 91.11 595628 22541.658 3 5.341 22546.998
jstack：view thread detail
$ top -Hp 35253
203384 work 20 0 27.3g 10.6g 11560 S 16.7 4.2 583:47.11 http-nio-0.0.0.
$ printf "%x\n" 203384
31a78
$ jstack 35253 | grep 31a78 -A 100
"http-nio-0.0.0.0-8082-exec-259" #647 daemon prio=5 os_prio=0 cpu=35027157.90ms elapsed=30595411.19s tid=0x00007fe5741c3800 nid=0x31a78 waiting on condition [0x00007fe3eef9f000]
java.lang.Thread.State: TIMED_WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11/Native Method)
- parking to wait for <0x0000000620d00bb8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11/LockSupport.java:234)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(java.base@11/AbstractQueuedSynchronizer.java:2123)
at java.util.concurrent.LinkedBlockingQueue.poll(java.base@11/LinkedBlockingQueue.java:458)
at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:128)
at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:33)
at org.apache.tomcat.util.threads.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1113)
at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1176)
at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(java.base@11/Thread.java:834)
"http-nio-0.0.0.0-8082-exec-260" #648 daemon prio=5 os_prio=0 cpu=35198074.52ms elapsed=30595411.19s tid=0x00007fe5741c5800 nid=0x31a7a waiting on condition [0x00007fe3eee9e000]
java.lang.Thread.State: TIMED_WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11/Native Method)
- parking to wait for <0x0000000620d00bb8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11/LockSupport.java:234)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(java.base@11/AbstractQueuedSynchronizer.java:2123)
at java.util.concurrent.LinkedBlockingQueue.poll(java.base@11/LinkedBlockingQueue.java:458)
at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:128)
at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:33)
at org.apache.tomcat.util.threads.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1113)
at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1176)
at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(java.base@11/Thread.java:834)