|
| 1 | +--- |
| 2 | +layout: post |
| 3 | +title: "Exploring GHC profiling data in Jupyter" |
| 4 | +date: 2025-12-26 14:01:38 +0100 |
| 5 | +categories: blog |
| 6 | +--- |
| 7 | + |
| 8 | + |
| 9 | +Exploratory data analysis (EDA) isn't just for data scientists. Anyone that uses a system that emits data can benefit from the tools of EDA. And since charity begins at home, what better way to motivate this than a short post using DataHaskell tools to analyse GHC profiling logs. |
| 10 | + |
| 11 | +By treating performance analysis as a data exploration problem, we may unlock insights that might be difficult to see in a static report. |
| 12 | + |
| 13 | +This article is for you if: |
| 14 | + |
| 15 | +* • You've profiled Haskell programs before and want a more flexible way to explore the data beyond what static tools provide: filtering, joining, and comparing runs programmatically. |
| 16 | +* • You're comfortable with data tools (pandas, R, SQL) but haven't worked with GHC's profiling infrastructure this will show you how to bridge that gap. |
| 17 | +* • You want to compare performance across code changes by diffing two profiling runs to see exactly what got better or worse, attributed to specific cost centres. |
| 18 | +* • Or you're just curious about DataHaskell! |
| 19 | + |
| 20 | +## The example program |
| 21 | + |
| 22 | +For our scenario today we're going to compare the memory behaviour of two variants of a simple summing function. The first is a textbook strict fold: |
| 23 | + |
| 24 | +```haskell |
| 25 | +sumFast :: B.ByteString -> Int |
| 26 | +sumFast bs = |
| 27 | + let xs = parseAll bs |
| 28 | + in foldlStrict (\ !acc x -> acc + x) 0 xs |
| 29 | +``` |
| 30 | + |
| 31 | +The second version is almost identical, but it retains a sample of partial sums as it runs—a controlled memory leak that accumulates data over time: |
| 32 | + |
| 33 | +```haskell |
| 34 | +data Acc = Acc !Int !Int !SampleList |
| 35 | + |
| 36 | +sumLeaky :: B.ByteString -> Int |
| 37 | +sumLeaky bs = |
| 38 | + let xs = parseAll bs |
| 39 | + Acc s _ samples = foldlStrict step (Acc 0 0 Nil) xs |
| 40 | + in sampleLength samples `seq` s |
| 41 | + where |
| 42 | + step (Acc s i history) x = |
| 43 | + let !s' = s + x |
| 44 | + !i' = i + 1 |
| 45 | + !history' = if i' `rem` 50000 == 0 |
| 46 | + then Cons s' history |
| 47 | + else history |
| 48 | + in Acc s' i' history' |
| 49 | +``` |
| 50 | + |
| 51 | +Both compute the same result. Both have similar runtime. But one retains memory that the other doesn't—and we want to see that difference in the profiling data. |
| 52 | + |
| 53 | +To generate eventlogs, you need to: |
| 54 | + |
| 55 | +1. Compile with profiling enabled: `cabal build --enable-profiling --profiling-detail=all-functions -O2` |
| 56 | +2. Run with the right RTS flags: `cabal run your-program -- +RTS -hc -l-agu -RTS` |
| 57 | + |
| 58 | +Here `-hc` requests heap profiling by cost centre (we'll explain what that means shortly), and `-l-agu` enables the eventlog while disabling some less relevant event types. This produces a `.eventlog` file alongside your executable. For our example, we generate two: `fast.eventlog` and `leaky.eventlog`. |
| 59 | + |
| 60 | +The standard tool for visualising these logs is eventlog2html, which produces beautiful interactive HTML reports. |
| 61 | + |
| 62 | + |
| 63 | + |
| 64 | + |
| 65 | +It's excellent for getting a quick overview—but sometimes you need more. You might want to filter to specific cost centres, compare two runs side-by-side, compute derived metrics, or ask questions the tool's authors didn't anticipate. |
| 66 | + |
| 67 | +We'd like to see if we can get this and then more using a SQL-like API to explore our eventlog data. In this blog post we'll do two things: firstly, we'll show how to regenerate the heap usage chart from eventlog2html. Secondly we'll show how to use operations like join to diff two runs. |
| 68 | + |
| 69 | +## Generating eventlogs |
| 70 | + |
| 71 | +GHC can emit detailed runtime information into eventlog files. These binary logs contain a stream of timestamped events: garbage collection statistics, heap samples, cost centre attributions, and more. |
| 72 | + |
| 73 | +## From eventlogs to dataframes |
| 74 | + |
| 75 | +An eventlog is just a pile of raw facts with disjointed descriptions of what happened and when it happened. To turn it into answers, we need tools that can ingest event streams, normalise timestamps, join disparate metrics, and visualise relationships. |
| 76 | + |
| 77 | +We'll use the ghc-events library to parse the binary format, then load the data into a DataFrame. This gives us a familiar columnar interface. If you've used pandas or dplyr, the operations should feel natural. |
| 78 | + |
| 79 | +We write some [custom code to parse eventlog files](https://gist.github.com/mchav/ae93567450075fb65d0579254f7dc406) into structures that we'll eventually turn into dataframes. |
| 80 | + |
| 81 | + |
| 82 | + |
| 83 | +After parsing, we have a table with three columns: time, cc_label (the cost centre label), and residency (bytes retained): |
| 84 | + |
| 85 | + |
| 86 | + |
| 87 | +### A quick note on cost centres |
| 88 | + |
| 89 | +A cost centre is GHC's unit of attribution for profiling. When you compile with `-profiling-detail=all-functions`, GHC inserts cost centres at function boundaries. Each heap sample then records how much memory is attributed to each cost centre. |
| 90 | +Cost centre labels look like `sumLeaky.step.history' (Main)`. That's the function history' defined inside step inside sumLeaky, in the Main module. These hierarchical names let you trace allocations back to specific expressions in your code. |
| 91 | + |
| 92 | +## Aggregation |
| 93 | + |
| 94 | +Raw performance data is noisy. The runtime might emit a "Heap Size" event every few microseconds, creating thousands of data points per second of runtime. Using DataFrame functions, we can group these by a coarser time grain and calculate the mean, effectively "smoothing" the signal. |
| 95 | + |
| 96 | + |
| 97 | + |
| 98 | + |
| 99 | + |
| 100 | +Now we have one row per cost centre, with summary statistics. But the real power comes when we compare runs. |
| 101 | + |
| 102 | +## Joining two profiling runs |
| 103 | + |
| 104 | +To diff the fast and leaky versions, we perform a full outer join on the cost centre label: |
| 105 | + |
| 106 | + |
| 107 | + |
| 108 | +The result tells us exactly where the memory went. The history' binding where we cons onto the sample list accounts for the retained memory. |
| 109 | + |
| 110 | +## Correlating different metrics |
| 111 | + |
| 112 | +Eventlogs contain multiple types of events. Beyond heap samples by cost centre, we get: |
| 113 | + |
| 114 | +* • HeapLive: actual live bytes after GC |
| 115 | +* • HeapSize: total heap size requested from the OS |
| 116 | +* • BlocksSize: memory in block allocator |
| 117 | + |
| 118 | +We can parse these into separate DataFrames, aggregate by time, and join them together: |
| 119 | + |
| 120 | + |
| 121 | + |
| 122 | +This gives us a wide table where each row is a time bucket, and columns show different metrics for each run: |
| 123 | + |
| 124 | + |
| 125 | + |
| 126 | +## Plotting the results |
| 127 | + |
| 128 | +Now we can go ahead and plot the famous eventlog2html heap usage chart with both runs in the same chart. |
| 129 | + |
| 130 | + |
| 131 | + |
| 132 | +We can "zoom in" on the chart by taking the first 5 rows and see the difference in live bytes. |
| 133 | + |
| 134 | + |
| 135 | + |
| 136 | +The leaky version shows steadily increasing live bytes; the fast version stays flat. But more importantly, we can now query this data: what's the rate of growth? When does the leak become significant? Does block size track live bytes, or does the allocator hold onto memory after GC reclaims it? |
| 137 | + |
| 138 | +As an added bonus, We can run our profiling code in GHCi/a regular script as well and produce similar output. |
| 139 | + |
| 140 | + |
| 141 | + |
| 142 | +## What we learned |
| 143 | + |
| 144 | +The notebook captures the entire pipeline from raw eventlog to final visualisation. Re-run it after a code change and you get an updated diff automatically. Because everything is in DataFrames, we can filter to specific time ranges, compute ratios, correlate with GC events, or export to CSV for further analysis in other tools. |
| 145 | + |
| 146 | +This gives us a flexible way of exploring performance. |
| 147 | + |
| 148 | +The full notebook is available to explore in the [DataHaskell playground](https://ulwazi-exh9dbh2exbzgbc9.westus-01.azurewebsites.net/lab/tree/examples/performance_exploration.ipynb). |
| 149 | + |
| 150 | +## What's next? |
| 151 | + |
| 152 | +We are currently working on turning this workflow into a dedicated library. We're working with developers to see what data and charts will be the most useful for understanding performance. Our goal is to provide a seamless bridge between the GHC RTS and high-level analysis tools. Along with the library, we will be providing guides on how to use these data-science techniques to diagnose specific performance pathologies. |
| 153 | + |
| 154 | +As always watch this space and if this sort of work is interesting to you, hop over to the DataHaskell discord to get in on the action. |
0 commit comments