ghcide 0.2.0 startup performance regression when using splint

[willbush]

I noticed a startup performance regression when upgrading from 0.1.0 -> 0.2.0:

Before on 0.1.0 running time ghcide took 7.44s user 0.95s system 108% cpu 7.760 total.

Ran the above command after this commit:
willbush/exercises@c5611df

λ ~/code/exercises/haskell-exercises/ ghcide-0.2.0-update* ghcide --version
ghcide version: 0.1.0 (GHC: 8.8.3) (PATH: /nix/store/48ajx48f59s0yqd6qb34zj7xzhgn3vc9-ghcide-0.1.0/bin/ghcide)
λ ~/code/exercises/haskell-exercises/ ghcide-0.2.0-update time ghcide
ghcide version: 0.1.0 (GHC: 8.8.3) (PATH: /nix/store/48ajx48f59s0yqd6qb34zj7xzhgn3vc9-ghcide-0.1.0/bin/ghcide)
Ghcide setup tester in /home/will/code/exercises/haskell-exercises.
Report bugs at https://github.com/digital-asset/ghcide/issues

Step 1/6: Finding files to test in /home/will/code/exercises/haskell-exercises
Found 18 files

Step 2/6: Looking for hie.yaml files that control setup
Found 1 cradle

Step 3/6, Cradle 1/1: Loading /home/will/code/exercises/haskell-exercises/hie.yaml

Step 4/6, Cradle 1/1: Loading GHC Session

Step 5/6: Initializing the IDE

Step 6/6: Type checking the files
File:     /home/will/code/exercises/haskell-exercises/bench/BenchAll.hs
Hidden:   no
Range:    3:17-3:31
Source:   not found
Severity: DsError
Message:
  Could not load module ‘Criterion.Main’
  It is a member of the hidden package ‘criterion-1.5.6.2’.
  Perhaps you need to add ‘criterion’ to the build-depends in your .cabal file.
Files that failed:
 * /home/will/code/exercises/haskell-exercises/bench/BenchAll.hs

Completed (17 files worked, 1 file failed)
ghcide  7.44s user 0.95s system 108% cpu 7.760 total
λ ~/code/exercises/haskell-exercises/ ghcide-0.2.0-update

After upgrading to 0.2.0 running time ghcide took 69.99s user 1.81s system 106% cpu 1:07.33 total.

Ran the above command after this commit:
willbush/exercises@0627ace

Important to note that this is using the new multi-components feature which fix the bench component error that I was ignoring before.

λ ~/code/exercises/haskell-exercises/ ghcide-0.2.0-update* ghcide --version
ghcide version: 0.2.0 (GHC: 8.8.3) (PATH: /nix/store/ngv8g1lv1nzwqp0wac5d0i6vfmxsj122-ghcide-0.2.0/bin/ghcide)
λ ~/code/exercises/haskell-exercises/ ghcide-0.2.0-update* time ghcide
ghcide version: 0.2.0 (GHC: 8.8.3) (PATH: /nix/store/ngv8g1lv1nzwqp0wac5d0i6vfmxsj122-ghcide-0.2.0/bin/ghcide)
Ghcide setup tester in /home/will/code/exercises/haskell-exercises.
Report bugs at https://github.com/digital-asset/ghcide/issues

Step 1/4: Finding files to test in /home/will/code/exercises/haskell-exercises
Found 18 files

Step 2/4: Looking for hie.yaml files that control setup
Found 1 cradle

Step 3/4: Initializing the IDE

