From 3773f17403bb02b372673643780b9619151d22ea Mon Sep 17 00:00:00 2001 From: Ramamani Yeleswarapu Date: Thu, 18 Aug 2016 16:55:56 -0700 Subject: [PATCH] Enable OSProfiler support in Ironic This patch does the following: * Adds osprofiler wsgi middleware This middleware is used for 2 things: - It checks that person who wants to trace is trusted and knows secret HMAC key. - It starts tracing in case of proper trace headers and adds first wsgi trace point, with info about HTTP request. * Adds initialization of osprofiler at start of service - Initialize and set an oslo.messaging based notifier instance to osprofiler, which will be used to send notifications to Ceilometer. * Traces HTTP/RPC/DB API calls and SQL requests NOTE to test this patch: 1) Make the following changes in localrc to configure DevStack to enable OSProfiler: enable_plugin panko https://git.openstack.org/openstack/panko enable_plugin ceilometer https://git.openstack.org/openstack/ceilometer enable_plugin osprofiler https://git.openstack.org/openstack/osprofiler # Enable the following services CEILOMETER_NOTIFICATION_TOPICS=notifications,profiler ENABLED_SERVICES+=,ceilometer-acompute,ceilometer-acentral ENABLED_SERVICES+=,ceilometer-anotification,ceilometer-collector ENABLED_SERVICES+=,ceilometer-alarm-evaluator,ceilometer-alarm-notifier ENABLED_SERVICES+=,ceilometer-api NOTE: the order of enabling plugins matters. 2) Run stack.sh. Once DevStack environment is setup, enable profiler options in ironic.conf and restart ironic services: [profiler] enabled = true hmac_keys = SECRET_KEY trace_sqlalchemy = true 3) Use openstackclient and run baremetal command with --os-profile SECRET_KEY [--profile can be used, but it is deprecated.] For example, the following will cause the to be printed after node list: $ openstack --os-profile SECRET_KEY baremetal node list ..... ..... Trace ID: Display trace with command: osprofiler trace show --html 4) The trace results can be saved using this command: $ osprofiler trace show --html --out trace.html OSprofiler spec: https://review.openstack.org/#/c/103825/ Co-Authored-By: Tovin Seven Co-Authored-By: Hieu LE Partial-Bug: #1560704 Change-Id: Icd3d7c62cf7442de8a77fc67f119ae9b03725f02 --- doc/source/contributor/dev-quickstart.rst | 10 + doc/source/contributor/index.rst | 1 + doc/source/contributor/osprofiler-support.rst | 120 ++ doc/source/images/sample_trace.svg | 793 ++++++++++++ doc/source/images/sample_trace_details.svg | 1134 +++++++++++++++++ etc/ironic/ironic.conf.sample | 78 ++ ironic/api/app.py | 4 + ironic/cmd/api.py | 3 + ironic/cmd/conductor.py | 3 + ironic/common/config.py | 2 + ironic/common/profiler.py | 62 + ironic/common/rpc.py | 15 +- ironic/db/sqlalchemy/api.py | 14 +- ironic/tests/unit/api/test_ospmiddleware.py | 43 + ...e-osprofiler-support-e3839b0fa90d3831.yaml | 17 + requirements.txt | 1 + tools/config/ironic-config-generator.conf | 1 + 17 files changed, 2298 insertions(+), 3 deletions(-) create mode 100644 doc/source/contributor/osprofiler-support.rst create mode 100644 doc/source/images/sample_trace.svg create mode 100644 doc/source/images/sample_trace_details.svg create mode 100644 ironic/common/profiler.py create mode 100644 ironic/tests/unit/api/test_ospmiddleware.py create mode 100644 releasenotes/notes/enable-osprofiler-support-e3839b0fa90d3831.yaml diff --git a/doc/source/contributor/dev-quickstart.rst b/doc/source/contributor/dev-quickstart.rst index 5cf81c6755..5d5b4ec007 100644 --- a/doc/source/contributor/dev-quickstart.rst +++ b/doc/source/contributor/dev-quickstart.rst @@ -711,6 +711,16 @@ For more information about the supported parameters see:: Always be careful when running debuggers in time sensitive code, they may cause timeout errors that weren't there before. + +OSProfiler Tracing in Ironic +============================ + +OSProfiler is an OpenStack cross-project profiling library. It is being +used among OpenStack projects to look at performance issues and detect +bottlenecks. For details on how OSProfiler works and how to use it in ironic, +please refer to `OSProfiler Support Documentation `_. + + Building developer documentation ================================ diff --git a/doc/source/contributor/index.rst b/doc/source/contributor/index.rst index 5f5d993ac5..1779360d45 100644 --- a/doc/source/contributor/index.rst +++ b/doc/source/contributor/index.rst @@ -25,6 +25,7 @@ primarily for developers. Ironic System Architecture Provisioning State Machine Developing New Notifications + OSProfiler Tracing These pages contain information for PTLs, cross-project liaisons, and core reviewers. diff --git a/doc/source/contributor/osprofiler-support.rst b/doc/source/contributor/osprofiler-support.rst new file mode 100644 index 0000000000..7cf298f439 --- /dev/null +++ b/doc/source/contributor/osprofiler-support.rst @@ -0,0 +1,120 @@ +.. _OSProfiler-support: + +================ +About OSProfiler +================ + +OSProfiler is an OpenStack cross-project profiling library. Its API +provides different ways to add a new trace point. Trace points contain +two messages (start and stop). Messages like below are sent to a collector:: + + { + "name": -(start|stop), + "base_id": , + "parent_id": , + "trace_id": , + "info": + } + +The fields are defined as follows: + +``base_id`` - that is same for all trace points that belong to +one trace. This is used to simplify the process of retrieving all +trace points (related to one trace) from the collector. + +``parent_id`` - of parent trace point. + +``trace_id`` - of current trace point. + +``info`` - the dictionary that contains user information passed when +calling profiler start() & stop() methods. + +The profiler uses ceilometer as a centralized collector. Two other +alternatives for ceilometer are pure MongoDB driver and Elasticsearch. + +A notifier is setup to send notifications to ceilometer using oslo.messaging +and ceilometer API is used to retrieve all messages related to one trace. + +OSProfiler has entry point that allows the user to retrieve information +about traces and present it in HTML/JSON using CLI. + +For more details see `OSProfiler – Cross-project profiling library`_. + + +How to Use OSProfiler with Ironic in Devstack +============================================= + +To use or test OSProfiler in ironic, the user needs to setup Devstack +with OSProfiler and ceilometer. In addition to the setup described at +`Deploying Ironic with DevStack`_, the user needs to do the following: + +Add the following to ``localrc`` to enable OSProfiler and ceilometer:: + + enable_plugin panko https://git.openstack.org/openstack/panko + enable_plugin ceilometer https://git.openstack.org/openstack/ceilometer + enable_plugin osprofiler https://git.openstack.org/openstack/osprofiler + + # Enable the following services + CEILOMETER_NOTIFICATION_TOPICS=notifications,profiler + ENABLED_SERVICES+=,ceilometer-acompute,ceilometer-acentral + ENABLED_SERVICES+=,ceilometer-anotification,ceilometer-collector + ENABLED_SERVICES+=,ceilometer-alarm-evaluator,ceilometer-alarm-notifier + ENABLED_SERVICES+=,ceilometer-api + + +Run stack.sh. + +Once Devstack environment is setup, edit ``ironic.conf`` to set the following +profiler options and restart ironic services:: + + [profiler] + enabled = True + hmac_keys = SECRET_KEY # default value used across several OpenStack projects + + +In order to trace ironic using OSProfiler, use openstackclient to run +baremetal commands with + + ``--os-profile SECRET_KEY`` + +For example, the following will cause a to be printed after node list: + + ``$ openstack --os-profile SECRET_KEY baremetal node list`` + +Output of the above command will include the following:: + + Trace ID: + Display trace with command: + osprofiler trace show --html + +The trace results can be seen using this command:: + + $ osprofiler trace show --html + +The trace results can be saved in a file with ``--out file-name`` option:: + + $ osprofiler trace show --html --out trace.html + +Sample Trace: + +.. figure:: ../images/sample_trace.svg + :width: 660px + :align: left + :alt: Sample Trace + + +.. figure:: ../images/sample_trace_details.svg + :width: 660px + :align: left + :alt: Sample Trace Details + + +References +========== + +- `OSProfiler – Cross-project profiling library`_ +- `Deploying Ironic with DevStack`_ + +.. _OSProfiler – Cross-project profiling library: http://docs.openstack.org/osprofiler/latest/index.html +.. _Deploying Ironic with DevStack: http://docs.openstack.org/ironic/latest/contributor/dev-quickstart.html#deploying-ironic-with-devstack + diff --git a/doc/source/images/sample_trace.svg b/doc/source/images/sample_trace.svg new file mode 100644 index 0000000000..4452e2d1a0 --- /dev/null +++ b/doc/source/images/sample_trace.svg @@ -0,0 +1,793 @@ + + + + + + + + image/svg+xml + + + + + + + + + diff --git a/doc/source/images/sample_trace_details.svg b/doc/source/images/sample_trace_details.svg new file mode 100644 index 0000000000..cc42a26690 --- /dev/null +++ b/doc/source/images/sample_trace_details.svg @@ -0,0 +1,1134 @@ + + + + + + + + image/svg+xml + + + + + + + + + diff --git a/etc/ironic/ironic.conf.sample b/etc/ironic/ironic.conf.sample index c71d0e8516..b79235374e 100644 --- a/etc/ironic/ironic.conf.sample +++ b/etc/ironic/ironic.conf.sample @@ -3314,6 +3314,84 @@ #policy_dirs = policy.d +[profiler] + +# +# From osprofiler +# + +# +# Enables the profiling for all services on this node. Default +# value is False +# (fully disable the profiling feature). +# +# Possible values: +# +# * True: Enables the feature +# * False: Disables the feature. The profiling cannot be +# started via this project +# operations. If the profiling is triggered by another +# project, this project part +# will be empty. +# (boolean value) +# Deprecated group/name - [profiler]/profiler_enabled +#enabled = false + +# +# Enables SQL requests profiling in services. Default value is +# False (SQL +# requests won't be traced). +# +# Possible values: +# +# * True: Enables SQL requests profiling. Each SQL query will +# be part of the +# trace and can the be analyzed by how much time was spent for +# that. +# * False: Disables SQL requests profiling. The spent time is +# only shown on a +# higher level of operations. Single SQL queries cannot be +# analyzed this +# way. +# (boolean value) +#trace_sqlalchemy = false + +# +# Secret key(s) to use for encrypting context data for +# performance profiling. +# This string value should have the following format: +# [,,...], +# where each key is some random string. A user who triggers +# the profiling via +# the REST API has to set one of these keys in the headers of +# the REST API call +# to include profiling results of this node for this +# particular project. +# +# Both "enabled" flag and "hmac_keys" config options should be +# set to enable +# profiling. Also, to generate correct profiling information +# across all services +# at least one key needs to be consistent between OpenStack +# projects. This +# ensures it can be used from client side to generate the +# trace, containing +# information from all possible resources. (string value) +#hmac_keys = SECRET_KEY + +# +# Connection string for a notifier backend. Default value is +# messaging:// which +# sets the notifier to oslo_messaging. +# +# Examples of possible values: +# +# * messaging://: use oslo_messaging driver for sending +# notifications. +# (string value) +#connection_string = messaging:// + + [pxe] # diff --git a/ironic/api/app.py b/ironic/api/app.py index b657c55d37..05d3d38927 100644 --- a/ironic/api/app.py +++ b/ironic/api/app.py @@ -18,6 +18,7 @@ import keystonemiddleware.audit as audit_middleware from oslo_config import cfg import oslo_middleware.cors as cors_middleware +import osprofiler.web as osprofiler_web import pecan from ironic.api import config @@ -93,6 +94,9 @@ def setup_app(pecan_config=None, extra_hooks=None): app, dict(cfg.CONF), public_api_routes=pecan_config.app.acl_public_routes) + if CONF.profiler.enabled: + app = osprofiler_web.WsgiMiddleware(app) + # Create a CORS wrapper, and attach ironic-specific defaults that must be # included in all CORS responses. app = IronicCORS(app, CONF) diff --git a/ironic/cmd/api.py b/ironic/cmd/api.py index da44e3d449..2b7a0ebf9f 100644 --- a/ironic/cmd/api.py +++ b/ironic/cmd/api.py @@ -22,6 +22,7 @@ import sys from oslo_config import cfg from oslo_reports import guru_meditation_report as gmr +from ironic.common import profiler from ironic.common import service as ironic_service from ironic.common import wsgi_service from ironic.objects import base @@ -41,6 +42,8 @@ def main(): base.IronicObject.indirection_api = ( indirection.IronicObjectIndirectionAPI()) + profiler.setup('ironic_api', CONF.host) + # Build and start the WSGI app launcher = ironic_service.process_launcher() server = wsgi_service.WSGIService('ironic_api', CONF.api.enable_ssl_api) diff --git a/ironic/cmd/conductor.py b/ironic/cmd/conductor.py index 118ec961b6..b37356f1c0 100644 --- a/ironic/cmd/conductor.py +++ b/ironic/cmd/conductor.py @@ -26,6 +26,7 @@ from oslo_log import log from oslo_reports import guru_meditation_report as gmr from oslo_service import service +from ironic.common import profiler as profiler from ironic.common import rpc_service from ironic.common import service as ironic_service from ironic import version @@ -78,6 +79,8 @@ def main(): issue_startup_warnings(CONF) + profiler.setup('ironic_conductor', CONF.host) + launcher = service.launch(CONF, mgr) launcher.wait() diff --git a/ironic/common/config.py b/ironic/common/config.py index 743b7d1ec0..fedf5c2725 100644 --- a/ironic/common/config.py +++ b/ironic/common/config.py @@ -16,6 +16,7 @@ # under the License. from oslo_config import cfg +import osprofiler.opts as profiler_opts from ironic.common import rpc from ironic import version @@ -28,3 +29,4 @@ def parse_args(argv, default_config_files=None): version=version.version_info.release_string(), default_config_files=default_config_files) rpc.init(cfg.CONF) + profiler_opts.set_defaults(cfg.CONF) diff --git a/ironic/common/profiler.py b/ironic/common/profiler.py new file mode 100644 index 0000000000..90ca35c755 --- /dev/null +++ b/ironic/common/profiler.py @@ -0,0 +1,62 @@ +# 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_config import cfg +from oslo_log import log as logging +from osprofiler import initializer +from osprofiler import profiler + +from ironic.common import context + +CONF = cfg.CONF +LOG = logging.getLogger(__name__) + + +def setup(name, host='0.0.0.0'): + """Setup OSprofiler notifier and enable profiling. + + :param name: name of the service that will be profiled + :param host: hostname or host IP address that the service will be + running on. By default host will be set to 0.0.0.0, but + specifying host name / address usage is highly recommended. + :raises TypeError: in case of invalid connection string for + a notifier backend, which is set in + osprofiler.initializer.init_from_conf. + """ + if CONF.profiler.enabled: + admin_context = context.get_admin_context() + initializer.init_from_conf(conf=CONF, + context=admin_context.to_dict(), + project="ironic", + service=name, + host=host) + LOG.info("OSProfiler is enabled. Trace is generated using " + "[profiler]/hmac_keys specified in ironic.conf. " + "To disable, set [profiler]/enabled=false") + + +def trace_cls(name, **kwargs): + """Wrap the OSProfiler trace_cls decorator + + 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. For example, 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/ironic/common/rpc.py b/ironic/common/rpc.py index 2c20d8924a..ae2d21547a 100644 --- a/ironic/common/rpc.py +++ b/ironic/common/rpc.py @@ -16,6 +16,7 @@ from oslo_config import cfg import oslo_messaging as messaging from oslo_messaging.rpc import dispatcher +from osprofiler import profiler from ironic.common import context as ironic_context from ironic.common import exception @@ -95,9 +96,21 @@ class RequestContextSerializer(messaging.Serializer): return self._base.deserialize_entity(context, entity) def serialize_context(self, context): - return context.to_dict() + _context = context.to_dict() + prof = profiler.get() + if prof: + 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 ironic_context.RequestContext.from_dict(context) diff --git a/ironic/db/sqlalchemy/api.py b/ironic/db/sqlalchemy/api.py index 52ab2ae3d7..fe99d6a861 100644 --- a/ironic/db/sqlalchemy/api.py +++ b/ironic/db/sqlalchemy/api.py @@ -29,12 +29,15 @@ from oslo_utils import netutils from oslo_utils import strutils from oslo_utils import timeutils from oslo_utils import uuidutils +from osprofiler import sqlalchemy as osp_sqlalchemy +import sqlalchemy as sa from sqlalchemy.orm.exc import NoResultFound, MultipleResultsFound from sqlalchemy.orm import joinedload from sqlalchemy import sql from ironic.common import exception from ironic.common.i18n import _ +from ironic.common import profiler from ironic.common import states from ironic.conf import CONF from ironic.db import api @@ -53,14 +56,20 @@ def get_backend(): def _session_for_read(): - return enginefacade.reader.using(_CONTEXT) + return _wrap_session(enginefacade.reader.using(_CONTEXT)) # Please add @oslo_db_api.retry_on_deadlock decorator to all methods using # _session_for_write (as deadlocks happen on write), so that oslo_db is able # to retry in case of deadlocks. def _session_for_write(): - return enginefacade.writer.using(_CONTEXT) + return _wrap_session(enginefacade.writer.using(_CONTEXT)) + + +def _wrap_session(session): + if CONF.profiler.enabled and CONF.profiler.trace_sqlalchemy: + session = osp_sqlalchemy.wrap_session(sa, session) + return session def _get_node_query_with_tags(): @@ -191,6 +200,7 @@ def _filter_active_conductors(query, interval=None): return query +@profiler.trace_cls("db_api") class Connection(api.Connection): """SqlAlchemy connection.""" diff --git a/ironic/tests/unit/api/test_ospmiddleware.py b/ironic/tests/unit/api/test_ospmiddleware.py new file mode 100644 index 0000000000..c90ab34739 --- /dev/null +++ b/ironic/tests/unit/api/test_ospmiddleware.py @@ -0,0 +1,43 @@ +# 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 mock + +from oslo_config import cfg +from osprofiler import web + +from ironic.tests.unit.api import base + +CONF = cfg.CONF + + +class TestOsprofilerWsgiMiddleware(base.BaseApiTest): + """Provide a basic test for OSProfiler wsgi middleware. + + The tests below provide minimal confirmation that the OSProfiler wsgi + middleware is called. + """ + + def setUp(self): + super(TestOsprofilerWsgiMiddleware, self).setUp() + + @mock.patch.object(web, 'WsgiMiddleware') + def test_enable_osp_wsgi_request(self, mock_ospmiddleware): + CONF.profiler.enabled = True + self._make_app() + mock_ospmiddleware.assert_called_once_with(mock.ANY) + + @mock.patch.object(web, 'WsgiMiddleware') + def test_disable_osp_wsgi_request(self, mock_ospmiddleware): + CONF.profiler.enabled = False + self._make_app() + self.assertFalse(mock_ospmiddleware.called) diff --git a/releasenotes/notes/enable-osprofiler-support-e3839b0fa90d3831.yaml b/releasenotes/notes/enable-osprofiler-support-e3839b0fa90d3831.yaml new file mode 100644 index 0000000000..c001cb85bd --- /dev/null +++ b/releasenotes/notes/enable-osprofiler-support-e3839b0fa90d3831.yaml @@ -0,0 +1,17 @@ +--- +features: + - | + Adds OSProfiler support. This cross-project profiling library + provides the ability 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. + As part of the output, there will be a message with . + To see the HTML graphs, the following command should be used - + `$ osprofiler trace show --html --out result.html`. See + OSProfiler documentation: http://docs.openstack.org/developer/osprofiler/. +security: + - OSProfiler support requires passing of trace information between + various OpenStack services. This information is securely signed + by one of HMAC keys, defined in ironic.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/requirements.txt b/requirements.txt index 673ef4c9e5..c01800a261 100644 --- a/requirements.txt +++ b/requirements.txt @@ -30,6 +30,7 @@ oslo.reports>=0.6.0 # Apache-2.0 oslo.serialization>=1.10.0 # Apache-2.0 oslo.service>=1.10.0 # Apache-2.0 oslo.utils>=3.20.0 # Apache-2.0 +osprofiler>=1.4.0 # Apache-2.0 pecan!=1.0.2,!=1.0.3,!=1.0.4,!=1.2,>=1.0.0 # BSD requests>=2.14.2 # Apache-2.0 rfc3986>=0.3.1 # Apache-2.0 diff --git a/tools/config/ironic-config-generator.conf b/tools/config/ironic-config-generator.conf index 088c234bf6..f738cc4061 100644 --- a/tools/config/ironic-config-generator.conf +++ b/tools/config/ironic-config-generator.conf @@ -16,4 +16,5 @@ namespace = oslo.log namespace = oslo.service.service namespace = oslo.service.periodic_task namespace = oslo.service.sslutils +namespace = osprofiler namespace = keystonemiddleware.auth_token