Enable profiling of angular pages (with async requests)

The main difficulty in tracing async requests which are made during
the rendering of Angular-based pages is tracking the root request (the
one which was made to render the skeleton page which then initiated
all other requests) throughout other requests, so they form a cohesive
trace. This is solved by capturing the root request id and exposing it
as a profiler module constant in the process of interpolating
_scripts.html Django template. Then if that constant is not an empty
dictionary, profiler module intercepts all Angular requests and adds
osprofiler headers to them.

This patch also fixes issues which arose after transitioning to the
new version of angular-bootstrap.

Change-Id: I656028b969289a473f54594681d9313ff8a07fd8

openstack_dashboard/context_processors.py

@@ -24,6 +24,7 @@ import re
 from django.conf import settings
 
 from horizon import conf
+from openstack_dashboard.contrib.developer.profiler import api as profiler
 
 
 def openstack(request):
@@ -61,8 +62,14 @@ def openstack(request):
     context['WEBROOT'] = getattr(settings, "WEBROOT", "/")
 
     # Adding profiler support flag
-    enabled = getattr(settings, 'OPENSTACK_PROFILER', {}).get('enabled', False)
+    profiler_settings = getattr(settings, 'OPENSTACK_PROFILER', {})
-    context['profiler_enabled'] = enabled
+    profiler_enabled = profiler_settings.get('enabled', False)
+    context['profiler_enabled'] = profiler_enabled
+    if profiler_enabled and 'profile_page' in request.COOKIES:
+        index_view_id = request.META.get(profiler.ROOT_HEADER, '')
+        hmac_keys = profiler_settings.get('keys', [])
+        context['x_trace_info'] = profiler.update_trace_headers(
+            hmac_keys, parent_id=index_view_id)
 
     # Search for external plugins and append to javascript message catalog
     # internal plugins are under the openstack_dashboard domain

openstack_dashboard/contrib/developer/profiler/api.py

@@ -14,14 +14,18 @@
 #    under the License.
 
 import contextlib
+import json
 
 from django.conf import settings
+from osprofiler import _utils as utils
 from osprofiler.drivers.base import get_driver as profiler_get_driver
 from osprofiler import notifier
 from osprofiler import profiler
+from osprofiler import web
 from six.moves.urllib.parse import urlparse
 
 
+ROOT_HEADER = 'PARENT_VIEW_TRACE_ID'
 PROFILER_SETTINGS = getattr(settings, 'OPENSTACK_PROFILER', {})
 
 
@@ -88,15 +92,36 @@ def get_trace(request, trace_id):
         _data['is_leaf'] = not len(_data['children'])
         _data['visible'] = True
         _data['childrenVisible'] = True
+        finished = _data['info']['finished']
         for child in _data['children']:
-            rec(child, level + 1)
+            __, child_finished = rec(child, level + 1)
-        return _data
+            # NOTE(tsufiev): in case of async requests the root request usually
+            # finishes before the dependent requests do so, to we need to
+            # normalize the duration of all requests by the finishing time of
+            # the one which took longest
+            if child_finished > finished:
+                finished = child_finished
+        return _data, finished
 
     engine = _get_engine(request)
     trace = engine.get_report(trace_id)
-    # throw away toplevel node which is dummy and doesn't contain any info,
+    # NOTE(tsufiev): throw away toplevel node which is dummy and doesn't
-    # use its first and only child as the toplevel node
+    # contain any info, use its first and only child as the toplevel node
-    return rec(trace['children'][0])
+    data, max_finished = rec(trace['children'][0])
+    data['info']['max_finished'] = max_finished
+    return data
+
+
+def update_trace_headers(keys, **kwargs):
+    trace_headers = web.get_trace_id_headers()
+    trace_info = utils.signed_unpack(
+        trace_headers[web.X_TRACE_INFO], trace_headers[web.X_TRACE_HMAC],
+        keys)
+    trace_info.update(kwargs)
+    p = profiler.get()
+    trace_data = utils.signed_pack(trace_info, p.hmac_key)
+    return json.dumps({web.X_TRACE_INFO: trace_data[0],
+                       web.X_TRACE_HMAC: trace_data[1]})
 
 
 if not PROFILER_SETTINGS.get('enabled', False):

openstack_dashboard/contrib/developer/profiler/middleware.py

@@ -34,12 +34,25 @@ PROFILER_ENABLED = PROFILER_CONF.get('enabled', False)
 
 
 class ProfilerClientMiddleware(object):
+    profiler_headers = [
+        ('HTTP_X_TRACE_INFO', 'X-Trace-Info'),
+        ('HTTP_X_TRACE_HMAC', 'X-Trace-HMAC')
+    ]
+
     def __init__(self):
         if not PROFILER_ENABLED:
             raise exceptions.MiddlewareNotUsed()
         super(ProfilerClientMiddleware, self).__init__()
 
+    def is_async_profiling(self, request):
+        return self.profiler_headers[0][0] in request.META
+
     def process_request(self, request):
