Java garbage collection and analysis of stw in jvm

This article mainly introduces the quick understanding of Java garbage collection and stw in jvm, involving Java code pauses, threads in jvm and other related content. It is still very good. Friends who need it can refer to it.

The Stop-The-World mechanism in Java is referred to as STW. When executing the garbage collection algorithm, all other threads of the Java application are suspended (except for the garbage collection helper). ). A global pause phenomenon in Java, global pause, all Java code stops, native code can be executed, but cannot interact with the JVM; these phenomena are mostly caused by gc.

Stop the World (STW) during GC is everyone’s biggest enemy. But many people may not know that in addition to GC, pauses also occur under the JVM.

There is a special thread in the JVM - VM Threads, which is specially used to perform some special VM operations, such as dispatching GC, thread dump, etc. These tasks require the entire Heap and all threads. The state is static and can only be carried out if it is consistent. Therefore, the JVM introduced the concept of Safe Point and found a way to notify all threads to enter a static safe point when VM Operation is required.

In addition to GC, other VM Operations that trigger safety points include:

1. JIT related, such as Code deoptimization, Flushing code cache;

2. Class redefinition (e.g. javaagent, instrumentation generated by AOP code implantation);

3. Biased lock revocation cancels biased lock;

4. Various debug operation (e.g. thread dump or deadlock check);

Monitor the safe point to see what happened to the JVM?

The simplest way is to add one more sentence to the GC parameters of the JVM startup parameters:

-XX:+PrintGCApplicationStoppedTime

it All JVM pause times (not just GC) will be printed in the GC log.

2016-08-22T00:19:49.559+0800: 219.140: Total time for which application threads were stopped: 0.0053630 seconds

This It is a very useful required parameter that can print almost any pause...

However, in versions before JDK1.7.40, it did not print a timestamp, so you can only know how long the JVM has been paused. , but I don’t know when it stopped. At this time, a simple method is to add "-XX:+PrintGCApplicationConcurrentTime" to print the normal running time of the JVM between two pauses (also without timestamp), but at least it can be used with the GC log with timestamp to reverse Stop. It's about time it happened.

2016-08-22T00:19:50.183+0800: 219.764: Application time: 5.6240430 seconds

How to print the cause of the accident What about the pause?

Add two more parameters: -XX:+PrintSafepointStatistics -XX: PrintSafepointStatisticsCount=1

At this time, something like this will be printed in stdout Content

vmop [threads: total initially_running wait_to_block]1913.425: GenCollectForAllocation [ 55 2 0 ] [time: spin block sync cleanup vmop] page_trap_count [ 0 0 0 0 6 ] 0

This log is divided into two sections. The first section is the timestamp, the type of VM Operation, and the thread overview

total: the total number of threads in the safe point

initially_running: The number of threads that are running at the beginning of the safe point

wait_to_block: The number of threads that need to wait for suspension before VM Operation starts

The second line is the various stages when reaching the safepoint and the time it takes to perform the operation, the most important of which is vmop

spin: Waiting for the thread to respond to the

safepoint call The time of

block: the time it takes to suspend all threads

sync: equal to spin+block, this is the time it takes from the beginning to entering the safe point, which can be used Determine the time it takes to enter a safe point

cleanup: The time it takes to clean up

vmop: The time it takes to actually execute VM Operation

It can be seen that there are many However, the short safety points are all RevokeBias. For details, see the biased lock implementation principle. High-concurrency applications generally simply add "-XX:-UseBiasedLocking" to the startup parameters to cancel it. In addition, I also saw that some types are no vm operation. The document says that it is guaranteed to enter the safe point once every second (if the GC has passed this second, it is not necessary), for some non-urgent operations that need to be performed in the safe point. For example, some sampling profiler tools can be adjusted with -DGuaranteedSafepointInterval. However, it does not happen every second and the time is variable.

In actual combat, we used safe point logs and found that programs regularly called Thread Dump and so on. However, because safepoint logs are output to stdout by default, we usually do not enable it by default due to performance and cleanliness of stdout logs. Open only when needed.

Add the following three parameters to know more about what is happening in the VM. Unfortunately, the JVM will not transfer the security point log to vm.log just because these three parameters are set, but will print it twice in vain.

-XX:+UnlockDiagnosticVMOptions -XX:+LogVMOutput -XX:LogFile=/dev/shm/vm.log

Summarize

The above is the detailed content of Java garbage collection and analysis of stw in jvm. For more information, please follow other related articles on the PHP Chinese website!