Troubleshooting process that causes excessive server CPU usage on the online Java program

Blog go to: HTTP://WWW.JIANSHU.COM/P/3667157D63BB, blog better effect to see the original, the purpose of this blog post is a bookmark it, need to be able to locate the original text learning 1, fault phenomenon

Customer Service colleague Feedback platform system runs slowly, the webpage is serious, the problem persists after restarting the system several times, using the top command to view the server situation, found that the CPU occupancy rate is too high.

2, high CPU consumption problem location 2.1, positioning problem process

Use the top command to view resource usage, and find that the PID 14063 process consumes a lot of CPU resources, CPU usage is up to 776.1%, and memory usage is up to 29.8%.

[[email protected] ~]$ toptop - 14:51:10 up 233 days, 11:40,  7 users,  load average: 6.85, 5.62, 3.97Tasks: 192 total,   2 running, 190 sleeping,   0 stopped,   0 zombie%Cpu(s): 97.3 us,  0.3 sy,  0.0 ni,  2.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 stKiB Mem : 16268652 total,  5114392 free,  6907028 used,  4247232 buff/cacheKiB Swap:  4063228 total,  3989708 free,    73520 used.  8751512 avail Mem   PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                                               14063 ylp       20   0 9260488 4.627g  11976 S 776.1 29.8 117:41.66 java

2.2. Locating the problem thread

Use the PS-MP pid-o thread,tid,time command to view the thread condition of the process and find that the process has a high number of thread occupancy rates

[[email protected] ~]$ ps-mp 14063-o thread,tid,timeuser%cpu PRI SCNT wchan USER SYSTEM tid timeylp     361------02:05:58YLP 0.0 19-futex_--14063 00:00:00ylp 0.0 19         -poll_s--14064 00:00:00YLP 44.5----14065 00:15:30YLP 44.5 19--      --14066 00:15:30YLP 44.4----14067 00:15:29YLP 44.5 19---  -14068 00:15:30YLP 44.5----14069 00:15:30YLP 44.5 19----14070 00:15:30YLP 44.5----14071 00:15:30YLP 44.6----14072 00:15:32y LP 2.2 19-futex_--14073 00:00:46ylp 0.0 19-futex_--14074 00:00:00YLP 0    .0 19-futex_--14075 00:00:00ylp 0.0 19-futex_--14076 00:00:00YLP 0.7 19 -Futex_--14077 00:00:15 

As can be seen from the output information, the thread CPU usage between 14065~14072 is very high

2.3. View the problem thread stack

Pick the thread with Tid 14065, view the stack of the thread, turn the thread ID into 16, and convert using the printf "%x\n" tid command

[[email protected] ~]$ printf "%x\n" 1406536f1

Then use the Jstack command to print thread stack information, command format: Jstack pid |grep tid-a 30

[[email protected] ~]$ jstack 14063 |grep 36f1 -A 30"GC task thread#0 (ParallelGC)" prio=10 tid=0x00007fa35001e800 nid=0x36f1 runnable "GC task thread#1 (ParallelGC)" prio=10 tid=0x00007fa350020800 nid=0x36f2 runnable "GC task thread#2 (ParallelGC)" prio=10 tid=0x00007fa350022800 nid=0x36f3 runnable "GC task thread#3 (ParallelGC)" prio=10 tid=0x00007fa350024000 nid=0x36f4 runnable "GC task thread#4 (ParallelGC)" prio=10 tid=0x00007fa350026000 nid=0x36f5 runnable "GC task thread#5 (ParallelGC)" prio=10 tid=0x00007fa350028000 nid=0x36f6 runnable "GC task thread#6 (ParallelGC)" prio=10 tid=0x00007fa350029800 nid=0x36f7 runnable "GC task thread#7 (ParallelGC)" prio=10 tid=0x00007fa35002b800 nid=0x36f8 runnable "VM Periodic Task Thread" prio=10 tid=0x00007fa3500a8800 nid=0x3700 waiting on condition JNI global references: 392

As you can see from the output information, this thread is the GC thread of the JVM. At this point it can be basically determined that there is insufficient memory or a memory leak that causes the GC thread to run continuously, resulting in high CPU consumption.
So the next thing we're looking for in terms of memory

3, Memory problem location 3.1, use the Jstat-gcutil command to view the memory situation of the process

[[email protected] ~]$ jstat -gcutil 14063 2000 10  S0     S1     E      O      P     YGC     YGCT    FGC    FGCT     GCT     0.00   0.00 100.00  99.99  26.31     42   21.917   218 1484.830 1506.747  0.00   0.00 100.00  99.99  26.31     42   21.917   218 1484.830 1506.747  0.00   0.00 100.00  99.99  26.31     42   21.917   219 1496.567 1518.484  0.00   0.00 100.00  99.99  26.31     42   21.917   219 1496.567 1518.484  0.00   0.00 100.00  99.99  26.31     42   21.917   219 1496.567 1518.484  0.00   0.00 100.00  99.99  26.31     42   21.917   219 1496.567 1518.484  0.00   0.00 100.00  99.99  26.31     42   21.917   219 1496.567 1518.484  0.00   0.00 100.00  99.99  26.31     42   21.917   220 1505.439 1527.355  0.00   0.00 100.00  99.99  26.31     42   21.917   220 1505.439 1527.355  0.00   0.00 100.00  99.99  26.31     42   21.917   220 1505.439 1527.355

From the output information, it can be seen that the Eden area memory occupies the 100%,old area memory occupies 99.99%,full GC up to 220 times, and the frequent full Gc,full GC duration is also particularly long, the average time spent 6.8 seconds per full GC (1505.439/ 220). Based on this information, you can basically determine that there is a problem in the program code, there may be unreasonable creation of the object of the place

3.2. Analysis stack

To view the stack of a process using the Jstack command

[[email protected] ~]$ jstack 14063 >>jstack.out

After taking the jstack.out file from the server to the local, use the editor to find the information with the project directory and the thread state is runable, you can see that the Activityutil.java class 447 rows are using the Hashmap.put () method

paste_image.png3.3, code positioning

Open Project Engineering, find the Activityutil class of 477 lines, the code is as follows:

Paste_image.png

Once the relevant colleague is found, this code gets the configuration from the database and loops based on the values of the remain in the database, and the HashMap is put in the loop all the time.

Query the configuration in the database and find the number of remain is huge

Paste_image.png

At this point, the problem is fixed.

Troubleshooting process that causes excessive server CPU usage on the online Java program