haskell / haskell/cabal

-ddump-timings -ddump-to-file isn't useful when using cabal build

Open
#11,116 0 comments 0 reactions 0 assignees View on GitHub
cabal-install: v2-build system re: ghc-options type: bug
Dominant language
Haskell
Stars
1.7k
Forks
750
Avg merge
4d 3h
Merged PRs (30d)
28

Description

**Describe the bug**

When benchmarking GHC plugins, I'm using `-ddump-timings` and `-ddump-to-file` to collect time measures from GHC.

These flags produce a file with timing information like.

```
$ cat dist-newstyle/build/x86_64-linux/ghc-9.10.1/ddump-timings-bug-0.1.0.0/x/ddump-timings-bug/build/ddump-timings-bug/ddump-timings-bug-tmp/Main.dump-timings
Parser [Main]: alloc=105112 time=0.138
Renamer/typechecker [Main]: alloc=11916624 time=36.336
Desugar [Main]: alloc=273864 time=0.234
Simplifier [Main]: alloc=13366136 time=11.262
Specialise [Main]: alloc=45088 time=0.036
Float out(FOS {Lam = Just 0, Consts = True, OverSatApps = False}) [Main]: alloc=87344 time=0.069
Simplifier [Main]: alloc=219944 time=0.130
Simplifier [Main]: alloc=434768 time=0.218
Simplifier [Main]: alloc=116280 time=0.058
Float inwards [Main]: alloc=19072 time=0.010
Called arity analysis [Main]: alloc=20816 time=0.007
Simplifier [Main]: alloc=157752 time=0.404
Demand analysis (including Boxity) [Main]: alloc=61888 time=0.049
Constructed Product Result analysis [Main]: alloc=32536 time=0.017
Worker Wrapper binds [Main]: alloc=25680 time=0.015
Simplifier [Main]: alloc=119352 time=0.065
Exitification transformation [Main]: alloc=22272 time=0.007
Float out(FOS {Lam = Just 0, Consts = True, OverSatApps = True}) [Main]: alloc=79664 time=0.037
Common sub-expression [Main]: alloc=20792 time=0.007
Float inwards [Main]: alloc=19072 time=0.005
Simplifier [Main]: alloc=262480 time=0.144
Demand analysis [Main]: alloc=58592 time=0.033
CoreTidy [Main]: alloc=90224 time=0.070
LatePlugins [Main]: alloc=13888 time=0.010
CorePrep [Main]: alloc=40200 time=0.035
CoreToStg [Main]: alloc=82832 time=0.073
CodeGen [Main]: alloc=1407568 time=2.925
WriteIface [/home/facundo/ddump-timings-bug/dist-newstyle/build/x86_64-linux/ghc-9.10.1/ddump-timings-bug-0.1.0.0/x/ddump-timings-bug/build/ddump-timings-bug/ddump-timings-bug-tmp/Main.hi]: alloc=1229344 time=0.159
systool:as: alloc=115936 time=0.304
```

Unfortunately, cabal invokes `ghc --make` twice, once to build the modules with `ghc --make -no-link ...`, and once again to link the modules without `-no-link`. The second call sometimes overwrites the `*.dump-timings` files, as in

```
$ cat dist-newstyle/build/x86_64-linux/ghc-9.10.1/ddump-timings-bug-0.1.0.0/x/ddump-timings-bug/build/ddump-timings-bug/ddump-timings-bug-tmp/Main.dump-timings
systool:hs-cpp: alloc=274440 time=1.394

```

**To Reproduce**

Create the following `ddump-timings-bug.cabal` file
```
cabal-version: 3.4
name: ddump-timings-bug
version: 0.1.0.0
build-type: Simple

executable ddump-timings-bug
ghc-options: -ddump-timings -ddump-to-file
main-is: Main.hs
build-depends: base
hs-source-dirs: .
```

and create the following `Main.hs` file
```
-- CPP is important to reproduce the behavior, although this
-- module doesn't need it.
{-# LANGUAGE CPP #-}
module Main where
main :: IO ()
main = putStrLn "someFunc"
```

Then run
```
nix-shell -p haskell.compiler.ghc9122 cabal-install --run 'cabal build'
```

The output will be
```
$ cat dist-newstyle/build/x86_64-linux/ghc-9.10.1/ddump-timings-bug-0.1.0.0/x/ddump-timings-bug/build/ddump-timings-bug/ddump-timings-bug-tmp/Main.dump-timings
systool:hs-cpp: alloc=274440 time=1.394

```
which misses the timing information from the build step.

**Expected behavior**

The link step timings should be stored elsewhere, or there would be a way to avoid using `-ddump-timings` and `-ddump-to-file` when linking.

**System information**
- Operating system: Nixos
- `cabal` version: 3.12.1.0

Contributor guide

Open the contributing guide

Research direction

Start by reproducing the issue with the supplied ddump-timings-bug.cabal, Main.hs, and cabal build command. Trace how Cabal invokes GHC for the no-link and link steps and how ghc-options are applied. Done means build timings are preserved separately or there is a documented way to omit these flags during linking.

Written by the indexing model from the issue text.

Assessment

Tech stack
haskell
Domain
build-system
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
45/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.