#33 organise cprofile output as a sortable table (#200)

* add .venv* to .gitignore

* made the profile output a sortable table with links to the appropriate source code

* remove memoization of get_dot function since this was causing problem on python 2, and should probably be in a separate PR

* removed python 3 only spitlines

* fixed failing test due to PY3/2 differences in profile output

* fixed failing test due difference in python 3.4

* fixed failing test due to floating point precision

* fixed problem due to trying to import abs from math

* reverted incorrect attempt to fix flaky test due to floating point precision

project/test-requirements.txt

@@ -13,3 +13,4 @@ factory-boy==2.8.1
 freezegun==0.3.5
 networkx==1.11
 pydotplus==2.0.2
+contextlib2==0.5.5

project/tests/test_code.py

@@ -0,0 +1,47 @@
+from collections import namedtuple
+from django.test import TestCase
+from silk.views.code import _code, _code_context, _code_context_from_request
+
+
+FILE_PATH = __file__
+LINE_NUM = 5
+END_LINE_NUM = 10
+
+with open(__file__) as f:
+    ACTUAL_LINES = [l + '\n' for l in f.read().split('\n')]
+
+
+class CodeTestCase(TestCase):
+
+    def assertActualLineEqual(self, actual_line, end_line_num=None):
+        expected_actual_line = ACTUAL_LINES[LINE_NUM - 1:end_line_num or LINE_NUM]
+        self.assertEqual(actual_line, expected_actual_line)
+
+    def assertCodeEqual(self, code):
+        expected_code = [line.strip('\n') for line in ACTUAL_LINES[0:LINE_NUM + 10]] + ['']
+        self.assertEqual(code, expected_code)
+
+    def test_code(self):
+        for end_line_num in None, END_LINE_NUM:
+            actual_line, code = _code(FILE_PATH, LINE_NUM, end_line_num)
+            self.assertActualLineEqual(actual_line, end_line_num)
+            self.assertCodeEqual(code)
+
+    def test_code_context(self):
+        for end_line_num in None, END_LINE_NUM:
+            for prefix in '', 'salchicha_':
+                context = _code_context(FILE_PATH, LINE_NUM, end_line_num, prefix)
+                self.assertActualLineEqual(context[prefix + 'actual_line'], end_line_num)
+                self.assertCodeEqual(context[prefix + 'code'])
+                self.assertEqual(context[prefix + 'file_path'], FILE_PATH)
+                self.assertEqual(context[prefix + 'line_num'], LINE_NUM)
+
+    def test_code_context_from_request(self):
+        for end_line_num in None, END_LINE_NUM:
+            for prefix in '', 'salchicha_':
+                request = namedtuple('Request', 'GET')(dict(file_path=FILE_PATH, line_num=LINE_NUM))
+                context = _code_context_from_request(request, end_line_num, prefix)
+                self.assertActualLineEqual(context[prefix + 'actual_line'], end_line_num)
+                self.assertCodeEqual(context[prefix + 'code'])
+                self.assertEqual(context[prefix + 'file_path'], FILE_PATH)
+                self.assertEqual(context[prefix + 'line_num'], LINE_NUM)

project/tests/test_profile_parser.py

