From d61515b9ce60e57f15399e384b2540a143c29414 Mon Sep 17 00:00:00 2001 From: Trey Pendragon Date: Tue, 6 Mar 2018 17:27:41 -0800 Subject: [PATCH 1/4] Initial Datadog Instrumentation. --- Gemfile | 5 +- app/adapters/instrumented_adapter.rb | 112 +++++++++++++++++++++ config/initializers/datadog.rb | 26 +++-- config/initializers/valkyrie.rb | 32 +++--- spec/adapters/instrumented_adapter_spec.rb | 49 +++++++++ 5 files changed, 192 insertions(+), 32 deletions(-) create mode 100644 app/adapters/instrumented_adapter.rb create mode 100644 spec/adapters/instrumented_adapter_spec.rb diff --git a/Gemfile b/Gemfile index f7673706d1..060dd1ca08 100644 --- a/Gemfile +++ b/Gemfile @@ -4,6 +4,7 @@ source "https://rubygems.org" gem "autoprefixer-rails" gem "blacklight" gem 'bunny' +gem 'ddtrace' gem "devise-guests", git: "https://github.com/cbeer/devise-guests.git" gem "flutie" gem "honeybadger" @@ -51,10 +52,6 @@ group :development, :staging do gem "rack-mini-profiler", require: false end -group :production do - gem 'ddtrace' -end - group :test do gem 'chromedriver-helper' gem "database_cleaner" diff --git a/app/adapters/instrumented_adapter.rb b/app/adapters/instrumented_adapter.rb new file mode 100644 index 0000000000..45d0fc7476 --- /dev/null +++ b/app/adapters/instrumented_adapter.rb @@ -0,0 +1,112 @@ +# frozen_string_literal: true +class InstrumentedAdapter < SimpleDelegator + attr_reader :metadata_adapter + delegate :query_service, :persister, :is_a?, :kind_of?, to: :metadata_adapter + def initialize(metadata_adapter:) + super(metadata_adapter) + @metadata_adapter = metadata_adapter + end + + def persister + @persister ||= InstrumentedPersister.new(persister: metadata_adapter.persister, instrumented_adapter: self) + end + + def query_service + @query_service ||= InstrumentedQueryService.new(query_service: metadata_adapter.query_service, instrumented_adapter: self) + end + + def tracer + @tracer ||= Datadog.tracer + end + + class InstrumentedService < SimpleDelegator + attr_reader :instrumented_adapter + delegate :metadata_adapter, to: :instrumented_adapter + delegate :tracer, to: :instrumented_adapter + def trace(span_name, resource_describer = method(:resource_to_string)) + tracer.trace(span_name) do |span| + span.service = "valkyrie-#{metadata_adapter.class}" + span.span_type = Datadog::Ext::AppTypes::DB + output = yield + span.resource = resource_describer.call(output) + output + end + end + + def resource_to_string(resources) + Array.wrap(resources).map { |resource| "#{resource.class}" }.join(", ") + end + end + class InstrumentedPersister < InstrumentedService + def initialize(persister:, instrumented_adapter:) + @instrumented_adapter = instrumented_adapter + super(persister) + end + + def save(resource:) + trace('valkyrie.save') do + __getobj__.save(resource: resource) + end + end + + def delete(resource:) + trace('valkyrie.delete', ->(_) { resource_to_string(resource) }) do + __getobj__.delete(resource: resource) + end + end + + def save_all(resources:) + trace('valkyrie.save_all') do + __getobj__.save_all(resources: resources) + end + end + end + class InstrumentedQueryService < InstrumentedService + def initialize(query_service:, instrumented_adapter:) + @instrumented_adapter = instrumented_adapter + super(query_service) + end + + def find_by(id:) + trace('valkyrie.find_by_id', ->(_resource) { id.to_s }) do + __getobj__.find_by(id: id) + end + end + + def find_all + trace('valkyrie.find_all', ->(_resource) {}) do + __getobj__.find_all + end + end + + def find_all_of_model(model:) + trace('valkyrie.find_all_of_model', ->(_) { model.to_s }) do + __getobj__.find_all_of_model(model: model) + end + end + + def find_members(resource:, model: nil) + trace('valkyrie.find_members', ->(_) { resource_to_string(resource) }) do + __getobj__.find_members(resource: resource, model: model) + end + end + + def find_parents(resource:) + trace('valkyrie.find_parents', ->(_) { resource_to_string(resource) }) do + __getobj__.find_parents(resource: resource) + end + end + + def find_references_by(resource:, property:) + trace('valkyrie.find_references_by', ->(_) { "#{resource_to_string(resource)} - #{property}" }) do + __getobj__.find_references_by(resource: resource, property: property) + end + end + + def find_inverse_references_by(resource:, property:) + trace('valkyrie.find_inverse_references_by', ->(_) { "#{resource_to_string(resource)} - #{property}" }) do + __getobj__.find_inverse_references_by(resource: resource, property: property) + end + end + end +end diff --git a/config/initializers/datadog.rb b/config/initializers/datadog.rb index e69672f91d..93e7cf307c 100644 --- a/config/initializers/datadog.rb +++ b/config/initializers/datadog.rb @@ -1,20 +1,18 @@ # frozen_string_literal: true -if Rails.env.production? - require 'ddtrace' - Datadog.configure do |c| - # Rails - c.use :rails +Datadog.configure do |c| + c.tracer(enabled: false) unless Rails.env.production? + # Rails + c.use :rails - # Redis - c.use :redis + # Redis + c.use :redis - # Net::HTTP - c.use :http + # Net::HTTP + c.use :http - # Sidekiq - c.use :sidekiq + # Sidekiq + c.use :sidekiq - # Faraday - c.use :faraday - end + # Faraday + c.use :faraday end diff --git a/config/initializers/valkyrie.rb b/config/initializers/valkyrie.rb index b0e68b69c5..d98ac49613 100644 --- a/config/initializers/valkyrie.rb +++ b/config/initializers/valkyrie.rb @@ -66,7 +66,9 @@ ) Valkyrie::MetadataAdapter.register( - Valkyrie::Persistence::Postgres::MetadataAdapter.new, + InstrumentedAdapter.new( + metadata_adapter: Valkyrie::Persistence::Postgres::MetadataAdapter.new + ), :postgres ) @@ -76,19 +78,21 @@ ) Valkyrie::MetadataAdapter.register( - Valkyrie::Persistence::Solr::MetadataAdapter.new( - connection: Blacklight.default_index.connection, - resource_indexer: CompositeIndexer.new( - Valkyrie::Indexers::AccessControlsIndexer, - CollectionIndexer, - EphemeraBoxIndexer, - EphemeraFolderIndexer, - MemberOfIndexer, - FacetIndexer, - ProjectIndexer, - HumanReadableTypeIndexer, - SortingIndexer, - ImportedMetadataIndexer + InstrumentedAdapter.new( + metadata_adapter: Valkyrie::Persistence::Solr::MetadataAdapter.new( + connection: Blacklight.default_index.connection, + resource_indexer: CompositeIndexer.new( + Valkyrie::Indexers::AccessControlsIndexer, + CollectionIndexer, + EphemeraBoxIndexer, + EphemeraFolderIndexer, + MemberOfIndexer, + FacetIndexer, + ProjectIndexer, + HumanReadableTypeIndexer, + SortingIndexer, + ImportedMetadataIndexer + ) ) ), :index_solr diff --git a/spec/adapters/instrumented_adapter_spec.rb b/spec/adapters/instrumented_adapter_spec.rb new file mode 100644 index 0000000000..065f49661d --- /dev/null +++ b/spec/adapters/instrumented_adapter_spec.rb @@ -0,0 +1,49 @@ +# frozen_string_literal: true +require 'rails_helper' +require 'valkyrie/specs/shared_specs' + +RSpec.describe InstrumentedAdapter do + let(:adapter) do + described_class.new(metadata_adapter: Valkyrie::MetadataAdapter.find(:indexing_persister)) + end + let(:query_service) { adapter.query_service } + let(:persister) { adapter.persister } + let(:index_solr) { Valkyrie::MetadataAdapter.find(:index_solr) } + let(:tracer) { object_double(Datadog.tracer) } + let(:span) { object_double(Datadog.tracer.trace("bla")) } + it_behaves_like "a Valkyrie::Persister" + + before do + allow(tracer).to receive(:trace).and_yield(span) + allow(Datadog).to receive(:tracer).and_return(tracer) + allow(span).to receive(:service=) + allow(span).to receive(:span_type=) + allow(span).to receive(:resource=) + end + describe "saving" do + it "instruments information to datadog" do + resource = ScannedResource.new + output = adapter.persister.save(resource: resource) + expect(tracer).to have_received(:trace).with("valkyrie.save") + expect(span).to have_received(:resource=).with("ScannedResource") + adapter.persister.save_all(resources: [output]) + adapter.query_service.find_by(id: output.id) + adapter.query_service.find_all + adapter.query_service.find_members(resource: resource) + adapter.query_service.find_parents(resource: resource) + adapter.query_service.find_references_by(resource: resource, property: :member_ids) + adapter.query_service.find_inverse_references_by(resource: resource, property: :member_ids) + adapter.query_service.find_all_of_model(model: resource.class) + adapter.persister.delete(resource: output) + expect(tracer).to have_received(:trace).with("valkyrie.save_all") + expect(tracer).to have_received(:trace).with("valkyrie.find_by_id") + expect(tracer).to have_received(:trace).with("valkyrie.delete") + expect(tracer).to have_received(:trace).with("valkyrie.find_all") + expect(tracer).to have_received(:trace).with("valkyrie.find_members") + expect(tracer).to have_received(:trace).with("valkyrie.find_parents") + expect(tracer).to have_received(:trace).with("valkyrie.find_references_by") + expect(tracer).to have_received(:trace).with("valkyrie.find_inverse_references_by") + expect(tracer).to have_received(:trace).with("valkyrie.find_all_of_model") + end + end +end From 93f136bfb9b9770b9fcc02b757d63bd92140cd7b Mon Sep 17 00:00:00 2001 From: Trey Pendragon Date: Thu, 8 Mar 2018 10:09:50 -0800 Subject: [PATCH 2/4] Improve instrumentation. --- app/adapters/instrumented_adapter.rb | 82 ++++++++++++++-------- config/initializers/valkyrie.rb | 6 +- spec/adapters/instrumented_adapter_spec.rb | 45 ++++++------ 3 files changed, 80 insertions(+), 53 deletions(-) diff --git a/app/adapters/instrumented_adapter.rb b/app/adapters/instrumented_adapter.rb index 45d0fc7476..792207cb41 100644 --- a/app/adapters/instrumented_adapter.rb +++ b/app/adapters/instrumented_adapter.rb @@ -1,10 +1,11 @@ # frozen_string_literal: true class InstrumentedAdapter < SimpleDelegator - attr_reader :metadata_adapter + attr_reader :metadata_adapter, :tracer delegate :query_service, :persister, :is_a?, :kind_of?, to: :metadata_adapter - def initialize(metadata_adapter:) + def initialize(metadata_adapter:, tracer:) super(metadata_adapter) @metadata_adapter = metadata_adapter + @tracer = tracer end def persister @@ -15,26 +16,22 @@ def query_service @query_service ||= InstrumentedQueryService.new(query_service: metadata_adapter.query_service, instrumented_adapter: self) end - def tracer - @tracer ||= Datadog.tracer - end - class InstrumentedService < SimpleDelegator attr_reader :instrumented_adapter delegate :metadata_adapter, to: :instrumented_adapter delegate :tracer, to: :instrumented_adapter - def trace(span_name, resource_describer = method(:resource_to_string)) + def trace(resource, _resource_describer = nil) tracer.trace(span_name) do |span| span.service = "valkyrie-#{metadata_adapter.class}" span.span_type = Datadog::Ext::AppTypes::DB - output = yield - span.resource = resource_describer.call(output) + output = yield(span) + span.resource = resource output end end - def resource_to_string(resources) - Array.wrap(resources).map { |resource| "#{resource.class}" }.join(", ") + def span_name + 'valkyrie.persist' end end class InstrumentedPersister < InstrumentedService @@ -44,20 +41,26 @@ def initialize(persister:, instrumented_adapter:) end def save(resource:) - trace('valkyrie.save') do - __getobj__.save(resource: resource) + trace('valkyrie.save') do |span| + __getobj__.save(resource: resource).tap do |output| + span.set_tag('param.resource', output.id.to_s) + end end end def delete(resource:) - trace('valkyrie.delete', ->(_) { resource_to_string(resource) }) do - __getobj__.delete(resource: resource) + trace('valkyrie.delete') do |span| + __getobj__.delete(resource: resource).tap do + span.set_tag('param.resource', resource.id.to_s) + end end end def save_all(resources:) - trace('valkyrie.save_all') do - __getobj__.save_all(resources: resources) + trace('valkyrie.save_all') do |span| + __getobj__.save_all(resources: resources).tap do |output| + span.set_tag('param.resources', output.map { |x| x.id.to_s }) + end end end end @@ -68,45 +71,64 @@ def initialize(query_service:, instrumented_adapter:) end def find_by(id:) - trace('valkyrie.find_by_id', ->(_resource) { id.to_s }) do - __getobj__.find_by(id: id) + trace('valkyrie.find_by_id') do |span| + __getobj__.find_by(id: id).tap do + span.set_tag('param.id', id.to_s) + end end end def find_all - trace('valkyrie.find_all', ->(_resource) {}) do + trace('valkyrie.find_all') do __getobj__.find_all end end def find_all_of_model(model:) - trace('valkyrie.find_all_of_model', ->(_) { model.to_s }) do - __getobj__.find_all_of_model(model: model) + trace('valkyrie.find_all_of_model') do |span| + __getobj__.find_all_of_model(model: model).tap do + span.set_tag('param.model', model.to_s) + end end end def find_members(resource:, model: nil) - trace('valkyrie.find_members', ->(_) { resource_to_string(resource) }) do - __getobj__.find_members(resource: resource, model: model) + trace('valkyrie.find_members') do |span| + __getobj__.find_members(resource: resource, model: model).tap do + span.set_tag('param.model', model.to_s) + span.set_tag('param.resource', resource.id.to_s) + end end end def find_parents(resource:) - trace('valkyrie.find_parents', ->(_) { resource_to_string(resource) }) do - __getobj__.find_parents(resource: resource) + trace('valkyrie.find_parents') do |span| + __getobj__.find_parents(resource: resource).tap do + span.set_tag('param.resource', resource.id.to_s) + end end end def find_references_by(resource:, property:) - trace('valkyrie.find_references_by', ->(_) { "#{resource_to_string(resource)} - #{property}" }) do - __getobj__.find_references_by(resource: resource, property: property) + trace('valkyrie.find_references_by') do |span| + __getobj__.find_references_by(resource: resource, property: property).tap do + span.set_tag('param.resource', resource.id.to_s) + span.set_tag('param.property', property.to_s) + end end end def find_inverse_references_by(resource:, property:) - trace('valkyrie.find_inverse_references_by', ->(_) { "#{resource_to_string(resource)} - #{property}" }) do - __getobj__.find_inverse_references_by(resource: resource, property: property) + trace('valkyrie.find_inverse_references_by') do |span| + __getobj__.find_inverse_references_by(resource: resource, property: property).tap do + span.set_tag('param.resource', resource.id.to_s) + span.set_tag('param.property', property.to_s) + end end end + + def span_name + 'valkyrie.query' + end end end diff --git a/config/initializers/valkyrie.rb b/config/initializers/valkyrie.rb index d98ac49613..2f9f0548e2 100644 --- a/config/initializers/valkyrie.rb +++ b/config/initializers/valkyrie.rb @@ -67,7 +67,8 @@ Valkyrie::MetadataAdapter.register( InstrumentedAdapter.new( - metadata_adapter: Valkyrie::Persistence::Postgres::MetadataAdapter.new + metadata_adapter: Valkyrie::Persistence::Postgres::MetadataAdapter.new, + tracer: Datadog.tracer ), :postgres ) @@ -93,7 +94,8 @@ SortingIndexer, ImportedMetadataIndexer ) - ) + ), + tracer: Datadog.tracer ), :index_solr ) diff --git a/spec/adapters/instrumented_adapter_spec.rb b/spec/adapters/instrumented_adapter_spec.rb index 065f49661d..d40ca9bf8f 100644 --- a/spec/adapters/instrumented_adapter_spec.rb +++ b/spec/adapters/instrumented_adapter_spec.rb @@ -4,28 +4,28 @@ RSpec.describe InstrumentedAdapter do let(:adapter) do - described_class.new(metadata_adapter: Valkyrie::MetadataAdapter.find(:indexing_persister)) + described_class.new(metadata_adapter: Valkyrie::MetadataAdapter.find(:indexing_persister), tracer: tracer) end let(:query_service) { adapter.query_service } let(:persister) { adapter.persister } let(:index_solr) { Valkyrie::MetadataAdapter.find(:index_solr) } - let(:tracer) { object_double(Datadog.tracer) } - let(:span) { object_double(Datadog.tracer.trace("bla")) } + let(:tracer) { Datadog.tracer } it_behaves_like "a Valkyrie::Persister" - before do - allow(tracer).to receive(:trace).and_yield(span) - allow(Datadog).to receive(:tracer).and_return(tracer) - allow(span).to receive(:service=) - allow(span).to receive(:span_type=) - allow(span).to receive(:resource=) - end describe "saving" do + let(:tracer) { tracer_stub } + let(:tracer_stub) { instance_double(Datadog::Tracer) } + let(:span) { instance_double(Datadog::Span) } + before do + allow(tracer).to receive(:trace).and_yield(span) + allow(span).to receive(:service=) + allow(span).to receive(:span_type=) + allow(span).to receive(:resource=) + allow(span).to receive(:set_tag) + end it "instruments information to datadog" do resource = ScannedResource.new output = adapter.persister.save(resource: resource) - expect(tracer).to have_received(:trace).with("valkyrie.save") - expect(span).to have_received(:resource=).with("ScannedResource") adapter.persister.save_all(resources: [output]) adapter.query_service.find_by(id: output.id) adapter.query_service.find_all @@ -35,15 +35,18 @@ adapter.query_service.find_inverse_references_by(resource: resource, property: :member_ids) adapter.query_service.find_all_of_model(model: resource.class) adapter.persister.delete(resource: output) - expect(tracer).to have_received(:trace).with("valkyrie.save_all") - expect(tracer).to have_received(:trace).with("valkyrie.find_by_id") - expect(tracer).to have_received(:trace).with("valkyrie.delete") - expect(tracer).to have_received(:trace).with("valkyrie.find_all") - expect(tracer).to have_received(:trace).with("valkyrie.find_members") - expect(tracer).to have_received(:trace).with("valkyrie.find_parents") - expect(tracer).to have_received(:trace).with("valkyrie.find_references_by") - expect(tracer).to have_received(:trace).with("valkyrie.find_inverse_references_by") - expect(tracer).to have_received(:trace).with("valkyrie.find_all_of_model") + expect(tracer).to have_received(:trace).with("valkyrie.query").exactly(7).times + expect(tracer).to have_received(:trace).with("valkyrie.persist").exactly(3).times + expect(span).to have_received(:resource=).with("valkyrie.save") + expect(span).to have_received(:resource=).with("valkyrie.save_all") + expect(span).to have_received(:resource=).with("valkyrie.find_by_id") + expect(span).to have_received(:resource=).with("valkyrie.delete") + expect(span).to have_received(:resource=).with("valkyrie.find_all") + expect(span).to have_received(:resource=).with("valkyrie.find_members") + expect(span).to have_received(:resource=).with("valkyrie.find_parents") + expect(span).to have_received(:resource=).with("valkyrie.find_references_by") + expect(span).to have_received(:resource=).with("valkyrie.find_inverse_references_by") + expect(span).to have_received(:resource=).with("valkyrie.find_all_of_model") end end end From ac63bd5276e6c9bd0e21908dc578b9bb086e5472 Mon Sep 17 00:00:00 2001 From: Trey Pendragon Date: Thu, 8 Mar 2018 10:29:13 -0800 Subject: [PATCH 3/4] Set resource earlier. --- app/adapters/instrumented_adapter.rb | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/app/adapters/instrumented_adapter.rb b/app/adapters/instrumented_adapter.rb index 792207cb41..d792c06fec 100644 --- a/app/adapters/instrumented_adapter.rb +++ b/app/adapters/instrumented_adapter.rb @@ -24,9 +24,8 @@ def trace(resource, _resource_describer = nil) tracer.trace(span_name) do |span| span.service = "valkyrie-#{metadata_adapter.class}" span.span_type = Datadog::Ext::AppTypes::DB - output = yield(span) span.resource = resource - output + yield(span) end end From 135047151c901a81ae143c4bdea1aa0b5e37f7c6 Mon Sep 17 00:00:00 2001 From: Trey Pendragon Date: Thu, 8 Mar 2018 11:26:08 -0800 Subject: [PATCH 4/4] Set metadata as early as possible. --- app/adapters/instrumented_adapter.rb | 41 ++++++++++++---------------- 1 file changed, 17 insertions(+), 24 deletions(-) diff --git a/app/adapters/instrumented_adapter.rb b/app/adapters/instrumented_adapter.rb index d792c06fec..9fca6ea94c 100644 --- a/app/adapters/instrumented_adapter.rb +++ b/app/adapters/instrumented_adapter.rb @@ -49,9 +49,8 @@ def save(resource:) def delete(resource:) trace('valkyrie.delete') do |span| - __getobj__.delete(resource: resource).tap do - span.set_tag('param.resource', resource.id.to_s) - end + span.set_tag('param.resource', resource.id.to_s) + __getobj__.delete(resource: resource) end end @@ -71,9 +70,8 @@ def initialize(query_service:, instrumented_adapter:) def find_by(id:) trace('valkyrie.find_by_id') do |span| - __getobj__.find_by(id: id).tap do - span.set_tag('param.id', id.to_s) - end + span.set_tag('param.id', id.to_s) + __getobj__.find_by(id: id) end end @@ -85,44 +83,39 @@ def find_all def find_all_of_model(model:) trace('valkyrie.find_all_of_model') do |span| - __getobj__.find_all_of_model(model: model).tap do - span.set_tag('param.model', model.to_s) - end + span.set_tag('param.model', model.to_s) + __getobj__.find_all_of_model(model: model) end end def find_members(resource:, model: nil) trace('valkyrie.find_members') do |span| - __getobj__.find_members(resource: resource, model: model).tap do - span.set_tag('param.model', model.to_s) - span.set_tag('param.resource', resource.id.to_s) - end + span.set_tag('param.model', model.to_s) + span.set_tag('param.resource', resource.id.to_s) + __getobj__.find_members(resource: resource, model: model) end end def find_parents(resource:) trace('valkyrie.find_parents') do |span| - __getobj__.find_parents(resource: resource).tap do - span.set_tag('param.resource', resource.id.to_s) - end + span.set_tag('param.resource', resource.id.to_s) + __getobj__.find_parents(resource: resource) end end def find_references_by(resource:, property:) trace('valkyrie.find_references_by') do |span| - __getobj__.find_references_by(resource: resource, property: property).tap do - span.set_tag('param.resource', resource.id.to_s) - span.set_tag('param.property', property.to_s) - end + span.set_tag('param.resource', resource.id.to_s) + span.set_tag('param.property', property.to_s) + __getobj__.find_references_by(resource: resource, property: property) end end def find_inverse_references_by(resource:, property:) trace('valkyrie.find_inverse_references_by') do |span| - __getobj__.find_inverse_references_by(resource: resource, property: property).tap do - span.set_tag('param.resource', resource.id.to_s) - span.set_tag('param.property', property.to_s) - end + span.set_tag('param.resource', resource.id.to_s) + span.set_tag('param.property', property.to_s) + __getobj__.find_inverse_references_by(resource: resource, property: property) end end