#15938: Hadrian's recompilation check is extremely slow -------------------------------------+------------------------------------- Reporter: bgamari | Owner: alpmestan Type: bug | Status: patch Priority: high | Milestone: 8.8.1 Component: Build System | Version: 8.6.2 (Hadrian) | Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: | Unknown/Multiple Type of failure: None/Unknown | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Phab:D5412 Wiki Page: | -------------------------------------+------------------------------------- Comment (by alpmestan): I ran a (profiled) hadrian build with shake `0.17.3` _and_ [https://phabricator.haskell.org/D5412 D5412], stopped it while hadrian was building `_build/stage1/libraries/base/`, resumed it and killed the program one I saw the first `| Run [...]` appear. I excluded all profiling symbols but the ones from hadrian itself (and only toplevel functions), and here is what the top of the profile looks like for that last short run I mentionned: {{{ Wed Dec 5 12:38 2018 Time and Allocation Profiling Report (Final) hadrian +RTS -I0 -qg -p -RTS --lint --directory /home/alp/WT /ghc-landing -j8 total time = 1.96 secs (7280 ticks @ 1000 us, 8 processors) total alloc = 4,152,119,656 bytes (excludes profiling overheads) COST CENTRE MODULE SRC %time %alloc buildProgram Rules.Program src/Rules/Program.hs:(19,1)-(73,51) 39.9 43.4 generatePackageCode Rules.Generate src/Rules/Generate.hs:(102,1)-(150,49) 6.1 2.9 buildPackageDependencies Rules.Dependencies src/Rules/Dependencies.hs:(15,1)-(35,52) 5.5 3.1 libraryObjects Rules.Library src/Rules/Library.hs:(113,1)-(127,67) 5.3 3.2 textFileOracle Hadrian.Oracles.TextFile src/Hadrian/Oracles/TextFile.hs:(88,1)-(100,83) 4.9 1.6 configurePackage Rules.Register src/Rules/Register.hs:(24,1)-(27,38) 3.2 1.7 argsHashOracle Hadrian.Oracles.ArgsHash src/Hadrian/Oracles/ArgsHash.hs:(47,1)-(51,36) 2.2 1.9 readContextData Hadrian.Oracles.Cabal src/Hadrian/Oracles/Cabal.hs:34:1-44 2.2 2.4 get Hadrian.Oracles.Cabal.Type src/Hadrian/Oracles/Cabal/Type.hs:43:15-20 2.2 1.5 ? Hadrian.Expression src/Hadrian/Expression.hs:(74,1)-(76,30) 1.7 2.1 unifyPath Hadrian.Utilities src/Hadrian/Utilities.hs:132:1-36 1.7 3.2 main Main src/Main.hs:(20,1)-(58,65) 1.4 3.8 == Hadrian.Oracles.TextFile src/Hadrian/Oracles/TextFile.hs:70:23-24 1.2 0.0 readPackageData Hadrian.Oracles.Cabal src/Hadrian/Oracles/Cabal.hs:28:1-44 1.1 0.9 lookupValue Hadrian.Oracles.TextFile src/Hadrian/Oracles/TextFile.hs:30:1-55 1.1 1.7 <> Hadrian.Expression src/Hadrian/Expression.hs:35:5-46 0.9 1.1 -/- Hadrian.Utilities src/Hadrian/Utilities.hs:(136,1)-(139,34) 0.8 2.4 input Hadrian.Expression src/Hadrian/Expression.hs:134:1-35 0.6 1.2 rtsPackageArgs Settings.Packages src/Settings/Packages.hs:(170,1)-(301,73) 0.4 1.0 mappend Hadrian.Expression src/Hadrian/Expression.hs:40:5-18 0.4 1.1 cabalOracle Hadrian.Oracles.Cabal.Rules src/Hadrian/Oracles/Cabal/Rules.hs:(38,1)-(60,58) 0.3 1.2 get Hadrian.Oracles.ArgsHash src/Hadrian/Oracles/ArgsHash.hs:41:15-20 0.2 2.2 }}} `buildProgram` stands out, as we seem to be spending more than a third of our time there. Everything else looks perfectly reasonable. I will give a very quick shot at trying to understand why we spend so much time in `buildProgram`, and if I do understand and see a way to cut this down, I'll write a patch, otherwise we can probably work with few-seconds pauses for now. -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/15938#comment:36 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler