diff --git a/CHANGELOG.md b/CHANGELOG.md index 68ac44eb..f313b858 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,29 @@ please at an entry to the "unreleased changes" section below. ### Unreleased changes +## Version 2.3.3 + +- Capture measure and distribution metrics on exception and early return (#134) + +NOTE: Now that exceptions are measured statistics may behave differently. An exception example: +``` +StatsD.measure('myhttpcall') do + my_http_object.invoke +end +``` +Version 2.3.2 and below did not track metrics whenever a HTTP Timeout exception was raised. +2.3.3 and above will include those metrics which may increase the values included. + +A return example: +``` +StatsD.measure('myexpensivecalculation') do + return if expensive_calculation_disabled? + expensive_calculation +end +``` +If `expensive_calculation_disabled?` is true 50% of the time version 2.3.2 will drop the +average metric considerably. + ## Version 2.3.2 - Add option to override global prefix for metrics (#148) diff --git a/lib/statsd/instrument.rb b/lib/statsd/instrument.rb index e91d52bf..d081e665 100644 --- a/lib/statsd/instrument.rb +++ b/lib/statsd/instrument.rb @@ -58,17 +58,13 @@ def self.generate_metric_name(metric_name, callee, *args) if Process.respond_to?(:clock_gettime) # @private - def self.duration - start = Process.clock_gettime(Process::CLOCK_MONOTONIC) - yield - Process.clock_gettime(Process::CLOCK_MONOTONIC) - start + def self.current_timestamp + Process.clock_gettime(Process::CLOCK_MONOTONIC) end else # @private - def self.duration - start = Time.now - yield - Time.now - start + def self.current_timestamp + Time.now end end @@ -310,11 +306,16 @@ def measure(key, value = nil, *metric_options, &block) value, metric_options = parse_options(value, metric_options) type = (!metric_options.empty? && metric_options.first[:as_dist] ? :d : :ms) - result = nil - value = 1000 * StatsD::Instrument.duration { result = block.call } if block_given? - metric = collect_metric(type, key, value, metric_options) - result = metric unless block_given? - result + return collect_metric(type, key, value, metric_options) unless block_given? + + start = StatsD::Instrument.current_timestamp + begin + block.call + ensure + # Ensure catches both a raised exception and a return in the invoked block + value = 1000 * (StatsD::Instrument.current_timestamp - start) + collect_metric(type, key, value, metric_options) + end end # Emits a counter metric. @@ -373,11 +374,16 @@ def histogram(key, value, *metric_options) # end def distribution(key, value=nil, *metric_options, &block) value, metric_options = parse_options(value, metric_options) - result = nil - value = 1000 * StatsD::Instrument.duration { result = block.call } if block_given? - metric = collect_metric(:d, key, value, metric_options) - result = metric unless block_given? - result + + return collect_metric(:d, key, value, metric_options) unless block_given? + + start = StatsD::Instrument.current_timestamp + begin + block.call + ensure + value = 1000 * (StatsD::Instrument.current_timestamp - start) + collect_metric(:d, key, value, metric_options) + end end # Emits a key/value metric. diff --git a/lib/statsd/instrument/version.rb b/lib/statsd/instrument/version.rb index 5bb5606d..0ca62ec4 100644 --- a/lib/statsd/instrument/version.rb +++ b/lib/statsd/instrument/version.rb @@ -1,5 +1,5 @@ module StatsD module Instrument - VERSION = "2.3.2" + VERSION = "2.3.3" end end diff --git a/test/statsd_test.rb b/test/statsd_test.rb index be1de19d..7fe8a32c 100644 --- a/test/statsd_test.rb +++ b/test/statsd_test.rb @@ -46,7 +46,7 @@ def test_statsd_measure_with_explicit_value_and_sample_rate end def test_statsd_measure_with_benchmarked_block_duration - StatsD::Instrument.stubs(:duration).returns(1.12) + StatsD::Instrument.stubs(:current_timestamp).returns(5.0, 5.0 + 1.12) metric = capture_statsd_call do StatsD.measure('values.foobar') { 'foo' } end @@ -70,6 +70,40 @@ def test_statsd_measure_returns_return_value_of_block_even_if_nil assert_nil return_value end + def test_statsd_measure_with_return_in_block_still_captures + StatsD::Instrument.stubs(:current_timestamp).returns(5.0, 6.12) + result = nil + metric = capture_statsd_call do + lambda = -> do + StatsD.measure('values.foobar') { return 'from lambda'} + end + + result = lambda.call + end + + assert_equal 'from lambda', result + assert_equal 1120.0, metric.value + end + + def test_statsd_measure_with_exception_in_block_still_captures + StatsD::Instrument.stubs(:current_timestamp).returns(5.0, 6.12) + result = nil + metric = capture_statsd_call do + lambda = -> do + StatsD.measure('values.foobar') { raise 'from lambda'} + end + + begin + result = lambda.call + rescue + end + + end + + assert_nil result + assert_equal 1120.0, metric.value + end + def test_statsd_increment result = nil metric = capture_statsd_call { result = StatsD.increment('values.foobar', 3) } @@ -149,7 +183,7 @@ def test_statsd_distribution end def test_statsd_distribution_with_benchmarked_block_duration - StatsD::Instrument.stubs(:duration).returns(1.12) + StatsD::Instrument.stubs(:current_timestamp).returns(5.0, 5.0 + 1.12) metric = capture_statsd_call do StatsD.distribution('values.foobar') { 'foo' } end @@ -157,8 +191,44 @@ def test_statsd_distribution_with_benchmarked_block_duration assert_equal 1120.0, metric.value end + def test_statsd_distribution_with_return_in_block_still_captures + StatsD::Instrument.stubs(:current_timestamp).returns(5.0, 5.0 + 1.12) + result = nil + metric = capture_statsd_call do + lambda = -> do + StatsD.distribution('values.foobar') { return 'from lambda'} + end + + result = lambda.call + end + + assert_equal 'from lambda', result + assert_equal :d, metric.type + assert_equal 1120.0, metric.value + end + + def test_statsd_distribution_with_exception_in_block_still_captures + StatsD::Instrument.stubs(:current_timestamp).returns(5.0, 5.0 + 1.12) + result = nil + metric = capture_statsd_call do + lambda = -> do + StatsD.distribution('values.foobar') { raise 'from lambda'} + end + + begin + result = lambda.call + rescue + end + + end + + assert_nil result + assert_equal :d, metric.type + assert_equal 1120.0, metric.value + end + def test_statsd_distribution_with_block_and_options - StatsD::Instrument.stubs(:duration).returns(1.12) + StatsD::Instrument.stubs(:current_timestamp).returns(5.0, 5.0 + 1.12) metric = capture_statsd_call do StatsD.distribution('values.foobar', :tags => ['test'], :sample_rate => 0.9) { 'foo' } end