wlmcewen · August 23, 2016 04:29 · Dec 30, 2014 · Dec 29, 2014 · Dec 29, 2014
diff --git a/post.md → ...aky-sidekiq-applications-with-ruby-2.1.md b/post.md → ...aky-sidekiq-applications-with-ruby-2.1.md
diff --git a/post.md b/post.md
@@ -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.

diff --git a/post.md b/post.md
@@ -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.