Java application becomes slow in FileHandler.<init>

Environment

• Java
• OpenJDK

Issue

• Our application becomes slow and thread dumps show many threads blocked in openFiles calls from FileHandler.<init>:

        at java.logging@17.0.9/java.util.logging.FileHandler.openFiles(FileHandler.java:499)
        at java.logging@17.0.9/java.util.logging.FileHandler.<init>(FileHandler.java:342)

Resolution

• Ensure any past FileHandlers are closed when done with so their lock file can be released. A heap dump can help review any leaked/unclosed one during such an issue state.
• Consider creating and using one static FileHandler as possible to avoid repeat FileHandler initializations:

    private static FileHandler commonFileHandler;

    static {
        try {
            commonFileHandler = new FileHandler("patternValue", true); 
            commonFileHandler.setFormatter(new SimpleFormatter()); // Attach a formatter
        } catch (IOException e) {
            e.printStackTrace();
        }
    }

Root Cause

• App code is regularly initializing brand new FileHandlers and starts to face contention here. Content from github.com is not included.Line 499 of the FileHandler is specifically trying to synchronize on the FileHandler class's static locks map. If there is a FileHandler open for a given file/pattern already and thus owning a lock on it, then FileHandler.openFiles increments a unique identifier by 1 and tries creating/fetching this next lock file instead. By default, its possible for FileHandler.openFiles to attempt that across 100 unique incremented lock files. Closing the FileHandler releases a lock file, but if there are 100 FileHandlers open concurrently for the same file pattern at once, then any new FileHandler creation will throw a "Couldn't get lock" exception Content from github.com is not included.here
• Once it reaches that lock limit and the app continues attempting such a FileHandler creation across multiple threads, then every thread's FileHandler.openFiles call will loop 100 times over synchronized checks on the lock map to cause contention/slowness before finally throwing the above IOException. So these attempts would all become heavily degraded until reaching the exception point.

Diagnostic Steps

• Check also for exceptions like below indicating an excessive number of FileHandlers created:

java.io.IOException: Couldn't get lock for fileName

This solution is part of Red Hat’s fast-track publication program, providing a huge library of solutions that Red Hat engineers have created while supporting our customers. To give you the knowledge you need the instant it becomes available, these articles may be presented in a raw and unedited form.