Step 4/4: Type checking the files
[INFO] Consulting the cradle for "/home/will/code/exercises/haskell-exercises/test/AdventOfCode/Day4Spec.hs"
> Resolving dependencies...
> Build profile: -w ghc-8.8.3 -O1
> In order, the following will be built (use -v for more details):
>  - haskell-exercises-0.1.0.0 (lib) (configuration changed)
>  - haskell-exercises-0.1.0.0 (test:haskell-exercises-test) (configuration changed)
> Configuring library for haskell-exercises-0.1.0.0..
> Preprocessing library for haskell-exercises-0.1.0.0..
> Building library for haskell-exercises-0.1.0.0..
> [1 of 9] Compiling AdventOfCode.Day1 ( src/AdventOfCode/Day1.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/AdventOfCode/Day1.o ) [Splint changed]
> [2 of 9] Compiling AdventOfCode.Day3 ( src/AdventOfCode/Day3.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/AdventOfCode/Day3.o ) [Data.List.Extra changed]
> [3 of 9] Compiling AdventOfCode.Day4 ( src/AdventOfCode/Day4.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/AdventOfCode/Day4.o ) [Splint changed]
> [4 of 9] Compiling AdventOfCode.Day5 ( src/AdventOfCode/Day5.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/AdventOfCode/Day5.o ) [Splint changed]
> [5 of 9] Compiling Common.Fibonacci ( src/Common/Fibonacci.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/Common/Fibonacci.o ) [Splint changed]
> [6 of 9] Compiling Common.Helpers   ( src/Common/Helpers.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/Common/Helpers.o ) [Splint changed]
> [7 of 9] Compiling Common.Primes    ( src/Common/Primes.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/Common/Primes.o ) [Splint changed]
> [8 of 9] Compiling AdventOfCode.Day2 ( src/AdventOfCode/Day2.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/AdventOfCode/Day2.o )
> [9 of 9] Compiling ProjectEuler.Problems ( src/ProjectEuler/Problems.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/ProjectEuler/Problems.o )
> Configuring test suite 'haskell-exercises-test' for haskell-exercises-0.1.0.0..
> Warning: The package has an extraneous version range for a dependency on an
> internal library: haskell-exercises -any && ==0.1.0.0, haskell-exercises -any
> && ==0.1.0.0. This version range includes the current package but isn't needed
> as the current package's library will always be used.
> Preprocessing test suite 'haskell-exercises-test' for haskell-exercises-0.1.0.0..
[INFO] Using interface files cache dir: /home/will/.cache/ghcide/main-eefdd04e13d0e88bd75d0b0b3aceed75a156f06a
[INFO] Making new HscEnv[main]
[INFO] Consulting the cradle for "/home/will/code/exercises/haskell-exercises/src/ProjectEuler/Problems.hs"
> Resolving dependencies...
> Build profile: -w ghc-8.8.3 -O1
> In order, the following will be built (use -v for more details):
>  - haskell-exercises-0.1.0.0 (lib) (configuration changed)
> Configuring library for haskell-exercises-0.1.0.0..
> Preprocessing library for haskell-exercises-0.1.0.0..
[INFO] Using interface files cache dir: /home/will/.cache/ghcide/haskell-exercises-0.1.0.0-inplace-e22b30c2e452d949bb9ce34e1d96b55943a90485
[INFO] Using interface files cache dir: /home/will/.cache/ghcide/main-12942c39ee6a446941e165d3567bce01bd75f3c4
[INFO] Making new HscEnv[haskell-exercises-0.1.0.0-inplace,main]
[INFO] Consulting the cradle for "/home/will/code/exercises/haskell-exercises/bench/BenchAll.hs"
> Resolving dependencies...
> Build profile: -w ghc-8.8.3 -O1
> In order, the following will be built (use -v for more details):
>  - haskell-exercises-0.1.0.0 (lib) (configuration changed)
>  - haskell-exercises-0.1.0.0 (bench:haskell-exercises-bench) (configuration changed)
> Configuring library for haskell-exercises-0.1.0.0..
> Preprocessing library for haskell-exercises-0.1.0.0..
> Building library for haskell-exercises-0.1.0.0..
> Configuring benchmark 'haskell-exercises-bench' for haskell-exercises-0.1.0.0..
> Warning: The package has an extraneous version range for a dependency on an
> internal library: haskell-exercises -any && ==0.1.0.0, haskell-exercises -any
> && ==0.1.0.0. This version range includes the current package but isn't needed
> as the current package's library will always be used.
> Preprocessing benchmark 'haskell-exercises-bench' for haskell-exercises-0.1.0.0..
[INFO] Using interface files cache dir: /home/will/.cache/ghcide/main-048d6160eb48c12c9a06d27f4ee3a06cb0d87269
[INFO] Using interface files cache dir: /home/will/.cache/ghcide/haskell-exercises-0.1.0.0-inplace-ddfa2433c6638ac0417ba23f186728f884edea76
[INFO] Using interface files cache dir: /home/will/.cache/ghcide/main-048d6160eb48c12c9a06d27f4ee3a06cb0d87269
[INFO] Making new HscEnv[main,haskell-exercises-0.1.0.0-inplace,main]

Completed (18 files worked, 0 files failed)
ghcide  69.99s user 1.81s system 106% cpu 1:07.33 total
λ ~/code/exercises/haskell-exercises/ ghcide-0.2.0-update*

It hangs for a while after logging Preprocessing benchmark 'haskell-exercises-bench' for haskell-exercises-0.1.0.0.. using ~100% CPU.

[willbush]

It might be a hie-bios issue. time hie-bios check test/Main.hs is taking a lot longer for me. Want me to report it there?

