diff --git a/osprofiler/profiler.py b/osprofiler/profiler.py index 5795826..2e20da3 100644 --- a/osprofiler/profiler.py +++ b/osprofiler/profiler.py @@ -28,14 +28,19 @@ def _clean(): __local_ctx.profiler = None -def init(base_id=None, parent_id=None, hmac_key=None): - """Init profiler. +def init(hmac_key, base_id=None, parent_id=None): + """Init profiler instance for current thread. + + You should call profiler.init() before using osprofiler. + Otherwise profiler.start() and profiler.stop() methods won't do anything. + + :param hmac_key: secret key to sign trace information. :param base_id: Used to bind all related traces. :param parent_id: Used to build tree of traces. :returns: Profiler instance """ - __local_ctx.profiler = Profiler(base_id=base_id, parent_id=parent_id, - hmac_key=hmac_key) + __local_ctx.profiler = Profiler(hmac_key, base_id=base_id, + parent_id=parent_id) return __local_ctx.profiler @@ -48,7 +53,12 @@ def get_profiler(): def start(name, info=None): - """Send new start notification if profiler instance is presented.""" + """Send new start notification if profiler instance is presented. + + :param name: The name of action. E.g. wsgi, rpc, db, etc.. + :param info: Dictionary with extra trace information. For example in wsgi + it can be url, in rpc - message or in db sql - request. + """ profiler = get_profiler() if profiler: profiler.start(name, info=info) @@ -64,6 +74,20 @@ def stop(info=None): class Trace(object): def __init__(self, name, info=None): + """With statement way to use profiler start()/stop(). + + + >> with profiler.Trace("rpc", info={"any": "values"}) + >> some code + + instead of + + >> profiler.start() + >> try: + >> your code + >> finally: + profiler.stop() + """ self._name = name self._info = info @@ -76,7 +100,7 @@ class Trace(object): class Profiler(object): - def __init__(self, base_id=None, parent_id=None, hmac_key=None): + def __init__(self, hmac_key, base_id=None, parent_id=None): self.hmac_key = hmac_key if not base_id: base_id = str(uuid.uuid4()) @@ -84,25 +108,50 @@ class Profiler(object): self._name = collections.deque() def get_base_id(self): + """Return base if of trace. + + Base id is the same for all elements in one trace. It's main goal is + to be able to retrieve by one request all trace elements from storage. + """ return self._trace_stack[0] def get_parent_id(self): + """Returns parent trace element id.""" return self._trace_stack[-2] def get_id(self): + """Returns current trace element id.""" return self._trace_stack[-1] def start(self, name, info=None): - """Currently time measurement itself is delegated to - notification.api. Every message is marked with a unix - timestamp and for now it should be sufficient. - Later more precise measurements can be added here. + """Start new event. + + Adds new trace_id to trace stack and sends notification + to collector (may be ceilometer). With "info" and 3 ids: + base_id - to be able to retrieve all trace elements by one query + parent_id - to build tree of events (not just a list) + trace_id - current event id. + + As we are writing this code special for OpenStack, and there will be + only one implementation of notifier based on ceilometer notifer api. + That already contains timestamps, so we don't measure time by hand. + + :param name: name of trace element (db, wsgi, rpc, etc..) + :param info: Dictionary with any useful information related to this + trace element. (sql request, rpc message or url...) """ + self._name.append(name) self._trace_stack.append(str(uuid.uuid4())) self._notify('%s-start' % name, info) def stop(self, info=None): + """Finish latests event. + + Same as a start, but instead of pushing trace_id to stack it pops it. + + :param info: Dict with useful info. It will be send in notification. + """ self._notify('%s-stop' % self._name.pop(), info) self._trace_stack.pop() diff --git a/osprofiler/web.py b/osprofiler/web.py index f6adb10..e1259bc 100644 --- a/osprofiler/web.py +++ b/osprofiler/web.py @@ -66,9 +66,9 @@ class WsgiMiddleware(object): if not self._trace_is_valid(trace_info): return request.get_response(self.application) - profiler.init(trace_info.get("base_id"), - trace_info.get("parent_id"), - self.hmac_key) + profiler.init(self.hmac_key, + base_id=trace_info.get("base_id"), + parent_id=trace_info.get("parent_id")) info = { "request": { "host_url": request.host_url, diff --git a/tests/test_profiler.py b/tests/test_profiler.py index 13f303a..98d5b61 100644 --- a/tests/test_profiler.py +++ b/tests/test_profiler.py @@ -28,7 +28,7 @@ class ProfilerGlobMethodsTestCase(test.TestCase): self.assertIsNone(profiler.get_profiler()) def test_get_profiler_and_init(self): - p = profiler.init(base_id="1", parent_id="2") + p = profiler.init("secret", base_id="1", parent_id="2") self.assertEqual(profiler.get_profiler(), p) self.assertEqual(p.get_base_id(), "1") @@ -40,7 +40,7 @@ class ProfilerGlobMethodsTestCase(test.TestCase): profiler.start("name") def test_start(self): - p = profiler.init(base_id="1", parent_id="2") + p = profiler.init("secret", base_id="1", parent_id="2") p.start = mock.MagicMock() profiler.start("name", info="info") p.start.assert_called_once_with("name", info="info") @@ -50,7 +50,7 @@ class ProfilerGlobMethodsTestCase(test.TestCase): profiler.stop() def test_stop(self): - p = profiler.init(base_id="1", parent_id="2") + p = profiler.init("secret", base_id="1", parent_id="2") p.stop = mock.MagicMock() profiler.stop(info="info") p.stop.assert_called_once_with(info="info") @@ -59,27 +59,27 @@ class ProfilerGlobMethodsTestCase(test.TestCase): class ProfilerTestCase(test.TestCase): def test_profiler_get_base_id(self): - prof = profiler.Profiler(base_id="1", parent_id="2") + prof = profiler.Profiler("secret", base_id="1", parent_id="2") self.assertEqual(prof.get_base_id(), "1") @mock.patch("osprofiler.profiler.uuid.uuid4") def test_profiler_get_parent_id(self, mock_uuid4): mock_uuid4.return_value = "42" - prof = profiler.Profiler(base_id="1", parent_id="2") + prof = profiler.Profiler("secret", base_id="1", parent_id="2") prof.start("test") self.assertEqual(prof.get_parent_id(), "2") @mock.patch("osprofiler.profiler.uuid.uuid4") def test_profiler_get_base_id_unset_case(self, mock_uuid4): mock_uuid4.return_value = "42" - prof = profiler.Profiler() + prof = profiler.Profiler("secret") self.assertEqual(prof.get_base_id(), "42") self.assertEqual(prof.get_parent_id(), "42") @mock.patch("osprofiler.profiler.uuid.uuid4") def test_profiler_get_id(self, mock_uuid4): mock_uuid4.return_value = "43" - prof = profiler.Profiler() + prof = profiler.Profiler("secret") prof.start("test") self.assertEqual(prof.get_id(), "43") @@ -97,14 +97,14 @@ class ProfilerTestCase(test.TestCase): "info": info } - prof = profiler.Profiler(base_id="1", parent_id="2") + prof = profiler.Profiler("secret", base_id="1", parent_id="2") prof.start("test", info=info) mock_notify.assert_called_once_with(payload) @mock.patch("osprofiler.profiler.notifier.notify") def test_profiler_stop(self, mock_notify): - prof = profiler.Profiler(base_id="1", parent_id="2") + prof = profiler.Profiler("secret", base_id="1", parent_id="2") prof._trace_stack.append("44") prof._name.append("abc") @@ -123,6 +123,11 @@ class ProfilerTestCase(test.TestCase): self.assertEqual(len(prof._name), 0) self.assertEqual(prof._trace_stack, collections.deque(["1", "2"])) + def test_profiler_hmac(self): + hmac = "secret" + prof = profiler.Profiler(hmac, base_id="1", parent_id="2") + self.assertEqual(hmac, prof.hmac_key) + class TraceTestCase(test.TestCase): diff --git a/tests/test_web.py b/tests/test_web.py index d0b5a01..11a9b28 100644 --- a/tests/test_web.py +++ b/tests/test_web.py @@ -36,13 +36,13 @@ class WebTestCase(test.TestCase): self.addCleanup(profiler._clean) def test_add_trace_id_header_no_hmac(self): - profiler.init(base_id="y", parent_id="z") + profiler.init(None, base_id="y", parent_id="z") headers = {"a": 10, "b": 20} web.add_trace_id_header(headers) self.assertEqual(sorted(headers.keys()), ["a", "b"]) def test_add_trace_id_header(self): - profiler.init(base_id="y", parent_id="z", hmac_key="key") + profiler.init("key", base_id="y", parent_id="z") headers = {"a": 10, "b": 20} web.add_trace_id_header(headers) self.assertEqual(sorted(headers.keys()), @@ -189,7 +189,8 @@ class WebMiddlewareTestCase(test.TestCase): middleware = web.WsgiMiddleware("app", hmac_key, enabled=True) self.assertEqual("yeah!", middleware(request)) - mock_profiler_init.assert_called_once_with("1", "2", hmac_key) + mock_profiler_init.assert_called_once_with(hmac_key, base_id="1", + parent_id="2") expected_info = { "request": { "host_url": request.host_url,