Check the behavior of Java Intrinsic Locks with bpftrace

Overview

Java has a mechanism called Intrinsic Locks. Each object has its own unique lock (Monitor Lock), and easy multithreaded parallel processing can be realized with just the keyword synchronized. So how do the threads collaborate when the program is running? This time, use bpftrace to check this.

Work environment

The OS should be Ubuntu 20.04.

OpenJDK 14

The JDK's Dtrace feature is required, so build it from source.

$ apt-get update
$ DEBIAN_FRONTEND=noninteractive ln -fs /usr/share/zoneinfo/Asia/Shanghai /etc/localtime && apt-get install -y tzdata && dpkg-reconfigure --frontend noninteractive tzdata
$ apt-get install build-essential autoconf systemtap-sdt-dev libx11-dev libxext-dev libxrender-dev libxrandr-dev libxtst-dev libxt-dev libcups2-dev libfontconfig1-dev libasound2-dev unzip zip ccache -y

## clone source and boot jdk
$ mkdir jdk && cd jdk
$ git clone https://github.com/openjdk/jdk14u.git

$ wget https://download.java.net/java/GA/jdk13.0.2/d4173c853231432d94f001e99d882ca7/8/GPL/openjdk-13.0.2_linux-x64_bin.tar.gz
$ tar xvf openjdk-13.0.2_linux-x64_bin.tar.gz

$ cd jdk14u

$ bash configure --enable-debug --with-jvm-variants=server --enable-dtrace --with-boot-jdk=../jdk-13.0.2 --enable-ccache
$ make images

$ export JAVA_HOME=$PWD/build/linux-x86_64-server-fastdebug/jdk

bcc and bpftrace

## bcc
$ apt-get install -y linux-headers-$(uname -r) bison build-essential cmake flex g++ git libelf-dev zlib1g-dev libfl-dev systemtap-sdt-dev binutils-dev llvm-8-dev llvm-8-runtime libclang-8-dev clang-8 arping netperf iperf3 python3-distutils
$ git clone --recurse-submodules https://github.com/iovisor/bcc.git
$ mkdir bcc/build; cd bcc/build
$ cmake -DPYTHON_CMD=python3 ..
$ make -j8 && make install && ldconfig

$ cd ../..

## bpftrace

$ git clone https://github.com/iovisor/bpftrace.git
$ mkdir bpftrace/build; cd bpftrace/build

$ cmake -DHAVE_BCC_PROG_LOAD=ON -DHAVE_BCC_CREATE_MAP=ON -DBUILD_TESTING=OFF ..
$ make -j8 && make install

Prepare a sample program

Now, prepare this java program. All you are doing is calling two competing threats.

Test.java


public class Test {