λ ~/code/exercises/haskell-exercises/ ghcide-0.2.0-update ghcide --version
ghcide version: 0.1.0 (GHC: 8.8.3) (PATH: /nix/store/48ajx48f59s0yqd6qb34zj7xzhgn3vc9-ghcide-0.1.0/bin/ghcide)
λ ~/code/exercises/haskell-exercises/ ghcide-0.2.0-update hie-bios version
hie-bios version 0.4.0 compiled by GHC 8.8.3
λ ~/code/exercises/haskell-exercises/ ghcide-0.2.0-update time hie-bios check test/Main.hs
hie-bios check test/Main.hs  7.10s user 0.65s system 98% cpu 7.883 total
λ ~/code/exercises/haskell-exercises/ ghcide-0.2.0-update time hie-bios debug test
Root directory:      /home/will/code/exercises/haskell-exercises
GHC options:         -fbuilding-cabal-package -O0 -outputdir /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/haskell-exercises-test/haskell-exercises-test-tmp -odir /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/haskell-exercises-test/haskell-exercises-test-tmp -hidir /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/haskell-exercises-test/haskell-exercises-test-tmp -stubdir /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/haskell-exercises-test/haskell-exercises-test-tmp -i -i/home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/haskell-exercises-test/haskell-exercises-test-tmp -i/home/will/code/exercises/haskell-exercises/test -i/home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/haskell-exercises-test/autogen -i/home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/global-autogen -I/home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/haskell-exercises-test/autogen -I/home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/global-autogen -I/home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/haskell-exercises-test/haskell-exercises-test-tmp -optP-include -optP/home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/haskell-exercises-test/autogen/cabal_macros.h -hide-all-packages -Wmissing-home-modules -no-user-package-db -package-db /home/will/.cabal/store/ghc-8.8.3/package.db -package-db /home/will/code/exercises/haskell-exercises/dist-newstyle/packagedb/ghc-8.8.3 -package-db /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/package.conf.inplace -package-id array-0.5.4.0 -package-id base-4.13.0.0 -package-id bytestring-0.10.10.0 -package-id containers-0.6.2.1 -package-id extra-1.7.3-fff4295a289246150c9691a37ec25db605a485c03e6491c8fd3e2ac752498bb1 -package-id haskell-exercises-0.1.0.0-inplace -package-id hspec-2.7.1-DTGDYPmkrDq5rk3zcuroRh -package-id ilist-0.4.0.1-3bir64FlqXmCihO3Bl08qp -package-id safe-0.3.18-F31ek1WnrA3UJF2AhicNf -package-id splint-1.0.1.1-97e2e0b78e177291135562a287424dd5043758bde79c1f0430f4fb5b840fa54f -package-id utility-ht-0.0.15-1zMKpkUjWvmL5idQFPrnB1 -XHaskell2010 test/Main.hs CommonSpec ProjectEuler.ProblemsSpec AdventOfCode.Day1Spec AdventOfCode.Day2Spec AdventOfCode.Day3Spec AdventOfCode.Day4Spec AdventOfCode.Day5Spec -Wall -Wcompat -Widentities -Wincomplete-record-updates -Wincomplete-uni-patterns -Wpartial-fields -Wredundant-constraints -fplugin=Splint -hide-all-packages
System libraries:    /nix/store/jw9jhyn472jp8n287v2mywpv31wdrnln-ghc-8.8.3-with-packages/lib/ghc-8.8.3
Config Location:     /home/will/code/exercises/haskell-exercises/hie.yaml
Cradle:              Cradle {cradleRootDir = "/home/will/code/exercises/haskell-exercises", cradleOptsProg = CradleAction: Cabal}
Dependencies:        haskell-exercises.cabal cabal.project shell.nix default.nix
hie-bios debug test  3.56s user 0.53s system 96% cpu 4.227 total
λ ~/code/exercises/haskell-exercises/ ghcide-0.2.0-update
λ ~/code/exercises/haskell-exercises/ ghcide-0.2.0-update*
direnv: loading ~/code/exercises/haskell-exercises/.envrc
direnv: export +AR +AS +CC +CONFIG_SHELL +CXX +HOST_PATH +IN_NIX_SHELL +LD +NIX_BINTOOLS +NIX_BINTOOLS_WRAPPER_x86_64_unknown_linux_gnu_TARGET_HOST +NIX_BUILD_CORES +NIX_BUILD_TOP +NIX_CC +NIX_CC_WRAPPER_x86_64_unknown_linux_gnu_TARGET_HOST +NIX_ENFORCE_NO_NATIVE +NIX_GHCPKG +NIX_GHC_DOCDIR +NIX_GHC_LIBDIR +NIX_HARDENING_ENABLE +NIX_INDENT_MAKE +NIX_LDFLAGS +NIX_LOG_FD +NIX_STORE +NM +OBJCOPY +OBJDUMP +RANLIB +READELF +SIZE +SOURCE_DATE_EPOCH +STRINGS +STRIP +allowSubstitutes +buildInputs +builder +configureFlags +depsBuildBuild +depsBuildBuildPropagated +depsBuildTarget +depsBuildTargetPropagated +depsHostHost +depsHostHostPropagated +depsTargetTarget +depsTargetTargetPropagated +doCheck +doInstallCheck +extraClosure +installPhase +name +nativeBuildInputs +origArgs +origBuilder +origExtraClosure +origOutputs +origPATH +origSystem +out +outputs +patches +phases +preHook +preferLocalBuild +propagatedBuildInputs +propagatedNativeBuildInputs +shell +shellHook +stdenv +strictDeps +system ~LOCALE_ARCHIVE ~NIX_GHC ~PATH
λ ~/code/exercises/haskell-exercises/ ghcide-0.2.0-update* ghcide --version
ghcide version: 0.2.0 (GHC: 8.8.3) (PATH: /nix/store/ngv8g1lv1nzwqp0wac5d0i6vfmxsj122-ghcide-0.2.0/bin/ghcide)
direnv: loading ~/code/exercises/haskell-exercises/.envrc
direnv: export +AR +AS +CC +CONFIG_SHELL +CXX +HOST_PATH +IN_NIX_SHELL +LD +NIX_BINTOOLS +NIX_BINTOOLS_WRAPPER_x86_64_unknown_linux_gnu_TARGET_HOST +NIX_BUILD_CORES +NIX_BUILD_TOP +NIX_CC +NIX_CC_WRAPPER_x86_64_unknown_linux_gnu_TARGET_HOST +NIX_ENFORCE_NO_NATIVE +NIX_GHCPKG +NIX_GHC_DOCDIR +NIX_GHC_LIBDIR +NIX_HARDENING_ENABLE +NIX_INDENT_MAKE +NIX_LDFLAGS +NIX_LOG_FD +NIX_STORE +NM +OBJCOPY +OBJDUMP +RANLIB +READELF +SIZE +SOURCE_DATE_EPOCH +STRINGS +STRIP +allowSubstitutes +buildInputs +builder +configureFlags +depsBuildBuild +depsBuildBuildPropagated +depsBuildTarget +depsBuildTargetPropagated +depsHostHost +depsHostHostPropagated +depsTargetTarget +depsTargetTargetPropagated +doCheck +doInstallCheck +extraClosure +installPhase +name +nativeBuildInputs +origArgs +origBuilder +origExtraClosure +origOutputs +origPATH +origSystem +out +outputs +patches +phases +preHook +preferLocalBuild +propagatedBuildInputs +propagatedNativeBuildInputs +shell +shellHook +stdenv +strictDeps +system ~LOCALE_ARCHIVE ~NIX_GHC ~PATH
λ ~/code/exercises/haskell-exercises/ ghcide-0.2.0-update*
λ ~/code/exercises/haskell-exercises/ ghcide-0.2.0-update* ghcide --version
ghcide version: 0.2.0 (GHC: 8.8.3) (PATH: /nix/store/ngv8g1lv1nzwqp0wac5d0i6vfmxsj122-ghcide-0.2.0/bin/ghcide)
λ ~/code/exercises/haskell-exercises/ ghcide-0.2.0-update* hie-bios version
hie-bios version 0.5.0 compiled by GHC 8.8.3
λ ~/code/exercises/haskell-exercises/ ghcide-0.2.0-update* time hie-bios check test/Main.hs
hie-bios check test/Main.hs  63.33s user 0.80s system 99% cpu 1:04.26 total
λ ~/code/exercises/haskell-exercises/ ghcide-0.2.0-update* time hie-bios debug test
Root directory:      /home/will/code/exercises/haskell-exercises
Component directory: /home/will/code/exercises/haskell-exercises
GHC options:         -fbuilding-cabal-package -O0 -outputdir /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/haskell-exercises-test/haskell-exercises-test-tmp -odir /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/haskell-exercises-test/haskell-exercises-test-tmp -hidir /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/haskell-exercises-test/haskell-exercises-test-tmp -stubdir /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/haskell-exercises-test/haskell-exercises-test-tmp -i -i/home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/haskell-exercises-test/haskell-exercises-test-tmp -itest -i/home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/haskell-exercises-test/autogen -i/home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/global-autogen -I/home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/haskell-exercises-test/autogen -I/home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/global-autogen -I/home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/haskell-exercises-test/haskell-exercises-test-tmp -optP-include -optP/home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/haskell-exercises-test/autogen/cabal_macros.h -hide-all-packages -Wmissing-home-modules -no-user-package-db -package-db /home/will/.cabal/store/ghc-8.8.3/package.db -package-db /home/will/code/exercises/haskell-exercises/dist-newstyle/packagedb/ghc-8.8.3 -package-db /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/package.conf.inplace -package-id base-4.13.0.0 -package-id bytestring-0.10.10.0 -package-id containers-0.6.2.1 -package-id haskell-exercises-0.1.0.0-inplace -package-id hspec-2.7.1-AYqVNi5hQsf1wmfcMaAvYi -package-id safe-0.3.19-K9VEwmVF618FMbBq820Jtf -package-id splint-1.0.1.1-EfeGUjPg3EH5csaM5RQFKX -package-id utility-ht-0.0.15-Fwfs6jpVSckI8R4noxPJwJ -XHaskell2010 test/Main.hs CommonSpec ProjectEuler.ProblemsSpec AdventOfCode.Day1Spec AdventOfCode.Day2Spec AdventOfCode.Day3Spec AdventOfCode.Day4Spec AdventOfCode.Day5Spec -Wall -Wcompat -Widentities -Wincomplete-record-updates -Wincomplete-uni-patterns -Wpartial-fields -Wredundant-constraints -fplugin=Splint -hide-all-packages
System libraries:    /nix/store/pcn15ax93viwpfg7rxp4psnkvbs0b86p-ghc-8.8.3-with-packages/lib/ghc-8.8.3
Config Location:     /home/will/code/exercises/haskell-exercises/hie.yaml
Cradle:              Cradle {cradleRootDir = "/home/will/code/exercises/haskell-exercises", cradleOptsProg = CradleAction: Cabal}
Dependencies:        haskell-exercises.cabal cabal.project cabal.project.local shell.nix default.nix
hie-bios debug test  3.57s user 0.46s system 97% cpu 4.146 total
λ ~/code/exercises/haskell-exercises/ ghcide-0.2.0-update* time hie-bios check test/Main.hs
hie-bios check test/Main.hs  59.86s user 0.68s system 99% cpu 1:00.67 total

