diff --git a/Gemfile b/Gemfile index e50f9b90..9893ebf5 100644 --- a/Gemfile +++ b/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' diff --git a/Gemfile.lock b/Gemfile.lock index 8c981f56..09ee17b3 100644 --- a/Gemfile.lock +++ b/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 diff --git a/lib/travis/api/app.rb b/lib/travis/api/app.rb index a2763fdd..edc64310 100644 --- a/lib/travis/api/app.rb +++ b/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 diff --git a/lib/travis/api/v3/metrics.rb b/lib/travis/api/v3/metrics.rb new file mode 100644 index 00000000..6bf1bd3a --- /dev/null +++ b/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 diff --git a/lib/travis/api/v3/router.rb b/lib/travis/api/v3/router.rb index 8e39fc15..573c7c85 100644 --- a/lib/travis/api/v3/router.rb +++ b/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) diff --git a/spec/spec_helper.rb b/spec/spec_helper.rb index ced5e7af..5161936e 100644 --- a/spec/spec_helper.rb +++ b/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' diff --git a/spec/v3/metrics_spec.rb b/spec/v3/metrics_spec.rb new file mode 100644 index 00000000..a5afe054 --- /dev/null +++ b/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