Simulate Linux high CPU usage due to Java services
simulation analysis
-
Java makes CPU-heavy code
@RequestMapping("/test/cpu") @RestController public class TestCpuController { @GetMapping("/while") public R testHeightCpu() { if (ShiroUtils.getUserId().toString().equals("1")) { List<WmsAsnSku> skus = new ArrayList<>(); System.out.println("Start an infinite loop to create high CPU surroundings……"); while (true) { WmsAsnSku sku = new WmsAsnSku(); skus.add(sku); } } return R.ok(); } } -
Run the written service in Linux and call high-occupancy code
-
Enter Linux commands
top
High CPU usage of Java service found
-
Enter the jstack command
jstack [pid] >jstack.txt
may appear:
Unable to open socket file: target process not responding or HotSpot VM not loaded The -F option can be used when the target process is not responding
-
Enter the jstack -F command (emphasis)
jstack -F [pid] >jstack-f.txt
A similar log will appear in the jstack-f.txt text:
...... Thread 382910: (state = BLOCKED) - io.renren.modules.wms.web.TestCpuController.testHeightCpu() @bci=30, line=27 (Compiled frame) - sun.reflect.NativeMethodAccessorImpl.invoke0(java.lang.reflect.Method, java.lang.Object, java.lang.Object[]) @bci=0 (Compiled frame) - sun.reflect.NativeMethodAccessorImpl.invoke(java.lang.Object, java.lang.Object[]) @bci=100, line=62 (Compiled frame) - sun.reflect.DelegatingMethodAccessorImpl.invoke(java.lang.Object, java.lang.Object[]) @bci=6, line=43 (Compiled frame) ......
state = BLOCKED in the log indicates that the thread is currently locked. However, there may be many such threads in the log, but you can use keywords to retrieve text to quickly obtain logs related to the code you write, such as:
io.renren.modules.wms.web
The essence of this method is actually to directly search for the relevant interface packages in the project, because if there is a logic problem in the own code, it is very likely that there will be a user sending a request and then calling the relevant code, then it will inevitably go through the interface package.
Secondly, at the same time, in the control log of the Java service, the information of the jstack [pid] command will appear. (Note that it is in the console log, not the logback log, so restart the service carefully. Back up the console log before restarting the service). Console logs may appear similar to the following:
...... "http-nio-5699-exec-3" #43 daemon prio=5 os_prio=0 tid=0x00007f367d0f0000 nid=0x5d7be runnable [0x00007f36eb4f3000] java.lang.Thread.State: RUNNABLE at io.renren.modules.wms.web.TestCpuController.testHeightCpu(TestCpuController.java:29) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) ......
It can be seen that the thread is in the state of java.lang.Thread.State: RUNNABLE.
We can compare the thread log of the console and the jstack log, and the code that appears on both sides is most likely the problem to some extent. The rest should find the suspect code and conduct specific analysis.
At the same time, we can output the following command to obtain the high-occupancy thread ID through the process ID
top -Hp [pid]
The obtained thread ID is in decimal and needs to be converted to hexadecimal. It can then be retrieved in the console log.
But in the real environment (production environment) I have experienced, there are a lot of high occupancy, and after searching, I found that they are all GC-related threads. The reason I infer is: the Xmx (Xms) parameter I added when the service started limits the memory size, and then because this limit is exceeded, the GC starts to recycle objects (release memory)