Memory leak in threadpool

[fangmartin]

What did you do?

I wrote a routing function where each request inputs an image, and the backend uses PIL for processing. Therefore, I simplified the code into a multi-threaded pool processing form. I noticed that memory usage keeps increasing as the number of requests grows.

import base64
import gc
import io
import os
import time
from concurrent.futures import ThreadPoolExecutor, as_completed

import loguru
import psutil
from PIL import Image, ImageEnhance


def process_image(image_base64):
    """process image"""
    img_bytes = base64.b64decode(image_base64)

    with io.BytesIO(img_bytes) as img_stream:
        pil_image = Image.open(img_stream)
        pil_image.load()
        enhancer = ImageEnhance.Contrast(pil_image)
        image = enhancer.enhance(1.5)

        enhancer = ImageEnhance.Sharpness(image)
        image = enhancer.enhance(1.3)
        image = image.convert("RGB")

        image.close()

    del img_bytes
    return "processed"


def threadpool_infer(image_path):
    with Image.open(image_path) as image:
        with io.BytesIO() as output:
            image.save(output, format="JPEG")
            jpeg_bytes = output.getvalue()
            image_b64 = base64.b64encode(jpeg_bytes).decode("utf-8")

    total_requests = 100
    concurrent_requests = 10
    batch_size = concurrent_requests

    process = psutil.Process(os.getpid())
    start_time = time.time()
    start_mem = process.memory_info().rss / 1024 / 1024

    try:
        with ThreadPoolExecutor(max_workers=concurrent_requests) as pool:
            for i in range(0, total_requests, batch_size):
                current_batch = min(batch_size, total_requests - i)
                batch_num = i // batch_size + 1

                pre_batch_mem = process.memory_info().rss / 1024 / 1024
                loguru.logger.info(f"Batch {batch_num} starting. Memory: {pre_batch_mem:.2f}MB")

                futures = []
                for _ in range(current_batch):
                    future = pool.submit(process_image, image_b64)
                    futures.append(future)

                results = []
                for future in as_completed(futures):
                    results.append(future.result())

                gc.collect()

                post_batch_mem = process.memory_info().rss / 1024 / 1024
                batch_mem_diff = post_batch_mem - pre_batch_mem
                loguru.logger.info(
                    f"Batch {batch_num} completed. "
                    f"Processed {len(results)} images. "
                    f"Memory: {post_batch_mem:.2f}MB "
                    f"(batch diff: {batch_mem_diff:+.2f}MB)"
                )

    finally:
        end_time = time.time()
        end_mem = process.memory_info().rss / 1024 / 1024

        duration = end_time - start_time
        mem_diff = end_mem - start_mem

        loguru.logger.error(
            f"\nTotal Time: {duration:.2f}s, Memory: {mem_diff:+.2f}MB ({start_mem:.1f}MB -> {end_mem:.1f}MB)"
        )
        gc.collect()


if __name__ == "__main__":
    threadpool_infer("my_image.jpg")

Here are the results of executing 50 records:

