Debug mode with histogram of collector blocks runtime

CHANGELOG.md

@@ -10,6 +10,12 @@ and this project adheres to [Semantic Versioning](http://semver.org/spec/v2.0.0.
 ### Added
 
 - Ability to pass a block to `Yabeda::Histogram#measure` to automatically measure its runtime in seconds using [monotonic time](https://blog.dnsimple.com/2018/03/elapsed-time-with-ruby-the-right-way/).
+- Debug mode that will enable some additional metrics to help debug performance issues with your usage of Yabeda (or Yabeda itself). Use environment variable `YABEDA_DEBUG` to enable it or call `Yabeda.debug!`.
+- Debugging histogram `yabeda_collect_duration` that measures duration of every collect block, as they are used for collecting metrics of application state and usually makes some potentially slow queries to databases, network requests, etc.
+
+### Changed
+
+- Adapters now should use method `Yabeda.collect!` instead of manual calling of every collector block. 
 
 ## 0.9.0 - 2021-05-07
 

README.md

@@ -147,6 +147,20 @@ These are developed and maintained by other awesome folks:
  - [yabeda-gc](https://github.com/ianks/yabeda-gc) — metrics for Ruby garbage collection.
  - _…and more! You can write your own adapter and open a pull request to add it into this list._
 
+## Configuration
+
+Configuration is handled by [anyway_config] gem. With it you can load settings from environment variables (which names are constructed from config key upcased and prefixed with `YABEDA_`), YAML files, and other sources. See [anyway_config] docs for details.
+
+Config key | Type     | Default | Description |
+---------- | -------- | ------- | ----------- |
+`debug`    | boolean  | `false` | Collects metrics measuring Yabeda performance |
+
+## Debugging metrics
+
+ - Time of collector block run: `yabeda_collect_duration` (segmented by block source location). Collector blocks are used for collecting metrics of application state and usually makes some potentially slow queries to databases, network requests, etc.
+
+These are only enabled in debug mode. To enable it either set `debug` config key to `true` (e.g. by specifying `YABEDA_DEBUG=true` in your environment variables or executing `Yabeda.debug!` in your code).
+
 ## Roadmap (aka TODO or Help wanted)
 
  - Ability to change metric settings for individual adapters
@@ -220,3 +234,4 @@ The gem is available as open source under the terms of the [MIT License](https:/
 [yabeda-puma-plugin]: https://github.com/yabeda-rb/yabeda-puma-plugin/ "Collects Puma web-server metrics from puma control application"
 [yabeda-http_requests]: https://github.com/yabeda-rb/yabeda-http_requests/ "Builtin metrics to monitor external HTTP requests"
 [yabeda-schked]: https://github.com/yabeda-rb/yabeda-schked/ "Built-in metrics for monitoring Schked recurring jobs out of the box"
+[anyway_config]: https://github.com/palkan/anyway_config "Configuration library for Ruby gems and applications"

lib/yabeda.rb

@@ -1,8 +1,10 @@
 # frozen_string_literal: true
 
 require "concurrent"
+require "forwardable"
 
 require "yabeda/version"
+require "yabeda/config"
 require "yabeda/dsl"
 require "yabeda/tags"
 require "yabeda/errors"
@@ -13,6 +15,8 @@ module Yabeda
   include DSL
 
   class << self
+    extend Forwardable
+
     # @return [Hash<String, Yabeda::Metric>] All registered metrics
     def metrics
       @metrics ||= Concurrent::Hash.new
@@ -35,6 +39,25 @@ def collectors
       @collectors ||= Concurrent::Array.new
     end
 
+    def config
+      @config ||= Config.new
+    end
+
+    def_delegators :config, :debug?
+
+    # Execute all collector blocks for periodical retrieval of metrics
+    #
+    # This method is intended to be used by monitoring systems adapters
+    def collect!
+      collectors.each do |collector|
+        if config.debug?
+          yabeda.collect_duration.measure({ location: collector.source_location.join(":") }, &collector)
+        else
+          collector.call
+        end
+      end
+    end
+
     # @return [Hash<Symbol, Symbol>] All added global default tags
     def default_tags
       @default_tags ||= Concurrent::Hash.new
@@ -67,6 +90,8 @@ def configured?
     def configure!
       raise(AlreadyConfiguredError, @configured_by) if already_configured?
 
+      debug! if config.debug?
+
       configurators.each do |(group, block)|
         group group
         class_eval(&block)
@@ -83,6 +108,24 @@ def configure!
 
       @configured_by = caller_locations(1, 1)[0].to_s
     end
+
+    # Enable and setup service metrics to monitor yabeda performance
+    def debug!
+      return false if @debug_was_enabled_by # Prevent multiple calls
+
+      config.debug ||= true # Enable debug mode in config if it wasn't enabled from other sources
+      @debug_was_enabled_by = caller_locations(1, 1)[0].to_s
+
+      configure do
+        group :yabeda
+
+        histogram :collect_duration,
+                  tags: %i[location], unit: :seconds,
+                  buckets: [0.0001, 0.001, 0.005, 0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1, 2.5, 5, 10, 30, 60].freeze,
+                  comment: "A histogram for the time required to evaluate collect blocks"
+      end
+      true
+    end
     # rubocop: enable Metrics/MethodLength, Metrics/AbcSize
 
     # Forget all the configuration.
@@ -99,6 +142,7 @@ def reset!
       collectors.clear
       configurators.clear
       instance_variable_set(:@configured_by, nil)
+      instance_variable_set(:@debug_was_enabled_by, nil)
     end
     # rubocop: enable Metrics/AbcSize
   end

lib/yabeda/config.rb

@@ -0,0 +1,13 @@
+# frozen_string_literal: true
+
+require "anyway"
+
+module Yabeda
+  # Runtime configuration for the main yabeda gem
+  class Config < ::Anyway::Config
+    config_name :yabeda
+
+    # Declare and collect metrics about Yabeda performance
+    attr_config debug: false
+  end
+end

spec/yabeda_spec.rb

@@ -24,4 +24,73 @@
       it { expect { configure! }.to raise_error(Yabeda::AlreadyConfiguredError) }
     end
   end
+
+  describe ".debug!" do
+    subject(:debug!) { described_class.debug! }
+
+    before { described_class.config.debug = false }
+
+    after { described_class.reset! }
+
+    it { expect { debug! }.to change(described_class, :debug?).from(false).to(true) }
+
+    it "registers metrics" do
+      described_class.debug!
+      described_class.configure!
+
+      expect(described_class.yabeda.collect_duration).to be_a Yabeda::Histogram
+    end
+  end
+
+  describe ".collect!" do
+    subject(:collect!) { described_class.collect! }
+
+    let(:adapter) { instance_double("Yabeda::BaseAdapter", perform_histogram_measure!: true, register!: true) }
+    let(:collector) do
+      proc do
+        sleep(0.01)
+        described_class.test.measure({}, 42)
+      end
+    end
+
+    before do
+      collect_block = collector
+      ::Yabeda.configure do
+        histogram :test, buckets: [42]
+        collect(&collect_block)
+      end
+      allow(collect_block).to receive(:source_location).and_return(["/somewhere/metrics.rb", 25])
+      described_class.configure!
+      ::Yabeda.register_adapter(:test_adapter, adapter)
+    end
+
+    after do
+      described_class.reset!
+      described_class.config.debug = false
+    end
+
+    it "calls registered collector" do
+      collect!
+
+      expect(adapter).to have_received(:perform_histogram_measure!).with(described_class.test, {}, 42)
+    end
+
+    context "when in debug mode" do
+      before { described_class.debug! }
+
+      it "calls registered collector" do
+        collect!
+
+        expect(adapter).to have_received(:perform_histogram_measure!).with(described_class.test, {}, 42)
+      end
+
+      it "measures collector runtime" do
+        collect!
+
+        expect(adapter).to have_received(:perform_histogram_measure!).with(
+          described_class.yabeda.collect_duration, { location: "/somewhere/metrics.rb:25" }, be_between(0.005, 0.05),
+        )
+      end
+    end
+  end
 end

yabeda.gemspec

@@ -25,6 +25,7 @@ Gem::Specification.new do |spec|
   spec.executables   = spec.files.grep(%r{^exe/}) { |f| File.basename(f) }
   spec.require_paths = ["lib"]
 
+  spec.add_dependency "anyway_config", ">= 1.3", "< 3"
   spec.add_dependency "concurrent-ruby"
   spec.add_dependency "dry-initializer"