memory_profiler icon indicating copy to clipboard operation
memory_profiler copied to clipboard

pretty_print results in NO DATA

Open kevgrig opened this issue 2 years ago • 8 comments

I'm investigating memory usage in a Ruby on Rails 6 app. I wrote the following code around an initializer:

    if !ENV["MEMPROFILE"].blank?
      require 'memory_profiler'
      MemoryProfiler.start
    end

    # My initializer
    
    if !ENV["MEMPROFILE"].blank?
      puts "MEMPROFILE"
      report = MemoryProfiler.stop
      report.pretty_print
    end

Normally, the process uses about 1GB and with the profiler, it uses about 6GB, so it's clearly doing something, but the results printed show NO DATA. The # My initializer section above is definitely executing and doing a lot (I can see the print statements). Any thoughts?

MEMPROFILE
Total allocated: 0 bytes (0 objects)
Total retained:  0 bytes (0 objects)

allocated memory by gem
-----------------------------------
NO DATA

allocated memory by file
-----------------------------------
NO DATA

allocated memory by location
-----------------------------------
NO DATA

allocated memory by class
-----------------------------------
NO DATA

allocated objects by gem
-----------------------------------
NO DATA

allocated objects by file
-----------------------------------
NO DATA

allocated objects by location
-----------------------------------
NO DATA

allocated objects by class
-----------------------------------
NO DATA

retained memory by gem
-----------------------------------
NO DATA

retained memory by file
-----------------------------------
NO DATA

retained memory by location
-----------------------------------
NO DATA

retained memory by class
-----------------------------------
NO DATA

retained objects by gem
-----------------------------------
NO DATA

retained objects by file
NO DATA

retained objects by location
-----------------------------------
NO DATA

retained objects by class
-----------------------------------
NO DATA

Ruby version:

$ ruby -v
ruby 3.1.3p185 (2022-11-24 revision 1a6b16756e) [x86_64-linux]

Running on Linux Fedora 37 x64

kevgrig avatar Mar 15 '23 12:03 kevgrig

The # My initializer section above is definitely executing and doing a lot (I can see the print statements)

Can you share (at least a sketch of it) of what is done in this section? Are you trying to measure memory allocated only by that section of code in the initializer?

You may also find running memory_profiler as CLI helpful - https://github.com/SamSaffron/memory_profiler/pull/91.

fatkodima avatar Mar 16 '23 13:03 fatkodima

The # My initializer section above is definitely executing and doing a lot (I can see the print statements)

Can you share (at least a sketch of it) of what is done in this section?

It runs database queries and caches some results in memory. If I just run top at the start of the initializer until the end, RES goes up by about 500MB, so that's why I'm trying to investigate it and see how to optimize it.

Are you trying to measure memory allocated only by that section of code in the initializer?

Yeah, exactly.

You may also find running memory_profiler as CLI helpful - #91.

The issue is that this rails app is huge. I tried running around a larger block than the initializer and it used over 10GB and my laptop went out of memory, thus why I tried to just focus on this initializer.

kevgrig avatar Mar 16 '23 13:03 kevgrig

Thats strange. Just put a code similar to yours in a rails app's initializer, measuring 1000.times { |i| [i, "#{i}"] } and got the results.

Try to create a sample reproducible app. Maybe you (or some gem) monkey patched something. Try to step with the debugger through the MemoryProfiler.start/stop/pretty_print methods and see how it goes.

fatkodima avatar Mar 16 '23 14:03 fatkodima

I'm also seeing something like this:

irb(main):002> MemoryProfiler.report(allow_files: 'rubygems') { 100.times { x = 1*2 } }.pretty_print
Total allocated: 0 bytes (0 objects)
Total retained:  0 bytes (0 objects)

allocated memory by gem
-----------------------------------
NO DATA

allocated memory by file
-----------------------------------
NO DATA

allocated memory by location
-----------------------------------
NO DATA

allocated memory by class
-----------------------------------
NO DATA

allocated objects by gem
-----------------------------------
NO DATA

allocated objects by file
-----------------------------------
NO DATA

allocated objects by location
-----------------------------------
NO DATA

allocated objects by class
-----------------------------------
NO DATA

retained memory by gem
-----------------------------------
NO DATA

retained memory by file
-----------------------------------
NO DATA

retained memory by location
-----------------------------------
NO DATA

retained memory by class
-----------------------------------
NO DATA

retained objects by gem
-----------------------------------
NO DATA

retained objects by file
-----------------------------------
NO DATA

retained objects by location
-----------------------------------
NO DATA

retained objects by class
-----------------------------------
NO DATA

=> nil

irb(main):003> RUBY_VERSION
=> "3.2.2"

jcoyne avatar Oct 24 '23 20:10 jcoyne

@jcoyne You are seeing this because x = 1*2 does not allocate memory. This is an expected result.

fatkodima avatar Oct 24 '23 20:10 fatkodima

@fatkodima 🤦 Thanks I should have known that. It seems the same when I actually allocate stuff:

irb(main):002> MemoryProfiler.report(allow_files: 'rubygems') { 100.times { |i| [i, "#{i}"] } }.pretty_print
Total allocated: 0 bytes (0 objects)
Total retained:  0 bytes (0 objects)

allocated memory by gem
-----------------------------------
NO DATA
...

jcoyne avatar Oct 25 '23 00:10 jcoyne

Thats because nothing is allocated from 'rubygems'. Try

MemoryProfiler.report { 100.times { |i| [i, "#{i}"] } }.pretty_print

fatkodima avatar Oct 25 '23 08:10 fatkodima

Oh, I understood 'allow_files' to be the opposite of what it does. Thanks.

jcoyne avatar Oct 25 '23 11:10 jcoyne