Dispatch profiling (#1621)

These changes fix dispatch profiling, make it more usable in practice,
and document how to use it.

documentation/source/library-reference/dispatch-profiler/index.rst

@@ -0,0 +1,261 @@
+*****************************
+The DISPATCH-PROFILER library
+*****************************
+
+.. current-library:: dispatch-profiler
+
+The dispatch profiler library exposes the multimethod dispatch
+profiling capability built in to the Open Dylan run-time library,
+making it possible to identify costly function calls in code. While
+*dispatch coloring* can identify calls that could and could not be
+optimized at compile time, dispatch profiling shows which calls have
+an actual effect on dynamic performance.
+
+While this library can be quite useful, it was originally built as
+part of prototyping the dispatch mechanisms in Open Dylan, rather than
+as a polished tool. We hope that in the future this functionality can
+be incorporated into the debugger, making direct use of this library
+unnecessary.
+
+Preparing for Profiling
+***********************
+
+Before dispatch profiling can be enabled during program execution, you
+will need to request that the compiler generate generic function call
+data structures (with slightly higher overhead) that are capable of
+collecting profile counts. This can be done by setting the
+:envvar:`OPEN_DYLAN_PROFILE_ALL_CALLS` environment variable to a
+non-empty string when invoking the compiler:
+
+.. code-block:: console
+
+  $ OPEN_DYLAN_PROFILE_ALL_CALLS=1 dylan-compiler -build write-100mb
+
+
+Report Output Format
+********************
+
+After a profiling run, upon collection of dispatch statistics a
+profiling report can be written out. The report, sorted by ``COST``
+field, lists generic functions and call sites for which any method
+invocations are present in the dispatch cache. The following fields
+appear in the report:
+
+``GENERICS``
+  The count of generic functions in an application or library
+  appearing in the report.
+
+``CLASSES``
+  The total number of classes appearing in the application.
+
+``DEP-GFS``
+  Not currently supported (based on an analysis currently commented out
+  in the compiler).
+
+``CT-S-CALLS``
+  Count of static calls (i.e., to a specific known method or slot accessor)
+  as determined by the compiler for a library or application.
+
+``CT-D-CALLS``
+  Count of dynamic calls (i.e., using full run-time dispatch through the
+  :drm:`<generic-function>` object) as determined by the compiler for
+  a library or application.
+
+``S/D``
+  The ratio of (compile-time) static to dynamic calls.
+
+``RT-S-CALLS``
+  The number of call sites in the library or application where a
+  method was called but the ``COST`` was 0.
+
+``E-RT-S/D``
+  The ratio of the total number of static calls (``RT-S-CALLS`` plus
+  ``CT-S-CALLS``) to the total number of call sites identified by the
+  compiler (``CT-S-CALLS`` plus ``CT-D-CALLS``).
+
+``POLY``
+  The degree of polymorphism. For a given call site, represents the
+  number of distinct methods called. For a generic function, library,
+  or application, represents the total call site polymorphism divided
+  by the number of call sites.
+
+``TOT SIZE``
+  The memory storage size (in units of pointer-sized object slots)
+  used by method dispatch cache nodes.
+
+``AVG SIZE``
+  The average memory storage size (in units of pointer-sized object
+  slots) of each associated method dispatch cache node.
+
+``HITS``
+  The number of times that the dispatched method was found in the
+  method dispatch cache.
+
+``COST``
+  The total number of discriminator nodes traversed in order to locate
+  the dispatched method in the cache. Useful as an approximation for the
+  cost of method dispatch for a given call site or generic function.
+
+``COST/HIT``
+  The average number of discriminator nodes that needed to be
+  traversed in order to dispatch to the given method.
+
+``C-HITS``
+  The total number of discriminator nodes traversed with successful
+  discrimination tests.
+
+``C-TRIES``
+  The total number of discriminator nodes traversed (identical to
+  ``COST``).
+
+``HIT-RATE``
+  The ratio of ``C-HITS`` to ``C-TRIES``.
+
+The DISPATCH-PROFILER module
+****************************
+
+.. current-module:: dispatch-profiler
+
+.. macro:: with-dispatch-profiling-report
+   :statement:
+
+   Performs dispatch profiling over a body of code and prints out a
+   profiling report.
+
+   :macrocall:
+     .. parsed-literal::
+        with-dispatch-profiling-report (#key `keys`)
+          `body`
+        end
+
+   :param keys: Zero or more of the keywords provided by :gf:`print-dispatch-statistics`.
+   :param body: A body of Dylan code.
+
+   :description:
+
+     Executes the *body* with dispatch profiling enabled. Clears
+     dispatch profiling counters before beginning execution, disables
+     profiling and collects statistics at the end, and then writes out
+     a report using :gf:`print-dispatch-statistics`.
+
+   :example:
+
+     .. code-block:: dylan
+
+       define function main()
+         with-dispatch-profiling-report (by-library?: #t, profile-base: "write-100mb-")
+           let string = make(<string>, size: 100, fill: 'x');
+           with-open-file (stream = "/tmp/100mb.dylan.txt", direction: #"output")
+             for (i from 1 to 1024 * 1024)
+               write(stream, string);
+             end;
+           end;
+         end;
+       end function;
+
+.. generic-function:: decache-all-generics
+
+     Restores dispatch caches of generic functions in the given
+     library and dependent libraries to their initial states.
+
+   :signature: decache-all-generics (library) => ()
+
+   :parameter library: An instance of :class:`<library>`.
+
+.. generic-function:: clear-dispatch-profiling
+
+     Resets call site profile counts and discriminator hit counts.
+
+   :signature: clear-dispatch-profiling (library) => ()
+
+   :description:
+
+     Resets the call site profile counts and discriminator hit
+     counts of all dispatch cache nodes for generic functions in the
+     given library and dependent libraries.
+
+   :parameter library: An instance of :class:`<library>`.
+
+.. generic-function:: make-dispatch-statistics
+
+     Instantiates a new object for collecting dispatch statistics in
+     preparation for report output.
+
+   :signature: make-dispatch-statistics (shared-generic-caches?) => (#rest results)
+
+   :parameter shared-generic-caches?: An instance of :class:`<object>`.
+   :value results: An instance of :class:`<application-profile-results>`.
+
+.. generic-function:: clear-dispatch-statistics!
+
+     Resets a :class:`<application-profile-results>` to its initial state.
+
+   :signature: clear-dispatch-statistics! (profile) => ()
+
+   :parameter profile: An instance of :class:`<application-profile-results>`.
+
+.. generic-function:: collect-dispatch-statistics
+
+     Traverses generic function call sites in the given library and
+     collects dispatch statistics into the given profile results
+     object.
+
+   :signature: collect-dispatch-statistics (library profile) => ()
+
+   :parameter library: An instance of :class:`<library>`.
+   :parameter profile: An instance of :class:`<application-profile-results>`.
+
+.. generic-function:: print-dispatch-statistics
+
+    Prints out a summary of dispatch profiling results.
+
+   :signature: print-dispatch-statistics (app-results #key library profile-base full? by-library? hits-only? app-results-only? uncalled-methods? app-details?) => ()
+
+   :parameter app-results: An instance of :class:`<application-profile-results>`.
+   :parameter #key library: An instance of ``false-or(<symbol>)``.
+   :parameter #key profile-base: An instance of ``false-or(<string>)``.
+   :parameter #key full?: An instance of :class:`<object>`. Defaults to ``#t``.
+   :parameter #key by-library?: An instance of :class:`<object>`.
+   :parameter #key hits-only?: An instance of :class:`<object>`. Defaults to ``#t``.
+   :parameter #key app-results-only?: An instance of :class:`<object>`.
+   :parameter #key uncalled-methods?: An instance of :class:`<object>`.
+   :parameter #key app-details?: An instance of :class:`<object>`. Defaults to ``#t``.
+
+   :description:
+
+     If a particular ``library`` is requested (by name) and if
+     ``by-library?`` is not false, then then ``profile-base`` must be
+     provided, and the output is placed in files with names based on
+     the profile base name, the library name, and the extension
+     ``.prf``. Otherwise, the results summary is written to
+     :var:`*standard-output*`.
+
+     If ``hits-only?`` is not false (the default) then call sites that
+     never successfully used the method dispatch cache will be omitted
+     from the report. If ``uncalled-methods?`` is true, then the
+     report will list methods in the dispatch cache that were never
+     invoked.
+
+.. generic-function:: enable-generic-caches-only
+
+   :signature: enable-generic-caches-only (library) => ()
+
+     Disable call-site method dispatch caches.
+
+   :parameter library: An instance of :class:`<library>`.
+
+     Configures the dispatch mechanisms in the Open Dylan run-time to
+     only use per-:drm:`<generic-function>` caches for method dispatch
+     rather than call-site specific caches. This was intended to be
+     used for comparison purposes during the development of the
+     dispatch mechanisms.
+
+.. generic-function:: enable-call-site-caches-only
+
+     Configures the dispatch mechanisms in the Open Dylan run-time to
+     use call-site specific method dispatch caches.
+
+   :signature: enable-call-site-caches-only (library) => ()
+
+   :parameter library: An instance of :class:`<library>`.
+

documentation/source/library-reference/index.rst

@@ -25,6 +25,7 @@ Contents:
    collections/index
    coloring-stream/index
    common-dylan/index
+   dispatch-profiler/index
    dood/index
    dylan/index
    io/index

documentation/source/release-notes/2024.2.rst

@@ -77,6 +77,9 @@ System
 Other
 -----
 
+* The :lib:`dispatch-profiler` library is now usable and is
+  documented.
+
 * The obsolete (32-bit x86-only) ``stack-walker`` library was removed.
 
 Contributors

sources/dfmc/llvm-back-end/llvm-entry-points.dylan

@@ -2247,7 +2247,6 @@ define outer cache-header entry-point-descriptor profiling-cache-header
   let engine-cast = op--object-pointer-cast(be, engine, pcschen-class);
 
   // Increment the profiling counter atomically
-  // FIXME declare engine node count fields as <raw-machine-word>
   let rmw-slotptr-type
     = llvm-pointer-to(be, llvm-reference-type(be, dylan-value(#"<raw-machine-word>")));
   let count-1-ptr

sources/dfmc/modeling/functions.dylan

@@ -1634,8 +1634,8 @@ define concrete-engine-node-initialization <simple-call-site-cache-header-engine
 end concrete-engine-node-initialization;
 
 define primary &class <profiling-call-site-cache-header-engine-node> (<cache-header-engine-node>)
-  &slot profiling-call-site-cache-header-engine-node-count-1;
-  &slot profiling-call-site-cache-header-engine-node-count-2;
+  raw &slot profiling-call-site-cache-header-engine-node-count-1 :: <raw-machine-word>;
+  raw &slot profiling-call-site-cache-header-engine-node-count-2 :: <raw-machine-word>;
   &slot profiling-call-site-cache-header-engine-node-id;
   &slot profiling-call-site-cache-header-engine-node-library;
   slot  profiling-call-site-cache-header-engine-node-call;

sources/dylan/discrimination.dylan

@@ -699,10 +699,10 @@ define function compute-terminal-engine-node (ds :: <dispatch-state>)
       = bootstrap-typed-allocate-engine-node(<profiling-call-site-cache-header-engine-node>,
                                              engine-node$k-profiling-cache-header,
                                              0);
-    primitive-initialize-discriminator(new);
+    cache-header-engine-node-parent(new) := parent;
+    primitive-initialize-engine-node(new);
     %profile-count-low(new)  := as(<machine-word>, 0);
     %profile-count-high(new) := as(<machine-word>, 0);
-    cache-header-engine-node-parent(new) := parent;
     install-cache-header-engine-node-next(new, ans, %ds-gf(ds));
     new
   else

sources/dylan/new-dispatch.dylan

@@ -722,6 +722,7 @@ define function make-linear-class-keyed-discriminator
   let d :: <linear-class-keyed-discriminator>
     = bootstrap-allocate-repeated-discriminator(code, argnum, extra-bits, table-size, $ckd-empty);
   lckd-index(d) := 0;
+  lckd-hits(d) := 0;
   primitive-initialize-discriminator(d);
   d
 end function;
@@ -791,6 +792,7 @@ define inline function linear-class-key-lookup
           else
             let otherkey = %ckd-ref(d, i);
             if (pointer-id?(otherkey, key))
+              lckd-hits(d) := add-without-overflow(lckd-hits(d), 1);
               %ckd-ref(d, add-without-overflow(i, 1))
             // elseif (pointer-id?(otherkey, $ckd-empty))
             //   default
@@ -1236,6 +1238,7 @@ define function make-linear-singleton-discriminator
   singleton-discriminator-table(d) := v;
   singleton-discriminator-default(d) := $absent-engine-node;
   lsd-index(d)    := 0;
+  lsd-hits(d)     := 0;
   local method loop(i :: <integer>, l :: <list>)
           unless (l == #())
             if (~(i < len)) // @@@@ (i >= len)
@@ -1291,6 +1294,7 @@ define inline function immediate-linear-singleton-discriminator-element
             else
               let k = vector-element(table, i);
               if (pointer-id?(k, key))
+                lsd-hits(d) := add-without-overflow(lsd-hits(d), 1);
                 lsd-index(d) := i;
                 vector-element(table, i + 1)
               else
@@ -1341,6 +1345,7 @@ define inline function value-object-linear-singleton-discriminator-element
             else
               let k = vector-element(table, i);
               if (k ~== $absent-engine-node & k = key)
+                lsd-hits(d) := add-without-overflow(lsd-hits(d), 1);
                 lsd-index(d) := i;
                 vector-element(table, i + 1)
               else

sources/lib/dispatch-profiler/dispatch-profiler-library.dylan

@@ -33,6 +33,7 @@ define module dispatch-profiler
     clear-dispatch-statistics!,
     collect-dispatch-statistics,
     print-dispatch-statistics,
+    with-dispatch-profiling-report,
     enable-generic-caches-only,
     enable-call-site-caches-only
     ;

sources/lib/dispatch-profiler/dispatch-profiler.dylan

@@ -378,11 +378,6 @@ define method print-dispatch-statistics
      #key library :: false-or(<symbol>), profile-base :: false-or(<string>),
           full? = #t, by-library? = #f, hits-only? = #t, app-results-only? = #f, uncalled-methods? = #f, app-details? = #t)
   let stream   = #f;
-  // HACK: pentium-dw command parser is brain damaged
-  when (profile-base)
-    let end-index = find-key(profile-base, curry(\==, ' ')) | size(profile-base);
-    profile-base := copy-sequence(profile-base, end: end-index);
-  end when;
   local method current-stream (app-stream, library) => (stream)
           if (app-stream & app-stream ~== *standard-output*)
             app-stream
@@ -651,6 +646,24 @@ define method print-dispatch-statistics
   end block;
 end method;
 
+define macro with-dispatch-profiling-report
+  { with-dispatch-profiling-report(#rest ?options:expression)
+      ?:body
+     end }
+  => { block ()
+         clear-dispatch-profiling(%current-library());
+         profile-all-terminal-engine-nodes?() := #t;
+         *dispatch-profiling-enabled?* := #t;
+         ?body
+       cleanup
+         *dispatch-profiling-enabled?* := #f;
+
+         let stats = make-dispatch-statistics(#f);
+         collect-dispatch-statistics(%current-library(), stats);
+         print-dispatch-statistics(stats, ?options);
+       end }
+end macro;
+
 define method enable-call-site-caches-only (library)
   call-site-caches-enabled?()          := #t;
   profile-all-terminal-engine-nodes?() := #t;