Merge pull request #2958 from zendesk/grosser/traced

make scope tracing less overhead and use hooks to do it

lib/samson/hooks.rb

@@ -59,9 +59,25 @@ class UserError < StandardError
       :stage_clone,
       :stage_permitted_params,
       :trace_method,
+      :trace_scope,
       :asynchronous_performance_tracer
     ].freeze
 
+    # Hooks that are slow and we want performance info on
+    TRACED = [
+      :after_deploy,
+      :after_deploy_setup,
+      :after_docker_build,
+      :after_job_execution,
+      :before_deploy,
+      :before_docker_build,
+      :before_docker_repository_usage,
+      :ensure_build_is_successful,
+      :ref_status,
+      :stage_clone
+    ].freeze
+    (TRACED & EVENT_HOOKS).sort == TRACED.sort || raise("Unknown hook in traced")
+
     KNOWN = VIEW_HOOKS + EVENT_HOOKS
 
     @hooks = Hash.new { |h, k| h[k] = [] }
@@ -166,9 +182,7 @@ def only_callbacks_for_plugin(plugin_name, hook_name)
 
       # use
       def fire(name, *args)
-        Samson::PerformanceTracer.trace_execution_scoped("Custom/Hooks/#{name}") do
-          hooks(name).map { |hook| hook.call(*args) }
-        end
+        traced(name) { hooks(name).map { |hook| hook.call(*args) } }
       end
 
       def render_views(name, view, *args)
@@ -223,6 +237,14 @@ def render_stylesheets(view)
 
       private
 
+      def traced(name, &block)
+        if TRACED.include?(name)
+          Samson::PerformanceTracer.trace_execution_scoped("Custom/Hooks/#{name}", &block)
+        else
+          yield
+        end
+      end
+
       def render_assets(view, folder, file, method)
         Samson::Hooks.plugins.each do |plugin|
           full_file = plugin.engine.config.root.join("app/assets/#{folder}/#{plugin.name}/#{file}")

lib/samson/performance_tracer.rb

@@ -2,13 +2,9 @@
 module Samson
   module PerformanceTracer
     class << self
-      # NOTE: this cannot be a hook since it is used from Hooks#fire
-      def handlers
-        @handlers ||= []
-      end
-
-      def trace_execution_scoped(scope_name, &block)
-        handlers.inject(block) { |inner, plugin| -> { plugin.trace_execution_scoped(scope_name, &inner) } }.call
+      def trace_execution_scoped(scope, &block)
+        tracers = Samson::Hooks.fire(:trace_scope, scope).compact
+        tracers.inject(block) { |inner, tracer| -> { tracer.call(&inner) } }.call
       end
     end
 

plugins/datadog_tracer/lib/samson_datadog_tracer/samson_plugin.rb

@@ -8,14 +8,6 @@ def enabled?
       !!ENV['DATADOG_TRACER']
     end
 
-    def trace_execution_scoped(scope_name, &block)
-      if enabled?
-        Datadog.tracer.trace("Custom/Hooks/#{scope_name}", &block)
-      else
-        yield
-      end
-    end
-
     # We are not using super to make running newrelic (which uses alias) and datadog possible
     def trace_method(klass, method)
       wrap_method klass, method, "apm_tracer" do |&block|
@@ -51,8 +43,11 @@ def method_visibility(klass, method)
   end
 end
 
-require 'samson/performance_tracer'
-Samson::PerformanceTracer.handlers << SamsonDatadogTracer
+Samson::Hooks.callback :trace_scope do |scope|
+  if SamsonDatadogTracer.enabled?
+    ->(&block) { Datadog.tracer.trace("Custom/Hooks/#{scope}", &block) }
+  end
+end
 
 Samson::Hooks.callback :trace_method do |klass, method|
   if SamsonDatadogTracer.enabled?

plugins/datadog_tracer/test/samson_datadog_tracer/samson_plugin_test.rb

@@ -24,23 +24,6 @@ def self.trace(*)
     end
   end
 
