Where communities thrive


  • Join over 1.5M+ people
  • Join over 100K+ communities
  • Free without limits
  • Create your own community
People
Repo info
Activity
    Joe Rafaniello
    @jrafanie
    That's why I'd love to see if these leaks you're seeing are sustained
    Nick LaMuro
    @NickLaMuro
    well, I killed most of the scripts I was running from over the weekend, but they were going strong when I did (I have the logs if you want me to PM you the details)
    I also have a hotfix in place where I am removing the impact of the require from the MiqSystem.num_cpus running on three appliances at the moment
    Joe Rafaniello
    @jrafanie
    Ah, if that memorized require hotfix is the only change in effect, that should give us a better idea of it's impact over many hours. That should work.
    Nick LaMuro
    @NickLaMuro
    yeah. I also have one of the servers running with the 40.times { sync_workers } code in place
    Beni Cherniavsky-Paskin
    @cben

    load leaks, even on bare ruby (2.3.4p301 (2017-03-30 revision 58214) [x86_64-linux]):

    touch empty.rb
    ruby -e "1_000.times { 1_000.times { load './empty.rb' }; GC.start; STDOUT.write('.') }"

    (run top, VIRT keeps growing)
    require itself doesn't leak, even without GC.start:

    ruby -e "1_000.times { 1_000.times { require './empty.rb' }; STDOUT.write('.') }"

    However, same require loop in rails console leaks like crazy (0.4G -> 2.4G in one minute)!

    also with GC.

    $ bundle exec rails c
    ...
    [1] pry(main)> 1_000.times { 1_000.times { require './empty.rb' }; GC.start; STDOUT.write('.') }

    [require under rails c also feels way slower than bare ruby, but that's probably the load path, bootsnap would help, but that's off topic]

    Joe Rafaniello
    @jrafanie
    Can you try with newer rubies? Eliminate console and pry: require config/environment in your script and run your one line script with ruby
    I'll try it later with malloc vs jemalloc
    Does anyone know what objects in ObjectSpace.count_objects parsed code gets stored in, ie RubyVM Instruction sequences
    It would also be interesting if the code manifested itself as a string duplicated several times
    Beni Cherniavsky-Paskin
    @cben
    2.4.1: same results (with pry). no time to play more now, will install 2.5 later.
    Joe Rafaniello
    @jrafanie
    @cben @NickLaMuro I tested ruby 2.3.6, 2.4.3 and 2.5.0 with and without rails loaded. Something crazy is definitely going on
    Note, this is on osx, doing my appliance next

    rails

    ruby -e "require './config/environment'; puts Process.pid; 1_000.times { 1_000.times { require './empty.rb' }; GC.start; STDOUT.write('.') }"

    2.5.0 143 MB (much slower and doesn't leak)
    2.4.3 800MB and rising and I killed it (faster than ruby 2.5.0)
    2.3.6 800MB and rising and I killed it (faster than ruby 2.5.0)

    just ruby

    ruby -e "puts Process.pid; 1_000.times { 1_000.times { require './empty.rb' }; GC.start; STDOUT.write('.') }"

    2.5.0 4.8 MB much much faster than rails require
    2.4.3 4.9 MB much much faster than rails require
    2.3.6 5.5 MB much much faster than rails require
    Nick LaMuro
    @NickLaMuro
    @jrafanie when you say "much faster", are you saying how much faster it takes to execute?
    Joe Rafaniello
    @jrafanie
    yes
    I can time a small number of iterations for comparison
    Keenan Brock
    @kbrock
    @jrafanie how much memory for ruby -e "require './config/environment'; puts Process.pid ; sleep(20)" ?
    Nick LaMuro
    @NickLaMuro
    that is interesting, because usually bundler makes require faster, because it removes the slowness that is added by rubygems's require patches
    Keenan Brock
    @kbrock
    hard to know if the require is increasing those 800MB or if it is rails
    Nick LaMuro
    @NickLaMuro
    about 120MB of that is probably just our app getting loaded
    most of my processes start at 140MB on my machine
    Keenan Brock
    @kbrock
    @NickLaMuro have you removed the relative require and seen if that helps our memory situation?
    comment suggests that it is only needed for eval and irb
    Nick LaMuro
    @NickLaMuro
    I have done my require patch on an appliance, going to get some recent graphs...
    Before
    20180114_25131.png
    After
    20180115_11482.png
    But... there is a caveat
    This is still the heavily commented out code, so we are not doing a lot other than MiqWorker.status_update_all and MiqServer.sync_workers
    so re enabling all of that code might show a different leak
    but this one in particular, clearly is better
    Joe Rafaniello
    @jrafanie
    @NickLaMuro here's a smaller number of iterations with timing and memory usage

    ruby2.3.6

    11:07:20 ~/Code/manageiq (master) (2.3.6) + time ruby -e "require './config/environment'; puts Process.pid; 300.times { 300.times { require './empty.rb' }; GC.start; STDOUT.write('.') }"
    ** Using session_store: ActionDispatch::Session::MemCacheStore
    92309
    ............................................................................................................................................................................................................................................................................................................
    ruby -e   31.34s user 2.95s system 97% cpu 35.186 total
    225 MB

    ruby2.4.3

    11:04:17 ~/Code/manageiq (master) (2.4.3) + time ruby -e "require './config/environment'; puts Process.pid; 300.times { 300.times { require './empty.rb' }; GC.start; STDOUT.write('.') }"
    ** Using session_store: ActionDispatch::Session::MemCacheStore
    92257
    ............................................................................................................................................................................................................................................................................................................
    ruby -e   29.05s user 2.56s system 99% cpu 31.734 total
    213 MB

    ruby2.5.0

    11:05:11 ~/Code/manageiq (master) (2.5.0) + time ruby -e "require './config/environment'; puts Process.pid; 300.times { 300.times { require './empty.rb' }; GC.start; STDOUT.write('.') }"
    ** Using session_store: ActionDispatch::Session::MemCacheStore
    92279
    ............................................................................................................................................................................................................................................................................................................
    ruby -e   43.60s user 15.68s system 99% cpu 59.491 total
    134 MB
    ruby 2.3 and 2.4 memory did not stabilize, it was still rising, whereas 2.5.0 reached ~130 MB and stayed in that area
    (ruby 2.5.0 is roughly twice as slow but doens't seem to leak)
    Nick LaMuro
    @NickLaMuro
    yeah, that does seem to make sense
    what I was noticing in the mem dumps was basically the same memory, and no real pointers into the user space code
    Joe Rafaniello
    @jrafanie
    I gotta look at something else right now but I was going to try vanilla rails versions next
    Nick LaMuro
    @NickLaMuro
    that would be a good test
    Joe Rafaniello
    @jrafanie
    and see if any rails versions have this problem... to eliminate us or them
    If anyone does that before me, let me know so I don't do it. I'll ping the room if I come back and start on that
    Nick LaMuro
    @NickLaMuro
    I would rather you do it since it would keep consistency with what you did on your machine
    I can compare everything again on my machine after, but I am currently looking into where this memory in the require is coming from
    Joe Rafaniello
    @jrafanie
    ok, cool
    will do
    Joe Rafaniello
    @jrafanie
    @NickLaMuro vanilla rails 5.0.6 application looks completely fine... 47-51 MB, very similar timing
    chruby 2.3; bundle > /dev/null;
    time ruby -e "require './config/environment'; puts Process.pid; 300.times { 300.times { require './empty.rb' }; GC.start; STDOUT.write('.') }";
    
    chruby 2.4; bundle > /dev/null;
    time ruby -e "require './config/environment'; puts Process.pid; 300.times { 300.times { require './empty.rb' }; GC.start; STDOUT.write('.') }";
    
    chruby 2.5; bundle > /dev/null;
    time ruby -e "require './config/environment'; puts Process.pid; 300.times { 300.times { require './empty.rb' }; GC.start; STDOUT.write('.') }";
    
    
    93679
    ............................................................................................................................................................................................................................................................................................................
    ruby -e   6.63s user 1.11s system 95% cpu 8.083 total
    93692
    ............................................................................................................................................................................................................................................................................................................
    ruby -e   6.06s user 1.04s system 96% cpu 7.347 total
    93705
    ............................................................................................................................................................................................................................................................................................................
    ruby -e   6.69s user 1.07s system 96% cpu 8.067 total
    Although pure ruby crushes it (4-5 MB)
    chruby 2.3; bundle > /dev/null;
    time ruby -e "puts Process.pid; 300.times { 300.times { require './empty.rb' }; GC.start; STDOUT.write('.') }";
    
    chruby 2.4; bundle > /dev/null;
    time ruby -e "puts Process.pid; 300.times { 300.times { require './empty.rb' }; GC.start; STDOUT.write('.') }";
    
    chruby 2.5; bundle > /dev/null;
    time ruby -e "puts Process.pid; 300.times { 300.times { require './empty.rb' }; GC.start; STDOUT.write('.') }";
    
    
    93732
    ............................................................................................................................................................................................................................................................................................................
    ruby -e   1.22s user 0.68s system 99% cpu 1.905 total
    93735
    ............................................................................................................................................................................................................................................................................................................
    ruby -e   1.09s user 0.66s system 99% cpu 1.764 total
    93738
    ............................................................................................................................................................................................................................................................................................................
    ruby -e   0.91s user 0.62s system 99% cpu 1.536 total
    Time to bisect $LOADED_FEATURES in our app