ImageIO is synchronized

Question

I have a web application where users upload images. We validate the image data via ImageIO.read() and perform a few simple transformations on the resulting BufferedImage before saving it to disk.

While performing load testing, we realized that when many requests come in at the same time, they are being blocked in the ImageIO.read() call. Digging deeper, we noticed that the JPEGImageReader is synchronized and that only one BufferedImage is being created at a time.

Has anyone else come across this? I have been Googling this for a few days now and haven't come across another person that has had this issue, so maybe I am doing something wrong. I cannot come up with any logical reason why this would be. It seems to do with not being able to create individual Readers and Writers per image for some memory leak issue, but that explanation seems rather thin to me.

EDIT: Here is a performance tool that breaks down what is taking so long. I believe this is due to all of the threads waiting for the synchronization lock, JPEGImageReader source.

EDIT: The JAI libraries would have worked except that OpenJDK has removed support for critical parts of it, explicitly the JPEG codec.

SOLUTION: Given the amount of time I spent trying to find an alternative solution and failing to do so, my best solution was to process the images asynchronously, with respect to the requests. So, when a request comes in, the raw image data is stored as a supposedly valid image; then, an asynchronous process outside of the request threads will process each image one at a time. Due to the synchronicity of the ImageIO library, there is no gain from trying to do multiple at once. The images could be processed in parallel given that the library is not synchronous, only inefficient.

While doing the processing asynchronously adds a level of complexity, it's probably a good idea, with respect to modifying the image. What doesn't work is that we cannot process the original image in each request, which means that our system must make the assumption that each image is valid image data. When the asynchronous processor does get around to processing an image, inconsistencies in the system may occur if the data is bad.

Answer 1

EDIT: Firstly, haraldK's answer is correct and my original answer was wrong. It cannot be deleted however, only edited the OP should reassign the tick.

The ThreadLock mechanism is there to stop threads accessing different readers from their own, not to stop threads from accessing their own readers independently of and simultaniously with other threads.

Therefore ImageIO's JPEGImageReader should work fine asynchronously.

Answer 2

While performing load testing, we realized that when many requests come in at the same time, they are being blocked in the ImageIO.read() call. Digging deeper, we noticed that the JPEGImageReader is synchronized and that only one BufferedImage is being created at a time.

Has anyone else come across this?

As I mentioned in the comment section: From the performance analysis, it looks like a performance issue in the color management system of OpenJDK (lcms), because the color conversion should not take this long. My guess, without being able to debug further, is that this issue makes the decoding (appear) synchronized, even if ImageIO is capable of parallel decoding.

Here's an SSCCE that shows ImageIO perfectly capable of decoding multiple images at once.

import javax.imageio.ImageIO;
import javax.imageio.ImageReader;
import javax.imageio.event.IIOReadProgressListener;
import javax.imageio.stream.ImageInputStream;
import java.io.File;
import java.util.Iterator;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.atomic.AtomicInteger;

class MultipleJPEGDecoding {
    private static int threads = Runtime.getRuntime().availableProcessors();
    private static ExecutorService executorService = Executors.newFixedThreadPool(threads * 4);

    public static void main(final String[] args) throws InterruptedException {
        for (int i = 0; i < 100; i++) {
            final int index = i;

            executorService.submit(new Runnable() {
                public void run() {
                    try {
                        ImageInputStream stream = ImageIO.createImageInputStream(new File(args[index % args.length]));
                        try {
                            Iterator<ImageReader> readers = ImageIO.getImageReaders(stream);
                            if (!readers.hasNext()) {
                                System.err.println("No reader!");
                                return;
                            }

                            ImageReader reader = readers.next();
                            reader.setInput(stream);
                            reader.addIIOReadProgressListener(new ProgressListener(index));

                            try {
                                reader.read(0);
                            }
                            finally {
                                reader.dispose();
                            }
                        }
                        finally {
                            stream.close();
                        }
                    }
                    catch (Exception e) {
                        System.err.printf("Error reading %d\n", index);
                        e.printStackTrace();
                    }
                }
            });
        }

        executorService.shutdown();
    }

    static class ProgressListener implements IIOReadProgressListener {
        final static AtomicInteger simultaneous = new AtomicInteger(0);

        final int index;
        int nextProgress = 25;

        public ProgressListener(int index) {
            this.index = index;
        }

