✨ Generate event specific reports (#32)

This PR makes it possible to aggregate the runtime of event listeners
for all fired Sphinx events.
Tricky part in pyinstrument is that all event listeners appear under
`EventManager.emit`, so the event name is lost.
The PR monkeypatches Sphinx to use a custom Event listener which injects
an event specific `emit` function, so it can be tracked in pyinstrument.

The PR can be tested with `sphinx-analysis --project needs
--pyinstrument --tree`.
A new JSON report of name `pyinstrument_sphinx_events.json` is created.
It contains all unique combinations of file path, class and function of
all event listeners, so it will pick up all extensions that have
listeners registered.
The dictionary
`sphinx_performance/sphinx_events.py:CUSTOM_FRAMES_BY_EVENT` can be
modified to add more frames of interest (unrelated to events). It is
currently used to track the runtime of `sphinxcontrib-plantuml`.

The generated JSON file can be used for 2 purposes:
- As a support to the pyinstrument HTML report to get a per-event
aggregation
- To run in a CI and check how a PR to Sphinx or an extension affects
performance

The HTML report now contains event specific function names, so event
names can be searched.

docs/cli.rst

@@ -209,6 +209,7 @@ Example calls::
    sphinx-analysis --project --pages 10 --folders 3 --depth 2 --memray --flamegraph
    sphinx-analysis --project --pages 10 --folders 3 --depth 2 --runtime --stats
    sphinx-analysis --project needs --needs 40 --needtables 2 --pages 5 --folders 2 --depth 1 --pyinstrument --tree
+   sphinx-analysis --project basic --pyinstrument --tree --sphinx-events
    sphinx-analysis --ref medium --runtime --summary
 
 .. _option_runtime:
@@ -298,7 +299,7 @@ This may happen, if e.g. multiple projects are configured to be used, and ``sphi
 this.
 
 
-\-\- tree
+\-\-tree
 ~~~~~~~~~
 Creates a ``pyinstrument_profile.html`` file, which shows a runtime tree, profiled by ``--pyinstrument``.
 
@@ -309,3 +310,37 @@ Supported by: :ref:`option_pyinstrument`.
    :width: 49%
 
    pyinstrument tree in HTML file
+
+\-\- tree-filter
+~~~~~~~~~~~~~~~~
+
+Remove nodes that represent less than X seconds of the total time.
+This works on the tree structure generated by ``pyinstrument``, so it can only be used
+together with ``--pyinstrument --tree``.
+
+\-\-sphinx-events
+~~~~~~~~~~~~~~~~~
+
+Generates a JSON runtime summary for each Sphinx event. Only usable if
+``--pyinstrument`` is given. This works by monkey patching the Sphinx
+``EventManager.emit`` function, so the call tree reveals which Sphinx event got fired.
+The modification is visible in the call tree.
+
+The JSON output file ``pyinstrument_sphinx_events.json`` is generated into the
+current working directory.
+
+The feature can also collect custom frames, not related to Sphinx events.
+For this the (hard coded) variable ``CUSTOM_FRAMES_BY_REPORT_NAME`` in
+sphinx_performance/sphinx_events.py can be adapted.
+Any improvements to this variable in form of a PR is welcome.
+
+The custom pyinstrument frames will be added to the output JSON and can be used to get
+quick information for any Sphinx build step.
+Just like for events, the output JSON will contain unique function runtimes
+of all nodes below the given frame. The dictionary keys will be used also in the
+output JSON for humans to understand what it is.
+
+The feature can be used to also analyze runtime of extensions that are not called
+through the Sphinx event system, but by docutils, e.g. sphinxcontrib-plantuml.
+When running in a CI context, the output JSON can be used to quickly see performance
+problems or improvements introduced by new PRs.

docs/index.rst

@@ -34,6 +34,8 @@ It was created to answer questions like:
 * What are the performance bottlenecks during a Sphinx build?
 * What functions have an impact on the runtime?
 * Are there any memory problems?
+* How does my Sphinx extension perform?
+* What runtime is consumed by Sphinx events?
 
 To answer these questions, **two commandline tools** are provided:
 

pyproject.toml

@@ -96,6 +96,7 @@ max-complexity = 20
 
 [tool.ruff.per-file-ignores]
 "sphinx_performance/projects/basic/performance.py" = ["INP001"] # template dir
+"sphinx_performance/projects/events/performance.py" = ["INP001"] # template dir
 "sphinx_performance/projects/needs/performance.py" = ["INP001"] # template dir
 "sphinx_performance/projects/theme/performance.py" = ["INP001"] # template dir
 

sphinx_performance/analysis.py

@@ -1,4 +1,5 @@
 """Executes several performance tests."""
+import json
 import os.path
 import subprocess
 import sys
@@ -8,11 +9,12 @@
 from pathlib import Path
 
 import click
-from pyinstrument.renderers import HTMLRenderer
+from pyinstrument.renderers import JSONRenderer
 
 from sphinx_performance.call import Call
 from sphinx_performance.config import MEMORY_HTML, MEMORY_PROFILE, RUNTIME_PROFILE
 from sphinx_performance.projectenv import ProjectEnv
+from sphinx_performance.renderers.html import HTMLRendererFromJson
 from sphinx_performance.utils import console
 
 
@@ -138,6 +140,16 @@
         " time."
     ),
 )
