memory increasing to infinity

[FluffyDiscord]

Hi, I have issues with memory going wild and using every bit of ram it can get. I have simple function to create smaller version of an image and save it beside the source one.

This whole logic is inside GIN framework. The snippet that has memory leak is here and as you can see, I am getting desperate with the clearImagickWand() function which still doesn't work as it should.

What can I do beside using cmd and imagick's convert like a peasant.

The memory leak is not small. Every 15 or so images (jpg and png, bellow 1MB) my memory usage jumps by ~700MB which is absolutely insane

func clearImagickWand(mw *imagick.MagickWand) {
	mw.Clear()
	mw.Destroy()
	runtime.SetFinalizer(mw, nil)
	mw = nil
}

func createCoverImage(pathNoExtension string, coverPathName string) bool {
	sourceImagePath := getSourceImageForCover(filepath.Dir(pathNoExtension))
	mw := imagick.NewMagickWand()

	err := mw.ReadImage(sourceImagePath)
	if err != nil {
		clearImagickWand(mw)
		return false
	}

	width, height, err := mw.GetSize()
	if err != nil {
		clearImagickWand(mw)
		return false
	}

	// create thumb if we are requesting cover
	if width > 320 {
		scaleRatio := 320 / width
		width = width * scaleRatio
		height = height * scaleRatio

		err = mw.ResizeImage(width, height, imagick.FILTER_LANCZOS, -0.1)
		if err != nil {
			clearImagickWand(mw)
			return false
		}
	}

	err = mw.WriteImage(coverPathName)
	if err != nil {
		clearImagickWand(mw)
		return false
	}

	clearImagickWand(mw)

	return true
}

Whole script is in the attachment fileserver.zip (it's in zip since github doesn't approve of .go files), the GIN server is running inside a docker image:

FROM golang:1.17

COPY . /app

WORKDIR /app

RUN apt update
RUN apt install -y pkg-config libmagickwand-dev

RUN mkdir -p data/content
RUN mkdir -p data/cache

RUN go mod tidy
RUN go mod download
RUN go build -tags="jsoniter nomsgpack" -o fileserver

EXPOSE 9068

CMD ["/app/fileserver", "-p", "9068", "-b", "/app/data/content", "-c", "/app/data/cache"]

[justinfx]

Your usage of the library seems pretty minimal and straight-forward. I would be surprised if your custom clearImagickWand() is making any difference at all. Is that just a hail-Mary attempt to clear memory as fast as possible? Simply having a defer mw.Destroy() should be sufficient.

Some other ideas you can try:

• Update to imagemagick7 and use the v3 bindings
• Limit the number of possible concurrent ImageMagick conversions, using a semaphore (or workers). Having unbounded web handlers means that it is allowed to try and do as many concurrent image conversions as there are requests, and Go is going to end up spawning a lot of OS threads to try and service that. In my own image processing web server, I limit the conversions to something that matches the number of cores/memory my server has available.
• Try using runtime.LockOSThread() and runtime.UnlockOSThread() around your createCoverImage imagemagick functionality. In combination with a bounded number of image processors, this will also make sure the underlying ImageMagick C library uses consistent OS threads.

[FluffyDiscord]

Is that just a hail-Mary attempt to clear memory as fast as possible? Well I have tried that at first, just like the docs say, create a wand and defer mw.Destroy() under it, but that didn't seem to help - memory usage was still going up. The clearImagickWand() is just my silent scream in the darkness. Tried something and it didn't help much over the plain Destroy()

The issue will not be in concurrency as I send X number of requests, wait for them to process and then repeat, so it never gets over a certain number, but the memory grows nonetheless, never stopping. For example the test ran this function for 5 times for 20 images, clearing the generated cover.jpg in between so it forced this script to generate them again. After each run, reported memory usage was higher than before.

I have tried pprof this script and all I don't really understand it. Maybe you can get something out of it ?

The following dumps were made after one run (explanation above)

Dump heap

Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top20
Showing nodes accounting for 8835.81kB, 100% of 8835.81kB total
Showing top 20 nodes out of 59
      flat  flat%   sum%        cum   cum%
 3587.50kB 40.60% 40.60%  3587.50kB 40.60%  runtime.allocm
 1536.01kB 17.38% 57.99%  1536.01kB 17.38%  runtime.doaddtimer
 1024.41kB 11.59% 69.58%  1024.41kB 11.59%  runtime.malg
  600.58kB  6.80% 76.38%  1117.35kB 12.65%  github.com/go-playground/validator/v10.init
  540.51kB  6.12% 82.49%   540.51kB  6.12%  sync.(*Map).Store
  518.02kB  5.86% 88.36%   518.02kB  5.86%  os.ReadFile
  516.76kB  5.85% 94.21%   516.76kB  5.85%  regexp.onePassCopy
  512.01kB  5.79%   100%  1052.52kB 11.91%  mime.setExtensionType
         0     0%   100%   518.02kB  5.86%  github.com/gin-contrib/pprof.pprofHandler.func1
         0     0%   100%  1052.52kB 11.91%  github.com/gin-gonic/gin.(*Context).File (inline)
         0     0%   100%  1570.54kB 17.77%  github.com/gin-gonic/gin.(*Context).Next (inline)
         0     0%   100%  1570.54kB 17.77%  github.com/gin-gonic/gin.(*Engine).ServeHTTP
         0     0%   100%  1570.54kB 17.77%  github.com/gin-gonic/gin.(*Engine).handleHTTPRequest
         0     0%   100%  1570.54kB 17.77%  github.com/gin-gonic/gin.CustomRecoveryWithWriter.func1
         0     0%   100%  1570.54kB 17.77%  github.com/gin-gonic/gin.LoggerWithConfig.func1
         0     0%   100%  1052.52kB 11.91%  main.main.func1
         0     0%   100%  1052.52kB 11.91%  mime.TypeByExtension
         0     0%   100%  1052.52kB 11.91%  mime.initMime
         0     0%   100%  1052.52kB 11.91%  mime.initMimeUnix
         0     0%   100%  1052.52kB 11.91%  mime.loadMimeGlobsFile

