Memory leak investigation

[Ch4s3]

cc @i0rek : In reference to typhoeus/typhoeus#562, I'm running object space dumps and memory profiler against the gem.

Note Ethon uses version 1.9.18 of the FFI gem which is the latest.

Here's my current setup:

Gemfile

source 'https://rubygems.org'
gem 'ethon', '~> 0.11.0'
gem 'memory_profiler'

Code

require 'ethon'
require 'memory_profiler'
report = MemoryProfiler.report do
  100.times do
    easies = [
      Ethon::Easy.new(url: 'https://en.wikipedia.org/wiki/Catalan_Republic_(2017)'),
      Ethon::Easy.new(url: 'https://en.wikipedia.org/wiki/Kazakh_language'),
      Ethon::Easy.new(url: 'https://en.wikipedia.org/wiki/19th_National_Congress_of_the_Communist_Party_of_China'),
      Ethon::Easy.new(url: 'https://en.wikipedia.org/wiki/Japan'),
      Ethon::Easy.new(url: 'https://en.wikipedia.org/wiki/Main_Page'),
      Ethon::Easy.new(url: 'https://en.wikipedia.org/wiki/Portal:Science'),
      Ethon::Easy.new(url: 'https://en.wikipedia.org/wiki/Stanley_McDougall'),
      Ethon::Easy.new(url: 'https://en.wikipedia.org/wiki/Jean_Ginsburg'),
      Ethon::Easy.new(url: 'https://en.wikipedia.org/wiki/Northeaster_(painting)'),
      Ethon::Easy.new(url: 'https://en.wikipedia.org/wiki/Petrograd_Military_Revolutionary_Committee'),
      Ethon::Easy.new(url: 'https://en.wikipedia.org/wiki/Cyrus_the_Great')
    ]
    multi = Ethon::Multi.new

    easies.each do |easy|
      multi.add(easy)
    end

    multi.perform
  end
end

report.pretty_print(to_file: 'report.txt')

Rationale:

My own use of Typhoeus makes use of a repeated collection 10~ calls to an api hundreds of times per hour. This setup runs 11 get calls 100 times. This should be sufficient to cause a buildup of retained objects if that is indeed a problem

Preliminary Findings:

retained memory by gem
-----------------------------------
   4904262  ethon-0.11.0
    465144  ffi-1.9.18
      4576  other
       544  ruby-2.3.3/lib

retained memory by file
-----------------------------------
   3667334  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/easy/callbacks.rb
   1050328  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/curls/options.rb
    369144  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ffi-1.9.18/lib/ffi/pointer.rb
    114736  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/easy/operations.rb
     96000  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ffi-1.9.18/lib/ffi/autopointer.rb
     70216  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/multi/operations.rb
     ...
retained memory by location
-----------------------------------
   3627459  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/easy/callbacks.rb:25
   1050328  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/curls/options.rb:103
    369144  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ffi-1.9.18/lib/ffi/pointer.rb:52
    114736  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/easy/operations.rb:13
     48000  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ffi-1.9.18/lib/ffi/autopointer.rb:87
     48000  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ffi-1.9.18/lib/ffi/autopointer.rb:96
     34360  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/multi/operations.rb:174
     32835  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/easy/callbacks.rb:26
     12360  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/multi/operations.rb:144
     10456  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/multi/operations.rb:16
      6240  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/multi/operations.rb:142
      6240  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/multi/operations.rb:162
      2200  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/easy/callbacks.rb:38
      2200  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/easy/callbacks.rb:53
      2200  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/easy/callbacks.rb:67
       880  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/easy.rb:236
       ...
retained memory by class
-----------------------------------
   4030798  String
   1049568  Thread
     82360  FFI::Pointer
     76800  Method
     55016  Array
     48000  FFI::AutoPointer::CallableReleaser
     12720  FFI::MemoryPointer
      6240  Ethon::Curl::Msg
      3432  RubyVM::Env
      3168  Proc
      2864  Hash
      1336  Ethon::Easy
       720  FFI::Function
       440  Ethon::Easy::DebugInfo
       392  FFI::AutoPointer
      ...
retained objects by file
-----------------------------------
      2400  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ffi-1.9.18/lib/ffi/autopointer.rb
      2206  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/easy/operations.rb
      1695  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/multi/operations.rb
       574  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ffi-1.9.18/lib/ffi/pointer.rb
        99  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/easy/callbacks.rb
       ...
