From 94e7d026d6fcfd061e1d6eaf4b8846a77d32933d Mon Sep 17 00:00:00 2001 From: Simon Michael Date: Sun, 23 Aug 2015 10:23:20 -0700 Subject: [PATCH] doc: dev guide: benchmarking --- doc/developer-guide.md | 105 ++++++++++++++++++++++++++++++++++++++++- 1 file changed, 103 insertions(+), 2 deletions(-) diff --git a/doc/developer-guide.md b/doc/developer-guide.md index 733e3c2eb..a83d7f98c 100644 --- a/doc/developer-guide.md +++ b/doc/developer-guide.md @@ -304,7 +304,109 @@ $ make ghci-dev ``` --> -### Run the tests +### Run benchmarks + +Benchmarks are standard performance measurements, +which we define using `bench` declarations in cabal files. +There is [one in hledger.cabal](https://github.com/simonmichael/hledger/blob/master/hledger/hledger.cabal#L228), +with related code and data files in [hledger/bench/](https://github.com/simonmichael/hledger/tree/master/hledger/bench). + +To run the standard hledger benchmark, use `stack bench hledger`. +This installs haskell dependencies (but not system dependencies) and rebuilds as needed, +then runs [hledger/bench/bench.hs](https://github.com/simonmichael/hledger/blob/master/hledger/bench/bench.hs), +which by default shows quick elapsed-time measurements for several operations on a standard data file: + +```shell +$ stack bench hledger +NOTE: the bench command is functionally equivalent to 'build --bench' +... +hledger-0.26.98: benchmarks +Running 1 benchmarks... +Benchmark bench: RUNNING... +Benchmarking hledger in /Users/simon/src/hledger/hledger with timeit +read bench/10000x1000x10.journal [1.63s] +print [1.41s] +register [1.83s] +balance [0.24s] +stats [0.22s] +Total: 5.33s +Benchmark bench: FINISH +``` + +bench.hs has some other modes, which you can use by compiling and running it directly. +`--criterion` reports more detailed and dependable measurements, but takes longer: + +```shell +$ cd hledger; stack exec -- ghc -ibench bench/bench && bench/bench --criterion +... +Linking bench/bench ... +Benchmarking hledger in /Users/simon/src/hledger/hledger with criterion +benchmarking read bench/10000x1000x10.journal +time 1.414 s (1.234 s .. 1.674 s) + 0.996 R² (0.989 R² .. 1.000 R²) +mean 1.461 s (1.422 s .. 1.497 s) +std dev 59.69 ms (0.0 s .. 62.16 ms) +variance introduced by outliers: 19% (moderately inflated) + +benchmarking print +time 1.323 s (1.279 s .. 1.385 s) + 1.000 R² (0.999 R² .. 1.000 R²) +mean 1.305 s (1.285 s .. 1.316 s) +std dev 17.20 ms (0.0 s .. 19.14 ms) +variance introduced by outliers: 19% (moderately inflated) + +benchmarking register +time 1.995 s (1.883 s .. 2.146 s) + 0.999 R² (0.998 R² .. NaN R²) +mean 1.978 s (1.951 s .. 1.995 s) +std dev 25.09 ms (0.0 s .. 28.26 ms) +variance introduced by outliers: 19% (moderately inflated) + +benchmarking balance +time 251.3 ms (237.6 ms .. 272.4 ms) + 0.998 R² (0.997 R² .. 1.000 R²) +mean 260.4 ms (254.3 ms .. 266.5 ms) +std dev 7.609 ms (3.192 ms .. 9.638 ms) +variance introduced by outliers: 16% (moderately inflated) + +benchmarking stats +time 325.5 ms (299.1 ms .. 347.2 ms) + 0.997 R² (0.985 R² .. 1.000 R²) +mean 329.2 ms (321.5 ms .. 339.6 ms) +std dev 11.08 ms (2.646 ms .. 14.82 ms) +variance introduced by outliers: 16% (moderately inflated) +``` + +`--simplebench` shows a table of elapsed-time measurements for the commands defined in [bench/default.bench](https://github.com/simonmichael/hledger/blob/master/hledger/bench/default.bench). +It can also show the results for multiple h/ledger executables side by side, if you tweak the bench.hs code. +Unlike the other modes, it does not link with the hledger code directly, but runs the "hledger" executable found in $PATH (so ensure that's the one you intend to test). + +```shell +$ cd hledger; stack exec -- ghc -ibench bench/bench && bench/bench --simplebench +Benchmarking /Users/simon/.local/bin/hledger in /Users/simon/src/hledger/hledger with simplebench and shell +Using bench/default.bench +Running 4 tests 1 times with 1 executables at 2015-08-23 16:58:59.128112 UTC: +1: hledger -f bench/10000x1000x10.journal print [3.27s] +1: hledger -f bench/10000x1000x10.journal register [3.65s] +1: hledger -f bench/10000x1000x10.journal balance [2.06s] +1: hledger -f bench/10000x1000x10.journal stats [2.13s] + +Summary (best iteration): + ++-----------------------------------------++---------+ +| || hledger | ++=========================================++=========+ +| -f bench/10000x1000x10.journal print || 3.27 | +| -f bench/10000x1000x10.journal register || 3.65 | +| -f bench/10000x1000x10.journal balance || 2.06 | +| -f bench/10000x1000x10.journal stats || 2.13 | ++-----------------------------------------++---------+ +``` + +For quick, fine-grained performance measurements eg when troubleshooting or optimising, I use [dev.hs](https://github.com/simonmichael/hledger/blob/master/dev.hs). + + +### Run tests This command will install haskell dependencies (you might need to install additional system dependencies yourself) and run the package @@ -336,7 +438,6 @@ Test haddock doc generation: $ make haddocktest ``` - ### Add a test - identify what to test