-  describe ".trace_method_execution_scope" do
-    with_env DATADOG_TRACER: '1'
-
-    it "skips tracer when disabled" do
-      with_env DATADOG_TRACER: nil do
-        Datadog.expects(:tracer).never
-        SamsonDatadogTracer.trace_execution_scoped("test") { "without tracer" }
-      end
-    end
-
-    it "trigger tracer when enabled" do
-      Rails.stubs(:env).returns("staging")
-      Datadog.expects(:tracer).returns(fake_tracer)
-      SamsonDatadogTracer.trace_execution_scoped("test") { "with tracer" }
-    end
-  end
-
   describe ".trace_method" do
     let(:instance) do
       Class.new do
@@ -115,7 +98,6 @@ def pri_method
   describe "trace_method hook" do
     it "triggers Datadog tracer method when enabled" do
       with_env DATADOG_TRACER: "1" do
-        Datadog.expects(:tracer).returns(fake_tracer) # hook fire triggers tracing too
         SamsonDatadogTracer.expects(:trace_method)
         Samson::Hooks.fire :trace_method, User, :foobar
       end
@@ -126,4 +108,18 @@ def pri_method
       Samson::Hooks.fire :trace_method, User, :foobar
     end
   end
+
+  describe "trace_scope hook" do
+    it "skips tracer when disabled" do
+      Datadog.expects(:tracer).never
+      Samson::PerformanceTracer.trace_execution_scoped(:foo) { 1 }.must_equal 1
+    end
+
+    it "trigger tracer when enabled" do
+      with_env DATADOG_TRACER: "1" do
+        Datadog.expects(:tracer).returns(fake_tracer)
+        Samson::PerformanceTracer.trace_execution_scoped(:foo) { 1 }.must_equal 1
+      end
+    end
+  end
 end

plugins/new_relic/lib/samson_new_relic/samson_plugin.rb

@@ -32,23 +32,13 @@ def self.tracer_enabled?
     !!ENV['NEW_RELIC_LICENSE_KEY'] # same key as the newrelic_rpm gem uses
   end
 
-  def self.trace_execution_scoped(scope_name, &block)
-    if tracer_enabled?
-      NewRelic::Agent::MethodTracerHelpers.trace_execution_scoped("Custom/Hooks/#{scope_name}", &block)
-    else
-      yield
-    end
-  end
-
   def self.include_once(klass, mod)
     klass.include mod unless klass.include?(mod)
   end
 end
 
 # Railties need to be loaded before the application is initialized
 SamsonNewRelic.setup_initializers
-require 'samson/performance_tracer'
-Samson::PerformanceTracer.handlers << SamsonNewRelic
 
 Samson::Hooks.view :stage_form, "samson_new_relic/fields"
 Samson::Hooks.view :deploy_tab_nav, "samson_new_relic/deploy_tab_nav"
@@ -72,6 +62,12 @@ def self.include_once(klass, mod)
   end
 end
 
+Samson::Hooks.callback :trace_scope do |scope|
+  if SamsonNewRelic.tracer_enabled?
+    ->(&block) { NewRelic::Agent::MethodTracerHelpers.trace_execution_scoped("Custom/Hooks/#{scope}", &block) }
+  end
+end
+
 Samson::Hooks.callback :asynchronous_performance_tracer do |klass, method, options|
   if SamsonNewRelic.tracer_enabled?
     SamsonNewRelic.include_once klass, ::NewRelic::Agent::Instrumentation::ControllerInstrumentation

plugins/new_relic/test/samson_new_relic/samson_plugin_test.rb

@@ -50,26 +50,6 @@
     end
   end
 
