Merge lp:~caravone/txstatsd/statsd-timings-consistency into lp:txstatsd

[Curtis Caravone]

Added timing consistency (always take seconds but emit milliseconds) to ExtendedMetrics.
Added automatic timing option to ExtendedMetrics and signature of IMetrics timing methods.

Updated Nov. 28, 2011:

Made sure ExtendedMetrics and IMetrics had the updated timing() logic as well. Added unit tests for ExtendedMetrics.

Changed timing() method to clearly take durations in seconds and emit durations to txstatsd server in milliseconds
Add option for automatic calculation of timing duration

[Sidnei da Silva (sidnei)]

Looks good. Thanks!

One thing I noticed is that we're storing instance-level attributes here and in other metrics. Which means that we can't safely use them from different threads. We need to make sure that we use a per-thread metrics object in client code, or maybe handle the thread-safety here so the client code doesn't have to bother.

review: Approve

[Curtis Caravone (caravone)]

For the timer code I added, it would probably make sense to use a
thread-bound variable, since timing an activity generally makes the most
sense in the context of a thread. I'll take a look at the other uses of
instance-level attributes used and see what would appear to make the
most sense.

Curtis

On 11/26/11 7:34 AM, Sidnei da Silva wrote:
> Review: Approve
>
> Looks good. Thanks!
>
> One thing I noticed is that we're storing instance-level attributes here and in other metrics. Which means that we can't safely use them from different threads. We need to make sure that we use a per-thread metrics object in client code, or maybe handle the thread-safety here so the client code doesn't have to bother.

[Sidnei da Silva (sidnei)]

Please use no spaces around the equals sign on function arguments.

Other than that looks good. Once you fix that, please set a commit message in this MP and flip the status to Approved.

review: Approve

[Curtis Caravone (caravone)]

One thing I wasn't sure about was the expected behavior of the increment/decrement calls. As you can see from the unit tests, the basic Metrics object emits deltas for each increment/decrements, while the ExtendedMetrics version keeps a cumulative delta and emits that. Not sure if it's a bug or just a subtlety of the API.

[lp:~caravone/txstatsd/statsd-timings-consistency]

56. By Curtis Caravone on 2011-11-28

Formatting: Removed spaces around '=' in default function arguments

=== modified file 'txstatsd/metrics/extendedmetrics.py'
--- txstatsd/metrics/extendedmetrics.py	2011-09-14 12:01:10 +0000
+++ txstatsd/metrics/extendedmetrics.py	2011-11-28 17:18:41 +0000
@@ -39,8 +39,10 @@
             self._metrics[name] = metric
         self._metrics[name].decrement(value)
 
-    def timing(self, name, duration, sample_rate=1):
-        """Report this sample performed in duration ms."""
+    def timing(self, name, duration=None, sample_rate=1):
+        """Report this sample performed in duration seconds."""
+        if duration is None:
+            duration = self.calculate_duration()
         name = self.fully_qualify_name(name)
         if not name in self._metrics:
             metric = TimerMetric(self.connection,
 
=== modified file 'txstatsd/metrics/imetrics.py'
--- txstatsd/metrics/imetrics.py	2011-09-09 15:49:55 +0000
+++ txstatsd/metrics/imetrics.py	2011-11-28 17:18:41 +0000
@@ -14,5 +14,5 @@
     def decrement(name, value=1, sample_rate=1):
         """Decrement counter C{name} by C{count}."""
 
-    def timing(name, duration, sample_rate=1):
-        """Report that C{name} took C{duration} milliseconds."""
+    def timing(name, duration=None, sample_rate=1):
+        """Report that C{name} took C{duration} seconds."""
 
=== modified file 'txstatsd/metrics/metrics.py'
--- txstatsd/metrics/metrics.py	2011-11-25 23:56:31 +0000
+++ txstatsd/metrics/metrics.py	2011-11-28 17:18:41 +0000
@@ -90,14 +90,19 @@
         """Resets the duration timer for the next call to timing()"""
         self.last_time = time.time()
 
-    def timing(self, name, duration = None, sample_rate=1):
+    def calculate_duration(self):
+        """Resets the duration timer and returns the elapsed duration"""
+        current_time = time.time()
+        duration = current_time - self.last_time
+        self.last_time = current_time
+        return duration
+
+    def timing(self, name, duration=None, sample_rate=1):
         """Report that this sample performed in duration seconds.
            Default duration is the actual elapsed time since
            the last call to this method or reset_timing()"""
         if duration is None:
-            current_time = time.time()
-            duration = current_time - self.last_time
-            self.last_time = current_time
+            duration = self.calculate_duration()
         name = self.fully_qualify_name(name)
         if not name in self._metrics:
             metric = Metric(self.connection,
 
=== modified file 'txstatsd/metrics/timermetric.py'
--- txstatsd/metrics/timermetric.py	2011-09-14 12:01:10 +0000
+++ txstatsd/metrics/timermetric.py	2011-11-28 17:18:41 +0000
@@ -30,7 +30,7 @@
 
     def mark(self, duration):
         """Report this sample performed in duration (measured in seconds)."""
-        self.send("%s|ms" % duration)
+        self.send("%s|ms" % (duration * 1000))
 
 
 class TimerMetricReporter(object):
 
=== modified file 'txstatsd/tests/test_metrics.py'
--- txstatsd/tests/test_metrics.py	2011-11-25 23:56:31 +0000
+++ txstatsd/tests/test_metrics.py	2011-11-28 17:18:41 +0000
@@ -3,6 +3,7 @@
 import re
 import time
 from unittest import TestCase
+from txstatsd.metrics.extendedmetrics import ExtendedMetrics
 from txstatsd.metrics.metrics import Metrics
 
 
@@ -102,3 +103,18 @@
         self.assertEqual(self.connection.data,
                          'gauge:413|g')
 
+
+class TestExtendedMetrics(TestMetrics):
+    def setUp(self):
+        super(TestExtendedMetrics, self).setUp()
+        self.metrics = ExtendedMetrics(self.connection, 'txstatsd.tests')
+
+    def test_counter(self):
+        """Test the increment and decrement operations."""
+        self.metrics.increment('counter', 18)
+        self.assertEqual(self.connection.data,
+                         'txstatsd.tests.counter:18|c')
+        self.metrics.decrement('counter', 9)
+        self.assertEqual(self.connection.data,
+                         'txstatsd.tests.counter:9|c')
+