diff --git a/CHANGELOG.md b/CHANGELOG.md index dba8d7a30..bd8bd017b 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -26,13 +26,13 @@ # increment a simple counter Sentry::Metrics.incr('button_click') # set a value, unit and tags - Sentry::Metrics.incr('time', 5, 'second', tags: { browser:' firefox' }) + Sentry::Metrics.incr('time', 5, unit: 'second', tags: { browser:' firefox' }) # distribution - get statistical aggregates from an array of observations - Sentry::Metrics.distribution('page_load', 15.0, 'millisecond') + Sentry::Metrics.distribution('page_load', 15.0, unit: 'millisecond') # gauge - record statistical aggregates directly on the SDK, more space efficient - Sentry::Metrics.gauge('page_load', 15.0, 'millisecond') + Sentry::Metrics.gauge('page_load', 15.0, unit: 'millisecond') # set - get unique counts of elements Sentry::Metrics.set('user_view', 'jane') diff --git a/sentry-ruby/lib/sentry/metrics.rb b/sentry-ruby/lib/sentry/metrics.rb index 26b7c70e9..ab927b1c5 100644 --- a/sentry-ruby/lib/sentry/metrics.rb +++ b/sentry-ruby/lib/sentry/metrics.rb @@ -10,22 +10,20 @@ module Sentry module Metrics class << self - # TODO-neel-metrics define units, maybe symbols - - def incr(key, value = 1.0, unit = 'none', tags: {}, timestamp: nil) - Sentry.metrics_aggregator&.add(:c, key, value, unit, tags: tags, timestamp: timestamp) + def incr(key, value = 1.0, unit: 'none', tags: {}, timestamp: nil) + Sentry.metrics_aggregator&.add(:c, key, value, unit: unit, tags: tags, timestamp: timestamp) end - def distribution(key, value, unit = 'none', tags: {}, timestamp: nil) - Sentry.metrics_aggregator&.add(:d, key, value, unit, tags: tags, timestamp: timestamp) + def distribution(key, value, unit: 'none', tags: {}, timestamp: nil) + Sentry.metrics_aggregator&.add(:d, key, value, unit: unit, tags: tags, timestamp: timestamp) end - def set(key, value, unit = 'none', tags: {}, timestamp: nil) - Sentry.metrics_aggregator&.add(:s, key, value, unit, tags: tags, timestamp: timestamp) + def set(key, value, unit: 'none', tags: {}, timestamp: nil) + Sentry.metrics_aggregator&.add(:s, key, value, unit: unit, tags: tags, timestamp: timestamp) end - def gauge(key, value, unit = 'none', tags: {}, timestamp: nil) - Sentry.metrics_aggregator&.add(:g, key, value, unit, tags: tags, timestamp: timestamp) + def gauge(key, value, unit: 'none', tags: {}, timestamp: nil) + Sentry.metrics_aggregator&.add(:g, key, value, unit: unit, tags: tags, timestamp: timestamp) end end end diff --git a/sentry-ruby/lib/sentry/metrics/aggregator.rb b/sentry-ruby/lib/sentry/metrics/aggregator.rb index 056e9cf43..3cc75bda8 100644 --- a/sentry-ruby/lib/sentry/metrics/aggregator.rb +++ b/sentry-ruby/lib/sentry/metrics/aggregator.rb @@ -18,10 +18,16 @@ class Aggregator s: SetMetric } + # exposed only for testing + attr_reader :thread, :buckets, :flush_shift + def initialize(configuration, client) @client = client @logger = configuration.logger - @default_tags = { 'release' => configuration.release, 'environment' => configuration.environment } + + @default_tags = {} + @default_tags['release'] = configuration.release if configuration.release + @default_tags['environment'] = configuration.environment if configuration.environment @thread = nil @exited = false @@ -37,10 +43,11 @@ def initialize(configuration, client) def add(type, key, value, - unit, + unit: 'none', tags: {}, timestamp: nil) return unless ensure_thread + return unless METRIC_TYPES.keys.include?(type) timestamp = timestamp.to_i if timestamp.is_a?(Time) timestamp ||= Sentry.utc_now.to_i @@ -64,8 +71,6 @@ def add(type, end def flush(force: false) - log_debug("[Metrics::Aggregator] current bucket state: #{@buckets}") - flushable_buckets = get_flushable_buckets!(force) return if flushable_buckets.empty? @@ -77,9 +82,6 @@ def flush(force: false) is_json: false ) - log_debug("[Metrics::Aggregator] flushing buckets: #{flushable_buckets}") - log_debug("[Metrics::Aggregator] payload: #{payload}") - Sentry.background_worker.perform do @client.transport.send_envelope(envelope) end @@ -100,7 +102,7 @@ def ensure_thread @thread = Thread.new do loop do - # TODO use event for force flush later + # TODO-neel-metrics use event for force flush later sleep(FLUSH_INTERVAL) flush end diff --git a/sentry-ruby/spec/sentry/metrics/aggregator_spec.rb b/sentry-ruby/spec/sentry/metrics/aggregator_spec.rb new file mode 100644 index 000000000..abe6d00b5 --- /dev/null +++ b/sentry-ruby/spec/sentry/metrics/aggregator_spec.rb @@ -0,0 +1,299 @@ +require 'spec_helper' + +RSpec.describe Sentry::Metrics::Aggregator do + let(:string_io) { StringIO.new } + + # fix at 3 second offset to check rollup + let(:fake_time) { Time.new(2024, 1, 1, 1, 1, 3) } + + before do + perform_basic_setup do |config| + config.enable_metrics = true + config.enable_tracing = true + config.release = 'test-release' + config.environment = 'test' + config.logger = Logger.new(string_io) + end + end + + subject { Sentry.metrics_aggregator } + + describe '#add' do + it 'spawns new thread' do + expect { subject.add(:c, 'incr', 1) }.to change { Thread.list.count }.by(1) + expect(subject.thread).to be_a(Thread) + end + + it 'spawns only one thread' do + expect { subject.add(:c, 'incr', 1) }.to change { Thread.list.count }.by(1) + + expect(subject.thread).to receive(:alive?).and_call_original + expect { subject.add(:c, 'incr', 1) }.to change { Thread.list.count }.by(0) + end + + context 'when thread creation fails' do + before do + expect(Thread).to receive(:new).and_raise(ThreadError) + end + + it 'does not create new thread' do + expect { subject.add(:c, 'incr', 1) }.to change { Thread.list.count }.by(0) + end + + it 'noops' do + subject.add(:c, 'incr', 1) + expect(subject.buckets).to eq({}) + end + + it 'logs error' do + subject.add(:c, 'incr', 1) + expect(string_io.string).to match(/\[Metrics::Aggregator\] thread creation failed/) + end + end + + context 'when killed' do + before { subject.kill } + + it 'noops' do + subject.add(:c, 'incr', 1) + expect(subject.buckets).to eq({}) + end + + it 'does not create new thread' do + expect(Thread).not_to receive(:new) + expect { subject.add(:c, 'incr', 1) }.to change { Thread.list.count }.by(0) + end + end + + it 'does not add unsupported metric type' do + subject.add(:foo, 'foo', 1) + expect(subject.buckets).to eq({}) + end + + it 'has the correct bucket timestamp key rolled up to 10 seconds' do + allow(Time).to receive(:now).and_return(fake_time) + subject.add(:c, 'incr', 1) + expect(subject.buckets.keys.first).to eq(fake_time.to_i - 3) + end + + it 'has the correct bucket timestamp key rolled up to 10 seconds when passed explicitly' do + subject.add(:c, 'incr', 1, timestamp: fake_time + 9) + expect(subject.buckets.keys.first).to eq(fake_time.to_i + 7) + end + + it 'has the correct type in the bucket metric key' do + subject.add(:c, 'incr', 1) + type, _, _, _ = subject.buckets.values.first.keys.first + expect(type).to eq(:c) + end + + it 'has the correct key in the bucket metric key' do + subject.add(:c, 'incr', 1) + _, key, _, _ = subject.buckets.values.first.keys.first + expect(key).to eq('incr') + end + + it 'has the default unit \'none\' in the bucket metric key' do + subject.add(:c, 'incr', 1) + _, _, unit, _ = subject.buckets.values.first.keys.first + expect(unit).to eq('none') + end + + it 'has the correct custom unit in the bucket metric key' do + subject.add(:c, 'incr', 1, unit: 'second') + _, _, unit, _ = subject.buckets.values.first.keys.first + expect(unit).to eq('second') + end + + it 'has the correct default tags serialized in the bucket metric key' do + subject.add(:c, 'incr', 1) + _, _, _, tags = subject.buckets.values.first.keys.first + expect(tags).to eq([['environment', 'test'], ['release', 'test-release']]) + end + + it 'has the correct custom tags serialized in the bucket metric key' do + subject.add(:c, 'incr', 1, tags: { foo: 42 }) + _, _, _, tags = subject.buckets.values.first.keys.first + expect(tags).to include(['foo', '42']) + end + + it 'has the correct array value tags serialized in the bucket metric key' do + subject.add(:c, 'incr', 1, tags: { foo: [42, 43] }) + _, _, _, tags = subject.buckets.values.first.keys.first + expect(tags).to include(['foo', '42'], ['foo', '43']) + end + + context 'with running transaction' do + let(:transaction) { Sentry.start_transaction(name: 'foo', source: :view) } + before { Sentry.get_current_scope.set_span(transaction) } + + it 'has the transaction name in tags serialized in the bucket metric key' do + subject.add(:c, 'incr', 1) + _, _, _, tags = subject.buckets.values.first.keys.first + expect(tags).to include(['transaction', 'foo']) + end + + it 'does not has the low quality transaction name in tags serialized in the bucket metric key' do + transaction.set_name('foo', source: :url) + subject.add(:c, 'incr', 1) + _, _, _, tags = subject.buckets.values.first.keys.first + expect(tags).not_to include(['transaction', 'foo']) + end + end + + it 'creates a new CounterMetric instance if not existing' do + expect(Sentry::Metrics::CounterMetric).to receive(:new).and_call_original + subject.add(:c, 'incr', 1) + + metric = subject.buckets.values.first.values.first + expect(metric).to be_a(Sentry::Metrics::CounterMetric) + expect(metric.value).to eq(1.0) + end + + it 'reuses the existing CounterMetric instance' do + allow(Time).to receive(:now).and_return(fake_time) + + subject.add(:c, 'incr', 1) + metric = subject.buckets.values.first.values.first + expect(metric.value).to eq(1.0) + + expect(Sentry::Metrics::CounterMetric).not_to receive(:new) + expect(metric).to receive(:add).with(2).and_call_original + subject.add(:c, 'incr', 2) + expect(metric.value).to eq(3.0) + end + + it 'creates a new DistributionMetric instance if not existing' do + expect(Sentry::Metrics::DistributionMetric).to receive(:new).and_call_original + subject.add(:d, 'dist', 1) + + metric = subject.buckets.values.first.values.first + expect(metric).to be_a(Sentry::Metrics::DistributionMetric) + expect(metric.value).to eq([1.0]) + end + + it 'creates a new GaugeMetric instance if not existing' do + expect(Sentry::Metrics::GaugeMetric).to receive(:new).and_call_original + subject.add(:g, 'gauge', 1) + + metric = subject.buckets.values.first.values.first + expect(metric).to be_a(Sentry::Metrics::GaugeMetric) + expect(metric.serialize).to eq([1.0, 1.0, 1.0, 1.0, 1]) + end + + it 'creates a new SetMetric instance if not existing' do + expect(Sentry::Metrics::SetMetric).to receive(:new).and_call_original + subject.add(:s, 'set', 1) + + metric = subject.buckets.values.first.values.first + expect(metric).to be_a(Sentry::Metrics::SetMetric) + expect(metric.value).to eq(Set[1]) + end + end + + describe '#flush' do + context 'with empty buckets' do + it 'returns early and does nothing' do + expect(sentry_envelopes.count).to eq(0) + subject.flush + end + + it 'returns early and does nothing with force' do + expect(sentry_envelopes.count).to eq(0) + subject.flush(force: true) + end + end + + context 'with pending buckets' do + before do + allow(Time).to receive(:now).and_return(fake_time) + 10.times { subject.add(:c, 'incr', 1) } + 5.times { |i| subject.add(:d, 'dist', i, unit: 'second', tags: { "foö$-bar" => "snöwmän% 23{}" }) } + + allow(Time).to receive(:now).and_return(fake_time + 9) + 5.times { subject.add(:c, 'incr', 1) } + 5.times { |i| subject.add(:d, 'dist', i + 5, unit: 'second', tags: { "foö$-bar" => "snöwmän% 23{}" }) } + + expect(subject.buckets.keys).to eq([fake_time.to_i - 3, fake_time.to_i + 7]) + expect(subject.buckets.values[0].length).to eq(2) + expect(subject.buckets.values[1].length).to eq(2) + + # set the time such that the first set of metrics above are picked + allow(Time).to receive(:now).and_return(fake_time + 9 + subject.flush_shift) + end + + context 'without force' do + it 'updates the pending buckets in place' do + subject.flush + + expect(subject.buckets.keys).to eq([fake_time.to_i + 7]) + expect(subject.buckets.values[0].length).to eq(2) + end + + it 'calls the background worker' do + expect(Sentry.background_worker).to receive(:perform) + subject.flush + end + + it 'sends the flushable buckets in statsd envelope item with correct payload' do + subject.flush + + envelope = sentry_envelopes.first + expect(envelope.headers).to eq({}) + + item = envelope.items.first + expect(item.headers).to eq({ type: 'statsd', length: item.payload.bytesize }) + expect(item.is_json).to eq(false) + + incr, dist = item.payload.split("\n") + expect(incr).to eq("incr@none:10.0|c|#environment:test,release:test-release|T#{fake_time.to_i - 3}") + expect(dist).to eq("dist@second:0.0:1.0:2.0:3.0:4.0|d|" + + "#environment:test,fo_-bar:snöwmän 23{},release:test-release|" + + "T#{fake_time.to_i - 3}") + end + end + + context 'with force' do + it 'empties the pending buckets in place' do + subject.flush(force: true) + expect(subject.buckets).to eq({}) + end + + it 'calls the background worker' do + expect(Sentry.background_worker).to receive(:perform) + subject.flush(force: true) + end + + it 'sends all buckets in statsd envelope item with correct payload' do + subject.flush(force: true) + + envelope = sentry_envelopes.first + expect(envelope.headers).to eq({}) + + item = envelope.items.first + expect(item.headers).to eq({ type: 'statsd', length: item.payload.bytesize }) + expect(item.is_json).to eq(false) + + incr1, dist1, incr2, dist2 = item.payload.split("\n") + expect(incr1).to eq("incr@none:10.0|c|#environment:test,release:test-release|T#{fake_time.to_i - 3}") + expect(dist1).to eq("dist@second:0.0:1.0:2.0:3.0:4.0|d|" + + "#environment:test,fo_-bar:snöwmän 23{},release:test-release|" + + "T#{fake_time.to_i - 3}") + expect(incr2).to eq("incr@none:5.0|c|#environment:test,release:test-release|T#{fake_time.to_i + 7}") + expect(dist2).to eq("dist@second:5.0:6.0:7.0:8.0:9.0|d|" + + "#environment:test,fo_-bar:snöwmän 23{},release:test-release|" + + "T#{fake_time.to_i + 7}") + end + end + end + end + + describe '#kill' do + before { subject.add(:c, 'incr', 1) } + it 'logs message when killing the thread' do + expect(subject.thread).to receive(:kill) + subject.kill + expect(string_io.string).to match(/\[Metrics::Aggregator\] killing thread/) + end + end +end diff --git a/sentry-ruby/spec/sentry/metrics/counter_metric_spec.rb b/sentry-ruby/spec/sentry/metrics/counter_metric_spec.rb new file mode 100644 index 000000000..f92a0135f --- /dev/null +++ b/sentry-ruby/spec/sentry/metrics/counter_metric_spec.rb @@ -0,0 +1,25 @@ +require 'spec_helper' + +RSpec.describe Sentry::Metrics::CounterMetric do + subject { described_class.new(1) } + before { subject.add(2) } + + describe '#add' do + it 'adds float value' do + subject.add(3.0) + expect(subject.value).to eq(6.0) + end + end + + describe '#serialize' do + it 'returns value in array' do + expect(subject.serialize).to eq([3.0]) + end + end + + describe '#weight' do + it 'returns fixed value of 1' do + expect(subject.weight).to eq(1) + end + end +end diff --git a/sentry-ruby/spec/sentry/metrics/distribution_metric_spec.rb b/sentry-ruby/spec/sentry/metrics/distribution_metric_spec.rb new file mode 100644 index 000000000..7e5b2f2d4 --- /dev/null +++ b/sentry-ruby/spec/sentry/metrics/distribution_metric_spec.rb @@ -0,0 +1,25 @@ +require 'spec_helper' + +RSpec.describe Sentry::Metrics::DistributionMetric do + subject { described_class.new(1) } + before { subject.add(2) } + + describe '#add' do + it 'appends float value to array' do + subject.add(3.0) + expect(subject.value).to eq([1.0, 2.0, 3.0]) + end + end + + describe '#serialize' do + it 'returns whole array' do + expect(subject.serialize).to eq([1.0, 2.0]) + end + end + + describe '#weight' do + it 'returns length of array' do + expect(subject.weight).to eq(2) + end + end +end diff --git a/sentry-ruby/spec/sentry/metrics/gauge_metric_spec.rb b/sentry-ruby/spec/sentry/metrics/gauge_metric_spec.rb new file mode 100644 index 000000000..44be08465 --- /dev/null +++ b/sentry-ruby/spec/sentry/metrics/gauge_metric_spec.rb @@ -0,0 +1,29 @@ +require 'spec_helper' + +RSpec.describe Sentry::Metrics::GaugeMetric do + subject { described_class.new(0) } + before { 9.times { |i| subject.add(i + 1) } } + + describe '#add' do + it 'appends float value to array' do + subject.add(11) + expect(subject.last).to eq(11.0) + expect(subject.min).to eq(0.0) + expect(subject.max).to eq(11.0) + expect(subject.sum).to eq(56.0) + expect(subject.count).to eq(11) + end + end + + describe '#serialize' do + it 'returns array of statistics' do + expect(subject.serialize).to eq([9.0, 0.0, 9.0, 45.0, 10]) + end + end + + describe '#weight' do + it 'returns fixed value of 5' do + expect(subject.weight).to eq(5) + end + end +end diff --git a/sentry-ruby/spec/sentry/metrics/metric_spec.rb b/sentry-ruby/spec/sentry/metrics/metric_spec.rb new file mode 100644 index 000000000..a5ed3fd93 --- /dev/null +++ b/sentry-ruby/spec/sentry/metrics/metric_spec.rb @@ -0,0 +1,21 @@ +require 'spec_helper' + +RSpec.describe Sentry::Metrics::Metric do + describe '#add' do + it 'raises not implemented error' do + expect { subject.add(1) }.to raise_error(NotImplementedError) + end + end + + describe '#serialize' do + it 'raises not implemented error' do + expect { subject.serialize }.to raise_error(NotImplementedError) + end + end + + describe '#weight' do + it 'raises not implemented error' do + expect { subject.weight }.to raise_error(NotImplementedError) + end + end +end diff --git a/sentry-ruby/spec/sentry/metrics/set_metric_spec.rb b/sentry-ruby/spec/sentry/metrics/set_metric_spec.rb new file mode 100644 index 000000000..fdf74dd0d --- /dev/null +++ b/sentry-ruby/spec/sentry/metrics/set_metric_spec.rb @@ -0,0 +1,30 @@ +require 'spec_helper' + +RSpec.describe Sentry::Metrics::SetMetric do + subject { described_class.new('foo') } + + before do + 2.times { subject.add('foo') } + 2.times { subject.add('bar') } + 2.times { subject.add(42) } + end + + describe '#add' do + it 'appends new value to set' do + subject.add('baz') + expect(subject.value).to eq(Set['foo', 'bar', 'baz', 42]) + end + end + + describe '#serialize' do + it 'returns array of hashed values' do + expect(subject.serialize).to eq([Zlib.crc32('foo'), Zlib.crc32('bar'), 42]) + end + end + + describe '#weight' do + it 'returns length of set' do + expect(subject.weight).to eq(3) + end + end +end diff --git a/sentry-ruby/spec/sentry/metrics_spec.rb b/sentry-ruby/spec/sentry/metrics_spec.rb new file mode 100644 index 000000000..c74e84fa1 --- /dev/null +++ b/sentry-ruby/spec/sentry/metrics_spec.rb @@ -0,0 +1,85 @@ +require 'spec_helper' + +RSpec.describe Sentry::Metrics do + before do + perform_basic_setup do |config| + config.enable_metrics = true + end + end + + let(:aggregator) { Sentry.metrics_aggregator } + let(:fake_time) { Time.new(2024, 1, 1, 1, 1, 3) } + + describe '.incr' do + it 'passes default value of 1.0 with only key' do + expect(aggregator).to receive(:add).with( + :c, + 'foo', + 1.0, + unit: 'none', + tags: {}, + timestamp: nil + ) + + described_class.incr('foo') + end + + it 'passes through args to aggregator' do + expect(aggregator).to receive(:add).with( + :c, + 'foo', + 5.0, + unit: 'second', + tags: { fortytwo: 42 }, + timestamp: fake_time + ) + + described_class.incr('foo', 5.0, unit: 'second', tags: { fortytwo: 42 }, timestamp: fake_time) + end + end + + describe '.distribution' do + it 'passes through args to aggregator' do + expect(aggregator).to receive(:add).with( + :d, + 'foo', + 5.0, + unit: 'second', + tags: { fortytwo: 42 }, + timestamp: fake_time + ) + + described_class.distribution('foo', 5.0, unit: 'second', tags: { fortytwo: 42 }, timestamp: fake_time) + end + end + + describe '.set' do + it 'passes through args to aggregator' do + expect(aggregator).to receive(:add).with( + :s, + 'foo', + 'jane', + unit: 'none', + tags: { fortytwo: 42 }, + timestamp: fake_time + ) + + described_class.set('foo', 'jane', tags: { fortytwo: 42 }, timestamp: fake_time) + end + end + + describe '.gauge' do + it 'passes through args to aggregator' do + expect(aggregator).to receive(:add).with( + :g, + 'foo', + 5.0, + unit: 'second', + tags: { fortytwo: 42 }, + timestamp: fake_time + ) + + described_class.gauge('foo', 5.0, unit: 'second', tags: { fortytwo: 42 }, timestamp: fake_time) + end + end +end