-  describe ".trace_method_execution_scope" do
-    it "skips method trace when tracer disabled" do
-      NewRelic::Agent::MethodTracerHelpers.expects(:trace_execution_scoped).never
-      SamsonNewRelic.trace_execution_scoped("test") { "without tracer" }
-    end
-
-    it "trace execution scope when enabled" do
-      with_env NEW_RELIC_LICENSE_KEY: "1" do
-        NewRelic::Agent::MethodTracerHelpers.expects(:trace_execution_scoped)
-        SamsonNewRelic.trace_execution_scoped("test") { "with tracer" }
-      end
-    end
-
-    it "trace scope and returns execution result" do
-      with_env NEW_RELIC_LICENSE_KEY: "1" do
-        SamsonNewRelic.trace_execution_scoped("test") { "with tracer" }.must_equal("with tracer")
-      end
-    end
-  end
-
   describe ".find_api_key" do
     it "finds no key" do
       SamsonNewRelic.find_api_key.must_be_nil
@@ -144,7 +124,7 @@ def with_role
     end
   end
 
-  describe "#asynchronous_performance_tracer" do
+  describe "asynchronous_performance_tracer hook" do
     it "triggers asynchronous tracer when enabled" do
       with_env NEW_RELIC_LICENSE_KEY: "1" do
         Klass.expects(:add_transaction_tracer)
@@ -159,4 +139,18 @@ def with_role
       end
     end
   end
+
+  describe ".trace_method_execution_scope" do
+    it "skips method trace when tracer disabled" do
+      NewRelic::Agent::MethodTracerHelpers.expects(:trace_execution_scoped).never
+      Samson::PerformanceTracer.trace_execution_scoped(:foo) { 1 }.must_equal 1
+    end
+
+    it "trace execution scope when enabled" do
+      with_env NEW_RELIC_LICENSE_KEY: "1" do
+        NewRelic::Agent::MethodTracerHelpers.expects(:trace_execution_scoped).returns(2)
+        Samson::PerformanceTracer.trace_execution_scoped(:foo) { 1 }.must_equal 2
+      end
+    end
+  end
 end

test/lib/samson/hooks_test.rb

@@ -125,4 +125,16 @@ def hooks
       assert html.html_safe?
     end
   end
+
+  describe ".traced" do
+    it "traces when using a traced hook" do
+      Samson::PerformanceTracer.expects(:trace_execution_scoped).yields
+      Samson::Hooks.send(:traced, :after_deploy) { 1 }
+    end
+
+    it "traces when using a traced hook" do
+      Samson::PerformanceTracer.expects(:trace_execution_scoped).never
+      Samson::Hooks.send(:traced, :deploy_group_permitted_params) { 1 }.must_equal 1
+    end
+  end
 end

test/lib/samson/performance_tracer_test.rb

@@ -19,38 +19,32 @@ def pub_method2
   end
 
   describe '.trace_execution_scoped' do
-    let(:custom_tracer) do
-      Class.new do
-        def self.order
-          @order ||= []
-        end
-
-        def self.trace_execution_scoped(scope)
-          order << scope
-          yield
-        ensure
-          order << :after
-        end
-      end
-    end
-
     it 'calls all tracers' do
       SamsonDatadogTracer.expects(:enabled?)
       SamsonNewRelic.expects(:tracer_enabled?)
       Samson::PerformanceTracer.trace_execution_scoped('test_scope') { :scoped }.must_equal :scoped
     end
 
     it "calls tracer in correct order" do
-      begin
-        Samson::PerformanceTracer.handlers << custom_tracer
+      order = []
+      tracer = ->(scope) do
+        ->(&block) do
+          order << :before
+          order << scope
+          result = block.call
+          order << :after
+          result
+        end
+      end
+
+      Samson::Hooks.with_callback :trace_scope, tracer do
         Samson::PerformanceTracer.trace_execution_scoped('test_scope') do
-          custom_tracer.order << :inner
+          order << :inner
           :scoped
-        end.must_equal :scoped
-        custom_tracer.order.must_equal ['test_scope', :inner, :after]
-      ensure
-        Samson::PerformanceTracer.handlers.pop
-      end
+        end
+      end.must_equal :scoped
+
+      order.must_equal [:before, 'test_scope', :inner, :after]
     end
   end