@@ -0,0 +1,54 @@
+# future
+from __future__ import print_function
+# std
+import cProfile
+import sys
+# 3rd party
+import contextlib2 as contextlib
+from six import StringIO, PY3
+from django.test import TestCase
+# silk
+from silk.utils.profile_parser import parse_profile
+
+
+class ProfileParserTestCase(TestCase):
+
+    def test_profile_parser(self):
+        """
+        Verify that the function parse_profile produces the expected output.
+        """
+        with contextlib.closing(StringIO()) as stream:
+            with contextlib.redirect_stdout(stream):
+                cProfile.run('print()')
+            stream.seek(0)
+            actual = list(parse_profile(stream))
+            if PY3:
+                if sys.version_info < (3,5):
+                    expected = [
+                         ['ncalls', 'tottime', 'percall', 'cumtime', 'percall', 'filename:lineno(function)'],
+                         ['1', '0.000', '0.000', '0.000', '0.000', '<string>:1(<module>)'],
+                         ['1', '0.000', '0.000', '0.000', '0.000', '{built-in method exec}'],
+                         ['1', '0.000', '0.000', '0.000', '0.000', '{built-in method print}'],
+                         ['1', '0.000', '0.000', '0.000', '0.000', "{method 'disable' of '_lsprof.Profiler' objects}"],
+                    ]
+                else:
+                    expected = [
+                         ['ncalls', 'tottime', 'percall', 'cumtime', 'percall', 'filename:lineno(function)'],
+                         ['1', '0.000', '0.000', '0.000', '0.000', '<string>:1(<module>)'],
+                         ['1', '0.000', '0.000', '0.000', '0.000', '{built-in method builtins.exec}'],
+                         ['1', '0.000', '0.000', '0.000', '0.000', '{built-in method builtins.print}'],
+                         ['1', '0.000', '0.000', '0.000', '0.000', "{method 'disable' of '_lsprof.Profiler' objects}"],
+                    ]
+            else:
+                expected = [
+                    ['ncalls', 'tottime', 'percall', 'cumtime', 'percall', 'filename:lineno(function)'],
+                    ['1', '0.000', '0.000', '0.000', '0.000', '<string>:1(<module>)'],
+                    ['2', '0.000', '0.000', '0.000', '0.000', 'StringIO.py:208(write)'],
+                    ['2', '0.000', '0.000', '0.000', '0.000', 'StringIO.py:38(_complain_ifclosed)'],
+                    ['2', '0.000', '0.000', '0.000', '0.000', '{isinstance}'],
+                    ['2', '0.000', '0.000', '0.000', '0.000', '{len}'],
+                    ['2', '0.000', '0.000', '0.000', '0.000', "{method 'append' of 'list' objects}"],
+                    ['1', '0.000', '0.000', '0.000', '0.000', "{method 'disable' of '_lsprof.Profiler' objects}"]
+                ]
+
+            self.assertListEqual(actual, expected)

silk/models.py

@@ -2,6 +2,7 @@
 import json
 import base64
 import random
+import re
 
 from django.core.files.storage import FileSystemStorage
 from django.db import models
@@ -14,7 +15,9 @@
 from django.db import transaction
 from uuid import uuid4
 import sqlparse
+from django.utils.safestring import mark_safe
 
+from silk.utils.profile_parser import parse_profile
 from silk.config import SilkyConfig
 
 # Django 1.8 removes commit_on_success, django 1.5 does not have atomic
@@ -85,6 +88,23 @@ class Request(models.Model):
     def total_meta_time(self):
         return (self.meta_time or 0) + (self.meta_time_spent_queries or 0)
 
+    @property
+    def profile_table(self):
+        for n, columns in enumerate(parse_profile(self.pyprofile)):
+            location = columns[-1]
+            if n and '{' not in location and '<' not in location:
+                r = re.compile('(?P<src>.*\.py)\:(?P<num>[0-9]+).*')
+                m = r.search(location)
+                group = m.groupdict()
+                src = group['src']
+                num = group['num']
+                name = 'c%d' % n
+                fmt = '<a name={name} href="?pos={n}&file_path={src}&line_num={num}#{name}">{location}</a>'
+                rep = fmt.format(**dict(group, **locals()))
+                yield columns[:-1] + [mark_safe(rep)]
+            else:
+                yield columns
+
     # defined in atomic transaction within SQLQuery save()/delete() as well
     # as in bulk_create of SQLQueryManager
     # TODO: This is probably a bad way to do this, .count() will prob do?

silk/templates/silk/profile_detail.html