        public void imageStarted(ImageReader source, int imageIndex) {
            int inProgress = simultaneous.incrementAndGet();
            System.err.printf("Started reading image %d (now decoding %d images simultaneous)...\n", index, inProgress);
        }

        public void imageComplete(ImageReader source) {
            int inProgress = simultaneous.decrementAndGet();
            System.err.printf("Done reading image %d%s.\n", index, inProgress > 0 ? String.format(" (still decoding %d other images)", inProgress) : "");
        }

        public void imageProgress(ImageReader source, float percentageDone) {
            if (percentageDone > nextProgress) {
                int inProgress = simultaneous.get();
                System.err.printf("Progress on image %d (now decoding %d images simultaneous)...\n", index, inProgress);
                nextProgress += 25;
            }
        }

        public void sequenceStarted(ImageReader source, int minIndex) {
        }

        public void sequenceComplete(ImageReader source) {
        }

        public void thumbnailStarted(ImageReader source, int imageIndex, int thumbnailIndex) {
        }

        public void thumbnailProgress(ImageReader source, float percentageDone) {
        }

        public void thumbnailComplete(ImageReader source) {
        }

        public void readAborted(ImageReader source) {
        }
    }
}

Output looks like:

Started reading image 5 (now decoding 2 images simultaneous)...
Started reading image 0 (now decoding 16 images simultaneous)...
Started reading image 14 (now decoding 15 images simultaneous)...
Started reading image 4 (now decoding 14 images simultaneous)...
Started reading image 13 (now decoding 1 images simultaneous)...
Started reading image 11 (now decoding 13 images simultaneous)...
Started reading image 2 (now decoding 12 images simultaneous)...
Started reading image 15 (now decoding 4 images simultaneous)...
Started reading image 8 (now decoding 11 images simultaneous)...
Started reading image 7 (now decoding 10 images simultaneous)...
Started reading image 9 (now decoding 9 images simultaneous)...
Started reading image 6 (now decoding 8 images simultaneous)...
Started reading image 10 (now decoding 7 images simultaneous)...
Started reading image 1 (now decoding 6 images simultaneous)...
Started reading image 3 (now decoding 5 images simultaneous)...
Started reading image 12 (now decoding 3 images simultaneous)...
Progress on image 11 (now decoding 16 images simultaneous)...
Progress on image 15 (now decoding 16 images simultaneous)...
Progress on image 13 (now decoding 16 images simultaneous)...
Progress on image 13 (now decoding 16 images simultaneous)...
Progress on image 9 (now decoding 16 images simultaneous)...
Progress on image 9 (now decoding 16 images simultaneous)...
Progress on image 1 (now decoding 16 images simultaneous)...
Progress on image 3 (now decoding 16 images simultaneous)...
Progress on image 1 (now decoding 16 images simultaneous)...
Progress on image 3 (now decoding 16 images simultaneous)...
Progress on image 1 (now decoding 16 images simultaneous)...
Progress on image 13 (now decoding 16 images simultaneous)...
Progress on image 5 (now decoding 16 images simultaneous)...
Progress on image 9 (now decoding 16 images simultaneous)...
Progress on image 3 (now decoding 16 images simultaneous)...
Done reading image 3 (still decoding 15 other images).
Started reading image 16 (now decoding 15 images simultaneous)...
Progress on image 11 (now decoding 15 images simultaneous)...
Done reading image 13 (still decoding 14 other images).
Started reading image 17 (now decoding 15 images simultaneous)...
Progress on image 5 (now decoding 15 images simultaneous)...
Progress on image 4 (now decoding 15 images simultaneous)...
Progress on image 11 (now decoding 15 images simultaneous)...
Done reading image 9 (still decoding 14 other images).
Progress on image 5 (now decoding 15 images simultaneous)...
Progress on image 17 (now decoding 15 images simultaneous)...
Done reading image 11 (still decoding 14 other images).
Started reading image 19 (now decoding 15 images simultaneous)...
Progress on image 17 (now decoding 15 images simultaneous)...
Done reading image 5 (still decoding 14 other images).
Started reading image 18 (now decoding 15 images simultaneous)...
Progress on image 15 (now decoding 15 images simultaneous)...
Done reading image 1 (still decoding 14 other images).
Started reading image 21 (now decoding 15 images simultaneous)...
Progress on image 15 (now decoding 15 images simultaneous)...
Progress on image 21 (now decoding 15 images simultaneous)...
Done reading image 15 (still decoding 14 other images).
Progress on image 6 (now decoding 14 images simultaneous)...
Progress on image 21 (now decoding 14 images simultaneous)...
Progress on image 7 (now decoding 14 images simultaneous)...
Progress on image 21 (now decoding 14 images simultaneous)...
Progress on image 7 (now decoding 14 images simultaneous)...
Progress on image 19 (now decoding 14 images simultaneous)...
Progress on image 19 (now decoding 14 images simultaneous)...
Progress on image 7 (now decoding 14 images simultaneous)...
Progress on image 19 (now decoding 14 images simultaneous)...
Done reading image 7 (still decoding 13 other images).
Started reading image 23 (now decoding 14 images simultaneous)...
Progress on image 10 (now decoding 14 images simultaneous)...
Progress on image 23 (now decoding 14 images simultaneous)...
Progress on image 14 (now decoding 14 images simultaneous)...
Started reading image 22 (now decoding 15 images simultaneous)...
Progress on image 0 (now decoding 15 images simultaneous)...
Done reading image 21 (still decoding 14 other images).
Started reading image 24 (now decoding 15 images simultaneous)...
Started reading image 20 (now decoding 16 images simultaneous)...
Progress on image 2 (now decoding 16 images simultaneous)...
Progress on image 8 (now decoding 16 images simultaneous)...
Progress on image 17 (now decoding 15 images simultaneous)...
Done reading image 17 (still decoding 14 other images).
Started reading image 25 (now decoding 15 images simultaneous)...
Progress on image 23 (now decoding 15 images simultaneous)...
Done reading image 19 (still decoding 15 other images).
Started reading image 26 (now decoding 16 images simultaneous)...
Progress on image 23 (now decoding 16 images simultaneous)...
Done reading image 23 (still decoding 15 other images).
Started reading image 27 (now decoding 16 images simultaneous)...
Progress on image 4 (now decoding 16 images simultaneous)...
Progress on image 27 (now decoding 16 images simultaneous)...
Progress on image 27 (now decoding 16 images simultaneous)...
Progress on image 6 (now decoding 16 images simultaneous)...
Progress on image 12 (now decoding 16 images simultaneous)...
Progress on image 20 (now decoding 16 images simultaneous)...
Progress on image 0 (now decoding 16 images simultaneous)...
Progress on image 25 (now decoding 16 images simultaneous)...
Progress on image 25 (now decoding 16 images simultaneous)...
Progress on image 25 (now decoding 16 images simultaneous)...
Progress on image 14 (now decoding 16 images simultaneous)...
Progress on image 10 (now decoding 16 images simultaneous)...
Progress on image 8 (now decoding 16 images simultaneous)...
Progress on image 18 (now decoding 16 images simultaneous)...
Done reading image 25 (still decoding 15 other images).

