Unexpected memory consumption since release 8.3.0 #5797

helgeerbe · 2021-10-27T14:26:36Z

What did you do?

I'm the owner of picframe. This is a picture frame viewer for raspi, controlled via mqtt and automatticly integrated as mqtt device in homeassistant.

In an endless loop this programs displays one image on the frame, opens the next one and blend the new image smoothly in. To extract the image data PIL is used. So at the end just 2 images are kept in memory.

What did you expect to happen?

A stable memory consumption over a period of time. This was true up and including release 8.2.0.
I'm logging in a influxdb the system load and found this behavior.

Memory consumption is as expected stable. When suddenly the sawtooth line appears. (High cpu load two most left yellow peaks are the nightly backups).

What have I done?

apt get full-upgrade
pull all python modules required by picframe to their latest releases

pi@picframe:~ $ python3 --version
Python 3.7.3
pi@picframe:~ $ picframe -v
INFO:start.py:starting ['/home/pi/.local/bin/picframe', '-v']
picframe version:  0+untagged.365.gfc64728

Checking required packages......
PIL :  8.4.0
exifread :  2.3.2
pi3d :  2.48
yaml :  6.0
paho.mqtt :  1.5.1
iptcinfo3 :  2.1.4
numpy :  1.21.2
ninepatch : installed, but no version info

Checking optional packages......
pyheif :  0.5.1

What actually happened?

Starting with release 8.3.0 memory consumption is strange. Picframe starts with 6% total memory. While running, PIL allocated permanently memory which is freed frequently (sawtooth line). But at the end memory consumption reaches 100% in total and picframe crashes.

What are your OS, Python and Pillow versions?

OS: Rasbian
Description: Raspbian GNU/Linux 10 (buster)
Release: 10
Codename: buster
Linux picframe 5.10.63-v7+ 1459 SMP Wed Oct 6 16:41:10 BST 2021 armv7l GNU/Linux
Python: 3.7.2
Pillow: 8.3.0 - 8.4.0 (earlier releases behave as expected)

issue in picframe

Issue for picframe is tracked here

radarhere · 2021-10-27T21:31:35Z

Hi. Let me ask two questions

Are you installing Pllow from a wheel? I'm curious whether compiling Pillow from source fixes the problem. Or in other words, does the problem lie in our code itself, or does it maybe lie in our wheel and one of our packaged dependencies?
Are you able to put together a simple self-contained Python script, using just Pillow, that demonstrates the increased memory usage?

helgeerbe · 2021-10-28T07:48:28Z

Hi @radarhere

We use your provided packages. A simple pip3 uninstall Pillow and a pip3 install Pillow==version is enough to change the behavior.
I will check our code and try to write a simple example. I'm curious to myself

helgeerbe · 2021-10-29T11:08:03Z

Hi @radarhere

I hope I found the root cause in our code. We use the lib pi3d, down there in the code I see, that an numpy array is created. Here is an example code that shows this behavior.

from PIL import Image
import numpy as np

# endless loop
while(True) :
    np.array(Image.open("/home/pi/Pictures/Unu-2819.jpg"))

Using

Pillow 5.4.1 => CPU 100%, mem solid around 6%
Pillow 8.4.0 => CPU 100%, mem starting from 6% and rapidly growing to 100% and finally the process crashes.

paddywwoof · 2021-10-29T13:42:54Z

@helgeerbe are you saying that the garbage collector in python can't cope with the creation of numpy arrays that use byte arrays generated by PIL.Image.open()? What happens if you create python variables to "hang" the info on. i.e.

from PIL import Image
import numpy as np

while(True) :
    im = Image.open("/home/pi/Pictures/Unu-2819.jpg")
    np_im = np.array(im)
    # then with
    # im = None
    # np_im = None

pi3d does a little bit of manual 'destruction' of the OpenGL buffers as they slip through the python GC

PS and what happens if you comment out the np_im = .. line?

