From ecc8de8d6cccb06d7f4c8ecc144d37612ae1e9cc Mon Sep 17 00:00:00 2001 From: Dina Belova Date: Tue, 8 Dec 2015 14:32:10 +0300 Subject: [PATCH] Integrate OSProfiler and Nova * Add osprofiler wsgi middleware. This middleware is used for 2 things: 1) It checks that person who want to trace is trusted and knows secret HMAC key. 2) It starts tracing in case of proper trace headers and adds the first wsgi trace point with info about the HTTP request * Add initialization of osprofiler on start of a service Currently that includes oslo.messaging notifier instance creation to send Ceilometer backend notifications. oslo-spec: https://review.openstack.org/#/c/103825/ python-novaclient change: https://review.openstack.org/#/c/254699/ based on: https://review.openstack.org/#/c/105096/ Co-Authored-By: Boris Pavlovic Co-Authored-By: Munoz, Obed N Co-Authored-By: Roman Podoliaka Co-Authored-By: Tovin Seven Implements: blueprint osprofiler-support-in-nova Change-Id: I82d2badc8c1fcec27c3fce7c3c20e0f3b76414f1 --- etc/nova/api-paste.ini | 11 ++- nova/cells/rpcapi.py | 2 + nova/cert/rpcapi.py | 2 + nova/compute/api.py | 2 + nova/compute/rpcapi.py | 2 + nova/conductor/manager.py | 2 + nova/conductor/rpcapi.py | 3 + nova/config.py | 5 + nova/console/rpcapi.py | 2 + nova/consoleauth/rpcapi.py | 2 + nova/db/sqlalchemy/api.py | 10 ++ nova/image/api.py | 2 + nova/manager.py | 23 +++++ nova/network/api.py | 2 + nova/network/neutronv2/api.py | 3 +- nova/network/rpcapi.py | 2 + nova/profiler.py | 73 ++++++++++++++ nova/rpc.py | 44 ++++++++- nova/scheduler/rpcapi.py | 2 + nova/service.py | 17 ++++ nova/tests/unit/test_profiler.py | 96 +++++++++++++++++++ nova/tests/unit/test_rpc.py | 75 +++++++++++++++ nova/utils.py | 24 +++++ nova/virt/libvirt/vif.py | 2 + nova/virt/libvirt/volume/volume.py | 2 + ...d-osprofiler-support-b04f1e4cfa550440.yaml | 27 ++++++ setup.cfg | 4 + test-requirements.txt | 1 + tox.ini | 4 + 29 files changed, 439 insertions(+), 7 deletions(-) create mode 100644 nova/profiler.py create mode 100644 nova/tests/unit/test_profiler.py create mode 100644 releasenotes/notes/add-osprofiler-support-b04f1e4cfa550440.yaml diff --git a/etc/nova/api-paste.ini b/etc/nova/api-paste.ini index cbac3e9ea5bd..f180ab315198 100644 --- a/etc/nova/api-paste.ini +++ b/etc/nova/api-paste.ini @@ -28,13 +28,13 @@ use = call:nova.api.openstack.urlmap:urlmap_factory [composite:openstack_compute_api_v21] use = call:nova.api.auth:pipeline_factory_v21 -noauth2 = cors http_proxy_to_wsgi compute_req_id faultwrap sizelimit noauth2 osapi_compute_app_v21 -keystone = cors http_proxy_to_wsgi compute_req_id faultwrap sizelimit authtoken keystonecontext osapi_compute_app_v21 +noauth2 = cors http_proxy_to_wsgi compute_req_id faultwrap sizelimit osprofiler noauth2 osapi_compute_app_v21 +keystone = cors http_proxy_to_wsgi compute_req_id faultwrap sizelimit osprofiler authtoken keystonecontext osapi_compute_app_v21 [composite:openstack_compute_api_v21_legacy_v2_compatible] use = call:nova.api.auth:pipeline_factory_v21 -noauth2 = cors http_proxy_to_wsgi compute_req_id faultwrap sizelimit noauth2 legacy_v2_compatible osapi_compute_app_v21 -keystone = cors http_proxy_to_wsgi compute_req_id faultwrap sizelimit authtoken keystonecontext legacy_v2_compatible osapi_compute_app_v21 +noauth2 = cors http_proxy_to_wsgi compute_req_id faultwrap sizelimit osprofiler noauth2 legacy_v2_compatible osapi_compute_app_v21 +keystone = cors http_proxy_to_wsgi compute_req_id faultwrap sizelimit osprofiler authtoken keystonecontext legacy_v2_compatible osapi_compute_app_v21 [filter:request_id] paste.filter_factory = oslo_middleware:RequestId.factory @@ -48,6 +48,9 @@ paste.filter_factory = nova.api.openstack:FaultWrapper.factory [filter:noauth2] paste.filter_factory = nova.api.openstack.auth:NoAuthMiddleware.factory +[filter:osprofiler] +paste.filter_factory = nova.profiler:WsgiMiddleware.factory + [filter:sizelimit] paste.filter_factory = oslo_middleware:RequestBodySizeLimiter.factory diff --git a/nova/cells/rpcapi.py b/nova/cells/rpcapi.py index 78fb764a2223..0ae6716449d4 100644 --- a/nova/cells/rpcapi.py +++ b/nova/cells/rpcapi.py @@ -32,6 +32,7 @@ from nova import exception from nova.i18n import _LE from nova import objects from nova.objects import base as objects_base +from nova import profiler from nova import rpc LOG = logging.getLogger(__name__) @@ -39,6 +40,7 @@ LOG = logging.getLogger(__name__) CONF = nova.conf.CONF +@profiler.trace_cls("rpc") class CellsAPI(object): '''Cells client-side RPC API diff --git a/nova/cert/rpcapi.py b/nova/cert/rpcapi.py index 74f80966a602..cc418844b0d7 100644 --- a/nova/cert/rpcapi.py +++ b/nova/cert/rpcapi.py @@ -19,11 +19,13 @@ Client side of the cert manager RPC API. import oslo_messaging as messaging import nova.conf +from nova import profiler from nova import rpc CONF = nova.conf.CONF +@profiler.trace_cls("rpc") class CertAPI(object): '''Client side of the cert rpc API. diff --git a/nova/compute/api.py b/nova/compute/api.py index d3ec801c6cbf..c9324aba1254 100644 --- a/nova/compute/api.py +++ b/nova/compute/api.py @@ -76,6 +76,7 @@ from nova.objects import keypair as keypair_obj from nova.objects import quotas as quotas_obj from nova.pci import request as pci_request import nova.policy +from nova import profiler from nova import rpc from nova.scheduler import client as scheduler_client from nova.scheduler import utils as scheduler_utils @@ -191,6 +192,7 @@ def _diff_dict(orig, new): return result +@profiler.trace_cls("compute_api") class API(base.Base): """API for interacting with the compute manager.""" diff --git a/nova/compute/rpcapi.py b/nova/compute/rpcapi.py index 3284d01b9127..b7aa07d4fd11 100644 --- a/nova/compute/rpcapi.py +++ b/nova/compute/rpcapi.py @@ -27,6 +27,7 @@ from nova import objects from nova.objects import base as objects_base from nova.objects import migrate_data as migrate_data_obj from nova.objects import service as service_obj +from nova import profiler from nova import rpc CONF = nova.conf.CONF @@ -54,6 +55,7 @@ def _compute_host(host, instance): return instance.host +@profiler.trace_cls("rpc") class ComputeAPI(object): '''Client side of the compute rpc API. diff --git a/nova/conductor/manager.py b/nova/conductor/manager.py index 476d9241bdc6..177cd33fa122 100644 --- a/nova/conductor/manager.py +++ b/nova/conductor/manager.py @@ -42,6 +42,7 @@ from nova import network from nova import notifications from nova import objects from nova.objects import base as nova_object +from nova import profiler from nova import rpc from nova.scheduler import client as scheduler_client from nova.scheduler import utils as scheduler_utils @@ -176,6 +177,7 @@ def obj_target_cell(obj, cell): yield +@profiler.trace_cls("rpc") class ComputeTaskManager(base.Base): """Namespace for compute methods. diff --git a/nova/conductor/rpcapi.py b/nova/conductor/rpcapi.py index e94bcd80347a..3b7097c257f6 100644 --- a/nova/conductor/rpcapi.py +++ b/nova/conductor/rpcapi.py @@ -21,11 +21,13 @@ from oslo_versionedobjects import base as ovo_base import nova.conf from nova.objects import base as objects_base +from nova import profiler from nova import rpc CONF = nova.conf.CONF +@profiler.trace_cls("rpc") class ConductorAPI(object): """Client side of the conductor RPC API @@ -247,6 +249,7 @@ class ConductorAPI(object): object_versions=object_versions) +@profiler.trace_cls("rpc") class ComputeTaskAPI(object): """Client side of the conductor 'compute' namespaced RPC API diff --git a/nova/config.py b/nova/config.py index db64ddf8f74a..a9b265701f23 100644 --- a/nova/config.py +++ b/nova/config.py @@ -16,6 +16,7 @@ # under the License. from oslo_log import log +from oslo_utils import importutils from nova.common import config import nova.conf @@ -23,6 +24,8 @@ from nova.db.sqlalchemy import api as sqlalchemy_api from nova import rpc from nova import version +profiler = importutils.try_import('osprofiler.opts') + CONF = nova.conf.CONF @@ -39,6 +42,8 @@ def parse_args(argv, default_config_files=None, configure_db=True, log.set_defaults(default_log_levels=log.get_default_log_levels() + extra_default_log_levels) rpc.set_defaults(control_exchange='nova') + if profiler: + profiler.set_defaults(CONF) config.set_middleware_defaults() CONF(argv[1:], diff --git a/nova/console/rpcapi.py b/nova/console/rpcapi.py index e78260d628d9..3141a7bbfa0e 100644 --- a/nova/console/rpcapi.py +++ b/nova/console/rpcapi.py @@ -19,11 +19,13 @@ Client side of the console RPC API. import oslo_messaging as messaging import nova.conf +from nova import profiler from nova import rpc CONF = nova.conf.CONF +@profiler.trace_cls("rpc") class ConsoleAPI(object): '''Client side of the console rpc API. diff --git a/nova/consoleauth/rpcapi.py b/nova/consoleauth/rpcapi.py index 18810c99edda..1c7dceaa5e58 100644 --- a/nova/consoleauth/rpcapi.py +++ b/nova/consoleauth/rpcapi.py @@ -19,11 +19,13 @@ Client side of the consoleauth RPC API. import oslo_messaging as messaging import nova.conf +from nova import profiler from nova import rpc CONF = nova.conf.CONF +@profiler.trace_cls("rpc") class ConsoleAuthAPI(object): '''Client side of the consoleauth rpc API. diff --git a/nova/db/sqlalchemy/api.py b/nova/db/sqlalchemy/api.py index fb3dc9eedf26..407d8a725315 100644 --- a/nova/db/sqlalchemy/api.py +++ b/nova/db/sqlalchemy/api.py @@ -31,6 +31,7 @@ from oslo_db.sqlalchemy import update_match from oslo_db.sqlalchemy import utils as sqlalchemyutils from oslo_log import log as logging from oslo_utils import excutils +from oslo_utils import importutils from oslo_utils import timeutils from oslo_utils import uuidutils import six @@ -68,6 +69,7 @@ from nova.i18n import _, _LI, _LE, _LW from nova import quota from nova import safe_utils +profiler_sqlalchemy = importutils.try_import('osprofiler.sqlalchemy') CONF = nova.conf.CONF @@ -110,6 +112,14 @@ def configure(conf): main_context_manager.configure(**_get_db_conf(conf.database)) api_context_manager.configure(**_get_db_conf(conf.api_database)) + if profiler_sqlalchemy and CONF.profiler.enabled \ + and CONF.profiler.trace_sqlalchemy: + + main_context_manager.append_on_engine_create( + lambda eng: profiler_sqlalchemy.add_tracing(sa, eng, "db")) + api_context_manager.append_on_engine_create( + lambda eng: profiler_sqlalchemy.add_tracing(sa, eng, "db")) + def create_context_manager(connection=None): """Create a database context manager object. diff --git a/nova/image/api.py b/nova/image/api.py index b390e10a1757..e2d6192c59bb 100644 --- a/nova/image/api.py +++ b/nova/image/api.py @@ -16,8 +16,10 @@ images used by the compute layer. """ from nova.image import glance +from nova import profiler +@profiler.trace_cls("nova_image") class API(object): """Responsible for exposing a relatively stable internal API for other diff --git a/nova/manager.py b/nova/manager.py index 71003002642b..c73d18fbad16 100644 --- a/nova/manager.py +++ b/nova/manager.py @@ -52,9 +52,11 @@ This module provides Manager, a base class for managers. """ from oslo_service import periodic_task +import six import nova.conf from nova.db import base +from nova import profiler from nova import rpc @@ -66,7 +68,28 @@ class PeriodicTasks(periodic_task.PeriodicTasks): super(PeriodicTasks, self).__init__(CONF) +class ManagerMeta(profiler.get_traced_meta(), type(PeriodicTasks)): + """Metaclass to trace all children of a specific class. + + This metaclass wraps every public method (not starting with _ or __) + of the class using it. All children classes of the class using ManagerMeta + will be profiled as well. + + Adding this metaclass requires that the __trace_args__ attribute be added + to the class we want to modify. That attribute is a dictionary + with one mandatory key: "name". "name" defines the name + of the action to be traced (for example, wsgi, rpc, db). + + The OSprofiler-based tracing, although, will only happen if profiler + instance was initiated somewhere before in the thread, that can only happen + if profiling is enabled in nova.conf and the API call to Nova API contained + specific headers. + """ + + +@six.add_metaclass(ManagerMeta) class Manager(base.Base, PeriodicTasks): + __trace_args__ = {"name": "rpc"} def __init__(self, host=None, db_driver=None, service_name='undefined'): if not host: diff --git a/nova/network/api.py b/nova/network/api.py index 2efbe69452ad..c7d6827a69ce 100644 --- a/nova/network/api.py +++ b/nova/network/api.py @@ -28,6 +28,7 @@ from nova.network import model as network_model from nova.network import rpcapi as network_rpcapi from nova import objects from nova.objects import base as obj_base +from nova import profiler from nova import utils CONF = cfg.CONF @@ -35,6 +36,7 @@ CONF = cfg.CONF LOG = logging.getLogger(__name__) +@profiler.trace_cls("network_api") class API(base_api.NetworkAPI): """API for doing networking via the nova-network network manager. diff --git a/nova/network/neutronv2/api.py b/nova/network/neutronv2/api.py index 1084e78d6bf3..f9642b233ec2 100644 --- a/nova/network/neutronv2/api.py +++ b/nova/network/neutronv2/api.py @@ -39,9 +39,9 @@ from nova.pci import request as pci_request from nova.pci import utils as pci_utils from nova.pci import whitelist as pci_whitelist from nova.policies import base as base_policies +from nova import profiler from nova import service_auth - CONF = nova.conf.CONF LOG = logging.getLogger(__name__) @@ -74,6 +74,7 @@ def _load_auth_plugin(conf): raise neutron_client_exc.Unauthorized(message=err_msg) +@profiler.trace_cls("neutron_api") class ClientWrapper(clientv20.Client): """A Neutron client wrapper class. diff --git a/nova/network/rpcapi.py b/nova/network/rpcapi.py index 110f44c8cbcd..e9ef4edd2592 100644 --- a/nova/network/rpcapi.py +++ b/nova/network/rpcapi.py @@ -22,12 +22,14 @@ from oslo_serialization import jsonutils import nova.conf from nova import exception from nova.objects import base as objects_base +from nova import profiler from nova import rpc CONF = nova.conf.CONF +@profiler.trace_cls("rpc") class NetworkAPI(object): '''Client side of the network rpc API. diff --git a/nova/profiler.py b/nova/profiler.py new file mode 100644 index 000000000000..71d2eb09b0d2 --- /dev/null +++ b/nova/profiler.py @@ -0,0 +1,73 @@ +# Copyright 2016 IBM Corporation. +# All Rights Reserved. +# +# Licensed under the Apache License, Version 2.0 (the "License"); you may +# not use this file except in compliance with the License. You may obtain +# a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, WITHOUT +# WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the +# License for the specific language governing permissions and limitations +# under the License. + +from oslo_utils import importutils +import webob.dec + +import nova.conf + +profiler = importutils.try_import('osprofiler.profiler') +profiler_web = importutils.try_import('osprofiler.web') + +CONF = nova.conf.CONF + + +class WsgiMiddleware(object): + + def __init__(self, application, **kwargs): + self.application = application + + @classmethod + def factory(cls, global_conf, **local_conf): + if profiler_web: + return profiler_web.WsgiMiddleware.factory(global_conf, + **local_conf) + + def filter_(app): + return cls(app, **local_conf) + + return filter_ + + @webob.dec.wsgify + def __call__(self, request): + return request.get_response(self.application) + + +def get_traced_meta(): + if profiler and 'profiler' in CONF and CONF.profiler.enabled: + return profiler.TracedMeta + else: + # NOTE(rpodolyaka): if we do not return a child of type, then Python + # fails to build a correct MRO when osprofiler is not installed + class NoopMeta(type): + pass + return NoopMeta + + +def trace_cls(name, **kwargs): + """Wrap the OSProfiler trace_cls decorator so that it will not try to + patch the class unless OSProfiler is present and enabled in the config + + :param name: The name of action. E.g. wsgi, rpc, db, etc.. + :param kwargs: Any other keyword args used by profiler.trace_cls + """ + + def decorator(cls): + if profiler and 'profiler' in CONF and CONF.profiler.enabled: + trace_decorator = profiler.trace_cls(name, kwargs) + return trace_decorator(cls) + return cls + + return decorator diff --git a/nova/rpc.py b/nova/rpc.py index 21345b18ef38..9e170a2a60da 100644 --- a/nova/rpc.py +++ b/nova/rpc.py @@ -32,6 +32,7 @@ from oslo_log import log as logging import oslo_messaging as messaging from oslo_serialization import jsonutils from oslo_service import periodic_task +from oslo_utils import importutils from oslo_utils import timeutils import nova.conf @@ -40,6 +41,8 @@ import nova.exception from nova.i18n import _ from nova import objects +profiler = importutils.try_import("osprofiler.profiler") + CONF = nova.conf.CONF @@ -150,13 +153,45 @@ class RequestContextSerializer(messaging.Serializer): return nova.context.RequestContext.from_dict(context) +class ProfilerRequestContextSerializer(RequestContextSerializer): + def serialize_context(self, context): + _context = super(ProfilerRequestContextSerializer, + self).serialize_context(context) + + prof = profiler.get() + if prof: + # FIXME(DinaBelova): we'll add profiler.get_info() method + # to extract this info -> we'll need to update these lines + trace_info = { + "hmac_key": prof.hmac_key, + "base_id": prof.get_base_id(), + "parent_id": prof.get_id() + } + _context.update({"trace_info": trace_info}) + + return _context + + def deserialize_context(self, context): + trace_info = context.pop("trace_info", None) + if trace_info: + profiler.init(**trace_info) + + return super(ProfilerRequestContextSerializer, + self).deserialize_context(context) + + def get_transport_url(url_str=None): return messaging.TransportURL.parse(CONF, url_str, TRANSPORT_ALIASES) def get_client(target, version_cap=None, serializer=None): assert TRANSPORT is not None - serializer = RequestContextSerializer(serializer) + + if profiler: + serializer = ProfilerRequestContextSerializer(serializer) + else: + serializer = RequestContextSerializer(serializer) + return messaging.RPCClient(TRANSPORT, target, version_cap=version_cap, @@ -165,7 +200,12 @@ def get_client(target, version_cap=None, serializer=None): def get_server(target, endpoints, serializer=None): assert TRANSPORT is not None - serializer = RequestContextSerializer(serializer) + + if profiler: + serializer = ProfilerRequestContextSerializer(serializer) + else: + serializer = RequestContextSerializer(serializer) + return messaging.get_rpc_server(TRANSPORT, target, endpoints, diff --git a/nova/scheduler/rpcapi.py b/nova/scheduler/rpcapi.py index d636fd03a420..d776fe769976 100644 --- a/nova/scheduler/rpcapi.py +++ b/nova/scheduler/rpcapi.py @@ -20,11 +20,13 @@ import oslo_messaging as messaging import nova.conf from nova.objects import base as objects_base +from nova import profiler from nova import rpc CONF = nova.conf.CONF +@profiler.trace_cls("rpc") class SchedulerAPI(object): '''Client side of the scheduler rpc API. diff --git a/nova/service.py b/nova/service.py index d2b622a32a1b..5a15cd95a166 100644 --- a/nova/service.py +++ b/nova/service.py @@ -43,6 +43,10 @@ from nova import utils from nova import version from nova import wsgi +osprofiler = importutils.try_import("osprofiler") +osprofiler_initializer = importutils.try_import("osprofiler.initializer") + + LOG = logging.getLogger(__name__) CONF = nova.conf.CONF @@ -81,6 +85,17 @@ def _update_service_ref(service): service.save() +def setup_profiler(binary, host): + if osprofiler and CONF.profiler.enabled: + osprofiler.initializer.init_from_conf( + conf=CONF, + context=context.get_admin_context().to_dict(), + project="nova", + service=binary, + host=host) + LOG.info(_LI("OSProfiler is enabled.")) + + class Service(service.Service): """Service object for binaries running on hosts. @@ -110,6 +125,7 @@ class Service(service.Service): if objects_base.NovaObject.indirection_api: conductor_api = conductor.API() conductor_api.wait_until_ready(context.get_admin_context()) + setup_profiler(binary, self.host) def __repr__(self): return "<%(cls_name)s: host=%(host)s, binary=%(binary)s, " \ @@ -319,6 +335,7 @@ class WSGIService(service.Service): # Pull back actual port used self.port = self.server.port self.backdoor_port = None + setup_profiler(name, self.host) def reset(self): """Reset server greenpool size to default and service version cache. diff --git a/nova/tests/unit/test_profiler.py b/nova/tests/unit/test_profiler.py new file mode 100644 index 000000000000..482c996f917d --- /dev/null +++ b/nova/tests/unit/test_profiler.py @@ -0,0 +1,96 @@ +# Copyright 2016 OpenStack Foundation +# All Rights Reserved. +# +# Licensed under the Apache License, Version 2.0 (the "License"); you may +# not use this file except in compliance with the License. You may obtain +# a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, WITHOUT +# WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the +# License for the specific language governing permissions and limitations +# under the License. + +import inspect +import os + +from oslo_utils import importutils +import osprofiler.opts as profiler +import six.moves as six + +from nova import conf +from nova import test + + +class TestProfiler(test.NoDBTestCase): + def test_all_public_methods_are_traced(self): + # NOTE(rpodolyaka): osprofiler only wraps class methods when option + # CONF.profiler.enabled is set to True and the default value is False, + # which means in our usual test run we use original, not patched + # classes. In order to test, that we actually properly wrap methods + # we are interested in, this test case sets CONF.profiler.enabled to + # True and reloads all the affected Python modules (application of + # decorators and metaclasses is performed at module import time). + # Unfortunately, this leads to subtle failures of other test cases + # (e.g. super() is performed on a "new" version of a class instance + # created after a module reload while the class name is a reference to + # an "old" version of the class). Thus, this test is run in isolation. + if not os.getenv('TEST_OSPROFILER', False): + self.skipTest('TEST_OSPROFILER env variable is not set. ' + 'Skipping osprofiler tests...') + + # reinitialize the metaclass after enabling osprofiler + profiler.set_defaults(conf.CONF) + self.flags(enabled=True, group='profiler') + six.reload_module(importutils.import_module('nova.manager')) + + classes = [ + 'nova.api.manager.MetadataManager', + 'nova.cells.manager.CellsManager', + 'nova.cells.rpcapi.CellsAPI', + 'nova.cert.manager.CertManager', + 'nova.cert.rpcapi.CertAPI', + 'nova.compute.api.API', + 'nova.compute.manager.ComputeManager', + 'nova.compute.rpcapi.ComputeAPI', + 'nova.conductor.manager.ComputeTaskManager', + 'nova.conductor.manager.ConductorManager', + 'nova.conductor.rpcapi.ComputeTaskAPI', + 'nova.conductor.rpcapi.ConductorAPI', + 'nova.console.manager.ConsoleProxyManager', + 'nova.console.rpcapi.ConsoleAPI', + 'nova.consoleauth.manager.ConsoleAuthManager', + 'nova.consoleauth.rpcapi.ConsoleAuthAPI', + 'nova.image.api.API', + 'nova.network.api.API', + 'nova.network.manager.FlatDHCPManager', + 'nova.network.manager.FlatManager', + 'nova.network.manager.VlanManager', + 'nova.network.neutronv2.api.ClientWrapper', + 'nova.network.rpcapi.NetworkAPI', + 'nova.scheduler.manager.SchedulerManager', + 'nova.scheduler.rpcapi.SchedulerAPI', + 'nova.virt.libvirt.vif.LibvirtGenericVIFDriver', + 'nova.virt.libvirt.volume.volume.LibvirtBaseVolumeDriver', + ] + for clsname in classes: + # give the metaclass and trace_cls() decorator a chance to patch + # methods of the classes above + six.reload_module( + importutils.import_module(clsname.rsplit('.', 1)[0])) + cls = importutils.import_class(clsname) + + for attr, obj in cls.__dict__.items(): + # only public methods are traced + if attr.startswith('_'): + continue + # only checks callables + if not (inspect.ismethod(obj) or inspect.isfunction(obj)): + continue + # osprofiler skips static methods + if isinstance(obj, staticmethod): + continue + + self.assertTrue(getattr(obj, '__traced__', False), obj) diff --git a/nova/tests/unit/test_rpc.py b/nova/tests/unit/test_rpc.py index c71551193f0e..3f50efec2118 100644 --- a/nova/tests/unit/test_rpc.py +++ b/nova/tests/unit/test_rpc.py @@ -182,6 +182,7 @@ class TestRPC(testtools.TestCase): mock_url.parse.assert_called_once_with(conf, None, rpc.TRANSPORT_ALIASES) + @mock.patch.object(rpc, 'profiler', None) @mock.patch.object(rpc, 'RequestContextSerializer') @mock.patch.object(messaging, 'RPCClient') def test_get_client(self, mock_client, mock_ser): @@ -199,6 +200,7 @@ class TestRPC(testtools.TestCase): serializer=ser) self.assertEqual('client', client) + @mock.patch.object(rpc, 'profiler', None) @mock.patch.object(rpc, 'RequestContextSerializer') @mock.patch.object(messaging, 'get_rpc_server') def test_get_server(self, mock_get, mock_ser): @@ -216,6 +218,42 @@ class TestRPC(testtools.TestCase): executor='eventlet', serializer=ser) self.assertEqual('server', server) + @mock.patch.object(rpc, 'profiler', mock.Mock()) + @mock.patch.object(rpc, 'ProfilerRequestContextSerializer') + @mock.patch.object(messaging, 'RPCClient') + def test_get_client_profiler_enabled(self, mock_client, mock_ser): + rpc.TRANSPORT = mock.Mock() + tgt = mock.Mock() + ser = mock.Mock() + mock_client.return_value = 'client' + mock_ser.return_value = ser + + client = rpc.get_client(tgt, version_cap='1.0', serializer='foo') + + mock_ser.assert_called_once_with('foo') + mock_client.assert_called_once_with(rpc.TRANSPORT, + tgt, version_cap='1.0', + serializer=ser) + self.assertEqual('client', client) + + @mock.patch.object(rpc, 'profiler', mock.Mock()) + @mock.patch.object(rpc, 'ProfilerRequestContextSerializer') + @mock.patch.object(messaging, 'get_rpc_server') + def test_get_server_profiler_enabled(self, mock_get, mock_ser): + rpc.TRANSPORT = mock.Mock() + ser = mock.Mock() + tgt = mock.Mock() + ends = mock.Mock() + mock_ser.return_value = ser + mock_get.return_value = 'server' + + server = rpc.get_server(tgt, ends, serializer='foo') + + mock_ser.assert_called_once_with('foo') + mock_get.assert_called_once_with(rpc.TRANSPORT, tgt, ends, + executor='eventlet', serializer=ser) + self.assertEqual('server', server) + def test_get_notifier(self): rpc.LEGACY_NOTIFIER = mock.Mock() mock_prep = mock.Mock() @@ -364,6 +402,43 @@ class TestRequestContextSerializer(test.NoDBTestCase): mock_req.from_dict.assert_called_once_with('context') +class TestProfilerRequestContextSerializer(test.NoDBTestCase): + def setUp(self): + super(TestProfilerRequestContextSerializer, self).setUp() + self.ser = rpc.ProfilerRequestContextSerializer(mock.Mock()) + + @mock.patch('nova.rpc.profiler') + def test_serialize_context(self, mock_profiler): + prof = mock_profiler.get.return_value + prof.hmac_key = 'swordfish' + prof.get_base_id.return_value = 'baseid' + prof.get_id.return_value = 'parentid' + + context = mock.Mock() + context.to_dict.return_value = {'project_id': 'test'} + + self.assertEqual({'project_id': 'test', + 'trace_info': { + 'hmac_key': 'swordfish', + 'base_id': 'baseid', + 'parent_id': 'parentid'}}, + self.ser.serialize_context(context)) + + @mock.patch('nova.rpc.profiler') + def test_deserialize_context(self, mock_profiler): + serialized = {'project_id': 'test', + 'trace_info': { + 'hmac_key': 'swordfish', + 'base_id': 'baseid', + 'parent_id': 'parentid'}} + + context = self.ser.deserialize_context(serialized) + + self.assertEqual('test', context.project_id) + mock_profiler.init.assert_called_once_with( + hmac_key='swordfish', base_id='baseid', parent_id='parentid') + + class TestClientRouter(test.NoDBTestCase): @mock.patch('nova.objects.InstanceMapping.get_by_instance_uuid') @mock.patch('nova.rpc.create_transport') diff --git a/nova/utils.py b/nova/utils.py index d775e579aa2f..5a4b783452f3 100644 --- a/nova/utils.py +++ b/nova/utils.py @@ -60,6 +60,8 @@ from nova.i18n import _, _LE, _LI, _LW import nova.network from nova import safe_utils +profiler = importutils.try_import('osprofiler.profiler') + CONF = nova.conf.CONF @@ -1045,6 +1047,22 @@ def validate_integer(value, name, min_value=None, max_value=None): return value +def _serialize_profile_info(): + if not profiler: + return None + prof = profiler.get() + trace_info = None + if prof: + # FIXME(DinaBelova): we'll add profiler.get_info() method + # to extract this info -> we'll need to update these lines + trace_info = { + "hmac_key": prof.hmac_key, + "base_id": prof.get_base_id(), + "parent_id": prof.get_id() + } + return trace_info + + def spawn(func, *args, **kwargs): """Passthrough method for eventlet.spawn. @@ -1056,6 +1074,7 @@ def spawn(func, *args, **kwargs): context when using this method to spawn a new thread. """ _context = common_context.get_current() + profiler_info = _serialize_profile_info() @functools.wraps(func) def context_wrapper(*args, **kwargs): @@ -1063,6 +1082,8 @@ def spawn(func, *args, **kwargs): # available for the logger to pull from threadlocal storage. if _context is not None: _context.update_store() + if profiler_info and profiler: + profiler.init(**profiler_info) return func(*args, **kwargs) return eventlet.spawn(context_wrapper, *args, **kwargs) @@ -1079,6 +1100,7 @@ def spawn_n(func, *args, **kwargs): context when using this method to spawn a new thread. """ _context = common_context.get_current() + profiler_info = _serialize_profile_info() @functools.wraps(func) def context_wrapper(*args, **kwargs): @@ -1086,6 +1108,8 @@ def spawn_n(func, *args, **kwargs): # available for the logger to pull from threadlocal storage. if _context is not None: _context.update_store() + if profiler_info and profiler: + profiler.init(**profiler_info) func(*args, **kwargs) eventlet.spawn_n(context_wrapper, *args, **kwargs) diff --git a/nova/virt/libvirt/vif.py b/nova/virt/libvirt/vif.py index 6ab2fa7c57d6..1c1583bfa4e0 100644 --- a/nova/virt/libvirt/vif.py +++ b/nova/virt/libvirt/vif.py @@ -34,6 +34,7 @@ from nova.network import linux_net from nova.network import model as network_model from nova.network import os_vif_util from nova import objects +from nova import profiler from nova import utils from nova.virt.libvirt import config as vconfig from nova.virt.libvirt import designer @@ -82,6 +83,7 @@ def is_vif_model_valid_for_virt(virt_type, vif_model): return vif_model in valid_models[virt_type] +@profiler.trace_cls("vif_driver") class LibvirtGenericVIFDriver(object): """Generic VIF driver for libvirt networking.""" diff --git a/nova/virt/libvirt/volume/volume.py b/nova/virt/libvirt/volume/volume.py index fff56c7931ac..237ee0ca5ddf 100644 --- a/nova/virt/libvirt/volume/volume.py +++ b/nova/virt/libvirt/volume/volume.py @@ -23,6 +23,7 @@ import nova.conf from nova import exception from nova.i18n import _LE from nova.i18n import _LW +from nova import profiler from nova.virt.libvirt import config as vconfig import nova.virt.libvirt.driver from nova.virt.libvirt import host @@ -35,6 +36,7 @@ CONF = nova.conf.CONF SHOULD_LOG_DISCARD_WARNING = True +@profiler.trace_cls("volume_api") class LibvirtBaseVolumeDriver(object): """Base class for volume drivers.""" def __init__(self, host, is_block_dev): diff --git a/releasenotes/notes/add-osprofiler-support-b04f1e4cfa550440.yaml b/releasenotes/notes/add-osprofiler-support-b04f1e4cfa550440.yaml new file mode 100644 index 000000000000..dda94eacb08b --- /dev/null +++ b/releasenotes/notes/add-osprofiler-support-b04f1e4cfa550440.yaml @@ -0,0 +1,27 @@ +--- +features: + - OSProfiler support was added. This cross-project profiling library + allows to trace various OpenStack requests through all OpenStack + services that support it. To initiate OpenStack + request tracing `--profile ` option needs to be added to + the CLI command. This key needs to present one of the secret keys + defined in nova.conf configuration file with `hmac_keys` option + under the `[profiler]` configuration section. To enable or disable + Nova profiling the appropriate `enabled` option under the same + section needs to be set either to `True` or `False`. By default + Nova will trace all API and RPC requests, but there is an opportunity + to trace DB requests as well. For this purpose `trace_sqlalchemy` + option needs to be set to `True`. As a prerequisite OSProfiler + library and its storage backend needs to be installed to the + environment. If so (and if profiling is enabled in nova.conf) + the trace can be generated via following command, for instance - + `$ nova --profile SECRET_KEY boot --image --flavor `. + At the end of output there will be message with , and + to plot nice HTML graphs the following command should be used - + `$ osprofiler trace show --html --out result.html` +security: + - OSProfiler support requires passing of trace information + between various OpenStack services. This information is + securely signed by one of HMAC keys, defined in nova.conf configuration + file. To allow cross-project tracing user should use the key, that is + common among all OpenStack services he or she wants to trace. diff --git a/setup.cfg b/setup.cfg index 9dbd5a3b7981..195b2b150dbe 100644 --- a/setup.cfg +++ b/setup.cfg @@ -218,6 +218,10 @@ output_file = nova/locale/nova.pot [wheel] universal = 1 +[extras] +osprofiler = + osprofiler>=1.4.0 # Apache-2.0 + [pbr] # Treat sphinx warnings as errors during the docs build; this helps us keep # the documentation clean. diff --git a/test-requirements.txt b/test-requirements.txt index a3503a08a78b..4d607f133fa1 100644 --- a/test-requirements.txt +++ b/test-requirements.txt @@ -19,6 +19,7 @@ os-api-ref>=1.0.0 # Apache-2.0 oslosphinx>=4.7.0 # Apache-2.0 oslotest>=1.10.0 # Apache-2.0 os-testr>=0.8.0 # Apache-2.0 +osprofiler>=1.4.0 # Apache-2.0 testrepository>=0.0.18 # Apache-2.0/BSD testresources>=0.2.4 # Apache-2.0/BSD testscenarios>=0.4 # Apache-2.0/BSD diff --git a/tox.ini b/tox.ini index 4652da5a774d..e19dd4048da0 100644 --- a/tox.ini +++ b/tox.ini @@ -9,6 +9,7 @@ usedevelop = True whitelist_externals = bash find rm + env install_command = pip install -c{env:UPPER_CONSTRAINTS_FILE:https://git.openstack.org/cgit/openstack/requirements/plain/upper-constraints.txt} {opts} {packages} setenv = VIRTUAL_ENV={envdir} OS_TEST_PATH=./nova/tests/unit @@ -28,16 +29,19 @@ passenv = http_proxy HTTP_PROXY https_proxy HTTPS_PROXY no_proxy NO_PROXY OS_DEB commands = {[testenv]commands} bash tools/pretty_tox.sh '{posargs}' + env TEST_OSPROFILER=1 bash tools/pretty_tox.sh 'nova.tests.unit.test_profiler' [testenv:py34] commands = {[testenv]commands} bash tools/pretty_tox3.sh '{posargs}' + env TEST_OSPROFILER=1 bash tools/pretty_tox.sh 'nova.tests.unit.test_profiler' [testenv:py35] commands = {[testenv]commands} bash tools/pretty_tox3.sh '{posargs}' + env TEST_OSPROFILER=1 bash tools/pretty_tox.sh 'nova.tests.unit.test_profiler' [testenv:pep8] basepython = python2.7