    private static synchronized void enter(String name) {
        try {
            System.out.println("enter " + name);
            Thread.sleep(1000);
            System.out.println("exit " + name);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }

    public static void main(String[] args) {
        new Thread(() -> enter("foo"), "foo").start();
        new Thread(() -> enter("bar"), "bar").start();
    }
}

Compile

$ $JAVA_HOME/bin/javac Test.java

Execution and results

First, start this bpftrace command in another terminal to prepare the trace.

$ bpftrace - <<EOF
BEGIN { printf("%-12s %-6s %-27s %s\n", "TIME", "TID", "ACTION", "DESC"); }

usdt:$JAVA_HOME/lib/server/libjvm.so:hotspot:thread__start { printf("%-12ld %-6d %-27s", elapsed, arg2, "start");printf("name=%s\n", str(arg0)); }
usdt:$JAVA_HOME/lib/server/libjvm.so:hotspot:thread__stop { printf("%-12ld %-6d %-27s", elapsed, arg2, "stop");printf("name=%s\n", str(arg0)); }

usdt:$JAVA_HOME/lib/server/libjvm.so:hotspot:monitor__contended__enter { printf("%-12ld %-6d %-27s", elapsed, arg0, "monitor_contended_enter"); printf("monitor=0x%lx, class=%s\n", arg1, str(arg2)); }
usdt:$JAVA_HOME/lib/server/libjvm.so:hotspot:monitor__contended__entered { printf("%-12ld %-6d %-27s", elapsed, arg0, "monitor_contended_entered"); printf("monitor=0x%lx, class=%s\n", arg1, str(arg2)); }
usdt:$JAVA_HOME/lib/server/libjvm.so:hotspot:monitor__contended__exit { printf("%-12ld %-6d %-27s", elapsed, arg0, "monitor_contended_exit"); printf("monitor=0x%lx, class=%s\n", arg1, str(arg2)); }
EOF

Attaching 6 probes...

Next, run the previous java program

$ $JAVA_HOME/bin/java -XX:+ExtendedDTraceProbes  Test
enter bar
exit bar
enter foo
exit foo

The two threats ran in sequence. So what about tracing?

Attaching 6 probes...
TIME         TID    ACTION                      DESC
3568183750   2      start                      name=Reference Handler
3568644123   3      start                      name=Finalizer
3581708591   1      monitor_contended_exit     monitor=0x7f7314003100, class=java/lang/Object����
3583984755   4      start                      name=Signal Dispatcher
3584404128   6      start                      name=C2 CompilerThread0
3584475441   5      start                      name=Service Thread
3584812927   7      start                      name=C1 CompilerThread0
3585382491   8      start                      name=Sweeper thread
3618900047   9      start                      name=Common-Cleaner
4170272484   2      monitor_contended_exit     monitor=0x7f7314005100, class=java/lang/ref/ReferenceQueue$Lock���#
4176664886   10     start                      name=Notification Thread
4201863620   11     start                      name=foo
4202328663   12     start                      name=bar
4203255448   11     monitor_contended_enter    monitor=0x7f7314007000, class=java/lang/Class�����
5229989467   12     monitor_contended_exit     monitor=0x7f7314007000, class=java/lang/Class�����
5230226530   11     monitor_contended_entered  monitor=0x7f7314007000, class=java/lang/Class�����
5230593438   12     stop                       name=bar
6242293321   11     stop                       name=foo
6247012424   4      stop                       name=Signal Dispatcher

What you can see here is that after some JVM System threats were started, so were the foo and bar threats. And foo is now in the state of monitor_contended_enter, because of course the bar entered the critical region first. After that, bar becomes monitor_contended_exit and leaves the critical region. Immediately foo also became monitor_contended_entered and execution started.

Summary

It's a simple application, but bpftrace or bcc is a very powerful tool, and I'd like to explore more possibilities in the future.

Reference material

Recommended Posts

Check the behavior of Java Intrinsic Locks with bpftrace
Check the contents of the Java certificate store
Check the contents of params with pry
Memo: [Java] Check the contents of the directory
[Java] Check the number of occurrences of characters
[Java] [Spring] Test the behavior of the logger
Check the domain by checking the MX record of the email address with java
Calculate the similarity score of strings with JAVA
Summary of ToString behavior with Java and Groovy annotations
[Java] Check the JDK version of the built war file
Monitor the internal state of Java programs with Kubernetes
Check the result of generic parameter inference with JShell
Check the behavior of include, exclude, ExhaustedRetryException of Spring Retry
The story of making dto, dao-like with java, sqlite
Replace only part of the URL host with java
I didn't understand the behavior of Java Scanner and .nextLine ().
Command to check the number and status of Java threads
Check the operation of two roles with a chat application
Check the status of Java application without using monitoring tool
Java beginners briefly summarized the behavior of Array and ArrayList
[Java] Simplify the implementation of data history management with Reladomo
[Java] Check the difference between orElse and orElseGet with IntStream
About the behavior when doing a file map with java
Be sure to compare the result of Java compareTo with 0
About the behavior of ruby Hash # ==
[Java 8] Duplicate deletion (& duplicate check) with Stream
[Java] Delete the elements of List
[Rails] Check the contents of the object
[Java1.8 +] Get the date of the next x day of the week with LocalDate
[Java version] The story of serialization
Check the version of Cent OS
The story of not knowing the behavior of String by passing Java by reference
Try Hello World with the minimum configuration of Heroku Java spring-boot
[Java] Element existence check with Stream
Check the migration status of rails
Follow the link with Selenium (Java)
A story about hitting the League Of Legends API with JAVA
I tried to check the operation of gRPC server with grpcurl
The point of addiction when performing basic authentication with Java URLConnection
See the behavior of entity update with Spring Boot + Spring Data JPA
Overwrite upload of file with the same name with BOX SDK (java)
How to check for the contents of a java fixed-length string
Graph the sensor information of Raspberry Pi in Java and check it with a web browser
The behavior of JS running on `Java SE 8 Nashorn` suddenly changed
Is the version of Elasticsearch you are using compatible with Java 11?
The origin of Java lambda expressions
The story of making a game launcher with automatic loading function [Java]
Let's express the result of analyzing Java bytecode with a class diagram
[Java] Check if the character string is composed only of blanks (= Blank)
[Java] Get MimeType from the contents of the file with Apathce Tika [Kotlin]
Check the operation using jetty with Maven.
Get the result of POST in Java
Examine the memory usage of Java elements
[Java] Get the day of the specific day of the week
Compare the elements of an array (Java)
[day: 5] I summarized the basics of Java
What are the updated features of java 13
Easily measure the size of Java Objects
Looking back on the basics of Java
Check the processing contents with [rails] binding.pry
Output of the book "Introduction to Java"