v3: add metrics

Gemfile

@@ -37,6 +37,7 @@ gem 'customerio'
 
 group :test do
   gem 'rspec',         '~> 2.13'
+  gem 'rspec-its'
   gem 'factory_girl',  '~> 2.4.0'
   gem 'mocha',         '~> 0.12'
   gem 'database_cleaner', '~> 0.8.0'

Gemfile.lock

@@ -276,6 +276,9 @@ GEM
     rspec-core (2.99.2)
     rspec-expectations (2.99.2)
       diff-lcs (>= 1.1.3, < 2.0)
+    rspec-its (1.0.1)
+      rspec-core (>= 2.99.0.beta1)
+      rspec-expectations (>= 2.99.0.beta1)
     rspec-mocks (2.99.2)
     sidekiq (3.3.0)
       celluloid (>= 0.16.0)
@@ -362,6 +365,7 @@ DEPENDENCIES
   rb-fsevent (~> 0.9.1)
   rerun
   rspec (~> 2.13)
+  rspec-its
   s3!
   sentry-raven!
   simplecov

lib/travis/api/app.rb

@@ -122,7 +122,6 @@ module Travis::Api
         use Travis::Api::App::Middleware::Logging
         use Travis::Api::App::Middleware::ScopeCheck
         use Travis::Api::App::Middleware::UserAgentTracker
-        use Travis::Api::App::Middleware::Metriks
 
         # make sure this is below ScopeCheck so we have the token
         use Rack::Attack if Endpoint.production?
@@ -133,6 +132,9 @@ module Travis::Api
         # rewrite should come after V3 hook
         use Travis::Api::App::Middleware::Rewrite
 
+        # v3 has its own metriks
+        use Travis::Api::App::Middleware::Metriks
+
         SettingsEndpoint.subclass :env_vars
         if Travis.config.endpoints.ssh_key
           SingletonSettingsEndpoint.subclass :ssh_key

lib/travis/api/v3/metrics.rb

@@ -0,0 +1,103 @@
+require 'metriks'
+
+module Travis::API::V3
+  class Metrics
+    class MetriksTracker
+      def initialize(prefix: "api.v3")
+        @prefx = prefix
+      end
+
+      def time(name, duration)
+        ::Metriks.timer("#{@prefix}.#{name}").update(duration)
+      end
+
+      def mark(name)
+        ::Metriks.meter("#{@prefix}.#{name}").mark
+      end
+    end
+
+    class Processor
+      attr_reader :queue, :tracker
+
+      def initialize(queue_size: 1000, tracker: MetriksTracker.new)
+        @tracker = tracker
+        @queue   = queue_size ? ::SizedQueue.new(queue_size) : ::Queue.new
+      end
+
+      def create(**options)
+        Metrics.new(self, **options)
+      end
+
+      def start
+        Thread.new { loop { process(queue.pop) } }
+      end
+
+      def process(metrics)
+        metrics.process(tracker)
+      rescue Exception => e
+        $stderr.puts e.message, e.backtrace
+      end
+    end
+
+    def initialize(processor, time: Time.now)
+      @processor  = processor
+      @start_time = time
+      @name_after = nil
+      @ticks      = []
+      @success    = nil
+      @name       = "unknown".freeze
+    end
+
+    def tick(event, time: Time.now)
+      @ticks << [event, time]
+      self
+    end
+
+    def success(**options)
+      finish(true, **options)
+    end
+
+    def failure(**options)
+      finish(false, **options)
+    end
+
+    def name_after(factory)
+      @name       = nil
+      @name_after = factory
+      self
+    end
+
+    def finish(success, time: Time.now, status: nil)
+      @success  = !!success
+      @status   = status
+      @status ||= success ? 200 : 500
+      @end_time = time
+      @processor.queue << self
+      self
+    end
+
+    def name
+      @name ||= @name_after.name[/[^:]+::[^:]+$/].underscore.tr(?/.freeze, ?..freeze)
+    end
+
+    def process(tracker)
+      tracker.mark("status.#{@status}")
+
+      if @success
+        process_ticks(tracker)
+        tracker.time("#{name}.overall", @end_time - @start_time)
+        tracker.mark("#{name}.success")
+      else
+        tracker.mark("#{name}.failure")
+      end
+    end
+
+    def process_ticks(tracker)
+      start = @start_time
+      @ticks.each do |event, time|
+        tracker.time("#{name}.#{event}", time - start)
+        start = time
+      end
+    end
+  end
+end

