diff options
author | Dina Belova <dbelova@mirantis.com> | 2015-11-13 15:56:41 +0300 |
---|---|---|
committer | Dina Belova <dbelova@mirantis.com> | 2015-12-24 23:40:02 +0300 |
commit | 7925c1200cf40fe5c68bb2804fa28ffd87dba867 (patch) | |
tree | 631394d84d9f75ee303442b6e05fe4b74315a19b | |
parent | dc0b65b15217c37da882b70f5f98d71305a474f1 (diff) | |
download | osprofiler-7925c1200cf40fe5c68bb2804fa28ffd87dba867.tar.gz |
Fix Ceilometer parser to use events
Change-Id: I83aa97b3caadb053fddc76088d19ed5110035c67
-rw-r--r-- | osprofiler/cmd/template.html | 16 | ||||
-rw-r--r-- | osprofiler/parsers/ceilometer.py | 64 | ||||
-rw-r--r-- | osprofiler/profiler.py | 12 | ||||
-rw-r--r-- | osprofiler/sqlalchemy.py | 5 | ||||
-rw-r--r-- | osprofiler/web.py | 1 | ||||
-rw-r--r-- | tests/parsers/test_ceilometer.py | 443 | ||||
-rw-r--r-- | tests/test_profiler.py | 17 | ||||
-rw-r--r-- | tests/test_sqlalchemy.py | 5 | ||||
-rw-r--r-- | tests/test_web.py | 1 |
9 files changed, 372 insertions, 192 deletions
diff --git a/osprofiler/cmd/template.html b/osprofiler/cmd/template.html index 369c498..c99f8f8 100644 --- a/osprofiler/cmd/template.html +++ b/osprofiler/cmd/template.html @@ -125,19 +125,17 @@ var metadata = {}; angular.forEach(info, function(value, key) { var parts = key.split("."); - if (parts[0] == "info"){ + if (parts[0] == "meta"){ - if (parts.length != 2){ - this[key] = value; + if (parts.length == 2){ + this[parts[1]] = value; } else{ - var group_name = parts[1].split(":"); - if (group_name.length == 2){ - if (!(group_name[0] in this)) - this[group_name[0]] = {}; + var group_name = parts[1]; + if (!(group_name in this)) + this[group_name] = {}; - this[group_name[0]][group_name[1]] = value; - } + this[group_name][parts[2]] = value; } }; }, metadata); diff --git a/osprofiler/parsers/ceilometer.py b/osprofiler/parsers/ceilometer.py index 535e2b2..267bfa9 100644 --- a/osprofiler/parsers/ceilometer.py +++ b/osprofiler/parsers/ceilometer.py @@ -13,7 +13,6 @@ # License for the specific language governing permissions and limitations # under the License. - import datetime @@ -56,35 +55,50 @@ def parse_notifications(notifications): finished_at = 0 for n in notifications: - meta = n["metadata"] - key = meta["trace_id"] - - if key not in result: - result[key] = { - "info": { - "name": meta["name"].split("-")[0] - }, - "parent_id": meta["parent_id"], - "trace_id": meta["trace_id"] - } + traits = n["traits"] - skip_keys = ["base_id", "trace_id", "parent_id", "name", "event_type"] + def find_field(f_name): + return [t["value"] for t in traits if t["name"] == f_name][0] - for k in meta: - if k not in skip_keys: - result[key]["info"][k] = meta[k] + trace_id = find_field("trace_id") + parent_id = find_field("parent_id") + name = find_field("name") + project = find_field("project") + service = find_field("service") + host = find_field("host") + timestamp = find_field("timestamp") try: - timestamp = datetime.datetime.strptime(n["timestamp"], + timestamp = datetime.datetime.strptime(timestamp, "%Y-%m-%dT%H:%M:%S.%f") except ValueError: - timestamp = datetime.datetime.strptime(n["timestamp"], + timestamp = datetime.datetime.strptime(timestamp, "%Y-%m-%dT%H:%M:%S") - if meta["name"].endswith("stop"): - result[key]["info"]["finished"] = timestamp + if trace_id not in result: + result[trace_id] = { + "info": { + "name": name.split("-")[0], + "project": project, + "service": service, + "meta.host": host, + "host": host, + }, + "trace_id": trace_id, + "parent_id": parent_id, + } + + skip_keys = ["base_id", "trace_id", "parent_id", + "name", "project", "service", "host", "timestamp"] + + for k in traits: + if k["name"] not in skip_keys: + result[trace_id]["info"]["meta.%s" % k["name"]] = k["value"] + + if name.endswith("stop"): + result[trace_id]["info"]["finished"] = timestamp else: - result[key]["info"]["started"] = timestamp + result[trace_id]["info"]["started"] = timestamp if not started_at or started_at > timestamp: started_at = timestamp @@ -96,7 +110,7 @@ def parse_notifications(notifications): # NOTE(boris-42): Unfortunately this is the simplest way that works in # py26 and py27 microsec = (dt.microseconds + (dt.seconds + dt.days * 24 * 3600) * 1e6) - return (int)(microsec / 1000.0) + return int(microsec / 1000.0) for r in result.values(): # NOTE(boris-42): We are not able to guarantee that ceilometer consumed @@ -126,6 +140,8 @@ def get_notifications(ceilometer, base_id): :param base_id: Base id of trace elements. """ - _filter = "{\"=\": {\"resource_id\": \"profiler-%s\"}}" % base_id + _filter = [{"field": "base_id", "op": "eq", "value": base_id}] + # limit is hardcoded in this code state. Later that will be changed via + # connection string usage return [n.to_dict() - for n in ceilometer.query_samples.query(_filter, None, None)] + for n in ceilometer.events.list(_filter, limit=100000)] diff --git a/osprofiler/profiler.py b/osprofiler/profiler.py index 9ddbbea..d6ef92a 100644 --- a/osprofiler/profiler.py +++ b/osprofiler/profiler.py @@ -14,8 +14,10 @@ # under the License. import collections +import datetime import functools import inspect +import socket import threading import uuid @@ -245,6 +247,7 @@ class _Profiler(object): base_id = str(uuid.uuid4()) self._trace_stack = collections.deque([base_id, parent_id or base_id]) self._name = collections.deque() + self._host = socket.gethostname() def get_base_id(self): """Return base if of trace. @@ -272,7 +275,7 @@ class _Profiler(object): 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. + only one implementation of notifier based on ceilometer notifier api. That already contains timestamps, so we don't measure time by hand. :param name: name of trace element (db, wsgi, rpc, etc..) @@ -280,6 +283,8 @@ class _Profiler(object): trace element. (sql request, rpc message or url...) """ + info = info or {} + info["host"] = self._host self._name.append(name) self._trace_stack.append(str(uuid.uuid4())) self._notify("%s-start" % name, info) @@ -291,6 +296,8 @@ class _Profiler(object): :param info: Dict with useful info. It will be send in notification. """ + info = info or {} + info["host"] = self._host self._notify("%s-stop" % self._name.pop(), info) self._trace_stack.pop() @@ -299,7 +306,8 @@ class _Profiler(object): "name": name, "base_id": self.get_base_id(), "trace_id": self.get_id(), - "parent_id": self.get_parent_id() + "parent_id": self.get_parent_id(), + "timestamp": datetime.datetime.utcnow(), } if info: payload["info"] = info diff --git a/osprofiler/sqlalchemy.py b/osprofiler/sqlalchemy.py index eac1087..e98c59c 100644 --- a/osprofiler/sqlalchemy.py +++ b/osprofiler/sqlalchemy.py @@ -46,7 +46,10 @@ def _before_cursor_execute(name): """Add listener that will send trace info before query is executed.""" def handler(conn, cursor, statement, params, context, executemany): - info = {"db.statement": statement, "db.params": params} + info = {"db": { + "statement": statement, + "params": params} + } profiler.start(name, info=info) return handler diff --git a/osprofiler/web.py b/osprofiler/web.py index 2bedee4..ed9832d 100644 --- a/osprofiler/web.py +++ b/osprofiler/web.py @@ -111,7 +111,6 @@ class WsgiMiddleware(object): profiler.init(**trace_info) info = { "request": { - "host_url": request.host_url, "path": request.path, "query": request.query_string, "method": request.method, diff --git a/tests/parsers/test_ceilometer.py b/tests/parsers/test_ceilometer.py index 4d6ae54..8afedc9 100644 --- a/tests/parsers/test_ceilometer.py +++ b/tests/parsers/test_ceilometer.py @@ -21,7 +21,6 @@ from tests import test class CeilometerParserTestCase(test.TestCase): - def test_build_empty_tree(self): self.assertEqual(ceilometer._build_tree({}), []) @@ -88,167 +87,319 @@ class CeilometerParserTestCase(test.TestCase): self.assertEqual(ceilometer.parse_notifications([]), expected) def test_parse_notifications(self): - samples = [ + events = [ { - "id": "896f5e52-d4c9-11e3-a117-46c0b36ac153", - "metadata": { - "base_id": "f5587500-07d1-41a0-b434-525d3c28ac49", - "event_type": "profiler.nova", - "host": "0.0.0.0", - "service": "osapi_compute", - "project": "nova", - "name": "WSGI-stop", - "parent_id": "82281b35-63aa-45fc-8578-5a32a66370ab", - "trace_id": "837eb0bd-323a-4e3f-b223-3be78ad86aab" - }, - "meter": "WSGI-stop", - "project_id": None, - "recorded_at": "2014-05-06T02:53:03.110724", - "resource_id": "profiler-f5587500-07d1-41a0-b434-525d3c28ac49", - "source": "openstack", - "timestamp": "2014-05-06T02:52:59.357020", - "type": "gauge", - "unit": "sample", - "user_id": None, - "volume": 1.0 - }, + "traits": [ + { + "type": "string", + "name": "base_id", + "value": "7253ca8c-33b3-4f84-b4f1-f5a4311ddfa4" + }, + { + "type": "string", + "name": "host", + "value": "ubuntu" + }, + { + "type": "string", + "name": "method", + "value": "POST" + }, + { + "type": "string", + "name": "name", + "value": "wsgi-start" + }, + { + "type": "string", + "name": "parent_id", + "value": "7253ca8c-33b3-4f84-b4f1-f5a4311ddfa4" + }, + { + "type": "string", + "name": "project", + "value": "keystone" + }, + { + "type": "string", + "name": "service", + "value": "main" + }, + { + "type": "string", + "name": "timestamp", + "value": "2015-12-23T14:02:22.338776" + }, + { + "type": "string", + "name": "trace_id", + "value": "06320327-2c2c-45ae-923a-515de890276a" + } + ], + "raw": {}, + "generated": "2015-12-23T10:41:38.415793", + "event_type": "profiler.main", + "message_id": "65fc1553-3082-4a6f-9d1e-0e3183f57a47"}, { - "id": "895043a0-d4c9-11e3-a117-46c0b36ac153", - "metadata": { - "base_id": "f5587500-07d1-41a0-b434-525d3c28ac49", - "event_type": "profiler.nova", - "host": "0.0.0.0", - "service": "osapi_compute", - "project": "nova", - "name": "WSGI-start", - "parent_id": "82281b35-63aa-45fc-8578-5a32a66370ab", - "trace_id": "837eb0bd-323a-4e3f-b223-3be78ad86aab" - }, - "meter": "WSGI-start", - "project_id": None, - "recorded_at": "2014-05-06T02:53:03.020620", - "resource_id": "profiler-f5587500-07d1-41a0-b434-525d3c28ac49", - "source": "openstack", - "timestamp": "2014-05-06T02:52:59.225552", - "type": "gauge", - "unit": "sample", - "user_id": None, - "volume": 1.0 + "traits": + [ + { + "type": "string", + "name": "base_id", + "value": "7253ca8c-33b3-4f84-b4f1-f5a4311ddfa4" + }, + { + "type": "string", + "name": "host", + "value": "ubuntu" + }, + { + "type": "string", + "name": "name", + "value": "wsgi-stop" + }, + { + "type": "string", + "name": "parent_id", + "value": "7253ca8c-33b3-4f84-b4f1-f5a4311ddfa4" + }, + { + "type": "string", + "name": "project", + "value": "keystone" + }, + { + "type": "string", + "name": "service", + "value": "main" + }, + { + "type": "string", + "name": "timestamp", + "value": "2015-12-23T14:02:22.380405" + }, + { + "type": "string", + "name": "trace_id", + "value": "016c97fd-87f3-40b2-9b55-e431156b694b" + } + ], + "raw": {}, + "generated": "2015-12-23T10:41:38.406052", + "event_type": "profiler.main", + "message_id": "3256d9f1-48ba-4ac5-a50b-64fa42c6e264"}, + { + "traits": + [ + { + "type": "string", + "name": "base_id", + "value": "7253ca8c-33b3-4f84-b4f1-f5a4311ddfa4" + }, + { + "type": "string", + "name": "db.params", + "value": "[]" + }, + { + "type": "string", + "name": "db.statement", + "value": "SELECT 1" + }, + { + "type": "string", + "name": "host", + "value": "ubuntu" + }, + { + "type": "string", + "name": "name", + "value": "db-start" + }, + { + "type": "string", + "name": "parent_id", + "value": "06320327-2c2c-45ae-923a-515de890276a" + }, + { + "type": "string", + "name": "project", + "value": "keystone" + }, + { + "type": "string", + "name": "service", + "value": "main" + }, + { + "type": "string", + "name": "timestamp", + "value": "2015-12-23T14:02:22.395365" + }, + { + "type": "string", + "name": "trace_id", + "value": "1baf1d24-9ca9-4f4c-bd3f-01b7e0c0735a" + } + ], + "raw": {}, + "generated": "2015-12-23T10:41:38.984161", + "event_type": "profiler.main", + "message_id": "60368aa4-16f0-4f37-a8fb-89e92fdf36ff" }, - { - "id": "89558414-d4c9-11e3-a117-46c0b36ac153", - "metadata": { - "base_id": "f5587500-07d1-41a0-b434-525d3c28ac49", - "event_type": "profiler.nova", - "host": "0.0.0.0", - "service": "osapi_compute", - "project": "nova", - "info.db:multiparams": "(immutabledict({}),)", - "info.db:params": "{}", - "name": "db-start", - "parent_id": "837eb0bd-323a-4e3f-b223-3be78ad86aab", - "trace_id": "f8ab042e-1085-4df2-9f3a-cfb6390b8090" - }, - "meter": "db-start", - "project_id": None, - "recorded_at": "2014-05-06T02:53:03.038692", - "resource_id": "profiler-f5587500-07d1-41a0-b434-525d3c28ac49", - "source": "openstack", - "timestamp": "2014-05-06T02:52:59.273422", - "type": "gauge", - "unit": "sample", - "user_id": None, - "volume": 1.0 + "traits": + [ + { + "type": "string", + "name": "base_id", + "value": "7253ca8c-33b3-4f84-b4f1-f5a4311ddfa4" + }, + { + "type": "string", + "name": "host", + "value": "ubuntu" + }, + { + "type": "string", + "name": "name", + "value": "db-stop" + }, + { + "type": "string", + "name": "parent_id", + "value": "06320327-2c2c-45ae-923a-515de890276a" + }, + { + "type": "string", + "name": "project", + "value": "keystone" + }, + { + "type": "string", + "name": "service", + "value": "main" + }, + { + "type": "string", + "name": "timestamp", + "value": "2015-12-23T14:02:22.415486" + }, + { + "type": "string", + "name": "trace_id", + "value": "1baf1d24-9ca9-4f4c-bd3f-01b7e0c0735a" + } + ], + "raw": {}, + "generated": "2015-12-23T10:41:39.019378", + "event_type": "profiler.main", + "message_id": "3fbeb339-55c5-4f28-88e4-15bee251dd3d" }, { - "id": "892d3018-d4c9-11e3-a117-46c0b36ac153", - "metadata": { - "base_id": "f5587500-07d1-41a0-b434-525d3c28ac49", - "event_type": "profiler.generic", - "host": "ubuntu", - "service": "nova-conductor", - "project": "nova", - "name": "db-stop", - "parent_id": "aad4748f-99d5-45c8-be0a-4025894bb3db", - "trace_id": "8afee05d-0ad2-4515-bd03-db0f2d30eed0" - }, - "meter": "db-stop", - "project_id": None, - "recorded_at": "2014-05-06T02:53:02.894015", - "resource_id": "profiler-f5587500-07d1-41a0-b434-525d3c28ac49", - "source": "openstack", - "timestamp": "2014-05-06T02:53:00.473201", - "type": "gauge", - "unit": "sample", - "user_id": None, - "volume": 1.0 + "traits": + [ + { + "type": "string", + "name": "base_id", + "value": "7253ca8c-33b3-4f84-b4f1-f5a4311ddfa4" + }, + { + "type": "string", + "name": "host", + "value": "ubuntu" + }, + { + "type": "string", + "name": "method", + "value": "GET" + }, + { + "type": "string", + "name": "name", + "value": "wsgi-start" + }, + { + "type": "string", + "name": "parent_id", + "value": "7253ca8c-33b3-4f84-b4f1-f5a4311ddfa4" + }, + { + "type": "string", + "name": "project", + "value": "keystone" + }, + { + "type": "string", + "name": "service", + "value": "main" + }, + { + "type": "string", + "name": "timestamp", + "value": "2015-12-23T14:02:22.427444" + }, + { + "type": "string", + "name": "trace_id", + "value": "016c97fd-87f3-40b2-9b55-e431156b694b" + } + ], + "raw": {}, + "generated": "2015-12-23T10:41:38.360409", + "event_type": "profiler.main", + "message_id": "57b971a9-572f-4f29-9838-3ed2564c6b5b" } ] - excepted = { - "info": { - "finished": 1247, - "name": "total", - "started": 0 - }, - "children": [ - { - "info": { - "finished": 131, - "host": "0.0.0.0", - "service": "osapi_compute", - "name": "WSGI", - "project": "nova", - "started": 0 - }, - "parent_id": "82281b35-63aa-45fc-8578-5a32a66370ab", - "trace_id": "837eb0bd-323a-4e3f-b223-3be78ad86aab", - "children": [{ - "children": [], - "info": { - "finished": 47, - "host": "0.0.0.0", - "service": "osapi_compute", - "project": "nova", - "info.db:multiparams": "(immutabledict({}),)", - "info.db:params": "{}", - "name": "db", - "started": 47 - }, - - "parent_id": "837eb0bd-323a-4e3f-b223-3be78ad86aab", - "trace_id": "f8ab042e-1085-4df2-9f3a-cfb6390b8090" - }] - }, - { - "children": [], - "info": { - "finished": 1247, - "host": "ubuntu", - "name": "db", - "service": "nova-conductor", - "project": "nova", - "started": 1247 - }, - "parent_id": "aad4748f-99d5-45c8-be0a-4025894bb3db", - "trace_id": "8afee05d-0ad2-4515-bd03-db0f2d30eed0" - } - ] - } + expected = {"children": [ + {"children": [ + {"children": [], + "info": {"finished": 76, + "host": "ubuntu", + "meta.db.params": "[]", + "meta.db.statement": "SELECT 1", + "meta.host": "ubuntu", + "name": "db", + "project": "keystone", + "service": "main", + "started": 56}, + "parent_id": "06320327-2c2c-45ae-923a-515de890276a", + "trace_id": "1baf1d24-9ca9-4f4c-bd3f-01b7e0c0735a"}], + "info": {"finished": 0, + "host": "ubuntu", + "meta.host": "ubuntu", + "meta.method": "POST", + "name": "wsgi", + "project": "keystone", + "service": "main", + "started": 0}, + "parent_id": "7253ca8c-33b3-4f84-b4f1-f5a4311ddfa4", + "trace_id": "06320327-2c2c-45ae-923a-515de890276a"}, + {"children": [], + "info": {"finished": 41, + "host": "ubuntu", + "meta.host": "ubuntu", + "meta.method": "GET", + "name": "wsgi", + "project": "keystone", + "service": "main", + "started": 88}, + "parent_id": "7253ca8c-33b3-4f84-b4f1-f5a4311ddfa4", + "trace_id": "016c97fd-87f3-40b2-9b55-e431156b694b"}], + "info": {"finished": 88, "name": "total", "started": 0}} - self.assertEqual(ceilometer.parse_notifications(samples), excepted) + self.assertEqual(expected, ceilometer.parse_notifications(events)) def test_get_notifications(self): mock_ceil_client = mock.MagicMock() results = [mock.MagicMock(), mock.MagicMock()] - mock_ceil_client.query_samples.query.return_value = results + mock_ceil_client.events.list.return_value = results base_id = "10" result = ceilometer.get_notifications(mock_ceil_client, base_id) - expected_filter = ( - "{\"=\": {\"resource_id\": \"profiler-%s\"}}" % base_id) - mock_ceil_client.query_samples.query.assert_called_once_with( - expected_filter, None, None) + expected_filter = [{"field": "base_id", "op": "eq", "value": base_id}] + mock_ceil_client.events.list.assert_called_once_with(expected_filter, + limit=100000) self.assertEqual(result, [results[0].to_dict(), results[1].to_dict()]) diff --git a/tests/test_profiler.py b/tests/test_profiler.py index 7f4f201..bf8874c 100644 --- a/tests/test_profiler.py +++ b/tests/test_profiler.py @@ -15,6 +15,7 @@ import collections import copy +import datetime import mock import re @@ -87,10 +88,13 @@ class ProfilerTestCase(test.TestCase): prof.start("test") self.assertEqual(prof.get_id(), "43") + @mock.patch("osprofiler.profiler.datetime") @mock.patch("osprofiler.profiler.uuid.uuid4") @mock.patch("osprofiler.profiler.notifier.notify") - def test_profiler_start(self, mock_notify, mock_uuid4): + def test_profiler_start(self, mock_notify, mock_uuid4, mock_datetime): mock_uuid4.return_value = "44" + now = datetime.datetime.utcnow() + mock_datetime.datetime.utcnow.return_value = now info = {"some": "info"} payload = { @@ -98,7 +102,8 @@ class ProfilerTestCase(test.TestCase): "base_id": "1", "parent_id": "2", "trace_id": "44", - "info": info + "info": info, + "timestamp": now, } prof = profiler._Profiler("secret", base_id="1", parent_id="2") @@ -106,8 +111,11 @@ class ProfilerTestCase(test.TestCase): mock_notify.assert_called_once_with(payload) + @mock.patch("osprofiler.profiler.datetime") @mock.patch("osprofiler.profiler.notifier.notify") - def test_profiler_stop(self, mock_notify): + def test_profiler_stop(self, mock_notify, mock_datetime): + now = datetime.datetime.utcnow() + mock_datetime.datetime.utcnow.return_value = now prof = profiler._Profiler("secret", base_id="1", parent_id="2") prof._trace_stack.append("44") prof._name.append("abc") @@ -120,7 +128,8 @@ class ProfilerTestCase(test.TestCase): "base_id": "1", "parent_id": "2", "trace_id": "44", - "info": info + "info": info, + "timestamp": now, } mock_notify.assert_called_once_with(payload) diff --git a/tests/test_sqlalchemy.py b/tests/test_sqlalchemy.py index 7c56049..1a6e75a 100644 --- a/tests/test_sqlalchemy.py +++ b/tests/test_sqlalchemy.py @@ -27,10 +27,7 @@ class SqlalchemyTracingTestCase(test.TestCase): handler = sqlalchemy._before_cursor_execute("sql") handler(mock.MagicMock(), 1, 2, 3, 4, 5) - expected_info = { - "db.statement": 2, - "db.params": 3 - } + expected_info = {"db": {"statement": 2, "params": 3}} mock_profiler.start.assert_called_once_with("sql", info=expected_info) @mock.patch("osprofiler.sqlalchemy.profiler") diff --git a/tests/test_web.py b/tests/test_web.py index 99513f4..060abd3 100644 --- a/tests/test_web.py +++ b/tests/test_web.py @@ -254,7 +254,6 @@ class WebMiddlewareTestCase(test.TestCase): parent_id="2") expected_info = { "request": { - "host_url": request.host_url, "path": request.path, "query": request.query_string, "method": request.method, |