and dump alloc

File: fileserver
Build ID: f7c3c0a1ad1074ecf6bcb8c7b1ca236ffba705c1
Type: alloc_space
Time: May 9, 2022 at 12:01am (CEST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top20
Showing nodes accounting for 57.81MB, 92.04% of 62.81MB total
Showing top 20 nodes out of 107
      flat  flat%   sum%        cum   cum%
   28.88MB 45.99% 45.99%    29.38MB 46.78%  io.copyBuffer
    5.29MB  8.42% 54.41%     9.57MB 15.23%  compress/flate.NewWriter
    4.03MB  6.42% 60.83%     4.03MB  6.42%  runtime/pprof.StartCPUProfile
    3.50MB  5.58% 66.41%     3.50MB  5.58%  runtime.allocm
    3.18MB  5.06% 71.47%     4.28MB  6.81%  compress/flate.(*compressor).init
       2MB  3.18% 74.65%        2MB  3.18%  os.statNolog
    1.50MB  2.39% 77.04%     1.50MB  2.39%  runtime.doaddtimer
    1.16MB  1.84% 78.88%     1.16MB  1.84%  runtime/pprof.writeGoroutineStacks
    1.10MB  1.75% 80.64%     1.10MB  1.75%  compress/flate.newDeflateFast (inline)
    1.01MB  1.62% 82.25%     1.01MB  1.62%  os.ReadFile
    1.01MB  1.61% 83.86%     1.01MB  1.61%  runtime/pprof.(*protobuf).string (inline)
       1MB  1.59% 85.45%        1MB  1.59%  runtime.malg
    0.59MB  0.93% 86.39%     1.09MB  1.74%  github.com/go-playground/validator/v10.init
    0.53MB  0.84% 87.23%     0.53MB  0.84%  sync.(*Map).Store
    0.51MB  0.81% 88.04%     9.06MB 14.42%  runtime/pprof.writeHeapInternal
    0.50MB   0.8% 88.85%     0.50MB   0.8%  regexp.onePassCopy
    0.50MB   0.8% 89.65%     0.50MB   0.8%  bufio.NewReaderSize
    0.50MB   0.8% 90.45%     0.50MB   0.8%  runtime/pprof.(*profileBuilder).stringIndex
    0.50MB   0.8% 91.24%     0.50MB   0.8%  runtime/pprof.(*profileBuilder).emitLocation
    0.50MB   0.8% 92.04%     0.50MB   0.8%  net/http.Header.Clone

I will try the imagick7 tomorrow and report my findings

[justinfx]

The memory is most definitely held in C by ImageMagick. So your pprof will reflect the Go memory looking quite small (am I right?). From what I have seen, continuous memory growth tends to be caused by either many OS threads into ImageMagick or an older ImageMagick version or a particular image format delegate plugin (depends on your input and output types).

You can search the issue history on this project and see similar discussions to resolve memory growth.

What approach are you using to read the memory growth? Is it the RSS (no virtual / swap).

[FluffyDiscord]

Just tried imagick 7 with v3 bindings and it behaves the same (maaaaybe a bit slower on the memory growth, but still increasing forever).

I am using docker stats to see the memory usage and also htop from the container insides. I did read #136, but there's no fix, just a bunch of speculations.

[justinfx]

If you see this in a docker container then I should be able to reproduce it. Can you give me your exact setup including input and output image format. If I can run it and see the behavior maybe that will help narrow it down. Have you tried reproducing it outside of docker on a host?

On Wed, 11 May 2022, 6:19 am Mossshine, @.***> wrote:

Just tried imagick 7 with v3 bindings and it behaves the same (maaaaybe a bit slower on the memory growth, but still increasing forever).

I am using docker stats to see the memory usage and also htop from the container insides. I did read #136 https://github.com/gographics/imagick/issues/136, but there's no fix, just a bunch of speculations.

— Reply to this email directly, view it on GitHub https://github.com/gographics/imagick/issues/276#issuecomment-1122721169, or unsubscribe https://github.com/notifications/unsubscribe-auth/AACE7RUGTFD34TB7HGJXEM3VJKSCPANCNFSM5VO4FCSQ . You are receiving this because you commented.Message ID: @.***>

[FluffyDiscord]

I have not tried to reproduce it outside of docker, so I have no idea how it behaves outside as I have to run in on my windows machine in docker and then on my unRAID machine where only dockers or VMs are a thing.

Sure, you can download the test here projectfiles.zip

• unpack it
• update volume absolute paths in the compose.yml to point in to the unpacked cache and data folder
• run docker-compose up
• wait for a while, the imagick 7 build takes it's sweet time
• open another terminal with docker stats
• run php run_to_cycle_cover_images.php to see memory creeping up and not freeing

There are just a few sample images, so you may need to run the php script twice or so to really see the issue.

If you have trouble running the php script, let me know, I can move it into bash (just found php on my hand so I used it)

[justinfx]

@FluffyDiscord I gave your project a test and what I noticed was that over the course of the 50 loops of converting the batch of 10 images, I would see the memory usage fluctuate up and down, slowly rising to between the 300-450MB range. Once the loops finished, the ram settled at around 350MB. When I ran the 50 loops against that same instance again, I noticed the ram did not continue to grow. It fluctuated a smaller amount and still settled back at that 350MB amount again. This doesn't seem like a memory leak, but rather just the Go runtime allocating memory and hanging on to a bit that is not being taken back by the OS, presumably because the system is not under memory pressure.

This is the bash script I was using:

#!/bin/bash

set -eu

for i in {1..50}; do
	echo "=== Loop $i ==="
	find ./data -type f -name cover.jpg -exec rm -f {} \;

	for j in $(ls -1 data); do
		echo "  id $j" 
		curl --fail-early http://localhost:9068/$j/cover.jpg > /dev/null
	done
done

When I ran go tool pprof to collect a heap profile, before and after the image processing, the top10 basically looked the same, with Go not reporting it was holding any real memory (which I assume means the memory is either not fully being released back to the OS even though Go has released it, or that it is being cached somewhere in ImageMagick C library layer).

I also tested moving the creation/destroy of the MagickWand into the createCoverImage() handler each time (as it should be) and it didnt much much difference to the memory usage at all. Using runtime.LockOSThread also made no difference since there isn't any concurrent processing going on.

[FluffyDiscord]

Interesting. Would you mind sharing with me your docker version and OS ?

If this can't be reproduced outside my windows and unraid machine, then this issue can be closed...

Unraid

Linux 5.15.37-Unraid.

docker

Client:
 Version:           20.10.14
 API version:       1.41
 Go version:        go1.16.15
 Git commit:        a224086
 Built:             Thu Mar 24 01:45:09 2022
 OS/Arch:           linux/amd64
 Context:           default
 Experimental:      true

Server: Docker Engine - Community
 Engine:
  Version:          20.10.14
  API version:      1.41 (minimum version 1.12)
  Go version:       go1.16.15
  Git commit:       87a90dc
  Built:            Thu Mar 24 01:49:54 2022
  OS/Arch:          linux/amd64
  Experimental:     false
 containerd:
  Version:          v1.5.11
  GitCommit:        3df54a852345ae127d1fa3092b95168e4a88e2f8
 runc:
  Version:          1.0.3
  GitCommit:        v1.0.3-0-gf46b6ba2
 docker-init:
  Version:          0.19.0
  GitCommit:        de40ad01

[justinfx]

I'm running the identical docker version as your specs, and I am running it in Ubuntu 20.04 under Windows WSL2

[ZhiliangLin]

ReadImageBlob, 7M pdf (41 pages) covert to image, memory increase to 9G

[justinfx]

ReadImageBlob, 7M pdf (41 pages) covert to image, memory increase to 9G

Are you saying it never decreases after releasing the resources, in a single call? Do you have details? ImageMagick version and distro?

[ZhiliangLin]

yes, in a single call, but not after releasing the resources, just after ReadImageBlob(data).

ImageMagick 7.1.0-0 Q16 x86_64 2021-06-13 imagick.v3 Mac 12.4

[justinfx]

But that wouldn't be a memory leak then or be something we can fix in this binding library. That's likely either C ImageMagick or the ghostscript delegate plugin.

[ZhiliangLin]

Yes, this is not a memory leak. I just can't find a solution in any other places :( Anyway, thanks for your reply.

[justinfx]

What did they say about it on the ImageMagick forum or issue tracker?

[qizhanchan]

func clearImagickWand(mw *imagick.MagickWand) {
	mw.RemoveImage()
	mw.Clear()
	mw.Destroy()
	runtime.SetFinalizer(mw, nil)
	mw = nil
}```  
RemoveImage worked in my case

[acelot]

In my case MALLOC_ARENA_MAX variable set to 2 helped. This value tells the Imagemagick's malloc allocator to use memory sparingly. See https://devcenter.heroku.com/articles/tuning-glibc-memory-behavior. Also set GOMEMLIMIT to desired max memory limit.