helgeerbe · 2021-10-29T14:45:29Z

I can run some further tests. Watching top in real-time I can see that memory is freed. But at the end memory consumption is faster than freeing. That explains the sigtooth graph.
Switching Pillow back to an older version, memory seems to be freed immediately. Memory consumption is always between 6 to 8 %. No growth as expected.

paddywwoof · 2021-10-29T16:22:00Z

When I try it here (on Raspberry Pi, it's fine on ubuntu x64 with lots of memory) I find the installed version of pillow is often running Image.__del__() when I ctrl-C to stop. That method was completely removed after 30 Oct 2019 cc63f66#diff-4805c79264fea07df59058db82ed74bb2f5c5023e212ac678536a534c56e5be2 and it was wrapped in an only python3 block before.

It's generally a bad idea to try to second guess the GC but maybe something is needed for small memory computers.

helgeerbe · 2021-10-29T16:32:11Z

while(True) :
    Image.open("/home/pi/Pictures/Unu-2819.jpg")

Works fine. No memory consumption.

while(True) :
    np_arr = np.array(Image.open("/home/pi/Pictures/Unu-2819.jpg"))

Does not work.

while(True) :
    im = Image.open("/home/pi/Pictures/Unu-2819.jpg")
    np_arr = np.array(im)
    im = None
    np_arr = None

Does not work.

pip3 uninstall Pillow
 pip3 install Pillow==8.2.0

And everything is fine again

paddywwoof · 2021-10-29T16:40:20Z

Yes, I've tried all permutations and it always seems to hang onto the memory with v8.3.0 though it never actually runs out for me - probably not big enough image. Using the older __del__ with file pointer checks etc doesn't make any difference. It's possibly something in the C code to save reloading things to memory if they might be needed later, but I've no idea really.

radarhere · 2021-11-08T21:30:57Z

Given what you're seeing, I suspect this is due to #5379, where we replaced our Image's __array_interface__ with __array__.

Are you sure this isn't a problem better addressed by the NumPy team?

rlevine · 2021-11-19T06:21:01Z

Hit the same issue - poor 512MB Heroku dynos didn't know what hit them. "Memory quota vastly exceeded." *chuckle*
36 2967x2992 8-bit png images with alpha channel, 33.86MB each, High water mark at 1.55GB, 1.2GB of memory that didn't go away.

============================================================
   973    181.9 MiB    181.9 MiB   @profile
   974                             def color_substitute(image, old_color, new_color):
   975    260.9 MiB     79.0 MiB       data = numpy.array(
   976    181.9 MiB      0.0 MiB       image)  # "data" is a height x width x 4 (assuming an alpha channel) numpy array
   977    260.9 MiB      0.0 MiB       red, green, blue, alpha = data.T  # Transpose bands
   978                                         
   979                                 # Replace old color with new color... (leaves alpha values alone...)
   980    278.8 MiB     17.9 MiB       color_areas = (red == old_color[0]) & (green == old_color[1]) & (blue == old_color[2])
   981    278.8 MiB      0.0 MiB       color_areas = color_areas.T  # transpose the array; back in the same orientation as original
   982    279.0 MiB      0.2 MiB       data[..., :-1][color_areas] = new_color  # vegematic
   983                                         
   984    279.0 MiB      0.0 MiB       return Image.fromarray(data)

Python 3.10.0
PIL : 8.4.0
numpy : 1.21.4

radarhere · 2021-11-19T07:55:04Z

Hi @rlevine. To confirm my theory, would you be able to install https://github.com/radarhere/Pillow/tree/numpy (or just open PIL/Image.py and make the radarhere@2779305 changes) and see if that fixes the problem?

rlevine · 2021-11-19T17:24:42Z

Chicken dinner. Memory for 36 passes through the function goes from 1488 MiB to 267 MiB, about 1.28GB difference.
Somebody missing a decref for the underlying cstruct?

Thanks!

Rick

Pillow==8.4.0 as distributed

984 1488.4 MiB 0.0 MiB 1 return Image.fromarray(data)

8.4.0 with radarhere/Pillow@2779305 applied

984 268.6 MiB 0.0 MiB 1 return Image.fromarray(data)

homm · 2021-11-19T19:48:54Z

I'm investigating this. The fix really simple:

        class ArrayData:
            def __init__(self, new):
                __array_interface__ = new

But I still don't understand the nature of cyclic references here. That's what I see:

import numpy, gc
from PIL import Image
im = Image.new('RGB', (4, 4))

try:
   gc.disable()
   gc.collect()
   gc.set_debug(gc.DEBUG_LEAK | gc.DEBUG_STATS)
   numpy.array(im)
   gc.collect()
   for item in gc.garbage:
      print('>>>', type(item), repr(item))
finally:
   gc.set_debug(0)
   gc.enable()
   gc.garbage.clear()
   gc.collect()

>>> <class 'tuple'> (4, 4, 3)
>>> <class 'dict'> {'shape': (4, 4, 3), 'typestr': '|u1', 'version': 3, 'data': b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'}
>>> <class 'tuple'> (<class 'object'>,)
>>> <class 'dict'> {'__module__': 'PIL.Image', '__array_interface__': {'shape': (4, 4, 3), 'typestr': '|u1', 'version': 3, 'data': b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'}, '__dict__': <attribute '__dict__' of 'ArrayData' objects>, '__weakref__': <attribute '__weakref__' of 'ArrayData' objects>, '__doc__': None}
>>> <class 'type'> <class 'PIL.Image.Image.__array__.<locals>.ArrayData'>
>>> <class 'getset_descriptor'> <attribute '__dict__' of 'ArrayData' objects>
>>> <class 'getset_descriptor'> <attribute '__weakref__' of 'ArrayData' objects>
>>> <class 'tuple'> (<class 'PIL.Image.Image.__array__.<locals>.ArrayData'>, <class 'object'>)

And from my point of view there couldn't be any circular refs.

homm · 2021-11-19T19:56:15Z

Oh, I get it finally. It turns that every class definition is a circular reference to itself:

In [15]: class ArrayData: 
    ...:     pass 
    ...: ArrayData.__mro__                                                                                                      
Out[15]: (__main__.ArrayData, object)

The smallest case which will grow infinitely:

gc.disable()
while True:
    class ArrayData:
        pass

So we just should move ArrayData definition to Image namespace, for example:

class Image:
    class _ArrayData:
        def __init__(self, new):
            __array_interface__ = new
                
    def __array__(self, dtype=None):
        ...
        return np.array(self._ArrayData(new), dtype)

homm · 2021-11-19T20:01:00Z

By the way, if anyone is curious about the performance of Pillow → NumPy conversions, there is an article with a helper function that works significantly faster: https://uploadcare.com/blog/fast-import-of-pillow-images-to-numpy-opencv-arrays/

Unfortunately, this enhancement is barely implementable within Pillow codebase.

homm · 2021-11-19T20:12:12Z

@rlevine

Somebody missing a decref for the underlying cstruct?

Nope, this is totally garbage pressure. We should always be very careful with circular references when working with large objects.

radarhere · 2021-11-19T23:15:58Z

Thanks @homm. I've created PR #5844 with your suggestion.

rlevine · 2021-11-20T00:06:44Z

Works! Thanks!

pcicales · 2022-04-08T16:16:23Z

I appear to be having this same issue with PIL==9.1.0.

I am observing the same sawtooth memory pattern, followed by 100% memory usage, when loading and unloading PIL images in a loop. Additionally I am passing PIL objects through helper functions, which may have something to do with it, I am not certain yet. The images are loaded using PIL, then converted to np arrays, then unloaded from memory using .close() and = None

@hugovk @homm could you try to reproduce? Same exact scripts as above.

radarhere · 2022-04-08T22:56:26Z

The original fix to this issue involved making Image.__array__ more efficient. With the upcoming release of NumPy 1.23, we have the opportunity to simplify further by switching back to Image.__array_interface__.

Would you mind testing https://github.com/radarhere/Pillow/tree/numpy and seeing if that solves your problem?

pcicales · 2022-04-09T19:26:16Z

@radarhere Just installed. Here is the package info. I will be testing this shortly.

 Name                    Version                   Build                    Channel
pillow                      9.1.0                     pypi_0                    pypi

 Name                 Version                   Build                    Channel
numpy                   1.21.2                py37h20f2e39_0
numpy-base              1.21.2                py37h79a1101_0

Current:

 Name                    Version                   Build                    Channel
pillow                      9.2.0.dev0               pypi_0                    pypi

 Name                    Version                   Build                    Channel
numpy                    1.21.2                py37h20f2e39_0
numpy-base                1.21.2                py37h79a1101_0

pcicales · 2022-04-09T23:17:47Z

@radarhere Seems to still have the leak - cpu mem gradually increases to 100%.

Should I revert back to an older version of PIL? Maybe 8.2.0?

radarhere · 2022-04-10T02:31:57Z

8.2.0 is the version before changed from __array_interface__ to __array__. That version would made sense, except that if that version would work, I would also have expect https://github.com/radarhere/Pillow/tree/numpy to work.

If there is any older version of Pillow that works for you, that would be useful debugging information to have.

Would you be able to open a new issue, specify your operating system details, and simple code to demonstrate the problem?

helgeerbe · 2022-04-11T11:33:08Z

Just to let you know. I upgraded to 9.1.0and it worked for me. So it must be something else. It seems not to be my original reported issue.

pcicales · 2022-04-11T18:05:09Z

@radarhere Interesting - I will do so. I am trying to pinpoint where memory is not being released; do you have any recommendations on best practices for doing so? Currently I am just logging cpu memory, but I think it would be helpful for us if I could pinpoint the PIL/np operation that is causing the issue.

Just to let you know. I upgraded to 9.1.0and it worked for me. So it must be something else. It seems not to be my original reported issue.

What is strange is that I am observing the same strange zig-zag memory pattern, which made me think it must have been related to your issue. I guess I may be seeing the same symptoms but for a different bug.

wiredfool · 2022-04-11T18:15:58Z

Try running it under valgrind, using the massif tool. It's slow, but it gives a really good profile of where and when memory is allocated. Alternately, the tracemalloc in py3 works pretty well to narrow it down to a line of python.

Rahul-Matta · 2022-12-05T19:32:15Z

@wiredfool @pcicales @helgeerbe
is it good to use > Pillow:9.1.0 to avoid memory consumption?
I am using Pillow:8.4.0 currently it's causing all four processors would hit 100% usage on the libc library.

wiredfool · 2022-12-05T19:39:21Z

@Rahul-Matta That doesn't sound anything like what's happening here. You're best off posting a complete bug report as a new issue.

Rahul-Matta · 2022-12-05T19:50:37Z

Okay, @wiredfool #6781 as new bug.

radarhere added the Memory label Oct 27, 2021

helgeerbe mentioned this issue Oct 29, 2021

Memory issue PIL >= 8.3.0 helgeerbe/picframe#182

Closed

radarhere added the NumPy label Nov 8, 2021

radarhere mentioned this issue Nov 19, 2021

Do not redeclare class each time when converting to NumPy #5844

Merged

hugovk closed this as completed in #5844 Nov 21, 2021

paddywwoof mentioned this issue Apr 8, 2022

New Buster issue: "Can't roll back Pillow; was not uninstalled" helgeerbe/picframe#259

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Unexpected memory consumption since release 8.3.0 #5797

Unexpected memory consumption since release 8.3.0 #5797

helgeerbe commented Oct 27, 2021 •

edited

radarhere commented Oct 27, 2021

helgeerbe commented Oct 28, 2021

helgeerbe commented Oct 29, 2021 •

edited

paddywwoof commented Oct 29, 2021 •

edited

helgeerbe commented Oct 29, 2021

paddywwoof commented Oct 29, 2021

helgeerbe commented Oct 29, 2021

paddywwoof commented Oct 29, 2021

radarhere commented Nov 8, 2021 •

edited

rlevine commented Nov 19, 2021 •

edited

radarhere commented Nov 19, 2021

rlevine commented Nov 19, 2021

homm commented Nov 19, 2021

homm commented Nov 19, 2021 •

edited

homm commented Nov 19, 2021 •

edited

homm commented Nov 19, 2021

radarhere commented Nov 19, 2021

rlevine commented Nov 20, 2021 •

edited by radarhere

pcicales commented Apr 8, 2022 •

edited

radarhere commented Apr 8, 2022

pcicales commented Apr 9, 2022 •

edited

pcicales commented Apr 9, 2022 •

edited

radarhere commented Apr 10, 2022

helgeerbe commented Apr 11, 2022

pcicales commented Apr 11, 2022 •

edited

wiredfool commented Apr 11, 2022 •

edited

Rahul-Matta commented Dec 5, 2022 •

edited

wiredfool commented Dec 5, 2022

Rahul-Matta commented Dec 5, 2022

Unexpected memory consumption since release 8.3.0 #5797

Unexpected memory consumption since release 8.3.0 #5797

Comments

helgeerbe commented Oct 27, 2021 • edited

What did you do?

What did you expect to happen?

What actually happened?

What are your OS, Python and Pillow versions?

issue in picframe

radarhere commented Oct 27, 2021

helgeerbe commented Oct 28, 2021

helgeerbe commented Oct 29, 2021 • edited

paddywwoof commented Oct 29, 2021 • edited

helgeerbe commented Oct 29, 2021

paddywwoof commented Oct 29, 2021

helgeerbe commented Oct 29, 2021

paddywwoof commented Oct 29, 2021

radarhere commented Nov 8, 2021 • edited

rlevine commented Nov 19, 2021 • edited

radarhere commented Nov 19, 2021

rlevine commented Nov 19, 2021

homm commented Nov 19, 2021

homm commented Nov 19, 2021 • edited

homm commented Nov 19, 2021 • edited

homm commented Nov 19, 2021

radarhere commented Nov 19, 2021

rlevine commented Nov 20, 2021 • edited by radarhere

pcicales commented Apr 8, 2022 • edited

radarhere commented Apr 8, 2022

pcicales commented Apr 9, 2022 • edited

pcicales commented Apr 9, 2022 • edited

radarhere commented Apr 10, 2022

helgeerbe commented Apr 11, 2022

pcicales commented Apr 11, 2022 • edited

wiredfool commented Apr 11, 2022 • edited

Rahul-Matta commented Dec 5, 2022 • edited

wiredfool commented Dec 5, 2022

Rahul-Matta commented Dec 5, 2022

helgeerbe commented Oct 27, 2021 •

edited

helgeerbe commented Oct 29, 2021 •

edited

paddywwoof commented Oct 29, 2021 •

edited

radarhere commented Nov 8, 2021 •

edited

rlevine commented Nov 19, 2021 •

edited

homm commented Nov 19, 2021 •

edited

homm commented Nov 19, 2021 •

edited

rlevine commented Nov 20, 2021 •

edited by radarhere

pcicales commented Apr 8, 2022 •

edited

pcicales commented Apr 9, 2022 •

edited

pcicales commented Apr 9, 2022 •

edited

pcicales commented Apr 11, 2022 •

edited

wiredfool commented Apr 11, 2022 •

edited

Rahul-Matta commented Dec 5, 2022 •

edited