@@ -7,6 +7,7 @@
 {% block js %}
     <script type="text/javascript" src="{% static 'silk/lib/viz-lite.js' %}"></script>
     <script type="text/javascript" src="{% static 'silk/lib/svg-pan-zoom.min.js' %}"></script>
+    <script type="text/javascript" src="{% static 'silk/lib/sortable.js' %}"></script>
     {{ block.super }}
 {% endblock %}
 
@@ -67,6 +68,26 @@
         svg {
           display: block;
         }
+
+        .file-path {
+            font-size: 13px;
+        }
+
+        .file-path>a {
+            color: black;
+        }
+
+        .file-path>a:hover {
+            color: #9dd0ff;
+        }
+
+        .file-path>a:active {
+            color: #594F4F;
+        }
+
+        #pyprofile-table {
+            margin-top: 25px;
+        }
 
     </style>
 {% endblock %}
@@ -143,13 +164,38 @@
                 <div class="heading">
                     <div class="inner-heading">Python Profiler</div>
                 </div>
+
                 <div class="description">
-                    The below is a dump from the cPython profiler.
+                    Below is a dump from the cPython profiler.
+                    {% if silk_request.prof_file %}
+                    Click <a href="{% url 'silk:request_profile_download' request_id=silk_request.pk %}">here</a> to download profile.
+                    {% endif %}
                 </div>
-                {% if silk_request.prof_file %}
-                Click <a href="{% url 'silk:request_profile_download' request_id=silk_request.pk %}">here</a> to download profile.
-                {% endif %}
-                <pre class="pyprofile">{{ silk_request.pyprofile }}</pre>
+
+                <table id='pyprofile-table' class="sortable">
+                    {% for row in silk_request.profile_table %}
+                        <tr>
+                            {% for column in row %}
+                                {% if forloop.parentloop.counter0 %}
+                                    <td>
+                                        {% if forloop.counter0 == file_column %}
+                                            <div class="file-path">
+                                                {{ column }}
+                                            </div>
+                                            {% if forloop.parentloop.counter0 == pos %}
+                                                {% code pyprofile_code pyprofile_actual_line %}
+                                            {% endif %}
+                                        {% else %}
+                                            {{ column }}
+                                        {% endif %}
+                                    </td>
+                                {% else %}
+                                    <th>{{ column }}</th>
+                                {% endif %}
+                            {% endfor %}
+                        </tr>
+                    {% endfor %}
+                </table>
                 {% endif %}
             </div>
 

silk/utils/profile_parser.py

@@ -0,0 +1,21 @@
+from six import text_type
+import re
+
+
+_pattern = re.compile(' +')
+
+
+def parse_profile(output):
+    """
+    Parse the output of cProfile to a list of tuples.
+    """
+    if isinstance(output, text_type):
+        output = output.split('\n')
+    for i, line in enumerate(output):
+        # ignore n function calls, total time and ordered by and empty lines
+        line = line.strip()
+        if i > 3 and line:
+            columns = _pattern.split(line)[0:]
+            function = ' '.join(columns[5:])
+            columns = columns[:5] + [function]
+            yield columns

silk/views/code.py

@@ -4,8 +4,10 @@
 
 
 def _code(file_path, line_num, end_line_num=None):
+    line_num = int(line_num)
     if not end_line_num:
         end_line_num = line_num
+    end_line_num = int(end_line_num)
     actual_line = []
     lines = ''
     with open(file_path, 'r') as f:
@@ -19,10 +21,23 @@ def _code(file_path, line_num, end_line_num=None):
     return actual_line, code
 
 
