Skip to content

Commit

Permalink
Merge b142a06 into 3652cf7
Browse files Browse the repository at this point in the history
  • Loading branch information
lawrencejones committed Jun 16, 2019
2 parents 3652cf7 + b142a06 commit 4cd340d
Show file tree
Hide file tree
Showing 8 changed files with 210 additions and 1 deletion.
1 change: 1 addition & 0 deletions .ruby-version
@@ -0,0 +1 @@
2.6.2
5 changes: 5 additions & 0 deletions Gemfile
Expand Up @@ -6,6 +6,11 @@ def ruby_version?(constraint)
Gem::Dependency.new('', constraint).match?('', RUBY_VERSION)
end

group :development do
gem 'pry'
gem 'pry-byebug'
end

group :test do
gem 'coveralls'
gem 'json', '< 2.0' if ruby_version?('< 2.0')
Expand Down
12 changes: 12 additions & 0 deletions lib/prometheus/client.rb
Expand Up @@ -2,6 +2,7 @@

require 'prometheus/client/registry'
require 'prometheus/client/config'
require 'prometheus/client/tracer'

module Prometheus
# Client is a ruby implementation for a Prometheus compatible client.
Expand All @@ -14,5 +15,16 @@ def self.registry
def self.config
@config ||= Config.new
end

# Most people will want to use a global tracer instead of building their own, similar
# to how most will use the global metrics registry.
def self.tracer
@tracer ||= Tracer.new
end

# Delegate to the Tracer.
def self.trace(metric, labels = {}, &block)
tracer.trace(metric, labels, &block)
end
end
end
68 changes: 68 additions & 0 deletions lib/prometheus/client/tracer.rb
@@ -0,0 +1,68 @@
# frozen_string_literal: true

module Prometheus
module Client
# For metrics that track durations over the course of long-running tasks, we need to
# ensure the metric is updated gradually while they execute instead of right at the
# end. This class is used to track on-going 'traces', records of tasks starting and
# stopping, and exposes a method `collect` that will update the associated metric with
# the time elapsed since the last `collect`.
class Tracer
Trace = Struct.new(:metric, :labels, :time)

def initialize
@lock = Mutex.new
@traces = []
end

# Start and manage the life of a trace. Pass a long-running block to this method to
# ensure the associated metric is updated gradually throughout the execution.
def trace(metric, labels = {})
start(metric, labels)
yield
ensure
stop(metric, labels)
end

# Update currently traced metrics- this will increment all on-going traces with the
# delta of time between the last update and now. This should be called just before
# serving a /metrics request.
def collect(traces = @traces)
@lock.synchronize do
now = monotonic_now
traces.each do |trace|
time_since = [now - trace.time, 0].max
trace.time = now
trace.metric.increment(
by: time_since,
labels: trace.labels,
)
end
end
end

private

def start(metric, labels = {})
@lock.synchronize { @traces << Trace.new(metric, labels, monotonic_now) }
end

def stop(metric, labels = {})
matching = nil
@lock.synchronize do
matching, @traces = @traces.partition do |trace|
trace.metric == metric && trace.labels == labels
end
end

collect(matching)
end

# We're doing duration arithmetic which should make use of monotonic clocks, to
# avoid changes to the system time from affecting our metrics.
def monotonic_now
Process.clock_gettime(Process::CLOCK_MONOTONIC)
end
end
end
end
22 changes: 22 additions & 0 deletions lib/prometheus/middleware/trace_collector.rb
@@ -0,0 +1,22 @@
# encoding: UTF-8

require 'prometheus/client'

module Prometheus
module Middleware
# This class integrates with a Prometheus::Client::Tracer to update associated metric
# traces just prior to serving metrics. By default, this will collect traces on the
# global Client tracer.
class TraceCollector
def initialize(app, options = {})
@app = app
@tracer = options[:tracer] || Client.tracer
end