2025-03-28 18:24:49.837 | INFO     | __main__:threadpool_infer:55 - Batch 1 starting. Memory: 93.73MB
2025-03-28 18:24:50.393 | INFO     | __main__:threadpool_infer:70 - Batch 1 completed. Processed 10 images. Memory: 434.20MB (batch diff: +340.47MB)
2025-03-28 18:24:50.393 | INFO     | __main__:threadpool_infer:55 - Batch 2 starting. Memory: 434.20MB
2025-03-28 18:24:50.893 | INFO     | __main__:threadpool_infer:70 - Batch 2 completed. Processed 10 images. Memory: 696.03MB (batch diff: +261.83MB)
2025-03-28 18:24:50.893 | INFO     | __main__:threadpool_infer:55 - Batch 3 starting. Memory: 696.03MB
2025-03-28 18:24:51.368 | INFO     | __main__:threadpool_infer:70 - Batch 3 completed. Processed 10 images. Memory: 738.77MB (batch diff: +42.73MB)
2025-03-28 18:24:51.368 | INFO     | __main__:threadpool_infer:55 - Batch 4 starting. Memory: 738.77MB
2025-03-28 18:24:51.849 | INFO     | __main__:threadpool_infer:70 - Batch 4 completed. Processed 10 images. Memory: 739.19MB (batch diff: +0.42MB)
2025-03-28 18:24:51.849 | INFO     | __main__:threadpool_infer:55 - Batch 5 starting. Memory: 739.19MB
2025-03-28 18:24:52.347 | INFO     | __main__:threadpool_infer:70 - Batch 5 completed. Processed 10 images. Memory: 739.36MB (batch diff: +0.17MB)
2025-03-28 18:24:52.348 | INFO     | __main__:threadpool_infer:55 - Batch 6 starting. Memory: 739.36MB
2025-03-28 18:24:52.845 | INFO     | __main__:threadpool_infer:70 - Batch 6 completed. Processed 10 images. Memory: 739.56MB (batch diff: +0.20MB)
2025-03-28 18:24:52.846 | INFO     | __main__:threadpool_infer:55 - Batch 7 starting. Memory: 739.56MB
2025-03-28 18:24:53.326 | INFO     | __main__:threadpool_infer:70 - Batch 7 completed. Processed 10 images. Memory: 754.36MB (batch diff: +14.80MB)
2025-03-28 18:24:53.326 | INFO     | __main__:threadpool_infer:55 - Batch 8 starting. Memory: 754.36MB
2025-03-28 18:24:53.808 | INFO     | __main__:threadpool_infer:70 - Batch 8 completed. Processed 10 images. Memory: 757.69MB (batch diff: +3.33MB)
2025-03-28 18:24:53.808 | INFO     | __main__:threadpool_infer:55 - Batch 9 starting. Memory: 757.69MB
2025-03-28 18:24:54.315 | INFO     | __main__:threadpool_infer:70 - Batch 9 completed. Processed 10 images. Memory: 764.31MB (batch diff: +6.62MB)
2025-03-28 18:24:54.315 | INFO     | __main__:threadpool_infer:55 - Batch 10 starting. Memory: 764.31MB
2025-03-28 18:24:54.815 | INFO     | __main__:threadpool_infer:70 - Batch 10 completed. Processed 10 images. Memory: 767.67MB (batch diff: +3.36MB)
2025-03-28 18:24:54.816 | ERROR    | __main__:threadpool_infer:84 - 
Total Time: 4.98s, Memory: +673.62MB (93.7MB -> 767.4MB)

What did you expect to happen?

The memory, taken by a PIL image copy, should be released after each request.

What did you expect to happen?

The memory isn't released.

What are your OS, Python and Pillow versions?

• OS: MacOS 15.3.2
• Python: 3.11.9
• Pillow: 10.4.0

--------------------------------------------------------------------
Pillow 10.4.0
Python 3.11.9 (main, Apr 19 2024, 11:43:47) [Clang 14.0.6 ]
--------------------------------------------------------------------
Python executable is /opt/anaconda3/envs/llm-composition-score/bin/python3
System Python files loaded from /opt/anaconda3/envs/llm-composition-score
--------------------------------------------------------------------
Python Pillow modules loaded from /opt/anaconda3/envs/llm-composition-score/lib/python3.11/site-packages/PIL
Binary Pillow modules loaded from /opt/anaconda3/envs/llm-composition-score/lib/python3.11/site-packages/PIL
--------------------------------------------------------------------
--- PIL CORE support ok, compiled for 10.4.0
--- TKINTER support ok, loaded 8.6
--- FREETYPE2 support ok, loaded 2.13.2
--- LITTLECMS2 support ok, loaded 2.16
--- WEBP support ok, loaded 1.4.0
--- WEBP Transparency support ok
--- WEBPMUX support ok
--- WEBP Animation support ok
--- JPEG support ok, compiled for libjpeg-turbo 3.0.3
--- OPENJPEG (JPEG2000) support ok, loaded 2.5.2
--- ZLIB (PNG/ZIP) support ok, loaded 1.3.1
--- LIBTIFF support ok, loaded 4.6.0
*** RAQM (Bidirectional Text) support not installed
*** LIBIMAGEQUANT (Quantization method) support not installed
--- XCB (X protocol) support ok
--------------------------------------------------------------------

[radarhere]

I'm guessing that my_image.jpg is quite large?

You may be interested in reading #7935, #5401 or #3610

[fangmartin]

@radarhere The image size is 2M~4M

[radarhere]

Could you upload a copy?

[fangmartin]

@radarhere This is my picture

[wiredfool]

The gold standard is running under valgrind, since the massif tool can tell us exactly where the allocations are. Unfortunately, valgrind doesn't run on macos.

Running this under a python3.12-dbg envrionment (without valgrind) on Ubuntu 22.04, I'm seeing:

