The Morpho Profiler

The morpho profiler

Morpho provides a simple profiler to help identify bottlenecks in the program. To use it run morpho with the -profilecommand line switch. As the program runs, a separate monitor thread runs independently and samples the state of the morpho virtual machine at regular intervals, deducing at each time which function or method is in use. At the end of program execution, the profiler prints a report. A sample run[^7] might produce something like:

===Profiler output: Execution took 51.019 seconds with 272450 samples===
issame                              32.98% [89866 samples]
Delaunay.dedup                      15.63% [42580 samples]
(garbage collector)                 13.41% [36528 samples]
List.ismember                       7.16% [19518 samples]
Delaunay.triangulate                6.40% [17450 samples]
List.enumerate                      3.58% [9750 samples]
Show.trianglecomplexobjectdata      2.59% [7065 samples]
Circumsphere.init                   2.24% [6091 samples]
OneSidedHookeElasticity.integrandfn 1.77% [4834 samples]
Matrix.column                       1.25% [3412 samples]
(anonymous)                         1.25% [3406 samples]
List.count                          1.01% [2758 samples]
Range.enumerate                     0.90% [2451 samples]
...

On the first line, the profiler reports the time elapsed between the start and end of executing the program (which does not include compilation time) and the total number of samples taken. In subsequent lines, the profiler reports the name of a function or method, the number of samples in which the virtual machine was observed to be in that function, and the overall fraction of samples as a percentage. The list is sorted so that the most common function is reported first. The profiler reports on both user-implemented functions and morpho functions and methods that are implemented in C (but visible to the user).

There are some special entries: anonymous functions are reported as (anonymous); time in the global context, i.e. outside of a function or method is reported as (global); time spent in the garbage collector is reported as (garbage collector), here on the third line. Garbage collection in this example is frequently \(\sim10\%\) of execution time; if it becomes significantly higher, this may suggest your program is creating too many temporary objects.

How to interpret and act on profiler data is something of an art form. In the above example, the largest fraction of execution time was spent in a relatively function, issame, that compared two objects. An obvious strategy would have been to simply reimplement the function in C, which would have undoubtedly improved the performance. However, on inspecting the code it was realized that issame was actually being called by Delaunay.dedup to remove entries from a data structure, and that by using a different data structure this step could be entirely eliminated providing a significant performance gain.

Hence, optimization involves not only thinking about the performance of individual pieces of code, but also the data structures and algorithms being used. The profiler simply directs the programmer's attention to the most time consuming bits of code to avoid optimizing sections of code that aren't called frequently.