[willbush]

Actually, after running time ghcide again, its hanging on [INFO] Making new HscEnv[haskell-exercises-0.1.0.0-inplace,main].

Think I narrowed this down a bit. I'm using this GHC plugin https://github.com/tfausak/splint, and I remember from reading the blog post that the author says it adds a tenth of a second per module.

So I commented out every line in my cabal file that has splint and ghcide 8.33s user 1.38s system 101% cpu 9.579 total:

λ ~/code/exercises/haskell-exercises/ ghcide-0.2.0-update time ghcide
ghcide version: 0.2.0 (GHC: 8.8.3) (PATH: /nix/store/ngv8g1lv1nzwqp0wac5d0i6vfmxsj122-ghcide-0.2.0/bin/ghcide)
Ghcide setup tester in /home/will/code/exercises/haskell-exercises.
Report bugs at https://github.com/digital-asset/ghcide/issues

Step 1/4: Finding files to test in /home/will/code/exercises/haskell-exercises
Found 18 files

Step 2/4: Looking for hie.yaml files that control setup
Found 1 cradle

Step 3/4: Initializing the IDE

Step 4/4: Type checking the files
[INFO] Consulting the cradle for "/home/will/code/exercises/haskell-exercises/test/AdventOfCode/Day1Spec.hs"
> Resolving dependencies...
> Build profile: -w ghc-8.8.3 -O1
> In order, the following will be built (use -v for more details):
>  - haskell-exercises-0.1.0.0 (lib) (configuration changed)
>  - haskell-exercises-0.1.0.0 (test:haskell-exercises-test) (configuration changed)
> Configuring library for haskell-exercises-0.1.0.0..
> Preprocessing library for haskell-exercises-0.1.0.0..
> Building library for haskell-exercises-0.1.0.0..
> Configuring test suite 'haskell-exercises-test' for haskell-exercises-0.1.0.0..
> Warning: The package has an extraneous version range for a dependency on an
> internal library: haskell-exercises -any && ==0.1.0.0, haskell-exercises -any
> && ==0.1.0.0. This version range includes the current package but isn't needed
> as the current package's library will always be used.
> Preprocessing test suite 'haskell-exercises-test' for haskell-exercises-0.1.0.0..
[INFO] Using interface files cache dir: /home/will/.cache/ghcide/main-a92ea35edd4cfe0347f9d9425ad905c5ba2c4e1a
[INFO] Making new HscEnv[main]
[INFO] Consulting the cradle for "/home/will/code/exercises/haskell-exercises/src/Common/Primes.hs"
> Resolving dependencies...
> Build profile: -w ghc-8.8.3 -O1
> In order, the following will be built (use -v for more details):
>  - haskell-exercises-0.1.0.0 (lib) (configuration changed)
> Configuring library for haskell-exercises-0.1.0.0..
> Preprocessing library for haskell-exercises-0.1.0.0..
[INFO] Using interface files cache dir: /home/will/.cache/ghcide/haskell-exercises-0.1.0.0-inplace-b4e0a8652609d44b7c9fd0bfa0e95f0d3b384925
[INFO] Using interface files cache dir: /home/will/.cache/ghcide/main-d3742137e0e88c8f86158187a0f63a20d69a2da9
[INFO] Making new HscEnv[haskell-exercises-0.1.0.0-inplace,main]
[INFO] Consulting the cradle for "/home/will/code/exercises/haskell-exercises/bench/BenchAll.hs"
> Resolving dependencies...
> Build profile: -w ghc-8.8.3 -O1
> In order, the following will be built (use -v for more details):
>  - haskell-exercises-0.1.0.0 (lib) (configuration changed)
>  - haskell-exercises-0.1.0.0 (bench:haskell-exercises-bench) (configuration changed)
> Configuring library for haskell-exercises-0.1.0.0..
> Preprocessing library for haskell-exercises-0.1.0.0..
> Building library for haskell-exercises-0.1.0.0..
> Configuring benchmark 'haskell-exercises-bench' for haskell-exercises-0.1.0.0..
> Warning: The package has an extraneous version range for a dependency on an
> internal library: haskell-exercises -any && ==0.1.0.0, haskell-exercises -any
> && ==0.1.0.0. This version range includes the current package but isn't needed
> as the current package's library will always be used.
> Preprocessing benchmark 'haskell-exercises-bench' for haskell-exercises-0.1.0.0..
[INFO] Using interface files cache dir: /home/will/.cache/ghcide/main-8bab1fe4d73f15810e0acc7d36264bddd7d2fd03
[INFO] Using interface files cache dir: /home/will/.cache/ghcide/haskell-exercises-0.1.0.0-inplace-4749039437757701ff7f79b2460659a78f7eb2b3
[INFO] Using interface files cache dir: /home/will/.cache/ghcide/main-8bab1fe4d73f15810e0acc7d36264bddd7d2fd03
[INFO] Making new HscEnv[main,haskell-exercises-0.1.0.0-inplace,main]

