[GHC] #15938: Hadrian's recompilation check is extremely slow

[GHC]

#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