retained objects by location
-----------------------------------
      2206  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/easy/operations.rb:13
      1200  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ffi-1.9.18/lib/ffi/autopointer.rb:87
      1200  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ffi-1.9.18/lib/ffi/autopointer.rb:96
       859  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/multi/operations.rb:174
       574  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ffi-1.9.18/lib/ffi/pointer.rb:52
       309  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/multi/operations.rb:144
       201  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/multi/operations.rb:16
       156  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/multi/operations.rb:142
       156  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/multi/operations.rb:162
        22  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/easy.rb:236
        22  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/easy/callbacks.rb:38
        22  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/easy/callbacks.rb:53
        22  /Users/chase/.rvm/gems/ruby-2.3.3/gems/ethon-0.11.0/lib/ethon/easy/callbacks.rb:67
        ...
retained objects by class
-----------------------------------
      2059  FFI::Pointer
      1370  Array
      1200  FFI::AutoPointer::CallableReleaser
      1200  Method
       630  String
       318  FFI::MemoryPointer
       156  Ethon::Curl::Msg
       ...

Notable Lines of Code:

https://github.com/typhoeus/ethon/blob/v0.11.0/lib/ethon/easy/operations.rb#L13
https://github.com/typhoeus/ethon/blob/v0.11.0/lib/ethon/easy/callbacks.rb#L25
https://github.com/typhoeus/ethon/blob/v0.11.0/lib/ethon/curls/options.rb#L103
https://github.com/typhoeus/ethon/blob/v0.11.0/lib/ethon/multi/operations.rb#L174
https://github.com/ffi/ffi/blob/1.9.18/lib/ffi/pointer.rb#L52
https://github.com/ffi/ffi/blob/1.9.18/lib/ffi/autopointer.rb#L87

The full report of a single run can be viewed here

This will undoubtedly require some further investigation.

[him3010]

hey facing similar issues while using typhoeus. Any updates regarding the fix or any monkeypatch around it?

[erwanlr]

Having this one as well, but with the allocated memory. This is quite notable when the response is large and is causing one of our scanner to go OOM in such cases. Using Typhoeus::Config.memoize = false as suggested at typhoeus/typhoeus#562 (comment) does not do the trick

For example, with a response of 110kb:

• 100 requests

  20.71 MB  /.rvm/rubies/ruby-2.7.1/lib/ruby/gems/2.7.0/gems/ethon-0.12.0/lib/ethon/easy/callbacks.rb:25
  12.28 MB  /.rvm/rubies/ruby-2.7.1/lib/ruby/gems/2.7.0/gems/ffi-1.13.1/lib/ffi/pointer.rb:60
  

• 300 requests

  60.04 MB  /.rvm/rubies/ruby-2.7.1/lib/ruby/gems/2.7.0/gems/ethon-0.12.0/lib/ethon/easy/callbacks.rb:25
  35.00 MB  /.rvm/rubies/ruby-2.7.1/lib/ruby/gems/2.7.0/gems/ffi-1.13.1/lib/ffi/pointer.rb:60
  

• 500 requests

  99.36 MB  /.rvm/rubies/ruby-2.7.1/lib/ruby/gems/2.7.0/gems/ethon-0.12.0/lib/ethon/easy/callbacks.rb:25
  57.69 MB  /.rvm/rubies/ruby-2.7.1/lib/ruby/gems/2.7.0/gems/ffi-1.13.1/lib/ffi/pointer.rb:60
  

and 1k requests with a response of 4.1kb

 6.83 MB  /.rvm/rubies/ruby-2.7.1/lib/ruby/gems/2.7.0/gems/ethon-0.12.0/lib/ethon/easy/callbacks.rb:25
 6.81 MB  /.rvm/rubies/ruby-2.7.1/lib/ruby/gems/2.7.0/gems/ffi-1.13.1/lib/ffi/pointer.rb:60

Notable lines of Code are the same than the first post:

• https://github.com/ffi/ffi/blob/1.13.1/lib/ffi/pointer.rb#L60
• https://github.com/typhoeus/ethon/blob/v0.12.0/lib/ethon/easy/callbacks.rb#L25

[bettysteger]

any news or fixes?