+        if self.is_async_profiling(request):
+            for src_header, dst_header in self.profiler_headers:
+                request.META[dst_header] = request.META.get(src_header)
+            return None
+
         if 'profile_page' in request.COOKIES:
             hmac_key = PROFILER_CONF.get('keys')[0]
             profiler.init(hmac_key)
@@ -76,8 +89,8 @@ class ProfilerMiddleware(object):
         return True
 
     def process_view(self, request, view_func, view_args, view_kwargs):
-        # do not profile ajax requests for now
+
-        if not self.is_enabled(request) or request.is_ajax():
+        if not self.is_enabled(request):
             return None
 
         trace_info = profiler_utils.signed_unpack(
@@ -98,6 +111,8 @@ class ProfilerMiddleware(object):
             }
         }
         with api.traced(request, view_func.__name__, info) as trace_id:
+            request.META[api.ROOT_HEADER] = profiler.get().get_id()
+
             response = view_func(request, *view_args, **view_kwargs)
             url = reverse('horizon:developer:profiler:index')
             message = safestring.mark_safe(
@@ -115,8 +130,4 @@ class ProfilerMiddleware(object):
 
     def process_response(self, request, response):
         self.clear_profiling_cookies(request, response)
-        # do not profile ajax requests for now
-        if not self.is_enabled(request) or request.is_ajax():
-            return response
-
         return response

openstack_dashboard/contrib/developer/static/dashboard/developer/profiler/profiler.controller.js

@@ -51,7 +51,7 @@
    * are used while rendering trace node.
    */
   sharedProfilerController.$inject = [
-    '$modal',
+    '$uibModal',
     '$rootScope',
     '$templateCache',
     'horizon.dashboard.developer.profiler.basePath'
@@ -95,13 +95,13 @@
     }
 
     function getWidth(data, rootData) {
-      var full_duration = rootData.info.finished;
+      var full_duration = rootData.info.max_finished;
       var duration = (data.info.finished - data.info.started) * 100.0 / full_duration;
       return (duration >= 0.5) ? duration : 0.5;
     }
 
     function getStarted(data, rootData) {
-      var full_duration = rootData.info.finished;
+      var full_duration = rootData.info.max_finished;
       return data.info.started * 100.0 / full_duration;
     }
 
@@ -154,8 +154,8 @@
     ctrl.profilePage = profilePage;
 
     function profilePage() {
-      $cookies.put('profile_page', true);
+      $cookies.put('profile_page', true, {path: window.location.pathname});
       window.location.reload();
     }
   }
-})();
+})();

openstack_dashboard/contrib/developer/static/dashboard/developer/profiler/profiler.module.js

@@ -29,12 +29,31 @@
 
   config.$inject = [
     '$provide',
-    '$windowProvider'
+    '$windowProvider',
+    '$httpProvider',
+    'horizon.dashboard.developer.profiler.headers'
   ];
 
-  function config($provide, $windowProvider) {
+  function config($provide, $windowProvider, $httpProvider, headers) {
     var path = $windowProvider.$get().STATIC_URL + 'dashboard/developer/profiler/';
     $provide.constant('horizon.dashboard.developer.profiler.basePath', path);
+    if (Object.keys(headers).length) {
+      $httpProvider.interceptors.push(function() {
+        return {
+          'request': function(config) {
+            if (angular.isUndefined(config.headers)) {
+              config.headers = {};
+            }
+            if (headers) {
+              angular.forEach(headers, function(value, key) {
+                config.headers[key] = value;
+              });
+            }
+            return config;
+          }
+        };
+      });
+    }
   }
 
 })();

openstack_dashboard/contrib/developer/static/dashboard/developer/profiler/profiler.tree-node.html

@@ -9,10 +9,10 @@
   </td>
   <td>
     <div class="progress-text">
-      <progress>
+      <uib-progress>
-        <bar value="ctrl.getStarted(data, rootData)" type="transparent"></bar>
+        <uib-bar value="ctrl.getStarted(data, rootData)" type="transparent"></uib-bar>
-        <bar value="ctrl.getWidth(data, rootData)" type="info"></bar>
+        <uib-bar value="ctrl.getWidth(data, rootData)" type="info"></uib-bar>
-      </progress>
+      </uib-progress>
       <span class="progress-bar-text">
         {$ data.info.finished - data.info.started $} ms
       </span>

openstack_dashboard/templates/horizon/_scripts.html

@@ -66,6 +66,17 @@
   {% endcache %}
 {% endcompress %}
 
+{% if profiler_enabled %}
+  <script>
+    (function() {
+      angular.module('horizon.dashboard.developer.profiler')
+          .constant('horizon.dashboard.developer.profiler.headers',
+                {% if x_trace_info %}{{ x_trace_info|safe }}{% else %}{}{% endif %}
+      );
+    })();
+  </script>
+{% endif %}
+
 {% comment %} Client-side Templates (These should *not* be inside the "compress" tag.) {% endcomment %}
 {% include "horizon/client_side/templates.html" %}