Batch 1 starting. Memory: 34.87MB
Batch 1 completed. Processed 10 images. Memory: 37.36MB (batch diff: +2.49MB)
Batch 2 starting. Memory: 37.36MB
Batch 2 completed. Processed 10 images. Memory: 37.37MB (batch diff: +0.01MB)
Batch 3 starting. Memory: 37.37MB
Batch 3 completed. Processed 10 images. Memory: 37.37MB (batch diff: +0.00MB)
Batch 4 starting. Memory: 37.37MB
Batch 4 completed. Processed 10 images. Memory: 37.37MB (batch diff: +0.00MB)
Batch 5 starting. Memory: 37.37MB
Batch 5 completed. Processed 10 images. Memory: 37.37MB (batch diff: +0.00MB)
Batch 6 starting. Memory: 37.37MB
Batch 6 completed. Processed 10 images. Memory: 37.38MB (batch diff: +0.00MB)
Batch 7 starting. Memory: 37.38MB
Batch 7 completed. Processed 10 images. Memory: 37.39MB (batch diff: +0.01MB)
Batch 8 starting. Memory: 37.39MB
Batch 8 completed. Processed 10 images. Memory: 37.39MB (batch diff: +0.00MB)
Batch 9 starting. Memory: 37.39MB
Batch 9 completed. Processed 10 images. Memory: 37.39MB (batch diff: +0.00MB)
Batch 10 starting. Memory: 37.39MB
Batch 10 completed. Processed 10 images. Memory: 37.39MB (batch diff: +0.00MB)

Total Time: 7.12s, Memory: +2.60MB (34.9MB -> 37.5MB)

Note that is using print instead of loguru. Likely not the difference.

Using valgrind, I'm seeing something similar:

Batch 1 starting. Memory: 94.90MB
Batch 1 completed. Processed 10 images. Memory: 101.02MB (batch diff: +6.12MB)
Batch 2 starting. Memory: 101.02MB
Batch 2 completed. Processed 10 images. Memory: 104.63MB (batch diff: +3.61MB)
Batch 3 starting. Memory: 104.63MB
Batch 3 completed. Processed 10 images. Memory: 106.72MB (batch diff: +2.09MB)
Batch 4 starting. Memory: 106.72MB
Batch 4 completed. Processed 10 images. Memory: 106.72MB (batch diff: +0.00MB)
Batch 5 starting. Memory: 106.72MB
Batch 5 completed. Processed 10 images. Memory: 106.72MB (batch diff: +0.00MB)
Batch 6 starting. Memory: 106.72MB
Batch 6 completed. Processed 10 images. Memory: 106.72MB (batch diff: +0.00MB)
Batch 7 starting. Memory: 106.72MB
Batch 7 completed. Processed 10 images. Memory: 106.72MB (batch diff: +0.00MB)
Batch 8 starting. Memory: 106.72MB
Batch 8 completed. Processed 10 images. Memory: 106.72MB (batch diff: +0.00MB)
Batch 9 starting. Memory: 106.72MB
Batch 9 completed. Processed 10 images. Memory: 106.73MB (batch diff: +0.01MB)
Batch 10 starting. Memory: 106.73MB
Batch 10 completed. Processed 10 images. Memory: 106.73MB (batch diff: +0.00MB)

Total Time: 147.61s, Memory: +11.96MB (94.9MB -> 106.9MB)
==3287299== 
--------------------------------------------------------------------------------
Command:            python ./leak_8839.py
Massif arguments:   (none)
ms_print arguments: massif.out.3287299
--------------------------------------------------------------------------------


    MB
86.93^                                                              ##        
     |                                                              #         
     |                                                              #         
     |         @                                                @   # :       
     |         @                                                @   # :       
     |         @                                                @:::# :       
     |         @:                                               @: :# :       
     |         @:                                               @: :# :       
     |       ::@::::@@     :::::: ::    : ::::::::@::::::::::::@@: :# :  :    
     |       : @:: :@      : :::  :     : :::: :: @:: :: :: : :@@: :# :  :    
     |:::::::: @:: :@ :    : :::  :     : :::: :: @:: :: :: : :@@: :# :::::@::
     |: :::: : @:: :@ :    : :::  :     : :::: :: @:: :: :: : :@@: :# :::::@::
     |: :::: : @:: :@ :    : :::  :     : :::: :: @:: :: :: : :@@: :# :::::@::
     |: :::: : @:: :@ :::::: ::: :: :::::::::: :: @:: :: :: : :@@: :# :::::@::
     |: :::: : @:: :@ ::: :: ::: :: ::: :::::: :: @:: :: :: : :@@: :# :::::@::
     |: :::: : @:: :@ ::: :: ::: :: ::: :::::: :: @:: :: :: : :@@: :# :::::@::
     |: :::: : @:: :@ ::: :: ::: :: ::: :::::: :: @:: :: :: : :@@: :# :::::@::
     |: :::: : @:: :@ ::: :: ::: :: ::: :::::: :: @:: :: :: : :@@: :# :::::@::
     |: :::: : @:: :@ ::: :: ::: :: ::: :::::: :: @:: :: :: : :@@: :# :::::@::
     |: :::: : @:: :@ ::: :: ::: :: ::: :::::: :: @:: :: :: : :@@: :# :::::@::
   0 +----------------------------------------------------------------------->Gi
     0                                                                   108.3

