Introduction to the

We know that JIT just-in-time compilation was introduced in the JVM to speed up compilation. So when and how JIT compilation starts, is there any way for a proud programmer to explore the secrets of JIT compilation? The answer is yes, today and small sister with you to take a look at the secret behind the compilation.

More highlights:

• Blockchain from getting started to Giving up series tutorials – with ongoing updates covering cryptography, Hyperledger, Ethereum,Libra, Bitcoin and more
• Spring Boot 2.X Series tutorials: Learn Spring Boot from Scratch in seven days – continuous updates
• Spring 5.X Series tutorials: Everything you can think of in Spring5 – constantly updated
• Java Programmer from Handyman to Expert to God (2020 edition) – Ongoing updates with detailed articles and tutorials

LogCompilation profile

Junior sister: Brother F, JIT is such a magic tool, but it seems to be a black box. Is there any way to explore its inner essence?

The pursuit of truth and the spirit of exploration are our biggest strengths as programmers. If it were not for Bohr’s new theory of atomic structure, how could there be a breakthrough in atomic system? If it were not for Heisenberg’s matrix mechanics, how could there be the establishment of quantum mechanics?

JIT compilation log output is simple, using -xx :+LogCompilation is sufficient.

If you want to redirect logs to a LogFile, use -xx :LogFile=.

But to open the function, the analysis of the need to use – XX again: + UnlockDiagnosticVMOptions. So to sum up, we need to use it like this:

-XX:+UnlockDiagnosticVMOptions -XX:+LogCompilation -XX:LogFile=www.flydean.com.log
Copy the code

The use of LogCompilation

According to the above introduction, we will generate a JIT compilation log on the spot. For professional purposes, we need to use JMH to do performance tests.

JMH is a Java Microbenchmark Harness used for performance testing in the Open JDK. The suite has been included in JDK 12.

If you’re not using JDK 12, add the following dependencies:

<dependency>
    <groupId>org.openjdk.jmh</groupId>
    <artifactId>jmh-core</artifactId>
    <version>1.19</version>
</dependency>
<dependency>
    <groupId>org.openjdk.jmh</groupId>
    <artifactId>jmh-generator-annprocess</artifactId>
    <version>1.19</version>
</dependency>
Copy the code

For more details, see the article I wrote earlier: Using JMH (Java Microbenchmark Harness) to Do Performance Testing in Java.

Before, some friends said that the code also uses pictures to look good. After this article, we will try to convert the code into pictures to show it:

After reading my introduction to JMH, the above example should be very clear, the main is to do a cumulative operation, then warmup 5 rounds, test 5 rounds.

In the @fork annotation, we can configure JVM parameters. Why did I comment it out? Because I found that -xx :LogFile in jvmArgsPrepend doesn’t work.

I had no choice but to add:

After you run it, you get the output of the compile log file.

Parse the LogCompilation files

Brother F, I have a look at the generated file. It is so complicated. Can you see it clearly with your naked eye?

Don’t be afraid, just the content of a little more, if we fine fine analysis again, you will find that it is really very very…… Complex!

In fact, it is not good to write some simple white text? Why to analyze so complex, and no one to see, see also no one to understand the UNDERLYING JVM…..

Probably, this is professional bar!

The LogCompilation file is actually in XML format, so I’m going to take a look at the structure of it, just so you can get a sense of what it’s all about the next time you look at it.

The first and most basic information is the INFORMATION about the JVM, including the version of the JVM, the parameters for running the JVM, and some properties.

The logs we collect are actually divided into two types, the first type is the compilation logs of the application itself, and the second type is the internal logs generated by the compilation thread itself.

The second type of log is stored in hs_c*.log format, and is then merged with the final log output file to produce an overall log file when the JVM exits.

For example, the following two are internal logs of the compile thread:

<thread_logfile thread='22275' filename='/var/folders/n5/217y_bgn49z18zvjch907xb00000gp/T//hs_c22275_pid83940.log'/>
<thread_logfile thread='41731' filename='/var/folders/n5/217y_bgn49z18zvjch907xb00000gp/T//hs_c41731_pid83940.log'/>
Copy the code

The thread id=22275 is listed above. If we follow 22275, we can find the log of the specific compilation thread:

<compilation_log thread='22275'>
...
</compilation_log>
Copy the code

The above section surrounded by compilation_log is the compile log.

The following section indicates that the compile thread has started executing, where stamp represents the start time. The following chart shows the complete compile thread log:

<start_compile_thread name='C2 CompilerThread0' thread='22275' process='83940' stamp='0.058'/>
Copy the code

The following describes the method information to compile:

<task compile_id='10' method='java.lang.Object <init> ()V' bytes='1' count='1409' iicount='1409' stamp='0.153'>
Copy the code

The method names to compile are listed above. Compile_id is the internal compilation ID, bytes is the number of bytes in the method, and count is the number of times the method was called. Note that this is not the actual number of times the method was called, just an estimate.

Iicount is the number of times the interpreter is called.

Task_done: task_done: task_done: task_done: task_done

<task_done success='1' nmsize='120' count='1468' stamp='0.155'/>
Copy the code

Where, SUCCESS indicates whether the command was successfully executed, and nmsize indicates the size of the instruction compiled by the compiler, in bytes. There is also an inlined_bytes attribute which represents the number of inlined bytes, if inline.

<type id='1025' name='void'/>
Copy the code

Type represents the return type of the method.

<klass id='1030' name='java.lang.Object' flags='1'/>
Copy the code

Klass represents instance and array types.

<method id='1148' holder='1030' name='<init>' return='1025' flags='1' bytes='1' compile_id='1' compiler='c1' level='3' iicount='1419'/>
Copy the code

Method is the method to execute, and holder is the previous KLass ID, representing the instance or array object that defines the method. Method has a name and return, which corresponds to type above.

Flags indicates the access rights for the method.

Next comes Parse, which logs the analysis phase:

<parse method='1148' uses='1419.000000' stamp='0.153'>
Copy the code

Parse’s method ID is shown above. Uses is the number of uses.

<bc code='177' bci='0'/>
Copy the code

BC is short for byte Count, code is the number of bytes, and BCI is the index of byte code.

<dependency type='no_finalizable_subclasses' ctxk='1030'/>
Copy the code

Dependency analyzes class dependencies, type represents what type of dependency, and CTKX is the dependency context class.

Note that some parses may have uncommon_trap:

<uncommon_trap bci='10' reason='unstable_if' action='reinterpret' debug_id='0' comment='taken never'/>
Copy the code

What is uncommon_trap? Getting uncommon code is very uncommon, which is uncommon for code that is very generic, and then gets uncommon_trap.

There are two important fields in it. Reason indicates the reason for the unCOMMON_trap flag. Action Specifies the event that starts uncommon_trap.

Some places also have “call” :

<call method='1150' count='5154' prof_factor='1.000000' inline='1'/>
Copy the code

Call means that other methods will be called in this code. Count is the number of executions.

conclusion

I’ve finally covered the complexity of the compile log, which may not have covered all of it, and there are some other cases that are not listed here, but I’ll add them later if I encounter them.

Examples of this article github.com/ddean2009/l…

Author: Flydean program stuff

Link to this article: www.flydean.com/jvm-jit-log…

Source: Flydean’s blog

Welcome to pay attention to my public number: procedures those things, more wonderful waiting for you!