Completed (18 files worked, 0 files failed)
ghcide  8.33s user 1.38s system 101% cpu 9.579 total
λ ~/code/exercises/haskell-exercises/ ghcide-0.2.0-update*

Wonder if I can add a build flag to work aroud this issue without having to stop using splint.

[ndmitchell]

The first post talks about a regression of > 1 min, but might that have been an initial compile? hie-bios can take up to hours, as it first calls stack build/cabal build, and that might build half of Hackage.

Later measurements seem to be saying we've dropped from 7.5s to 10s? We expected the introduction of multi-component to impose about a 25% performance reduction (see haskell/ghcide#522), and neither number seems too concerning.

[willbush]

The first post talks about a regression of > 1 min, but might that have been an initial compile?

It was taking > 1 min every time I call ghcide in the terminal. Later measurement was just to show it was resolved by removing splint. Going from 7.44s to 8.33s by using multi-components seems fine to me. I'm not sure if this is an issue affecting any GHC plugin or an issue with splint. I opened an issue with that plugin (mentioned above) to make the author aware of it. Feel free to close if you feel this is not a ghcide problem.

[ndmitchell]

If you put back splint, does it take 1m to do ghcide? And do you see a similar delay when starting the IDE? This is using GHC 8.8.3, so split will be reparsing the source code, but shouldn't have much delay. I imagine a no-op plugin would also cause a delay, so my guess is a regression between source plugins and multi component. Maybe the source plugin gets repeatedly reloaded?

