Easy Haskell Profiling

Would you rather look at:

or

The above are two presentations of the same information - profiling reports for a Haskell program. I want to show you a tool that I wrote, which generates the second type of report and makes it easy to find the hot spots in your programs. To quote the package description:

visual-prof profiles your Haskell program and generates a HTML file containing its source code with parts of the code highlighted in different colors depending on the fraction of the running time that they take

The example above uses an inefficient project Euler solution which was posted on StackOverflow. In order to run the profiling, the code needs a main function. You can find the exact code that is used in this post at https://github.com/djv/VisualProf/blob/master/eu13.hs

Profiling in Haskell

To get the standard Haskell profiling report you have to compile with the -prof flag set. -auto-all means that you want profiling information for all the top-level functions. For our example we would compile with:

ghc -O2 --make eu13.hs -prof -auto-all -fforce-recomp

and then run:

./eu13 +RTS -p

The report is written in eu13.prof and is what you saw in the beginning of this post.

The first problem with the default report is that you only see the top-level profiling information, in our case 100% of the time is spent in numDivs. To drill down to the subexpression level, in order to find which part of the function definition is taking the most time, we need to add the so-called cost centers by hand. When you have big function definitions this becomes very tedious.

Another problem is that even with the manually added cost centers, you need to go back and forth between your source code and the profiling report.

Profiling with VisualProf

While working on a school project, I found myself wasting a lot of time manually adding SCCs and deciphering the profiling reports. That’s why I wrote VisualProf which produces an HTML profiling report with a single command line.

To generate the visual report from the example above, we’ll start by cloning the github repo:

git clone https://github.com/djv/VisualProf.git

In order to profile any Haskell code you need to have all the imported libraries installed with profiling enabled (cabal install -p libraryname). If you don’t have that turned on you’ll have to reinstall a lot of existing packages, which I don’t recommend. The better option is to work in a cabal sandbox:

cd VisualProf
cabal sandbox init

With or without a sandbox the next step is to run install:

cabal install visual-prof

To get the profiling report run:

./.cabal-sandbox/bin/visual-prof -px eu13.hs eu13

This will generate the HTML in eu13.hs.html and also the text report under eu13.prof.

Another example

If you are curious, I have included the pidigits benchmark as a second example in the github repo. It contains only one function with a pretty long definition, the visual profiling report is:

How does it work?

VisualProf goes through the following steps:

1. Parse the source code and wrap every subexpression in a SCC syntax tree element. The SCCs have consecutive numbers as identifiers.
2. Compile using ghc with profiling turned on and run the executable.
3. Parse the text profiling report and build a map from the SCC id to percentage of runtime used.
4. Go back to the source code and pretty print it but replacing every SCC with an HTML tag specifying the background color. The colors are calculated based on the values in the map from step 3.
5. Open the HTML report in your favourite browser.