-def _code_context(file_path, line_num):
-    actual_line, code = _code(file_path, line_num)
-    context = {'code': code, 'file_path': file_path, 'line_num': line_num, 'actual_line': actual_line}
-    return context
+def _code_context(file_path, line_num, end_line_num=None, prefix=''):
+    actual_line, code = _code(file_path, line_num, end_line_num)
+    return {
+        prefix + 'code': code,
+        prefix + 'file_path': file_path,
+        prefix + 'line_num': line_num,
+        prefix + 'actual_line': actual_line
+    }
+
+
+def _code_context_from_request(request, end_line_num=None, prefix=''):
+    file_path = request.GET.get('file_path')
+    line_num = request.GET.get('line_num')
+    result = {}
+    if file_path is not None and line_num is not None:
+        result = _code_context(file_path, line_num, end_line_num, prefix)
+    return result
 
 
 def _should_display_file_name(file_name):

silk/views/profile_detail.py

@@ -3,7 +3,7 @@
 from django.views.generic import View
 from silk.auth import login_possibly_required, permissions_possibly_required
 from silk.models import Profile
-from silk.views.sql_detail import _code
+from silk.views.code import _code_context, _code_context_from_request
 
 
 class ProfilingDetailView(View):
@@ -18,16 +18,21 @@ def get(self, request, *_, **kwargs):
         profile = Profile.objects.get(pk=profile_id)
         file_path = profile.file_path
         line_num = profile.line_num
+
+        context['pos'] = pos = int(request.GET.get('pos', 0))
+        if pos:
+            context.update(_code_context_from_request(request, prefix='pyprofile_'))
+
         context['profile'] = profile
         context['line_num'] = file_path
         context['file_path'] = line_num
+        context['file_column'] = 5
+
         if profile.request:
             context['silk_request'] = profile.request
         if file_path and line_num:
             try:
-                actual_line, code = _code(file_path, line_num, profile.end_line_num)
-                context['code'] = code
-                context['actual_line'] = actual_line
+                context.update(_code_context(file_path, line_num, profile.end_line_num))
             except IOError as e:
                 if e.errno == 2:
                     context['code_error'] = e.filename + ' does not exist.'

silk/views/profile_dot.py

@@ -52,13 +52,17 @@ def _create_dot(profile, cutoff):
         return fp.getvalue()
 
 
+def _get_dot(request_id, cutoff):
+    silk_request = get_object_or_404(Request, pk=request_id, prof_file__isnull=False)
+    profile = _create_profile(silk_request.prof_file)
+    result = dict(dot=_create_dot(profile, cutoff))
+    return HttpResponse(json.dumps(result).encode('utf-8'), content_type='application/json')
+
+
 class ProfileDotView(View):
 
     @method_decorator(login_possibly_required)
     @method_decorator(permissions_possibly_required)
     def get(self, request, request_id):
-        silk_request = get_object_or_404(Request, pk=request_id, prof_file__isnull=False)
         cutoff = float(request.GET.get('cutoff', '') or 5)
-        profile = _create_profile(silk_request.prof_file)
-        result = dict(dot=_create_dot(profile, cutoff))
-        return HttpResponse(json.dumps(result).encode('utf-8'), content_type='application/json')
+        return _get_dot(request_id, cutoff)

silk/views/sql_detail.py

@@ -8,28 +8,7 @@
 
 from silk.auth import login_possibly_required, permissions_possibly_required
 from silk.models import SQLQuery, Request, Profile
-
-
-def _code(file_path, line_num, end_line_num=None):
-    if not end_line_num:
-        end_line_num = line_num
-    actual_line = []
-    lines = ''
-    with open(file_path, 'r') as f:
-        r = range(max(0, line_num - 10), line_num + 10)
-        for i, line in enumerate(f):
-            if i in r:
-                lines += line
-            if i + 1 in range(line_num, end_line_num + 1):
-                actual_line.append(line)
-    code = lines.split('\n')
-    return actual_line, code
-
-
-def _code_context(file_path, line_num):
-    actual_line, code = _code(file_path, line_num)
-    context = {'code': code, 'file_path': file_path, 'line_num': line_num, 'actual_line': actual_line}
-    return context
+from silk.views.code import _code
 
 
 class SQLDetailView(View):