+@click.option(
+    "--sphinx-events",
+    is_flag=True,
+    default=False,
+    help=(
+        "Generates a JSON runtime summary for each Sphinx event. Only usable if"
+        " --pyinstrument is given. This works by monkey patching the Sphinx"
+        " EventManager.emit function. The modification is visible in the call tree."
+    ),
+)
 @click.pass_context
 def cli_analysis(
     ctx,
@@ -159,6 +171,7 @@ def cli_analysis(
     temp,
     tree,
     tree_filter,
+    sphinx_events,
 ):
     """CLI analysis handling."""
     max_profile_cnt = 2
@@ -221,6 +234,7 @@ def cli_analysis(
                     use_memray=memray,
                     use_memray_live=memray_live,
                     use_pyinstrument=pyinstrument,
+                    use_sphinx_events=sphinx_events,
                 )
 
                 console.print(
@@ -244,22 +258,38 @@ def cli_analysis(
                 if pyinstrument:
                     all_profile.save("pyinstrument_profile.json")
 
-    if pyinstrument and tree:
+    if pyinstrument and (tree or sphinx_events):
         processor_options = {}
         show_all = True
-        if tree_filter:
+        if tree and tree_filter:
             show_all = False
             processor_options["filter_threshold"] = tree_filter
 
-        html_data = HTMLRenderer(
+        json_str = JSONRenderer(
             show_all=show_all,
             processor_options=processor_options,
         ).render(
             all_profile,
         )
-        with Path.open("pyinstrument_profile.html", "w") as profile_html:
-            profile_html.write(html_data)
-            webbrowser.open_new_tab("pyinstrument_profile.html")
+
+        if tree:
+            html_data = HTMLRendererFromJson(
+                show_all=show_all,
+                processor_options=processor_options,
+            ).render(
+                json_str,
+            )
+            with Path("pyinstrument_profile.html").open("w") as events_json_file:
+                events_json_file.write(html_data)
+                webbrowser.open_new_tab("pyinstrument_profile.html")
+
+        if sphinx_events:
+            from sphinx_performance.sphinx_events import aggregate_event_runtime
+
+            json_obj = json.loads(json_str)
+            aggregate_json = aggregate_event_runtime(json_obj)
+            with Path("pyinstrument_sphinx_events.json").open("w") as events_json_file:
+                json.dump(aggregate_json, events_json_file, indent=2, sort_keys=True)
 
     if flamegraph:
         if runtime:

sphinx_performance/config.py

@@ -3,6 +3,7 @@
 
 PROJECTS = {
     "basic": Path(Path(__file__).parent) / "projects" / "basic",
+    "events": Path(Path(__file__).parent) / "projects" / "events",
     "needs": Path(Path(__file__).parent) / "projects" / "needs",
     "theme": Path(Path(__file__).parent) / "projects" / "theme",
 }

sphinx_performance/performance.py

@@ -16,6 +16,7 @@
 
 PROJECTS = {
     "basic": Path(Path(__file__).parent) / "projects" / "basic",
+    "events": Path(Path(__file__).parent) / "projects" / "events",
     "needs": Path(Path(__file__).parent) / "projects" / "needs",
     "theme": Path(Path(__file__).parent) / "projects" / "theme",
 }

sphinx_performance/projectenv.py

@@ -11,13 +11,15 @@
 import webbrowser
 from contextlib import suppress
 from pathlib import Path
+from unittest.mock import patch
 
 import memray
 from jinja2 import Template
 from pyinstrument import Profiler
 from sphinx.application import Sphinx
 
 from sphinx_performance.config import MEMORY_PROFILE, MEMRAY_PORT
+from sphinx_performance.sphinx_events import EventManager
 from sphinx_performance.utils import console
 
 NEED_CONFIG_DEFAULT = ["pages", "folders", "depth"]
@@ -489,6 +491,7 @@ def build_internal(
         use_memray_live=False,
         use_runtime=False,
         use_pyinstrument=False,
+        use_sphinx_events=False,
     ):
         """
         Build sphinx project via the Sphinx API call.
@@ -501,22 +504,34 @@ def build_internal(
             self.build_config["keep"] = True
 
         start_time = time.time()
-        app = Sphinx(
-            srcdir=self.target_path,
-            confdir=self.target_path,
-            outdir=self.target_build_path,
-            doctreedir=self.target_build_path,
-            buildername=str(self.build_config["builder"]),
-            parallel=int(self.build_config["parallel"]),
-        )
+
+        def init_sphinx_and_start_wrap():
+            def init_sphinx_and_start():
+                app = Sphinx(
+                    srcdir=self.target_path,
+                    confdir=self.target_path,
+                    outdir=self.target_build_path,
+                    doctreedir=self.target_build_path,
+                    buildername=str(self.build_config["builder"]),
+                    parallel=int(self.build_config["parallel"]),
+                )
+                return app.build()
+
+            if use_sphinx_events:
+                with patch("sphinx.application.EventManager", EventManager):
+                    return init_sphinx_and_start()
+            else:
+                return init_sphinx_and_start()
+
         if use_runtime:
             with cProfile.Profile() as profile:
-                app.build()
+                init_sphinx_and_start_wrap()
 
+        status_code = 0
         if use_memray:
             memray_file = memray.FileDestination(path=MEMORY_PROFILE, overwrite=True)
             with memray.Tracker(destination=memray_file):
-                app.build()
+                status_code = init_sphinx_and_start_wrap()
 
         if use_memray_live:
             console.print(
@@ -526,19 +541,19 @@ def build_internal(
             )
             memray_port = memray.SocketDestination(server_port=MEMRAY_PORT)
             with memray.Tracker(destination=memray_port):
-                app.build()
+                status_code = init_sphinx_and_start_wrap()
 
         if use_pyinstrument:
             profiler = Profiler()
             import inspect
 
             profiler.start(caller_frame=inspect.currentframe().f_back)
-            app.build()
+            status_code = init_sphinx_and_start_wrap()
             profile = profiler.stop()  # Returns a pyinstrument session
 
         end_time = time.time()
         build_time = end_time - start_time
-        return app.statuscode, build_time, profile
+        return status_code, build_time, profile
 
     def post_processing(self):
         if self.build_config["browser"]:

sphinx_performance/projects/events/README.md

@@ -0,0 +1,3 @@
+This project is for developing the sphinx-performance extension itself.
+It registeres to all known Sphinx events and the listener just waits a while.
+That way all events appear in the output tree with a significant runtime.