CC @mpickering who might be interested, but I suspect there's some detective work to prove the above theory first.

[willbush]

If you put back splint, does it take 1m to do ghcide?

It does. I double checked that.

And do you see a similar delay when starting the IDE?

I do. I haven't timed it, but It takes noticeable longer amount of time to start and restart lsp-workspace-restart in Emacs. With splint removed, from the time I restart to the time I get pop-up documentation seems like only a couple of seconds.

Plugin author replied here pointing out possible causes. I'll probably reply to that later today.

[willbush]

with this plugin: https://github.com/mbj/source-constraints added to all three components time ghcide gets:

10.09s user 1.58s system 108% cpu 10.731 total

With this no-opt plugin (which I got from here) added as a module to the library component and the test and bench components using it with -fplugin=DoNothing.Plugin:

module DoNothing.Plugin (plugin) where

import GhcPlugins

plugin :: Plugin
plugin = defaultPlugin { installCoreToDos = install }

install :: [CommandLineOption] -> [CoreToDo] -> CoreM [CoreToDo]
install _ todo = do
  putMsgS "Hello!"
  return todo

time ghcide gets:

9.89s user 1.52s system 106% cpu 10.728 total

I also tried to run https://github.com/kowainik/smuggler, but I couldn't get it to build for some reason.