lib/travis/api/v3/router.rb

@@ -1,30 +1,49 @@
 module Travis::API::V3
   class Router
     include Travis::API::V3
-    attr_accessor :routes
+    attr_accessor :routes, :metrics_processor
 
     def initialize(routes = Routes)
-      @routes = routes
+      @routes            = routes
+      @metrics_processor = Metrics::Processor.new
+
+      metrics_processor.start
       routes.draw_routes
     end
 
     def call(env)
       return service_index(env) if env['PATH_INFO'.freeze] == ?/.freeze
+      metrics         = @metrics_processor.create
       access_control  = AccessControl.new(env)
       factory, params = routes.factory_for(env['REQUEST_METHOD'.freeze], env['PATH_INFO'.freeze])
       env_params      = params(env)
 
       raise NotFound unless factory
+      metrics.name_after(factory)
 
-      filtered        = factory.filter_params(env_params)
-      service         = factory.new(access_control, filtered.merge(params))
-      result          = service.run
+      filtered = factory.filter_params(env_params)
+      service  = factory.new(access_control, filtered.merge(params))
+
+      metrics.tick(:prepare)
+      result   = service.run
+      metrics.tick(:service)
 
       env_params.each_key { |key| result.ignored_param(key, reason: "not whitelisted".freeze) unless filtered.include?(key) }
-      render(result, env_params, env)
+      response = render(result, env_params, env)
+
+      metrics.tick(:renderer)
+      metrics.success(status: response[0])
+      response
     rescue Error => error
-      result  = Result.new(access_control, :error, error)
-      V3.response(result.render(env_params, env), {}, status: error.status)
+      metrics.tick(:service)
+
+      result   = Result.new(access_control, :error, error)
+      response = V3.response(result.render(env_params, env), {}, status: error.status)
+
+      metrics.tick(:rendered)
+      metrics.failure(status: error.status)
+
+      response
     end
 
     def render(result, env_params, env)

spec/spec_helper.rb

@@ -3,6 +3,7 @@ ENV['RACK_ENV'] = ENV['RAILS_ENV'] = ENV['ENV'] = 'test'
 require 'support/coverage'
 
 require 'rspec'
+require 'rspec/its'
 require 'database_cleaner'
 require 'sinatra/test_helpers'
 require 'logger'

spec/v3/metrics_spec.rb

@@ -0,0 +1,42 @@
+require 'spec_helper'
+
+describe Travis::API::V3::Metrics do
+  class TestProcessor
+    attr_reader :times, :marks, :queue
+
+    def initialize
+      @queue = []
+      @times = []
+      @marks = []
+    end
+
+    def time(*args)
+      times << args
+    end
+
+    def mark(name)
+      marks << name
+    end
+  end
+
+  subject(:processor) { TestProcessor.new                                }
+  let(:metric)        { described_class.new(processor, time: Time.at(0)) }
+
+  before do
+    metric.name_after(Travis::API::V3::Services::Branch::Find)
+    metric.tick(:example,       time: Time.at(10))
+    metric.tick(:other_example, time: Time.at(15))
+    metric.success(time: Time.at(25))
+    metric.process(processor)
+  end
+
+  its(:queue) { should be == [metric] }
+
+  its(:times) { should be == [
+    ["branch.find.example",       10.0],
+    ["branch.find.other_example", 5.0],
+    ["branch.find.overall",       25.0]
+  ] }
+
+  its(:marks) { should be == ["status.200", "branch.find.success"] }
+end