def call(env)
@tracer.collect
@app.call(env)
end
end
end
end
2 changes: 1 addition & 1 deletion prometheus-client.gemspec
Expand Up @@ -12,7 +12,7 @@ Gem::Specification.new do |s|
s.homepage = 'https://github.com/prometheus/client_ruby'
s.license = 'Apache 2.0'

s.files = %w(README.md) + Dir.glob('{lib/**/*}')
s.files = %w(README.md) + Dir.glob('{lib/**/*}') - ['.ruby-version']
s.require_paths = ['lib']

s.add_dependency 'concurrent-ruby'
Expand Down
76 changes: 76 additions & 0 deletions spec/prometheus/client/tracer_spec.rb
@@ -0,0 +1,76 @@
# frozen_string_literal: true

require "prometheus/client"

describe Prometheus::Client::Tracer do
subject(:tracer) { described_class.new }
let(:metric) do
Prometheus::Client::Counter.new(:counter, docstring: "example", labels: %i[worker])
end

describe ".trace" do
# These tests try stubbing timing logic. Instead of using let's, we use a test
# instance variable @now to represent the current time, as returned by a monotonic
# clock system call.
#
# The #monotonic_now method of the tracer is stubbed to always return the current
# value of @now, and tests can manipulate time by advancing that instance variable.
#
# The tracer is normally passed a block that manipulates @now.
subject(:trace) { tracer.trace(metric, labels, &trace_block) }
let(:labels) { { worker: 1 } }
let(:trace_block) { -> { @now += 1.0 } }

before do
@now = 0.0 # set initial time
allow(tracer).to receive(:monotonic_now) { @now }
end

it "increments metric with elapsed duration" do
expect { trace }.to change { metric.values[labels] }.by(1.0)
end

context "when .collect is called during a trace" do
let(:latch) { Mutex.new }
let(:trace_block) do
-> { latch.synchronize { @now += 1.0 } }
end

it "increments metric with incremental duration" do
latch.lock # acquire the lock, trace should now block
trace_thread = Thread.new do
trace # will block until latch is released
end

# We need to block until the trace_thread has actually begun, otherwise we'll
# never be able to guarantee the trace was started at now = 0.0, even if this
# should happen almost immediately.
Timeout.timeout(1) { sleep(0.01) until tracer.collect.size > 0 }

# Advance the clock by 0.5s
@now += 0.5

# If we now collect, the metric should be incremented by the elapsed time (0.5s)
expect { tracer.collect }.to change { metric.values[labels] }.by(0.5)

# Collect once more should leave the metric unchanged, as no time has passed since
# the last collect
expect { tracer.collect }.to change { metric.values[labels] }.by(0.0)

# Unlocking the latch and allowing the trace thread to complete will execute the
# final part of a trace, which should update the metric with time elapsed. The
# trace thread advances time by 1s right before it ends, so we expect to update
# the metric by 1s.
#
# A bug would be if we incremented the metric by the time since our trace started
# and when it ended, which in total is 1.5s. This would suggest we never reset the
# trace clock when calling collect.
expect {
latch.unlock
trace_thread.join(1)
trace_thread.kill # in case thread misbehaves
}.to change { metric.values[labels] }.by(1.0)
end
end
end
end
25 changes: 25 additions & 0 deletions spec/prometheus/middleware/trace_collector_spec.rb
@@ -0,0 +1,25 @@
# frozen_string_literal: true

require "prometheus/client"
require "prometheus/middleware/trace_collector"

describe Prometheus::Middleware::TraceCollector do
subject(:collector) { described_class.new(app, options) }

let(:app) { double(call: []) }
let(:options) { { tracer: tracer } }
let(:tracer) { Prometheus::Client::Tracer.new }

describe ".call" do
subject(:call) { collector.call({}) }

# The most basic of tests, just verifying the tracer is invoked. We rely on the tests
# for the tracer to validate #collect works correctly.
it "calls tracer.collect, then the original app" do
expect(tracer).to receive(:collect).and_call_original
expect(app).to receive(:call)

call
end
end
end

0 comments on commit 4cd340d

Please sign in to comment.