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

[Curtis Caravone]

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

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.

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

56. By Curtis Caravone on 2011-11-28

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

Unmerged revisions

56. By Curtis Caravone on 2011-11-28

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

55. By Curtis Caravone on 2011-11-28

Added automatic timer support for ExtendedMetrics
Added unit tests for ExtendedMetrics

54. By Curtis Caravone on 2011-11-28

Fixed timing call in ExtendedMetrics and IMetrics to match Metrics

53. By Curtis Caravone on 2011-11-26

[r=sidnei] 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

52. By Sidnei da Silva on 2011-11-24

- Someone forgot to lint this.

51. By Lucio Torre on 2011-11-18

[r=sidnei,theiw] Add pluggable metric kind support to txstatsd.

50. By Ian Wilkinson on 2011-11-14

[r=sidnei] Resolve the host when instantiating the Twisted client.

49. By Sidnei da Silva on 2011-10-28

Delay importing the reactor such that other applications get a chance to pick their choice of reactor. [trivial]

48. By Lucio Torre on 2011-10-26

[r=sidnei] add probabilistic distinct counter

47. By Sidnei da Silva on 2011-10-25

Delay importing process module and reactor [trivial]

=== modified file 'txstatsd/metrics/metrics.py'
--- txstatsd/metrics/metrics.py	2011-11-18 19:45:18 +0000
+++ txstatsd/metrics/metrics.py	2011-11-26 00:06:23 +0000
@@ -1,4 +1,5 @@
 
+import time
 from txstatsd.metrics.gaugemetric import GaugeMetric
 from txstatsd.metrics.metermetric import MeterMetric
 from txstatsd.metrics.distinctmetric import DistinctMetric
@@ -29,6 +30,7 @@
         self.connection = connection
         self.namespace = namespace
         self._metrics = {}
+        self.last_time = 0
 
     def report(self, name, value, metric_type, sample_rate=1):
         """Report a generic metric.
@@ -84,15 +86,25 @@
             self._metrics[name] = metric
         self._metrics[name].send("%s|c" % -value)
 
-    def timing(self, name, duration, sample_rate=1):
-        """Report this sample performed in duration ms."""
+    def reset_timing(self):
+        """Resets the duration timer for the next call to timing()"""
+        self.last_time = time.time()
+
+    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
         name = self.fully_qualify_name(name)
         if not name in self._metrics:
             metric = Metric(self.connection,
                             name,
                             sample_rate)
             self._metrics[name] = metric
-        self._metrics[name].send("%s|ms" % duration)
+        self._metrics[name].send("%s|ms" % (duration * 1000))
 
     def distinct(self, name, item):
         name = self.fully_qualify_name(name)

=== modified file 'txstatsd/tests/test_metrics.py'
--- txstatsd/tests/test_metrics.py	2011-11-18 19:42:56 +0000
+++ txstatsd/tests/test_metrics.py	2011-11-26 00:06:23 +0000
@@ -1,7 +1,8 @@
 """Tests for the Metrics convenience class."""
 
+import re
+import time
 from unittest import TestCase
-
 from txstatsd.metrics.metrics import Metrics
 
 
@@ -49,9 +50,39 @@
 
     def test_timing(self):
         """Test the timing operation."""
-        self.metrics.timing('timing', 101123)
+        self.metrics.timing('timing', 101.1234)
         self.assertEqual(self.connection.data,
-                         'txstatsd.tests.timing:101123|ms')
+                         'txstatsd.tests.timing:101123.4|ms')
+
+    def test_timing_automatic(self):
+        """Test the automatic timing operation with explicit reset"""
+        start_time = time.time()
+
+        self.metrics.reset_timing()
+        time.sleep(.1)
+        self.metrics.timing('timing')
+
+        elapsed = time.time() - start_time
+
+        label, val, units = re.split(":|\|", self.connection.data)
+        self.assertEqual(label, 'txstatsd.tests.timing')
+        self.assertEqual(units, 'ms')
+        self.assertTrue(100 <= float(val) <= elapsed * 1000)
+
+    def test_timing_automatic_implicit_reset(self):
+        """Test the automatic timing operation with implicit reset"""
+        start_time = time.time()
+
+        self.metrics.timing('something_else')
+        time.sleep(.1)
+        self.metrics.timing('timing')
+
+        elapsed = time.time() - start_time
+
+        label, val, units = re.split(":|\|", self.connection.data)
+        self.assertEqual(label, 'txstatsd.tests.timing')
+        self.assertEqual(units, 'ms')
+        self.assertTrue(100 <= float(val) <= elapsed * 1000)
 
     def test_generic(self):
         """Test the GenericMetric class."""
@@ -70,3 +101,4 @@
         self.metrics.gauge('gauge', 413)
         self.assertEqual(self.connection.data,
                          'gauge:413|g')
+