From 75bb6217849be284106d05292e6cf34235ea1664 Mon Sep 17 00:00:00 2001 From: Dave Shawley Date: Sun, 18 Jul 2021 10:10:41 -0400 Subject: [PATCH 1/6] Add Connector.timer. This improves compatibility with python-statsd. --- CHANGELOG.rst | 4 ++++ docs/conf.py | 1 + sprockets_statsd/statsd.py | 16 ++++++++++++++++ tests/test_processor.py | 32 +++++++++++++++++++++++++++++++- 4 files changed, 52 insertions(+), 1 deletion(-) diff --git a/CHANGELOG.rst b/CHANGELOG.rst index 11a3e27..aabb5c1 100644 --- a/CHANGELOG.rst +++ b/CHANGELOG.rst @@ -1,3 +1,7 @@ +Next release +------------ +- Added ``Connector.timer`` method (addresses :issue:`8`) + :tag:`0.1.0 <0.0.1...0.1.0>` (10-May-2021) ------------------------------------------ - Added :envvar:`STATSD_ENABLED` environment variable to disable the Tornado integration diff --git a/docs/conf.py b/docs/conf.py index 7f1cdb5..b0e18c7 100644 --- a/docs/conf.py +++ b/docs/conf.py @@ -19,6 +19,7 @@ intersphinx_mapping = { # https://www.sphinx-doc.org/en/master/usage/extensions/extlinks.html extensions.append('sphinx.ext.extlinks') extlinks = { + 'issue': ("https://github.com/sprockets/sprockets-statsd/issues/%s", "#%s"), 'tag': ("https://github.com/sprockets/sprockets-statsd/compare/%s", "%s"), } diff --git a/sprockets_statsd/statsd.py b/sprockets_statsd/statsd.py index 513803e..d8080e7 100644 --- a/sprockets_statsd/statsd.py +++ b/sprockets_statsd/statsd.py @@ -1,6 +1,8 @@ import asyncio +import contextlib import logging import socket +import time import typing @@ -108,6 +110,20 @@ class AbstractConnector: """ self.inject_metric(f'timers.{path}', str(seconds * 1000.0), 'ms') + @contextlib.contextmanager + def timer(self, path): + """Send a timer metric using a context manager. + + :param path: timer to append the measured time to + + """ + start = time.time() + try: + yield + finally: + fini = time.time() + self.timing(path, max(fini, start) - start) + class Connector(AbstractConnector): """Sends metrics to a statsd server. diff --git a/tests/test_processor.py b/tests/test_processor.py index ab69c5e..e2f98d3 100644 --- a/tests/test_processor.py +++ b/tests/test_processor.py @@ -286,7 +286,13 @@ class ConnectorTests(ProcessorTestCase): recvd_path, _, rest = decoded.partition(':') recvd_value, _, recvd_code = rest.partition('|') self.assertEqual(path, recvd_path, 'metric path mismatch') - self.assertEqual(recvd_value, str(value), 'metric value mismatch') + if type_code == 'ms': + self.assertAlmostEqual(float(recvd_value), + value, + places=3, + msg='metric value mismatch') + else: + self.assertEqual(recvd_value, str(value), 'metric value mismatch') self.assertEqual(recvd_code, type_code, 'metric type mismatch') async def test_adjusting_counter(self): @@ -331,6 +337,30 @@ class ConnectorTests(ProcessorTestCase): self.assert_metrics_equal(self.statsd_server.metrics[0], 'timers.simple.timer', 12340.0, 'ms') + async def test_timing_context_manager(self): + with unittest.mock.patch( + 'sprockets_statsd.statsd.time.time') as time_function: + time_function.side_effect = [10.0, 22.345] + with self.connector.timer('some.timer'): + pass + self.assertEqual(2, time_function.call_count) + + await self.wait_for(self.statsd_server.message_received.acquire()) + self.assert_metrics_equal(self.statsd_server.metrics[0], + 'timers.some.timer', 12345.0, 'ms') + + async def test_timer_is_monotonic(self): + with unittest.mock.patch( + 'sprockets_statsd.statsd.time.time') as time_function: + time_function.side_effect = [10.001, 10.000] + with self.connector.timer('some.timer'): + pass + self.assertEqual(2, time_function.call_count) + + await self.wait_for(self.statsd_server.message_received.acquire()) + self.assert_metrics_equal(self.statsd_server.metrics[0], + 'timers.some.timer', 0.0, 'ms') + async def test_that_queued_metrics_are_drained(self): # The easiest way to test that the internal metrics queue # is drained when the processor is stopped is to monkey From 2d0b20054c517070a3d1d3caaab8d48d6d9e8a8b Mon Sep 17 00:00:00 2001 From: Dave Shawley Date: Sun, 18 Jul 2021 10:15:04 -0400 Subject: [PATCH 2/6] Update dev toolchain. --- setup.cfg | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/setup.cfg b/setup.cfg index 11b8123..35ff935 100644 --- a/setup.cfg +++ b/setup.cfg @@ -38,16 +38,16 @@ tornado = dev = asynctest==0.13.0 coverage==5.5 - flake8==3.8.4 + flake8==3.9.2 flake8-import-order==0.18.1 - sphinx==3.5.2 - sphinx-autodoc-typehints==1.11.1 + sphinx==4.1.1 + sphinx-autodoc-typehints==1.12.0 sprockets.http==2.2.0 tornado>=5 - yapf==0.30.0 + yapf==0.31.0 readthedocs = - sphinx==3.5.2 - sphinx-autodoc-typehints==1.11.1 + sphinx==4.1.1 + sphinx-autodoc-typehints==1.12.1 tornado>=5 [options.packages.find] From 3f0f46cd6d0a2144a0d31c84569eee78c49f8009 Mon Sep 17 00:00:00 2001 From: Dave Shawley Date: Sun, 18 Jul 2021 10:16:14 -0400 Subject: [PATCH 3/6] Bump from Beta to Production. I've been running this in production for a few months now without issue so I'm calling it production ready. --- setup.cfg | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/setup.cfg b/setup.cfg index 35ff935..d20f21e 100644 --- a/setup.cfg +++ b/setup.cfg @@ -13,7 +13,7 @@ project_urls: author = Dave Shawley author_email = daveshawley@gmail.com classifiers = - Development Status :: 4 - Beta + Development Status :: 5 - Production/Stable Intended Audience :: Developers License :: OSI Approved :: BSD License Natural Language :: English From 1c6ba8f80e9874bd5d44896952f84d30ace4df9b Mon Sep 17 00:00:00 2001 From: Dave Shawley Date: Sun, 18 Jul 2021 11:15:28 -0400 Subject: [PATCH 4/6] Implement the python-statsd Timer interface. --- CHANGELOG.rst | 1 + README.rst | 32 ++++++++++---- docs/index.rst | 4 ++ sprockets_statsd/statsd.py | 85 ++++++++++++++++++++++++++++++++++---- tests/test_processor.py | 80 +++++++++++++++++++++++++++++++++++ 5 files changed, 184 insertions(+), 18 deletions(-) diff --git a/CHANGELOG.rst b/CHANGELOG.rst index aabb5c1..caa614c 100644 --- a/CHANGELOG.rst +++ b/CHANGELOG.rst @@ -1,6 +1,7 @@ Next release ------------ - Added ``Connector.timer`` method (addresses :issue:`8`) +- Implement ``Timer`` abstraction from python-statsd :tag:`0.1.0 <0.0.1...0.1.0>` (10-May-2021) ------------------------------------------ diff --git a/README.rst b/README.rst index 117fb64..5584c4c 100644 --- a/README.rst +++ b/README.rst @@ -36,15 +36,29 @@ metric to send and the task consumes the internal queue when it is connected. The following convenience methods are available. You can also call ``inject_metric`` for complete control over the payload. -+--------------+--------------------------------------+ -| ``incr`` | Increment a counter metric | -+--------------+--------------------------------------+ -| ``decr`` | Decrement a counter metric | -+--------------+--------------------------------------+ -| ``gauge`` | Adjust or set a gauge metric | -+--------------+--------------------------------------+ -| ``timing`` | Append a duration to a timer metric | -+--------------+--------------------------------------+ ++--------------+--------------------------------------------------------------+ +| ``incr`` | Increment a counter metric | ++--------------+--------------------------------------------------------------+ +| ``decr`` | Decrement a counter metric | ++--------------+--------------------------------------------------------------+ +| ``gauge`` | Adjust or set a gauge metric | ++--------------+--------------------------------------------------------------+ +| ``timer`` | Append a duration to a timer metric using a context manager | ++--------------+--------------------------------------------------------------+ +| ``timing`` | Append a duration to a timer metric | ++--------------+--------------------------------------------------------------+ + +If you are a `python-statsd`_ user, then the method names should look very familiar. That is quite intentional. +I like the interface and many others do as well. There is one very very important difference though -- the +``timing`` method takes the duration as the number of **seconds** as a :class:`float` instead of the number of +milliseconds. + +.. warning:: + + If you are accustomed to using `python-statsd`_, be aware that the ``timing`` method expects the number of + seconds as a :class:`float` instead of the number of milliseconds. + +.. _python-statsd: https://statsd.readthedocs.io/en/latest/ Tornado helpers =============== diff --git a/docs/index.rst b/docs/index.rst index 96657cc..58e62af 100644 --- a/docs/index.rst +++ b/docs/index.rst @@ -46,6 +46,7 @@ Reference .. autoclass:: sprockets_statsd.statsd.Connector :members: + :inherited-members: incr, decr, gauge, timer, timing Tornado helpers --------------- @@ -63,6 +64,9 @@ Internals .. autoclass:: sprockets_statsd.statsd.Processor :members: +.. autoclass:: sprockets_statsd.statsd.Timer + :members: + .. autoclass:: sprockets_statsd.statsd.StatsdProtocol :members: diff --git a/sprockets_statsd/statsd.py b/sprockets_statsd/statsd.py index d8080e7..f8bb7ce 100644 --- a/sprockets_statsd/statsd.py +++ b/sprockets_statsd/statsd.py @@ -1,5 +1,4 @@ import asyncio -import contextlib import logging import socket import time @@ -47,6 +46,80 @@ class ThrottleGuard: self.counter = 0 +class Timer: + """Implement Timer interface from python-statsd. + + Instances of this class are returned from + :meth:`.AbstractConnector.timer` to maintain some compatibility + with `python-statsd`_. You should not create instances of this + class yourself. + + This implementation follows the careful protocol created by + python-statsd in that it raises :exc:`RuntimeError` in the + following cases: + + * :meth:`.stop` is called before calling :meth:`.start` + * :meth:`.send` is called before calling :meth:`.stop` + which requires a prior call to :meth:`.start` + + The call to :meth:`.send` clears the timing values so calling it + twice in a row will result in a :exc:`RuntimeError` as well. + + """ + def __init__(self, connector: 'AbstractConnector', path: str): + self._connector = connector + self._path = path + self._start_time, self._finish_time = None, None + + def start(self) -> 'Timer': + """Start the timer and return `self`.""" + self._start_time = time.time() + return self + + def stop(self, send: bool = True) -> 'Timer': + """Stop the timer and send the timing. + + :param send: immediately send the recorded timing to the + processor + + You can delay sending the timing by setting the `send` + parameter to :data:`False`. + + """ + if self._start_time is None: + raise RuntimeError('Timer.stop called before start') + self._finish_time = time.time() + if send: + self.send() + return self + + def send(self): + """Send the recorded timing to the connector. + + This method will raise a :exc:`RuntimeError` if a timing has + not been recorded by calling :meth:`start` and :meth:`stop` in + sequence. + + """ + if self._start_time is None: + raise RuntimeError('Timer.send called before start') + if self._finish_time is None: + raise RuntimeError('Timer.send called before stop') + + self._connector.timing( + self._path, + max(self._finish_time, self._start_time) - self._start_time) + self._start_time, self._finish_time = None, None + + def __enter__(self): + self.start() + return self + + def __exit__(self, exc_type, exc_val, exc_tb): + self.stop() + return False + + class AbstractConnector: """StatsD connector that does not send metrics or connect. @@ -110,19 +183,13 @@ class AbstractConnector: """ self.inject_metric(f'timers.{path}', str(seconds * 1000.0), 'ms') - @contextlib.contextmanager - def timer(self, path): + def timer(self, path) -> Timer: """Send a timer metric using a context manager. :param path: timer to append the measured time to """ - start = time.time() - try: - yield - finally: - fini = time.time() - self.timing(path, max(fini, start) - start) + return Timer(self, path) class Connector(AbstractConnector): diff --git a/tests/test_processor.py b/tests/test_processor.py index e2f98d3..eede86f 100644 --- a/tests/test_processor.py +++ b/tests/test_processor.py @@ -460,3 +460,83 @@ class ConnectorOptionTests(ProcessorTestCase): for _ in range(connector.processor.queue.qsize()): metric = await connector.processor.queue.get() self.assertEqual(metric, b'counters.counter:1|c') + + +class ConnectorTimerTests(ProcessorTestCase): + ip_protocol = socket.IPPROTO_TCP + + async def asyncSetUp(self): + await super().asyncSetUp() + self.connector = statsd.Connector(self.statsd_server.host, + self.statsd_server.port) + await self.connector.start() + await self.wait_for(self.statsd_server.client_connected.acquire()) + + async def asyncTearDown(self): + await self.wait_for(self.connector.stop()) + await super().asyncTearDown() + + async def test_that_stop_raises_if_not_started(self): + timer = self.connector.timer('whatever') + with self.assertRaises(RuntimeError): + timer.stop() + + async def test_that_start_returns_instance(self): + timer = self.connector.timer('whatever') + self.assertIs(timer, timer.start()) + + async def test_that_stop_returns_instance(self): + timer = self.connector.timer('whatever') + timer.start() + self.assertIs(timer, timer.stop()) + + async def test_that_timing_is_sent_by_stop(self): + timer = self.connector.timer('whatever') + timer.start() + self.assertTrue(self.statsd_server.message_received.locked(), + 'timing sent to server unexpectedly') + timer.stop() + await self.wait_for(self.statsd_server.message_received.acquire()) + + async def test_that_timing_send_can_be_delayed(self): + timer = self.connector.timer('whatever') + timer.start() + self.assertTrue(self.statsd_server.message_received.locked(), + 'timing sent to server unexpectedly') + timer.stop(send=False) + self.assertTrue(self.statsd_server.message_received.locked(), + 'timing sent to server unexpectedly') + + timer.send() + await self.wait_for(self.statsd_server.message_received.acquire()) + + async def test_that_send_raises_when_already_sent(self): + timer = self.connector.timer('whatever') + timer.start() + timer.stop(send=False) + timer.send() + await self.wait_for(self.statsd_server.message_received.acquire()) + with self.assertRaises(RuntimeError): + timer.send() + + async def test_that_send_raises_when_not_started(self): + timer = self.connector.timer('whatever') + with self.assertRaises(RuntimeError): + timer.send() + + async def test_that_send_raises_when_not_stopped(self): + timer = self.connector.timer('whatever') + timer.start() + with self.assertRaises(RuntimeError): + timer.send() + + async def test_that_timer_can_be_reused(self): + timer = self.connector.timer('whatever') + with timer: + pass + await self.wait_for(self.statsd_server.message_received.acquire()) + self.assertTrue(self.statsd_server.message_received.locked()) + + with timer: + pass + await self.wait_for(self.statsd_server.message_received.acquire()) From 65745010ad55d3893baac48267db2181933ecb96 Mon Sep 17 00:00:00 2001 From: Dave Shawley Date: Sun, 18 Jul 2021 11:23:33 -0400 Subject: [PATCH 5/6] Add datetime.timedelta support to `timing`. --- CHANGELOG.rst | 2 ++ sprockets_statsd/statsd.py | 6 +++++- tests/test_processor.py | 8 ++++++++ 3 files changed, 15 insertions(+), 1 deletion(-) diff --git a/CHANGELOG.rst b/CHANGELOG.rst index caa614c..198b6bd 100644 --- a/CHANGELOG.rst +++ b/CHANGELOG.rst @@ -2,6 +2,8 @@ Next release ------------ - Added ``Connector.timer`` method (addresses :issue:`8`) - Implement ``Timer`` abstraction from python-statsd +- ``Connector.timing`` now accepts :class:`datetime.timedelta` instances in addition + to :class:`float` instances :tag:`0.1.0 <0.0.1...0.1.0>` (10-May-2021) ------------------------------------------ diff --git a/sprockets_statsd/statsd.py b/sprockets_statsd/statsd.py index f8bb7ce..73d0393 100644 --- a/sprockets_statsd/statsd.py +++ b/sprockets_statsd/statsd.py @@ -1,4 +1,5 @@ import asyncio +import datetime import logging import socket import time @@ -174,13 +175,16 @@ class AbstractConnector: payload = str(value) self.inject_metric(f'gauges.{path}', payload, 'g') - def timing(self, path: str, seconds: float) -> None: + def timing(self, path: str, + seconds: typing.Union[float, datetime.timedelta]) -> None: """Send a timer metric. :param path: timer to append a value to :param seconds: number of **seconds** to record """ + if isinstance(seconds, datetime.timedelta): + seconds = seconds.total_seconds() self.inject_metric(f'timers.{path}', str(seconds * 1000.0), 'ms') def timer(self, path) -> Timer: diff --git a/tests/test_processor.py b/tests/test_processor.py index eede86f..312dd60 100644 --- a/tests/test_processor.py +++ b/tests/test_processor.py @@ -1,4 +1,5 @@ import asyncio +import datetime import logging import socket import time @@ -337,6 +338,13 @@ class ConnectorTests(ProcessorTestCase): self.assert_metrics_equal(self.statsd_server.metrics[0], 'timers.simple.timer', 12340.0, 'ms') + async def test_sending_timer_using_timedelta(self): + secs = datetime.timedelta(seconds=12, milliseconds=340) + self.connector.timing('simple.timer', secs) + await self.wait_for(self.statsd_server.message_received.acquire()) + self.assert_metrics_equal(self.statsd_server.metrics[0], + 'timers.simple.timer', 12340.0, 'ms') + async def test_timing_context_manager(self): with unittest.mock.patch( 'sprockets_statsd.statsd.time.time') as time_function: From 3b9b9ccb2fa4a9ab02dab6bb3d4f9212fca95878 Mon Sep 17 00:00:00 2001 From: Dave Shawley Date: Sun, 18 Jul 2021 12:06:35 -0400 Subject: [PATCH 6/6] Make sonar a little happier. I really should have commented the `pass` lines... --- tests/test_processor.py | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/tests/test_processor.py b/tests/test_processor.py index 312dd60..d7b03e3 100644 --- a/tests/test_processor.py +++ b/tests/test_processor.py @@ -350,7 +350,7 @@ class ConnectorTests(ProcessorTestCase): 'sprockets_statsd.statsd.time.time') as time_function: time_function.side_effect = [10.0, 22.345] with self.connector.timer('some.timer'): - pass + pass # exercising context manager self.assertEqual(2, time_function.call_count) await self.wait_for(self.statsd_server.message_received.acquire()) @@ -362,7 +362,7 @@ class ConnectorTests(ProcessorTestCase): 'sprockets_statsd.statsd.time.time') as time_function: time_function.side_effect = [10.001, 10.000] with self.connector.timer('some.timer'): - pass + pass # exercising context manager self.assertEqual(2, time_function.call_count) await self.wait_for(self.statsd_server.message_received.acquire()) @@ -541,10 +541,10 @@ class ConnectorTimerTests(ProcessorTestCase): async def test_that_timer_can_be_reused(self): timer = self.connector.timer('whatever') with timer: - pass + pass # exercising context manager await self.wait_for(self.statsd_server.message_received.acquire()) self.assertTrue(self.statsd_server.message_received.locked()) with timer: - pass + pass # exercising context manager await self.wait_for(self.statsd_server.message_received.acquire())