naqvis / crystal-vips

Crystal bindings for the libvips image processing library.
MIT License
39 stars 5 forks source link

Potential memory leak #4

Closed Manfred closed 1 year ago

Manfred commented 1 year ago

When I run crystal leak_test.cr with any file I see the the process grow to use gigabytes of memory. This happens both on Crystal 1.7.3 as well as Crystal 1.8.2.

I verified that this happens on macOS Venture on both and M1 and an Intel processor. I also verified that it happens on Ubuntu on an Intel processor. Finally I verified that it's not a Vips issue by porting leak_test.cr to Ruby and test with the Ruby bindings and there the memory usage stays below 70 megabytes.

I'm not really familiar with how memory management is supposed to be implemented for Vips bindings, so I don't know where to start looking for a solution.

naqvis commented 1 year ago

Thanks @Manfred. Yeah I'm able to reproduce that on M1 Crystal 1.8.2. My findings as below:

Image size: 3.4M OP: VipsForeignLoadJpegBuffer

Crystal uses bdwgc as its GC. I notice that GC cleanup is performed in the end. Might be due to the fact that we are invoking operation in a tight loop and GC doesn't get a chance to tick. Adding a small pause in loop keep the mem usage to some low value (around 100M).

I will try to dig deeper to see if there something which can be further optimized.

Manfred commented 1 year ago

I'm not sure if it's just garbage collection, because it doesn't improve when you call GC.collect in my testing.

I tried the following:

require "../src/vips"

Vips.leak = true

def print_memory_usage
  first = true
  `ps x -o pid,rss`.split("\n").each do |line|
    if first
      first = false
      next
    end

    pid, rss = line.strip.split(/\s+/)
    next unless pid.to_i == Process.pid

    megabytes = (rss.to_i / 1024).round(1)
    puts "Resident memory usage: #{megabytes} megabytes"
    break
  end
end

10.times do
  1000.times do
    Vips::Image.black(40, 40).write_to_target(IO::Memory.new, format: ".jpg")
  end
  print_memory_usage
end

3.times do
  sleep 1.seconds
  GC.collect
  print_memory_usage
end

And this gives me roughly the following output:

Resident memory usage: 42.3 megabytes
Resident memory usage: 56.6 megabytes
Resident memory usage: 71.0 megabytes
Resident memory usage: 85.0 megabytes
Resident memory usage: 100.1 megabytes
Resident memory usage: 113.8 megabytes
Resident memory usage: 128.1 megabytes
Resident memory usage: 142.1 megabytes
Resident memory usage: 156.7 megabytes
Resident memory usage: 171.5 megabytes
Resident memory usage: 171.5 megabytes
Resident memory usage: 171.5 megabytes
Resident memory usage: 171.5 megabytes

Any time you can spend on this is appreciated!

naqvis commented 1 year ago

@Manfred pushed changes to fix memory usage issue. After fix, running your provided sample yields following output on my box.

Please make sure you run shards update to fetch latest release

Resident memory usage: 34.5 megabytes
Resident memory usage: 35.2 megabytes
Resident memory usage: 35.4 megabytes
Resident memory usage: 35.5 megabytes
Resident memory usage: 35.6 megabytes
Resident memory usage: 35.7 megabytes
Resident memory usage: 35.7 megabytes
Resident memory usage: 35.7 megabytes
Resident memory usage: 35.8 megabytes
Resident memory usage: 35.8 megabytes
Resident memory usage: 35.8 megabytes
Resident memory usage: 35.8 megabytes
Resident memory usage: 35.8 megabytes
Manfred commented 1 year ago

That fixes the specific issue for me too, but when I add some operations the leaking comes back, for example:

Vips::Image.black(40, 40).thumbnail_image(
  20,
  crop: Vips::Enums::Interesting::Centre,
  size: Vips::Enums::Size::Down
).write_to_target(IO::Memory.new, format: ".jpg")
naqvis commented 1 year ago

Fixed and pushed changes. Please let me know if you are getting different results.

Manfred commented 1 year ago

Yeah, that definitely fixes it. Thanks!