Skip to content

Instantly share code, notes, and snippets.

Show Gist options
  • Save rda1902/5d4cfb6265fd9da8034646c59b48e37a to your computer and use it in GitHub Desktop.
Save rda1902/5d4cfb6265fd9da8034646c59b48e37a to your computer and use it in GitHub Desktop.

Revisions

  1. @krasnoukhov krasnoukhov renamed this gist Dec 30, 2014. 1 changed file with 0 additions and 0 deletions.
  2. @krasnoukhov krasnoukhov revised this gist Dec 29, 2014. 1 changed file with 0 additions and 7 deletions.
    7 changes: 0 additions & 7 deletions post.md
    Original file line number Diff line number Diff line change
    @@ -1,10 +1,3 @@
    ---
    layout: post
    title: Profiling memory leaky Sidekiq applications with Ruby 2.1
    date: 2013-01-07 18:00:00
    categories: posts
    ---

    My largest Sidekiq application had a memory leak and I was able to find and fix it in just few hours spent on analyzing Ruby's heap. In this post I'll show my profiling setup.

    As you might know Ruby 2.1 introduced a few great changes to [ObjectSpace](https://github.com/ruby/ruby/blob/v2_1_0/NEWS#L197), so now it's much easier to find a line of code that is allocating too many objects. Here is great [post](http://tmm1.net/ruby21-objspace/) explaining how it's working.
  3. @krasnoukhov krasnoukhov created this gist Dec 29, 2014.
    107 changes: 107 additions & 0 deletions post.md
    Original file line number Diff line number Diff line change
    @@ -0,0 +1,107 @@
    ---
    layout: post
    title: Profiling memory leaky Sidekiq applications with Ruby 2.1
    date: 2013-01-07 18:00:00
    categories: posts
    ---

    My largest Sidekiq application had a memory leak and I was able to find and fix it in just few hours spent on analyzing Ruby's heap. In this post I'll show my profiling setup.

    As you might know Ruby 2.1 introduced a few great changes to [ObjectSpace](https://github.com/ruby/ruby/blob/v2_1_0/NEWS#L197), so now it's much easier to find a line of code that is allocating too many objects. Here is great [post](http://tmm1.net/ruby21-objspace/) explaining how it's working.

    I was too lazy to set up some seeding and run it locally, so I checked that test suite passes when profiling is enabled and pushed debugging to production. Production environment also suited me better since my jobs data can't be fully random generated.

    So, in order to profile your worker, add this to your Sidekiq configuration:

    ```ruby
    if ENV["PROFILE"]
    require "objspace"
    ObjectSpace.trace_object_allocations_start
    Sidekiq.logger.info "allocations tracing enabled"

    module Sidekiq
    module Middleware
    module Server
    class Profiler
    # Number of jobs to process before reporting
    JOBS = 100

    class << self
    mattr_accessor :counter
    self.counter = 0

    def synchronize(&block)
    @lock ||= Mutex.new
    @lock.synchronize(&block)
    end
    end

    def call(worker_instance, item, queue)
    begin
    yield
    ensure
    self.class.synchronize do
    self.class.counter += 1

    if self.class.counter % JOBS == 0
    Sidekiq.logger.info "reporting allocations after #{self.class.counter} jobs"
    GC.start
    ObjectSpace.dump_all(output: File.open("heap.json", "w"))
    Sidekiq.logger.info "heap saved to heap.json"
    end
    end
    end
    end
    end
    end
    end
    end

    Sidekiq.configure_server do |config|
    config.server_middleware do |chain|
    chain.add Sidekiq::Middleware::Server::Profiler
    end
    end
    end
    ```

    Adjust number of jobs you want your worker to process before you have heap dumped.
    Run a sample worker: ```PROFILE=1 sidekiq -C config/sidekiq.yml``` and wait for jobs to be processed.

    After you have ```heap.json```, analyze it by running something like this:

    ```bash
    cat heap.json |
    ruby -rjson -ne ' obj = JSON.parse($_).values_at("file","line","type"); puts obj.join(":") if obj.first ' |
    sort |
    uniq -c |
    sort -n |
    tail -20
    ```

    You'll see a list of objects of specific types that are allocated on specific lines, sorted by objects count, for example:

    ```bash
    460 /home/whatever/.rvm/gems/ruby-2.1.0/bundler/gems/mongoid-3.1.6/lib/mongoid/dirty.rb:368:DATA
    460 /home/whatever/.rvm/gems/ruby-2.1.0/bundler/gems/mongoid-3.1.6/lib/mongoid/fields.rb:388:DATA
    460 /home/whatever/.rvm/gems/ruby-2.1.0/bundler/gems/mongoid-3.1.6/lib/mongoid/fields.rb:414:DATA
    460 /home/whatever/.rvm/gems/ruby-2.1.0/bundler/gems/mongoid-3.1.6/lib/mongoid/fields.rb:436:DATA
    460 /home/whatever/.rvm/gems/ruby-2.1.0/bundler/gems/mongoid-3.1.6/lib/mongoid/fields.rb:456:DATA
    472 /home/whatever/.rvm/gems/ruby-2.1.0/gems/activesupport-3.2.16/lib/active_support/concern.rb:115:ICLASS
    527 /home/whatever/.rvm/gems/ruby-2.1.0/gems/activesupport-3.2.16/lib/active_support/dependencies.rb:469:NODE
    529 /home/whatever/.rvm/gems/ruby-2.1.0/gems/activesupport-3.2.16/lib/active_support/core_ext/class/attribute.rb:79:NODE
    573 /home/whatever/.rvm/gems/ruby-2.1.0/gems/activesupport-3.2.16/lib/active_support/core_ext/array/wrap.rb:41:ARRAY
    606 /home/whatever/.rvm/gems/ruby-2.1.0/gems/activesupport-3.2.16/lib/active_support/dependencies.rb:469:ARRAY
    724 /home/whatever/.rvm/gems/ruby-2.1.0/gems/activesupport-3.2.16/lib/active_support/concern.rb:114:ICLASS
    844 /home/whatever/.rvm/gems/ruby-2.1.0/gems/journey-1.0.4/lib/journey/parser.rb:139:OBJECT
    861 /home/whatever/.rvm/gems/ruby-2.1.0/gems/activesupport-3.2.16/lib/active_support/dependencies.rb:469:DATA
    1147 /home/whatever/.rvm/gems/ruby-2.1.0/gems/activesupport-3.2.16/lib/active_support/dependencies.rb:469:STRING
    1165 /home/whatever/.rvm/gems/ruby-2.1.0/bundler/gems/mongoid-3.1.6/lib/mongoid/extensions/module.rb:22:STRING
    1242 /home/whatever/.rvm/gems/ruby-2.1.0/gems/activesupport-3.2.16/lib/active_support/core_ext/class/attribute.rb:74:ARRAY
    1281 /home/whatever/.rvm/gems/ruby-2.1.0/gems/activesupport-3.2.16/lib/active_support/core_ext/class/attribute.rb:81:DATA
    2083 /home/whatever/.rvm/gems/ruby-2.1.0/gems/activesupport-3.2.16/lib/active_support/core_ext/class/attribute.rb:74:NODE
    2429 /home/whatever/.rvm/gems/ruby-2.1.0/bundler/gems/mongoid-3.1.6/lib/mongoid/extensions/module.rb:22:DATA
    3325 /home/whatever/.rvm/gems/ruby-2.1.0/gems/activesupport-3.2.16/lib/active_support/core_ext/class/attribute.rb:74:DATA
    ```

    Repeat this action after more jobs are processed. If you see a constantly growing objects count somewhere, this is probably your leak.