Attempting to run time ghcide when it's not building takes 45.34s user 5.26s system 96% cpu 52.178 total and produces a lot of output with the same error for each file. I'm not sure it that's of any interest or relevance.

I even copied the Splint code directly into my project to test using the plugin the same way I was using the no-opt plugin and the issue remains.

I'm not sure how to proceed. Have any ideas?

[ndmitchell]

So it's suggestive that something in Splint is at fault (and by that, it probably means HLint underneath). A profile would be great, but I'm not sure if that's even remotely plausible to profile both Ghcide and Split in one go.

What is the time to run HLint on each file in isolation? e.g. for *.hs do hlint ..., not a single HLint run.

[willbush]

It takes 3 - 4 seconds.

λ ~/code/exercises/haskell-exercises/ master* time find -name '*.hs' | xargs -I {} sh -c "echo {};hlint {}"
./src/AdventOfCode/Day2.hs
No hints
./src/AdventOfCode/Day4.hs
No hints
./src/AdventOfCode/Day1.hs
No hints
./src/AdventOfCode/Day3.hs
No hints
./src/AdventOfCode/Day5.hs
No hints
./src/Common/Helpers.hs
No hints
./src/Common/Fibonacci.hs
No hints
./src/Common/Primes.hs
No hints
./src/ProjectEuler/Problems.hs
No hints
./test/AdventOfCode/Day2Spec.hs
No hints
./test/AdventOfCode/Day4Spec.hs
No hints
./test/AdventOfCode/Day5Spec.hs
No hints
./test/AdventOfCode/Day1Spec.hs
No hints
./test/AdventOfCode/Day3Spec.hs
No hints
./test/Main.hs
No hints
./test/ProjectEuler/ProblemsSpec.hs
No hints
./test/CommonSpec.hs
No hints
./bench/BenchAll.hs
No hints
./dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/b/haskell-exercises-bench/build/haskell-exercises-bench/autogen/Paths_haskell_exercises.hs
No hints
./dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/t/haskell-exercises-test/build/haskell-exercises-test/autogen/Paths_haskell_exercises.hs
No hints
./dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/autogen/Paths_haskell_exercises.hs
No hints
find -name '*.hs'  0.00s user 0.00s system 95% cpu 0.002 total
xargs -I {} sh -c "echo {};hlint {}"  3.86s user 0.13s system 97% cpu 4.078 total

[ndmitchell]

If you build the project however you normally do, both with/without Splint enabled, what's the time difference?

[willbush]

I added a redundant bracket so I could see that the linter is running or not in the build output.

without Splint:

λ ~/code/exercises/haskell-exercises/ master* cabal clean
λ ~/code/exercises/haskell-exercises/ master* time cabal build
Resolving dependencies...
Build profile: -w ghc-8.8.3 -O1
In order, the following will be built (use -v for more details):
 - haskell-exercises-0.1.0.0 (lib) (first run)
Configuring library for haskell-exercises-0.1.0.0..
Preprocessing library for haskell-exercises-0.1.0.0..
Building library for haskell-exercises-0.1.0.0..
[1 of 9] Compiling AdventOfCode.Day1 ( src/AdventOfCode/Day1.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/AdventOfCode/Day1.o )
[2 of 9] Compiling AdventOfCode.Day2 ( src/AdventOfCode/Day2.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/AdventOfCode/Day2.o )
[3 of 9] Compiling AdventOfCode.Day3 ( src/AdventOfCode/Day3.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/AdventOfCode/Day3.o )
[4 of 9] Compiling AdventOfCode.Day4 ( src/AdventOfCode/Day4.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/AdventOfCode/Day4.o )
[5 of 9] Compiling AdventOfCode.Day5 ( src/AdventOfCode/Day5.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/AdventOfCode/Day5.o )
[6 of 9] Compiling Common.Fibonacci ( src/Common/Fibonacci.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/Common/Fibonacci.o )
[7 of 9] Compiling Common.Helpers   ( src/Common/Helpers.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/Common/Helpers.o )
[8 of 9] Compiling Common.Primes    ( src/Common/Primes.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/Common/Primes.o )
[9 of 9] Compiling ProjectEuler.Problems ( src/ProjectEuler/Problems.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/ProjectEuler/Problems.o )
cabal build  3.88s user 0.43s system 98% cpu 4.366 total

with Splint:

λ ~/code/exercises/haskell-exercises/ master* cabal clean
λ ~/code/exercises/haskell-exercises/ master* time cabal build
Resolving dependencies...
Build profile: -w ghc-8.8.3 -O1
In order, the following will be built (use -v for more details):
 - haskell-exercises-0.1.0.0 (lib) (first run)
Configuring library for haskell-exercises-0.1.0.0..
Preprocessing library for haskell-exercises-0.1.0.0..
Building library for haskell-exercises-0.1.0.0..
[1 of 9] Compiling AdventOfCode.Day1 ( src/AdventOfCode/Day1.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/AdventOfCode/Day1.o )
[2 of 9] Compiling AdventOfCode.Day2 ( src/AdventOfCode/Day2.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/AdventOfCode/Day2.o )
[3 of 9] Compiling AdventOfCode.Day3 ( src/AdventOfCode/Day3.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/AdventOfCode/Day3.o )
[4 of 9] Compiling AdventOfCode.Day4 ( src/AdventOfCode/Day4.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/AdventOfCode/Day4.o )
[5 of 9] Compiling AdventOfCode.Day5 ( src/AdventOfCode/Day5.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/AdventOfCode/Day5.o )
[6 of 9] Compiling Common.Fibonacci ( src/Common/Fibonacci.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/Common/Fibonacci.o )
[7 of 9] Compiling Common.Helpers   ( src/Common/Helpers.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/Common/Helpers.o )

src/Common/Helpers.hs:10:15: warning:
    Redundant bracket
    Perhaps: acc
   |
10 |   go !acc 0 = (acc)
   |               ^^^^^
[8 of 9] Compiling Common.Primes    ( src/Common/Primes.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/Common/Primes.o )
[9 of 9] Compiling ProjectEuler.Problems ( src/ProjectEuler/Problems.hs, /home/will/code/exercises/haskell-exercises/dist-newstyle/build/x86_64-linux/ghc-8.8.3/haskell-exercises-0.1.0.0/build/ProjectEuler/Problems.o )
cabal build  4.90s user 0.48s system 99% cpu 5.426 total

It looks to have added about a second to the build time. I ran it a few times with and without splint and I didn't see a lot of variance.

[willbush]

So I looked into this a bunch back in June, got distracted and forgot about it and recently decided to look into it again some more. What I found is that it has something to do with the environment provided by the nix GHC with packages wrapper. The nix derivation I use to set up the environment uses developPackage, which uses that wrapper. I stumbled on that because I setup another fresh cabal project with nothing but "Hello, World" where I couldn't replicate the issue.

I used printenv to dump the environmental variables and painstakingly searched for what could be different between the two environments provided by nix (although through different methods).

It turned out the ordering of ghc-8.8.4 and ghc-8.8.4-with-packages in my PATH environment variable was the difference. When ghc-8.8.4-with-packages comes first, then ghcide takes a minute. When ghc-8.8.4 comes first, then it takes ~7 seconds. From my understanding with-packages is using packages already built by nix using the same compiler version. When I use ghc without packages cabal is used to build what's needed and caches them in some folder (maybe ~/.cabal/packages/hackage.haskell.org/).

It's still a mystery exactly what's wrong though. I added a bunch of logging to ghcide, compiled, and used that for testing to try to find where in the code it is going slow, but didn't really get anywhere. I really should take the time to learn to profile Haskell code properly.

I did try throwing a Strict language pragma at the top of Main.hs just to see if blindly making the code more strict would change what I was seeing. I randomly would get this error when I did that, but that could be unrelated:

[DEBUG] session done
[INFO] Consulting the cradle for "/home/will/code/tester/plugins/TestPlugin.hs"
> Resolving dependencies...
> cabal: internal error: eval_thunk_selector: strange selectee 4345696
>     (GHC version 8.8.4 for x86_64_unknown_linux)
>     Please report this as a GHC bug:  https://www.haskell.org/ghc/reportabug
[DEBUG] Session loading result: Left [CradleError (ExitFailure (-6)) ["Failed to parse result of calling cabal","Resolving dependencies...\n","cabal: internal error: eval_thunk_selector: strange selectee 4345696\n    (GHC version 8.8.4 for x86_64_unknown_linux)\n    Please report this as a GHC bug:  https://www.haskell.org/ghc/reportabug\n",""]]
File:     /home/will/code/tester/plugins/TestPlugin.hs
Hidden:   no
Range:    1:0-2:0
Source:   cradle
Severity: DsError
Message:
  Failed to parse result of calling cabal
  Resolving dependencies...

  cabal: internal error: eval_thunk_selector: strange selectee 4345696
  (GHC version 8.8.4 for x86_64_unknown_linux)
  Please report this as a GHC bug: https://www.haskell.org/ghc/reportabug