[...]

Progress on image 75 (now decoding 12 images simultaneous)...
Started reading image 73 (now decoding 13 images simultaneous)...
Progress on image 75 (now decoding 13 images simultaneous)...
Progress on image 73 (now decoding 13 images simultaneous)...
Progress on image 75 (now decoding 13 images simultaneous)...
Started reading image 74 (now decoding 14 images simultaneous)...
Progress on image 66 (now decoding 14 images simultaneous)...
Progress on image 64 (now decoding 14 images simultaneous)...
Progress on image 73 (now decoding 14 images simultaneous)...
Progress on image 60 (now decoding 14 images simultaneous)...
Progress on image 74 (now decoding 14 images simultaneous)...
Progress on image 58 (now decoding 14 images simultaneous)...
Done reading image 75 (still decoding 13 other images).
Progress on image 73 (now decoding 13 images simultaneous)...
Started reading image 77 (now decoding 14 images simultaneous)...
Done reading image 73 (still decoding 13 other images).
Progress on image 77 (now decoding 13 images simultaneous)...
Started reading image 78 (now decoding 14 images simultaneous)...
Progress on image 60 (now decoding 14 images simultaneous)...
Done reading image 48 (still decoding 13 other images).
Progress on image 77 (now decoding 13 images simultaneous)...
Started reading image 79 (now decoding 14 images simultaneous)...
Started reading image 70 (now decoding 15 images simultaneous)...
Progress on image 52 (now decoding 15 images simultaneous)...
Progress on image 71 (now decoding 15 images simultaneous)...
Started reading image 72 (now decoding 16 images simultaneous)...
Progress on image 71 (now decoding 16 images simultaneous)...
Progress on image 54 (now decoding 16 images simultaneous)...
Progress on image 68 (now decoding 16 images simultaneous)...
Progress on image 64 (now decoding 16 images simultaneous)...
Progress on image 66 (now decoding 16 images simultaneous)...
Progress on image 62 (now decoding 16 images simultaneous)...
Progress on image 79 (now decoding 16 images simultaneous)...
Progress on image 79 (now decoding 16 images simultaneous)...
Progress on image 79 (now decoding 16 images simultaneous)...
Progress on image 77 (now decoding 16 images simultaneous)...
Progress on image 68 (now decoding 16 images simultaneous)...
Done reading image 79 (still decoding 15 other images).
Done reading image 77 (still decoding 14 other images).
Started reading image 81 (now decoding 15 images simultaneous)...
Progress on image 74 (now decoding 15 images simultaneous)...
Progress on image 81 (now decoding 15 images simultaneous)...
Progress on image 81 (now decoding 15 images simultaneous)...
Progress on image 78 (now decoding 15 images simultaneous)...
Done reading image 60 (still decoding 14 other images).
Started reading image 82 (now decoding 15 images simultaneous)...
Started reading image 80 (now decoding 16 images simultaneous)...
Progress on image 76 (now decoding 14 images simultaneous)...
Progress on image 66 (now decoding 14 images simultaneous)...
Progress on image 70 (now decoding 14 images simultaneous)...
Done reading image 52 (still decoding 14 other images).
Done reading image 71 (still decoding 15 other images).
Progress on image 81 (now decoding 16 images simultaneous)...
Started reading image 84 (now decoding 15 images simultaneous)...
Started reading image 83 (now decoding 16 images simultaneous)...
Progress on image 58 (now decoding 16 images simultaneous)...
Progress on image 83 (now decoding 16 images simultaneous)...
Progress on image 83 (now decoding 16 images simultaneous)...
Progress on image 83 (now decoding 16 images simultaneous)...
Done reading image 81 (still decoding 15 other images).
Started reading image 85 (now decoding 16 images simultaneous)...
Progress on image 85 (now decoding 16 images simultaneous)...
Progress on image 74 (now decoding 16 images simultaneous)...
Done reading image 66 (still decoding 15 other images).
Started reading image 86 (now decoding 16 images simultaneous)...
Progress on image 64 (now decoding 16 images simultaneous)...
Progress on image 70 (now decoding 16 images simultaneous)...
Progress on image 78 (now decoding 16 images simultaneous)...
Progress on image 54 (now decoding 16 images simultaneous)...
Done reading image 58 (still decoding 15 other images).
Started reading image 87 (now decoding 16 images simultaneous)...
Progress on image 87 (now decoding 16 images simultaneous)...
Progress on image 84 (now decoding 16 images simultaneous)...
Progress on image 87 (now decoding 16 images simultaneous)...
Done reading image 64 (still decoding 15 other images).
Started reading image 88 (now decoding 16 images simultaneous)...
Progress on image 76 (now decoding 16 images simultaneous)...
Done reading image 83 (still decoding 15 other images).
Progress on image 62 (now decoding 15 images simultaneous)...
Progress on image 70 (now decoding 16 images simultaneous)...
Progress on image 85 (now decoding 16 images simultaneous)...
Started reading image 89 (now decoding 16 images simultaneous)...
Progress on image 72 (now decoding 16 images simultaneous)...
Progress on image 85 (now decoding 16 images simultaneous)...
Progress on image 89 (now decoding 16 images simultaneous)...
Done reading image 85 (still decoding 15 other images).
Progress on image 89 (now decoding 15 images simultaneous)...
Progress on image 82 (now decoding 15 images simultaneous)...
Progress on image 80 (now decoding 15 images simultaneous)...
Done reading image 74 (still decoding 14 other images).
Started reading image 91 (now decoding 15 images simultaneous)...
Started reading image 90 (now decoding 16 images simultaneous)...
Done reading image 62 (still decoding 15 other images).
Progress on image 87 (now decoding 15 images simultaneous)...
Progress on image 68 (now decoding 15 images simultaneous)...
Done reading image 87 (still decoding 14 other images).
Progress on image 91 (now decoding 14 images simultaneous)...
Started reading image 93 (now decoding 15 images simultaneous)...
Progress on image 93 (now decoding 15 images simultaneous)...
Progress on image 91 (now decoding 15 images simultaneous)...
Progress on image 91 (now decoding 15 images simultaneous)...
Progress on image 80 (now decoding 15 images simultaneous)...
Started reading image 92 (now decoding 16 images simultaneous)...
Done reading image 91 (still decoding 15 other images).
Started reading image 94 (now decoding 16 images simultaneous)...
Progress on image 93 (now decoding 16 images simultaneous)...
Progress on image 72 (now decoding 16 images simultaneous)...
Progress on image 93 (now decoding 16 images simultaneous)...
Done reading image 93 (still decoding 15 other images).
Started reading image 95 (now decoding 16 images simultaneous)...
Progress on image 95 (now decoding 16 images simultaneous)...
Progress on image 95 (now decoding 16 images simultaneous)...
Progress on image 76 (now decoding 16 images simultaneous)...
Progress on image 95 (now decoding 16 images simultaneous)...
Progress on image 72 (now decoding 16 images simultaneous)...
Done reading image 95 (still decoding 15 other images).
Started reading image 96 (now decoding 16 images simultaneous)...
Progress on image 94 (now decoding 16 images simultaneous)...
Progress on image 89 (now decoding 15 images simultaneous)...
Done reading image 89 (still decoding 14 other images).
Done reading image 54 (still decoding 15 other images).
Started reading image 97 (now decoding 14 images simultaneous)...
Started reading image 98 (now decoding 15 images simultaneous)...
Done reading image 70 (still decoding 13 other images).
Started reading image 99 (now decoding 16 images simultaneous)...
Progress on image 82 (now decoding 16 images simultaneous)...
Progress on image 99 (now decoding 16 images simultaneous)...
Progress on image 99 (now decoding 16 images simultaneous)...
Progress on image 97 (now decoding 16 images simultaneous)...
Progress on image 97 (now decoding 16 images simultaneous)...
Progress on image 97 (now decoding 16 images simultaneous)...
Done reading image 68 (still decoding 15 other images).
Done reading image 97 (still decoding 14 other images).
Progress on image 78 (now decoding 14 images simultaneous)...
Progress on image 99 (now decoding 14 images simultaneous)...
Done reading image 99 (still decoding 13 other images).
Progress on image 86 (now decoding 13 images simultaneous)...
Done reading image 72 (still decoding 12 other images).
Progress on image 82 (now decoding 12 images simultaneous)...
Progress on image 98 (now decoding 12 images simultaneous)...
Progress on image 84 (now decoding 12 images simultaneous)...
Progress on image 90 (now decoding 12 images simultaneous)...
Done reading image 76 (still decoding 11 other images).
Progress on image 92 (now decoding 11 images simultaneous)...
Progress on image 80 (now decoding 11 images simultaneous)...
Progress on image 94 (now decoding 11 images simultaneous)...
Progress on image 88 (now decoding 11 images simultaneous)...
Progress on image 84 (now decoding 11 images simultaneous)...
Progress on image 90 (now decoding 11 images simultaneous)...
Progress on image 92 (now decoding 11 images simultaneous)...
Progress on image 86 (now decoding 11 images simultaneous)...
Progress on image 94 (now decoding 10 images simultaneous)...
Done reading image 84 (still decoding 9 other images).
Progress on image 92 (now decoding 9 images simultaneous)...
Done reading image 78 (still decoding 10 other images).
Progress on image 88 (now decoding 9 images simultaneous)...
Progress on image 90 (now decoding 9 images simultaneous)...
Done reading image 80 (still decoding 8 other images).
Done reading image 82 (still decoding 7 other images).
Progress on image 86 (now decoding 7 images simultaneous)...
Progress on image 96 (now decoding 7 images simultaneous)...
Progress on image 88 (now decoding 7 images simultaneous)...
Done reading image 90 (still decoding 6 other images).
Done reading image 92 (still decoding 5 other images).
Progress on image 98 (now decoding 5 images simultaneous)...
Done reading image 94 (still decoding 4 other images).
Done reading image 86 (still decoding 3 other images).
Progress on image 96 (now decoding 3 images simultaneous)...
Done reading image 88 (still decoding 2 other images).
Progress on image 98 (now decoding 2 images simultaneous)...
Progress on image 96 (now decoding 2 images simultaneous)...
Done reading image 98 (still decoding 1 other images).
Done reading image 96.