Your trace is showing this: (with lines shortened)

Batch 1 starting. Memory: 93.73MB
Batch 1 completed. Processed 10 images. Memory: 434.20MB (batch diff: +340.47MB)
Batch 2 starting. Memory: 434.20MB
Batch 2 completed. Processed 10 images. Memory: 696.03MB (batch diff: +261.83MB)
Batch 3 starting. Memory: 696.03MB
Batch 3 completed. Processed 10 images. Memory: 738.77MB (batch diff: +42.73MB)
Batch 4 starting. Memory: 738.77MB
Batch 4 completed. Processed 10 images. Memory: 739.19MB (batch diff: +0.42MB)
Batch 5 starting. Memory: 739.19MB
Batch 5 completed. Processed 10 images. Memory: 739.36MB (batch diff: +0.17MB)
Batch 6 starting. Memory: 739.36MB
Batch 6 completed. Processed 10 images. Memory: 739.56MB (batch diff: +0.20MB)
Batch 7 starting. Memory: 739.56MB
Batch 7 completed. Processed 10 images. Memory: 754.36MB (batch diff: +14.80MB)
Batch 8 starting. Memory: 754.36MB
Batch 8 completed. Processed 10 images. Memory: 757.69MB (batch diff: +3.33MB)
Batch 9 starting. Memory: 757.69MB
Batch 9 completed. Processed 10 images. Memory: 764.31MB (batch diff: +6.62MB)
Batch 10 starting. Memory: 764.31MB
Batch 10 completed. Processed 10 images. Memory: 767.67MB (batch diff: +3.36MB)
Total Time: 4.98s, Memory: +673.62MB (93.7MB -> 767.4MB)

The raw image size is 10MB, the base64 is about 600k, raw image is about 400. Not sure why you're re-encoding it first thing, but that knocks down the size pretty significantly.

Running on macos, I'm seeing this:

Batch 1 starting. Memory: 41.81MB
Batch 1 completed. Processed 10 images. Memory: 236.75MB (batch diff: +194.94MB)
Batch 2 starting. Memory: 236.75MB
Batch 2 completed. Processed 10 images. Memory: 268.50MB (batch diff: +31.75MB)
Batch 3 starting. Memory: 268.50MB
Batch 3 completed. Processed 10 images. Memory: 268.69MB (batch diff: +0.19MB)
Batch 4 starting. Memory: 268.69MB
Batch 4 completed. Processed 10 images. Memory: 284.05MB (batch diff: +15.36MB)
Batch 5 starting. Memory: 284.05MB
Batch 5 completed. Processed 10 images. Memory: 284.20MB (batch diff: +0.16MB)
Batch 6 starting. Memory: 284.20MB
Batch 6 completed. Processed 10 images. Memory: 286.73MB (batch diff: +2.53MB)
Batch 7 starting. Memory: 286.73MB
Batch 7 completed. Processed 10 images. Memory: 291.70MB (batch diff: +4.97MB)
Batch 8 starting. Memory: 291.70MB
Batch 8 completed. Processed 10 images. Memory: 294.22MB (batch diff: +2.52MB)
Batch 9 starting. Memory: 294.22MB
Batch 9 completed. Processed 10 images. Memory: 294.22MB (batch diff: +0.00MB)
Batch 10 starting. Memory: 294.22MB
Batch 10 completed. Processed 10 images. Memory: 294.22MB (batch diff: +0.00MB)

Total Time: 2.52s, Memory: +252.09MB (41.8MB -> 293.9MB)

Which is similar to yours. I'd expect something like 10* (3* 10MB + 400k + 600k ) for a rough peak size of the threaded memory. A sample trace on macos is showing a peak memory footprint of 433M, which is probably about right. It's only showing a call graph, not a memory allocation graph, so it's not as useful as this for valgrind. Running that longer looks like a steady stage after the first 10 calls or so. There's noise but it's certainly not a steadily increasing memory allocation, which is what I'd expect from a leak.

So, the upshot here is -- I don't think there's a fundamental issue with Pillow, or we'd see something different in the Ubuntu traces, especially the non-valgrind one. There may be a difference with the underlying malloc/free implementation on macos, where it's not actually freeing back to the OS.

[fangmartin]

@wiredfool tks, I will try the information you mentioned in my environment.

[github-actions]

Closing this issue as no feedback has been received.