Tuesday, December 26, 2023

When concurrency bites (yet again!): class initialization deadlocks

Concurrent and parallel programming on JVM platform has never been easy: yes, it is significantly safer and simpler than in most programming languages (thanks to outstanding concurrency support by Java language, standard library and JVM) but still, surprises pop up from time to time.

In today's post we are going to learn how a seemingly innocent implementation may intermittently deadlock during the class initialization under some circumstances. To begin, here is the Options class we are going to work with along the way.

package com.example;

import java.util.HashMap;
import java.util.Map;
import java.util.Objects;

public final class Options {
    public final static Options EMPTY = new Builder().build();
    private final Map<String, String> options;
    
    public Options(final Map<String, String> options) {
        this.options = new HashMap<>(Objects.requireNonNull(options));
    }

    @Override
    public String toString() {
        return "Options=" + options.toString();
    }

    public static class Builder {
        public static final Options EMPTY = new Builder().build();
        private final Map<String, String> options = new HashMap<>();

        public Builder option(final String name, final String value) {
            this.options.put(name, value);
            return this;
        }

        public Options build() {
            return new Options(options);
        }
    }
}

The snippet above implements a variation of the Builder pattern (in this case, for Options class). Although the sample is somewhat made up, the similarities to the existing implementations aren't (for example, please check Parts of Rest High-Level Client not thread-safe out). At a glance, it seems to be no-brainer, the code compiles and runs perfectly fine (the console output serves as a proof in this case).

    public static void main(String[] args) {
        System.out.println("New instance: " + new Options.Builder().build());
        System.out.println("EMPTY Options instance: " + Options.EMPTY);
        System.out.println("EMPTY Options.Builder instance: " + Options.Builder.EMPTY);
    }

Once executed, we should see a few lines printed out.

New instance: Options={}
EMPTY Options instance: Options={}
EMPTY Options.Builder instance: Options={}

The attentive reviewer may spot something fishy about this implementation, specifically related to EMPTY static fields: there is an explicit bidirectional (or better to say, circular) dependency between Options and Options.Builder classes. But JVM is able to handle that, non issue, right? Well, yes and no, and to understand why, let us take a look at the variation of the initialization sequence that is triggered concurrently:

    public static void main(String[] args) {
        try (ExecutorService executor = Executors.newFixedThreadPool(2)) {
            executor.submit(() -> System.out.println("New instance: " + new Options.Builder().build()));
            executor.submit(() -> System.out.println("EMPTY Options instance: " + Options.EMPTY));
        }
    }

Surprisingly (or not?), the execution of this code intermittently hangs the JVM. If we look into the thread dump, the reason becomes very clear (thanks to JDK-8288064: Class initialization locking, the output has been redacted a bit to highlight the clues).

"pool-1-thread-1" #29 [8432] prio=5 os_prio=0 cpu=0.00ms elapsed=499.54s allocated=7800B defined_classes=1 tid=0x000002609f22b680 nid=8432 waiting on condition  [0x000000be184fe000]
   java.lang.Thread.State: RUNNABLE
	at com.example.Options$Builder.build(Options.java:35)
	- waiting on the Class initialization monitor for com.example.Options
	at com.example.Options$Builder.<clinit>(Options.java:26)
    ...

"pool-1-thread-2" #30 [19688] prio=5 os_prio=0 cpu=0.00ms elapsed=499.54s allocated=5184B defined_classes=1 tid=0x000002609f233e40 nid=19688 waiting on condition  [0x000000be185fe000]
   java.lang.Thread.State: RUNNABLE
	at com.example.Options.<clinit>(Options.java:9)
	- waiting on the Class initialization monitor for com.example.Options$Builder
    ...

The Options and Options.Builder classes deadlock during initialization (and indeed, Options needs Options.Builder to initialize EMPTY static field however Options.Builder needs Options to initialize own EMPTY static field). The JLS (Java Language Specification) is very clear on that (but how many of us have read the specification anyway?):

Because the Java programming language is multithreaded, initialization of a class or interface requires careful synchronization, since some other thread may be trying to initialize the same class or interface at the same time. There is also the possibility that initialization of a class or interface may be requested recursively as part of the initialization of that class or interface; for example, a variable initializer in class A might invoke a method of an unrelated class B, which might in turn invoke a method of class A. The implementation of the Java Virtual Machine is responsible for taking care of synchronization and recursive initialization by using the following procedure. - 12.4.2. Detailed Initialization Procedure

This is by no means a new issue that could be solved by restructuring the code, it has been known for years (JDK-4891511: Deadlock in class initialization specification, JLS 2nd ed. 12.4.2) but it still bites and not easy to troubleshoot (JDK-8059913: Deadlock finder is unable to find deadlocks caused by <clinit>). Luckily, JVM diagnostics is getting better and upcoming JDK-22 release will bring yet another improvement as part of JDK-8316229: Enhance class initialization logging, it should definitely help to debug apparent class initialization deadlocks (when JVM has class+init debug logging enabled using -Xlog:class+init=debug command line option).

...
[0.089s][debug][class,init] Thread "pool-1-thread-1" is initializing com.example.Options$Builder
[0.089s][debug][class,init] Thread "pool-1-thread-2" is initializing com.example.Options
[0.089s][info ][class,init] 511 Initializing 'com/example/Options$Builder' (0x000002b9dd001000) by thread "pool-1-thread-1"
[0.089s][info ][class,init] 512 Initializing 'com/example/Options' (0x000002b9dd001218) by thread "pool-1-thread-2"
[0.089s][debug][class,init] Thread "pool-1-thread-1" recursively initializing com.example.Options$Builder
[0.089s][debug][class,init] Thread "pool-1-thread-2" waiting for initialization of com.example.Options$Builder by thread "pool-1-thread-1"
[0.089s][debug][class,init] Thread "pool-1-thread-1" waiting for initialization of com.example.Options by thread "pool-1-thread-2"
...

Undoubtedly, JVM is very sophisticated piece of technology and each release (which is happening every six months these days) brings more features, bugfixes and improvements. Despite getting smarter, JVM still requires developers to be aware of its limitations and think about the code they write (would co-pilots and LLMs help with that is yet to be seen).

I πŸ‡ΊπŸ‡¦ stand πŸ‡ΊπŸ‡¦ with πŸ‡ΊπŸ‡¦ Ukraine.

No comments: