new fun with integration testing, including it in the controller inst…

…rumentation

lib/new_relic/agent/instrumentation/controller_instrumentation.rb

@@ -375,28 +375,16 @@ def _record_queue_length
       end
     end
 
+    include NewRelic::Agent::Instrumentation::QueueTime
+
     # Return a Time instance representing the upstream start time.
     # now is a Time instance to fall back on if no other candidate
     # for the start time is found.
     def _detect_upstream_wait(now)
       if newrelic_request_headers
-        if entry_time = newrelic_request_headers['HTTP_X_REQUEST_START']
-          if newrelic_request_headers['HTTP_X_HEROKU_QUEUE_DEPTH'] # this is a heroku measure
-            http_entry_time = entry_time.to_f / 1e3
-          else # apache / nginx
-            apache_parsed_time = entry_time[/t=(\d+)/, 1]
-            http_entry_time = apache_parsed_time.to_f/1e6 if apache_parsed_time
-          end
-        end
-      end
-      # If we didn't find the custom header, look for the mongrel timestamp
-      http_entry_time ||= Thread.current[:started_on] and http_entry_time = http_entry_time.to_f
-      if http_entry_time
-        queue_stat = NewRelic::Agent.agent.stats_engine.get_stats_no_scope 'WebFrontend/Mongrel/Average Queue Time'
-        total_time = (now - http_entry_time)
-        queue_stat.trace_call(total_time.to_f) unless total_time.to_f <= 0.0 # using remote timestamps could lead to negative queue time
+        parse_frontend_headers(newrelic_request_headers)
       end
-      return http_entry_time ? Time.at(http_entry_time) : now
+      now
     end
 
     def _dispatch_stat

lib/new_relic/agent/instrumentation/queue_time.rb

@@ -22,7 +22,8 @@ def current_time
           Time.now
         end
 
-        def parse_frontend_headers(env)
+        def parse_frontend_headers(headers)
+          env = headers.dup
           add_end_time_header(current_time, env)
           parse_middleware_time_from(env)
           parse_queue_time_from(env)
@@ -167,6 +168,7 @@ def record_time_stat(name, start_time, end_time) # (String, Time, Time) -> nil
         end
 
         def add_end_time_header(end_time, env) # (Time, Env) -> nil
+          return unless end_time
           env[APP_HEADER] = "t=#{convert_to_microseconds(end_time)}"
         end
 

test/new_relic/agent/agent_controller_test.rb

@@ -61,14 +61,55 @@ def test_mongrel_queue
 
   def test_heroku_queue
     engine.clear_stats
-    NewRelic::Control.instance.local_env.stubs(:mongrel).returns( stub('mongrel', :workers => stub('workers', :list => stub('list', :length => '10'))))
     NewRelic::Agent::AgentTestController.set_some_headers 'HTTP_X_HEROKU_QUEUE_DEPTH'=>'15'
     get :index
     assert_equal 1, stats('HttpDispatcher').call_count
     assert_equal 1, engine.get_stats_no_scope('Mongrel/Queue Length').call_count
     assert_equal 15, engine.get_stats_no_scope('Mongrel/Queue Length').total_call_time
     assert_equal 0, engine.get_stats_no_scope('WebFrontend/Mongrel/Average Queue Time').call_count
   end
+
+  def test_new_queue_integration
+    engine.clear_stats
+    start = ((Time.now - 1).to_f * 1_000_000).to_i
+    NewRelic::Agent::AgentTestController.set_some_headers 'HTTP_X_QUEUE_START'=> "t=#{start}"
+    get :index
+
+    check_metric_time('WebFrontend/QueueTime', 1, 0.1)
+  end
+
+
+  def test_new_middleware_integration
+    engine.clear_stats
+    start = ((Time.now - 1).to_f * 1_000_000).to_i
+    NewRelic::Agent::AgentTestController.set_some_headers 'HTTP_X_MIDDLEWARE_START'=> "t=#{start}"
+    get :index
+
+    check_metric_time('Middleware/all', 1, 0.1)
+  end
+
+  def test_new_server_time_integration
+    engine.clear_stats
+    start = ((Time.now - 1).to_f * 1_000_000).to_i
+    NewRelic::Agent::AgentTestController.set_some_headers 'HTTP_X_REQUEST_START'=> "t=#{start}"
+    get :index
+
+    check_metric_time('WebFrontend/WebServer/all', 1, 0.1)
+  end
+
+  def test_new_frontend_work_integration
+    engine.clear_stats
+    times = [Time.now - 3, Time.now - 2, Time.now - 1]
+    times.map! {|t| (t.to_f * 1_000_000).to_i }
+    NewRelic::Agent::AgentTestController.set_some_headers({
+                                                            'HTTP_X_SERVER_START'=> "t=#{times[0]}", 'HTTP_X_QUEUE_START' => "t=#{times[1]}", 'HTTP_X_MIDDLEWARE_START' => "t=#{times[2]}"})
+    get :index
+
+
+    check_metric_time('WebFrontend/WebServer/all', 1, 0.1)
+    check_metric_time('Middleware/all', 1, 0.1)
+    check_metric_time('WebFrontend/QueueTime', 1, 0.1)    
+  end
 
   def test_render_inline
     engine.clear_stats