Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Haskell extension hangs in VSCode #2340

Closed
barnabasmolnar opened this issue Nov 10, 2021 · 17 comments
Closed

Haskell extension hangs in VSCode #2340

barnabasmolnar opened this issue Nov 10, 2021 · 17 comments
Labels
performance Issues about memory consumption, responsiveness, etc. type: bug Something isn't right: doesn't work as intended, documentation is missing/outdated, etc..

Comments

@barnabasmolnar
Copy link

Linked issue on the IHP tracker: digitallyinduced/ihp#1209

When using HLS as part of IHP, either locally inside a WSL2 distro or via a Gitpod instance, the Haskell extension in VSCode hangs for a lot of time before becoming operational. For me, it's usually 4 minutes or so but a friend of mine on a weaker PC reported loading times up to 20-30 minutes.

I've provided some logs below.
Some of the actions that seem to have taken a lot of time are:

Wingman.getMetaprogramsAtSpan.TypeCheck (took 2m17s)
Wingman.codeLensProvider.GetBindings (took 3m34s)
RefineImports (took 3m34s)

When I'm using stack to manage my own Haskell projects, the extension seems to work fine and near instantaneously. Admittedly those projects are far smaller and have fewer files and everything... but ~4 minutes still seems very excessive to me.

Would be curious if anyone had similar issues and whether there might be a fix to speed things up.

Click to expand log
Found "/home/roy/Developer/personal/bookmark-app/hie.yaml" for "/home/roy/Developer/personal/bookmark-app/a"
Run entered for haskell-language-server-wrapper(haskell-language-server-wrapper) Version 1.4.0.0 x86_64 ghc-8.10.7
Current directory: /home/roy/Developer/personal/bookmark-app
Operating system: linux
Arguments: ["--lsp"]
Cradle directory: /home/roy/Developer/personal/bookmark-app
Cradle type: Bios

Tool versions found on the $PATH
cabal:		3.6.0.0
stack:		Not found
ghc:		8.10.7


Consulting the cradle to get project GHC version...
Project GHC version: 8.10.7
haskell-language-server exe candidates: ["haskell-language-server-8.10.7","haskell-language-server"]
Launching haskell-language-server exe at:/nix/store/kq65wynaxf8f0kmrx698npsrdg63g8fy-ghc-8.10.7-with-packages/bin/haskell-language-server-8.10.7
haskell-language-server version: 1.4.0.0 (GHC: 8.10.7) (PATH: /nix/store/xpwc04nd8g9vxjvjs3p4mwbi8vfqh00r-haskell-language-server-1.4.0.0/bin/haskell-language-server)
Starting (haskell-language-server)LSP server...
  with arguments: GhcideArguments {argsCommand = LSP, argsCwd = Nothing, argsShakeProfiling = Nothing, argsTesting = False, argsExamplePlugin = False, argsDebugOn = False, argsLogFile = Nothing, argsThreads = 0, argsProjectGhcVersion = False}
  with plugins: [PluginId "pragmas",PluginId "floskell",PluginId "fourmolu",PluginId "tactics",PluginId "ormolu",PluginId "stylish-haskell",PluginId "retrie",PluginId "brittany",PluginId "callHierarchy",PluginId "class",PluginId "haddockComments",PluginId "eval",PluginId "importLens",PluginId "refineImports",PluginId "moduleName",PluginId "hlint",PluginId "splice",PluginId "ghcide-hover-and-symbols",PluginId "ghcide-code-actions-imports-exports",PluginId "ghcide-code-actions-type-signatures",PluginId "ghcide-code-actions-bindings",PluginId "ghcide-code-actions-fill-holes",PluginId "ghcide-completions",PluginId "ghcide-type-lenses",PluginId "ghcide-core"]
  in directory: /home/roy/Developer/personal/bookmark-app
 Starting LSP server...
If you are seeing this in a terminal, you probably should have run WITHOUT the --lsp option!
Started LSP server in 0.03s
setInitialDynFlags cradle: Cradle {cradleRootDir = "/home/roy/Developer/personal/bookmark-app", cradleOptsProg = CradleAction: Cabal}
2021-11-09 15:21:22.047563019 [ThreadId 5] INFO hls:	Registering ide configuration: IdeConfiguration {workspaceFolders = fromList [NormalizedUri (-1027614979192674154) "file:///home/roy/Developer/personal/bookmark-app"], clientSettings = hashed Nothing}
2021-11-09 15:21:22.113315896 [ThreadId 96] INFO hls:	Consulting the cradle for "Main.hs"
Output from setting up the cradle Cradle {cradleRootDir = "/home/roy/Developer/personal/bookmark-app", cradleOptsProg = CradleAction: Bios}
2021-11-09 15:21:22.275097154 [ThreadId 96] INFO hls:	Using interface files cache dir: /home/roy/.cache/ghcide/main-dab85eb4a271bd8d9607ae60f8f36b13c8d958a8
2021-11-09 15:21:22.275301813 [ThreadId 96] INFO hls:	Making new HscEnv[main]
2021-11-09 15:21:22.324675893 [ThreadId 328] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-11-09 15:21:22.325520979 [ThreadId 328] INFO hls:	finish: ModuleName.ghcSession (took 0.00s)
2021-11-09 15:21:22.325719847 [ThreadId 324] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-11-09 15:21:22.326199157 [ThreadId 319] INFO hls:	finish: ModuleName.ghcSession (took 0.00s)
2021-11-09 15:21:22.326433995 [ThreadId 139] INFO hls:	finish: ModuleName.GetParsedModule (took 0.00s)
2021-11-09 15:21:22.326800403 [ThreadId 323] INFO hls:	finish: ModuleName.GetParsedModule (took 0.00s)
2021-11-09 15:21:22.330091861 [ThreadId 379] INFO hls:	finish: eval.GetParsedModuleWithComments (took 0.01s)
2021-11-09 15:21:22.330184467 [ThreadId 380] INFO hls:	finish: eval.GetParsedModuleWithComments (took 0.00s)
2021-11-09 15:21:22.330690486 [ThreadId 387] INFO hls:	finish: Wingman.codeLensProvider.GetAnnotatedParsedSource (took 0.00s)
2021-11-09 15:21:22.330752136 [ThreadId 386] INFO hls:	finish: Wingman.codeLensProvider.GetAnnotatedParsedSource (took 0.00s)
2021-11-09 15:24:56.248121566 [ThreadId 651] INFO hls:	finish: codeLens.TypeCheck (took 3m34s)
2021-11-09 15:24:56.248127775 [ThreadId 652] INFO hls:	finish: codeLens.TypeCheck (took 3m34s)
2021-11-09 15:24:56.248561625 [ThreadId 655] INFO hls:	finish: Wingman.getMetaprogramsAtSpan.TypeCheck (took 2m17s)
2021-11-09 15:24:56.248581634 [ThreadId 656] INFO hls:	finish: Wingman.getMetaprogramsAtSpan.TypeCheck (took 33.42s)
2021-11-09 15:24:56.248629944 [ThreadId 657] INFO hls:	finish: Wingman.getMetaprogramsAtSpan.TypeCheck (took 31.67s)
2021-11-09 15:24:56.248838763 [ThreadId 666] INFO hls:	finish:  (took 3m34s)
2021-11-09 15:24:56.248998323 [ThreadId 667] INFO hls:	finish:  (took 3m34s)
2021-11-09 15:24:56.250996724 [ThreadId 700] INFO hls:	finish: Wingman.codeLensProvider.GetBindings (took 3m34s)
2021-11-09 15:24:56.251188693 [ThreadId 702] INFO hls:	finish: codeLens.GetBindings (took 0.00s)
2021-11-09 15:24:56.25184629 [ThreadId 703] INFO hls:	finish: codeLens.GetBindings (took 0.00s)
2021-11-09 15:24:56.252512226 [ThreadId 699] INFO hls:	finish: Wingman.codeLensProvider.GetBindings (took 3m34s)
2021-11-09 15:24:56.252829056 [ThreadId 704] INFO hls:	finish: Wingman.emptyCaseScrutinees.TypeCheck (took 0.00s)
2021-11-09 15:24:56.252948795 [ThreadId 713] INFO hls:	finish: Wingman.emptyCaseScrutinees.TypeCheck (took 0.00s)
2021-11-09 15:24:56.252975745 [ThreadId 715] INFO hls:	finish: Wingman.emptyCaseScrutinees.GhcSessionDeps (took 0.00s)
2021-11-09 15:24:56.253053554 [ThreadId 720] INFO hls:	finish: codeLens.GetGlobalBindingTypeSigs (took 0.00s)
2021-11-09 15:24:56.253112739 [ThreadId 719] INFO hls:	finish: codeLens.GetGlobalBindingTypeSigs (took 0.00s)
2021-11-09 15:24:56.253022144 [ThreadId 717] INFO hls:	finish: Wingman.emptyCaseScrutinees.GhcSessionDeps (took 0.00s)
2021-11-09 15:24:56.277750874 [ThreadId 778] INFO hls:	finish: RefineImports (took 3m34s)
2021-11-09 15:24:56.277771453 [ThreadId 779] INFO hls:	finish: RefineImports (took 3m34s)
@pepeiborra
Copy link
Collaborator

If you are able to attend the HaskellExchange event next week, I will be giving a talk about HLS performance:

https://skillsmatter.com/conferences/13256-haskell-exchange-2021

If you are unable to attend, I expect that the recording will be made available after the event

@jneira jneira added type: bug Something isn't right: doesn't work as intended, documentation is missing/outdated, etc.. performance Issues about memory consumption, responsiveness, etc. labels Nov 10, 2021
@GavinRay97
Copy link

If you are able to attend the HaskellExchange event next week, I will be giving a talk about HLS performance:

skillsmatter.com/conferences/13256-haskell-exchange-2021

For context (and the lazy) the bit that I suppose most people will be interested in:

image

@pepeiborra
Copy link
Collaborator

Slides: https://drive.google.com/file/d/16FpmiHXX_rd2gAf5XVgWAIr4kg-AkUqX/view?usp=sharing

@barnabasmolnar
Copy link
Author

Issue still persists on IHP v.017.0 for me unfortunately...

Click to expand log
2021-12-14 15:29:40.5590000 [client] INFO Found server executable in $PATH: haskell-language-server-wrapper
2021-12-14 15:29:40.5590000 [client] INFO Activating the language server in working dir: /home/roy/Developer/personal/bookmark-app (the workspace folder)
2021-12-14 15:29:40.5590000 [client] INFO run command: haskell-language-server-wrapper --lsp
2021-12-14 15:29:40.5590000 [client] INFO debug command: haskell-language-server-wrapper --lsp
2021-12-14 15:29:40.5590000 [client] INFO server environment variables:
2021-12-14 15:29:40.5640000 [client] INFO Starting language server
Found "/home/roy/Developer/personal/bookmark-app/hie.yaml" for "/home/roy/Developer/personal/bookmark-app/a"
Run entered for haskell-language-server-wrapper(haskell-language-server-wrapper) Version 1.5.1.0 x86_64 ghc-8.10.7
Current directory: /home/roy/Developer/personal/bookmark-app
Operating system: linux
Arguments: ["--lsp"]
Cradle directory: /home/roy/Developer/personal/bookmark-app
Cradle type: Bios

Tool versions found on the $PATH
cabal:		3.6.2.0
stack:		Not found
ghc:		8.10.7


Consulting the cradle to get project GHC version...
Project GHC version: 8.10.7
haskell-language-server exe candidates: ["haskell-language-server-8.10.7","haskell-language-server"]
Launching haskell-language-server exe at:/nix/store/695041d2gxr0wbdzjmjlmlwy2w1dpdd1-ghc-8.10.7-with-packages/bin/haskell-language-server-8.10.7
haskell-language-server version: 1.5.1.0 (GHC: 8.10.7) (PATH: /nix/store/pf5p36nyz3yy7f7kqa49dbz2xvjd9wjm-haskell-language-server-1.5.1.0/bin/haskell-language-server)
Starting (haskell-language-server)LSP server...
  with arguments: GhcideArguments {argsCommand = LSP, argsCwd = Nothing, argsShakeProfiling = Nothing, argsTesting = False, argsExamplePlugin = False, argsDebugOn = False, argsLogFile = Nothing, argsThreads = 0, argsProjectGhcVersion = False}
  with plugins: [PluginId "pragmas",PluginId "floskell",PluginId "fourmolu",PluginId "tactics",PluginId "ormolu",PluginId "stylish-haskell",PluginId "retrie",PluginId "brittany",PluginId "callHierarchy",PluginId "class",PluginId "haddockComments",PluginId "eval",PluginId "importLens",PluginId "refineImports",PluginId "moduleName",PluginId "hlint",PluginId "splice",PluginId "ghcide-hover-and-symbols",PluginId "ghcide-code-actions-imports-exports",PluginId "ghcide-code-actions-type-signatures",PluginId "ghcide-code-actions-bindings",PluginId "ghcide-code-actions-fill-holes",PluginId "ghcide-completions",PluginId "ghcide-type-lenses",PluginId "ghcide-core"]
  in directory: /home/roy/Developer/personal/bookmark-app
 2021-12-14 16:29:40.701305916 [ThreadId 4] INFO hls:	Starting LSP server...
2021-12-14 16:29:40.701524194 [ThreadId 4] INFO hls:	If you are seeing this in a terminal, you probably should have run WITHOUT the --lsp option!
2021-12-14 16:29:40.703214748 [ThreadId 13] INFO hls:	Started LSP server in 0.00s
2021-12-14 16:29:41.609954639 [ThreadId 13] INFO hls:	Registering ide configuration: IdeConfiguration {workspaceFolders = fromList [NormalizedUri (-1027614979192674154) "file:///home/roy/Developer/personal/bookmark-app"], clientSettings = hashed Nothing}
2021-12-14 16:29:41.630279341 [ThreadId 71] INFO hls:	Consulting the cradle for "Main.hs"
2021-12-14 16:29:41.80854189 [ThreadId 71] INFO hls:	Using interface files cache dir: /home/roy/.cache/ghcide/main-dab85eb4a271bd8d9607ae60f8f36b13c8d958a8
2021-12-14 16:29:41.808755559 [ThreadId 71] INFO hls:	Making new HscEnv[main]
2021-12-14 16:29:41.886442484 [ThreadId 587] INFO hls:	finish: ModuleName.ghcSession (took 0.00s)
2021-12-14 16:29:41.886491449 [ThreadId 588] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:29:41.887525985 [ThreadId 612] INFO hls:	finish: Outline (took 0.00s)
2021-12-14 16:29:41.887615101 [ThreadId 616] INFO hls:	finish: ModuleName.ghcSession (took 0.00s)
2021-12-14 16:29:41.887787004 [ThreadId 617] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:29:41.890710328 [ThreadId 622] INFO hls:	finish: ModuleName.GetParsedModule (took 0.00s)
2021-12-14 16:29:41.891227546 [ThreadId 634] INFO hls:	finish: ModuleName.GetParsedModule (took 0.00s)
2021-12-14 16:29:41.892514276 [ThreadId 651] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:29:41.89272075 [ThreadId 652] INFO hls:	finish: ModuleName.ghcSession (took 0.00s)
2021-12-14 16:29:41.893629027 [ThreadId 668] INFO hls:	finish: ModuleName.GetParsedModule (took 0.00s)
2021-12-14 16:29:41.895027411 [ThreadId 583] INFO hls:	finish: eval.GetParsedModuleWithComments (took 0.01s)
2021-12-14 16:29:41.895034395 [ThreadId 648] INFO hls:	finish: eval.GetParsedModuleWithComments (took 0.00s)
2021-12-14 16:29:41.895216391 [ThreadId 611] INFO hls:	finish: eval.GetParsedModuleWithComments (took 0.01s)
2021-12-14 16:29:41.89544119 [ThreadId 621] INFO hls:	finish: Wingman.codeLensProvider.GetAnnotatedParsedSource (took 0.01s)
2021-12-14 16:29:41.89552302 [ThreadId 662] INFO hls:	finish: Wingman.codeLensProvider.GetAnnotatedParsedSource (took 0.00s)
2021-12-14 16:29:41.895575799 [ThreadId 628] INFO hls:	finish: Wingman.codeLensProvider.GetAnnotatedParsedSource (took 0.01s)
2021-12-14 16:29:53.099025173 [ThreadId 901] INFO hls:	finish: Pragmas.GetParsedModule (took 0.00s)
2021-12-14 16:29:53.098911353 [ThreadId 904] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:29:53.099100185 [ThreadId 902] INFO hls:	finish: HaddockComments.GetAnnotatedParsedSource (took 0.00s)
2021-12-14 16:29:53.099140621 [ThreadId 905] INFO hls:	finish: importLens (took 0.00s)
2021-12-14 16:29:53.099192872 [ThreadId 906] INFO hls:	finish: RefineImports (took 0.00s)
2021-12-14 16:29:53.099251761 [ThreadId 907] INFO hls:	finish: GhcideCodeActions.getParsedModule (took 0.00s)
2021-12-14 16:29:53.09930549 [ThreadId 908] INFO hls:	finish: splice.codeAction.GitHieAst (took 0.00s)
2021-12-14 16:29:53.09936115 [ThreadId 910] INFO hls:	finish: Pragmas.GetFileContents (took 0.00s)
2021-12-14 16:30:05.191656322 [ThreadId 937] INFO hls:	finish: eval.GetParsedModuleWithComments (took 0.00s)
2021-12-14 16:30:05.19210085 [ThreadId 938] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:30:05.192269238 [ThreadId 942] INFO hls:	finish: Wingman.codeLensProvider.GetAnnotatedParsedSource (took 0.00s)
2021-12-14 16:30:05.192235408 [ThreadId 941] INFO hls:	finish: ModuleName.ghcSession (took 0.00s)
2021-12-14 16:30:05.192344579 [ThreadId 943] INFO hls:	finish: ModuleName.GetParsedModule (took 0.00s)
2021-12-14 16:30:05.19736144 [ThreadId 954] INFO hls:	finish: eval.GetParsedModuleWithComments (took 0.00s)
2021-12-14 16:30:05.197550534 [ThreadId 959] INFO hls:	finish: ModuleName.ghcSession (took 0.00s)
2021-12-14 16:30:05.197545319 [ThreadId 956] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:30:05.197583143 [ThreadId 960] INFO hls:	finish: Wingman.codeLensProvider.GetAnnotatedParsedSource (took 0.00s)
2021-12-14 16:30:05.197704022 [ThreadId 962] INFO hls:	finish: ModuleName.GetParsedModule (took 0.00s)
2021-12-14 16:30:05.201626884 [ThreadId 972] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:30:05.201684447 [ThreadId 973] INFO hls:	finish: eval.GetParsedModuleWithComments (took 0.00s)
2021-12-14 16:30:05.201828351 [ThreadId 977] INFO hls:	finish: ModuleName.ghcSession (took 0.00s)
2021-12-14 16:30:05.201917752 [ThreadId 978] INFO hls:	finish: Wingman.codeLensProvider.GetAnnotatedParsedSource (took 0.00s)
2021-12-14 16:30:05.201985436 [ThreadId 980] INFO hls:	finish: ModuleName.GetParsedModule (took 0.00s)
2021-12-14 16:34:08.102456367 [ThreadId 903] INFO hls:	finish: retrie (took 4m15s)
2021-12-14 16:34:08.102729866 [ThreadId 955] INFO hls:	finish: codeLens.TypeCheck (took 4m03s)
2021-12-14 16:34:08.102727016 [ThreadId 936] INFO hls:	finish: codeLens.TypeCheck (took 4m03s)
2021-12-14 16:34:08.102884641 [ThreadId 975] INFO hls:	finish: codeLens.TypeCheck (took 4m03s)
2021-12-14 16:34:08.102934496 [ThreadId 649] INFO hls:	finish: codeLens.TypeCheck (took 4m26s)
2021-12-14 16:34:08.10305079 [ThreadId 584] INFO hls:	finish: codeLens.TypeCheck (took 4m26s)
2021-12-14 16:34:08.103223504 [ThreadId 613] INFO hls:	finish: codeLens.TypeCheck (took 4m26s)
2021-12-14 16:34:08.103361043 [ThreadId 614] INFO hls:	finish:  (took 4m26s)
2021-12-14 16:34:08.103373453 [ThreadId 586] INFO hls:	finish:  (took 4m26s)
2021-12-14 16:34:08.103508963 [ThreadId 650] INFO hls:	finish:  (took 4m26s)
2021-12-14 16:34:08.103494497 [ThreadId 974] INFO hls:	finish:  (took 4m03s)
2021-12-14 16:34:08.103530076 [ThreadId 957] INFO hls:	finish:  (took 4m03s)
2021-12-14 16:34:08.103660603 [ThreadId 939] INFO hls:	finish:  (took 4m03s)
2021-12-14 16:34:08.10428241 [ThreadId 909] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 4m15s)
2021-12-14 16:34:08.104629748 [ThreadId 687] INFO hls:	finish: Wingman.codeLensProvider.GetBindings (took 4m26s)
2021-12-14 16:34:08.104595409 [ThreadId 1118] INFO hls:	finish: codeLens.GetBindings (took 0.00s)
2021-12-14 16:34:08.105034111 [ThreadId 688] INFO hls:	finish: Wingman.codeLensProvider.GetBindings (took 4m26s)
2021-12-14 16:34:08.104628027 [ThreadId 1142] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:08.104622992 [ThreadId 1113] INFO hls:	finish: codeLens.GetBindings (took 0.00s)
2021-12-14 16:34:08.105079767 [ThreadId 1111] INFO hls:	finish: codeLens.GetBindings (took 0.00s)
2021-12-14 16:34:08.104759388 [ThreadId 961] INFO hls:	finish: Wingman.codeLensProvider.GetBindings (took 4m03s)
2021-12-14 16:34:08.104694947 [ThreadId 1112] INFO hls:	finish: codeLens.GetBindings (took 0.00s)
2021-12-14 16:34:08.105107618 [ThreadId 1114] INFO hls:	finish: codeLens.GetBindings (took 0.00s)
2021-12-14 16:34:08.105126337 [ThreadId 686] INFO hls:	finish: Wingman.codeLensProvider.GetBindings (took 4m26s)
2021-12-14 16:34:08.10514181 [ThreadId 944] INFO hls:	finish: Wingman.codeLensProvider.GetBindings (took 4m03s)
2021-12-14 16:34:08.105162588 [ThreadId 979] INFO hls:	finish: Wingman.codeLensProvider.GetBindings (took 4m03s)
2021-12-14 16:34:08.105213761 [ThreadId 1115] INFO hls:	finish: codeLens.GetBindings (took 0.00s)
2021-12-14 16:34:08.105335976 [ThreadId 1153] INFO hls:	finish: Wingman.emptyCaseScrutinees.TypeCheck (took 0.00s)
2021-12-14 16:34:08.105412199 [ThreadId 1155] INFO hls:	finish: Wingman.emptyCaseScrutinees.TypeCheck (took 0.00s)
2021-12-14 16:34:08.105481549 [ThreadId 1156] INFO hls:	finish: Wingman.emptyCaseScrutinees.TypeCheck (took 0.00s)
2021-12-14 16:34:08.105506565 [ThreadId 1158] INFO hls:	finish: Wingman.emptyCaseScrutinees.TypeCheck (took 0.00s)
2021-12-14 16:34:08.105540095 [ThreadId 1161] INFO hls:	finish: Wingman.emptyCaseScrutinees.TypeCheck (took 0.00s)
2021-12-14 16:34:08.105651425 [ThreadId 1162] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:08.105782044 [ThreadId 1159] INFO hls:	finish: Wingman.emptyCaseScrutinees.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:08.105804933 [ThreadId 1163] INFO hls:	finish: Wingman.emptyCaseScrutinees.TypeCheck (took 0.00s)
2021-12-14 16:34:08.105887137 [ThreadId 1164] INFO hls:	finish: Wingman.emptyCaseScrutinees.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:08.106087693 [ThreadId 1150] INFO hls:	finish: codeLens.GetGlobalBindingTypeSigs (took 0.00s)
2021-12-14 16:34:08.106101387 [ThreadId 1166] INFO hls:	finish: Wingman.emptyCaseScrutinees.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:08.106131553 [ThreadId 1154] INFO hls:	finish: codeLens.GetGlobalBindingTypeSigs (took 0.00s)
2021-12-14 16:34:08.106139316 [ThreadId 1151] INFO hls:	finish: codeLens.GetGlobalBindingTypeSigs (took 0.00s)
2021-12-14 16:34:08.106149683 [ThreadId 1167] INFO hls:	finish: Wingman.emptyCaseScrutinees.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:08.106263734 [ThreadId 1157] INFO hls:	finish: codeLens.GetGlobalBindingTypeSigs (took 0.00s)
2021-12-14 16:34:08.106464762 [ThreadId 1149] INFO hls:	finish: codeLens.GetGlobalBindingTypeSigs (took 0.00s)
2021-12-14 16:34:08.106622181 [ThreadId 1169] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:08.106656472 [ThreadId 1170] INFO hls:	finish: Wingman.emptyCaseScrutinees.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:08.106769269 [ThreadId 1148] INFO hls:	finish: codeLens.GetGlobalBindingTypeSigs (took 0.00s)
2021-12-14 16:34:08.1068146 [ThreadId 1168] INFO hls:	finish: Wingman.emptyCaseScrutinees.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:08.106952413 [ThreadId 1173] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:08.107139329 [ThreadId 1174] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:08.107203084 [ThreadId 1175] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:08.107372317 [ThreadId 1176] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:08.107330038 [ThreadId 1179] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:08.107547821 [ThreadId 1185] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:08.107541569 [ThreadId 1184] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:08.107594338 [ThreadId 1187] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:08.107611897 [ThreadId 1188] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:08.107615067 [ThreadId 1190] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:08.107763827 [ThreadId 1191] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:08.107816676 [ThreadId 1192] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:08.107876726 [ThreadId 1193] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:08.107930676 [ThreadId 1194] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:08.107981996 [ThreadId 1195] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:08.108111229 [ThreadId 1196] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:08.108162859 [ThreadId 1197] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:08.108234169 [ThreadId 1198] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:08.108285648 [ThreadId 1199] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:08.108339228 [ThreadId 1200] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:08.108462294 [ThreadId 1201] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:08.108516814 [ThreadId 1202] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:08.108567104 [ThreadId 1203] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:08.108621563 [ThreadId 1204] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:08.108689973 [ThreadId 1205] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:08.108831876 [ThreadId 1206] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:08.108882926 [ThreadId 1207] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:08.108968322 [ThreadId 1208] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:08.109029782 [ThreadId 1209] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:08.109084321 [ThreadId 1210] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:08.109239276 [ThreadId 1212] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:08.109298656 [ThreadId 1215] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:08.109371016 [ThreadId 1217] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:08.109430826 [ThreadId 1220] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:08.109492205 [ThreadId 1221] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:08.109654601 [ThreadId 1222] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:08.10970732 [ThreadId 1223] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:08.109844918 [ThreadId 1225] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:08.109889084 [ThreadId 1226] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:08.109940654 [ThreadId 1228] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:08.110068518 [ThreadId 1229] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:08.110118517 [ThreadId 1230] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:08.110178727 [ThreadId 1231] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:08.110229807 [ThreadId 1232] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:08.110279957 [ThreadId 1233] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:08.110414112 [ThreadId 1234] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:08.110486837 [ThreadId 1235] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:08.110549527 [ThreadId 1236] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:08.110604787 [ThreadId 1237] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:08.110641617 [ThreadId 1238] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:08.110787805 [ThreadId 1239] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:08.110843765 [ThreadId 1240] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:08.110916045 [ThreadId 1241] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:08.110968704 [ThreadId 1242] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:08.111019114 [ThreadId 1243] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:08.111147247 [ThreadId 1244] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:08.111205687 [ThreadId 1245] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:08.111261327 [ThreadId 1246] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:08.111324917 [ThreadId 1247] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:08.111376387 [ThreadId 1248] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:08.124816781 [ThreadId 976] INFO hls:	finish: RefineImports (took 4m03s)
2021-12-14 16:34:08.124809115 [ThreadId 940] INFO hls:	finish: RefineImports (took 4m03s)
2021-12-14 16:34:08.124925772 [ThreadId 615] INFO hls:	finish: RefineImports (took 4m26s)
2021-12-14 16:34:08.12481975 [ThreadId 585] INFO hls:	finish: RefineImports (took 4m26s)
2021-12-14 16:34:08.124823407 [ThreadId 653] INFO hls:	finish: RefineImports (took 4m26s)
2021-12-14 16:34:08.125176809 [ThreadId 958] INFO hls:	finish: RefineImports (took 4m03s)
2021-12-14 16:34:20.784889792 [ThreadId 1358] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:20.7849513 [ThreadId 1357] INFO hls:	finish: Pragmas.GetParsedModule (took 0.00s)
2021-12-14 16:34:20.785096882 [ThreadId 1364] INFO hls:	finish: HaddockComments.GetAnnotatedParsedSource (took 0.00s)
2021-12-14 16:34:20.7851586 [ThreadId 1365] INFO hls:	finish: retrie (took 0.00s)
2021-12-14 16:34:20.785179456 [ThreadId 1366] INFO hls:	finish: importLens (took 0.00s)
2021-12-14 16:34:20.785249786 [ThreadId 1368] INFO hls:	finish: RefineImports (took 0.00s)
2021-12-14 16:34:20.785301821 [ThreadId 1367] INFO hls:	finish: GhcideCodeActions.getParsedModule (took 0.00s)
2021-12-14 16:34:20.785388295 [ThreadId 1370] INFO hls:	finish: splice.codeAction.GitHieAst (took 0.00s)
2021-12-14 16:34:20.785325065 [ThreadId 1369] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:20.785493505 [ThreadId 1371] INFO hls:	finish: Pragmas.GetFileContents (took 0.00s)
2021-12-14 16:34:20.785525105 [ThreadId 1373] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:20.785476735 [ThreadId 1372] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:20.785588664 [ThreadId 1374] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:20.785754769 [ThreadId 1375] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:20.785809859 [ThreadId 1376] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:20.785863609 [ThreadId 1377] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:20.785922188 [ThreadId 1378] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:20.785978478 [ThreadId 1379] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:20.786116908 [ThreadId 1380] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:20.786176662 [ThreadId 1381] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:20.786226682 [ThreadId 1382] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:20.786273472 [ThreadId 1383] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:20.786323581 [ThreadId 1384] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:20.786455561 [ThreadId 1385] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:20.786528064 [ThreadId 1386] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:20.786577164 [ThreadId 1387] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:20.786627544 [ThreadId 1388] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:20.786677854 [ThreadId 1389] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:20.78680386 [ThreadId 1390] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:20.786852749 [ThreadId 1391] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:20.786904119 [ThreadId 1392] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:20.786955259 [ThreadId 1393] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:20.786991789 [ThreadId 1394] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:20.787100228 [ThreadId 1395] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:20.787150948 [ThreadId 1396] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:20.787236248 [ThreadId 1397] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:20.787296178 [ThreadId 1398] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:20.787345197 [ThreadId 1399] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:20.787453397 [ThreadId 1400] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:20.787502947 [ThreadId 1401] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:20.787552437 [ThreadId 1402] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:20.787601736 [ThreadId 1403] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:20.787650446 [ThreadId 1404] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:20.787781071 [ThreadId 1405] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:20.787831191 [ThreadId 1406] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:20.787881151 [ThreadId 1407] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:20.787931591 [ThreadId 1408] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:20.787981421 [ThreadId 1409] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:20.78808897 [ThreadId 1410] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:20.788160528 [ThreadId 1411] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:20.788229444 [ThreadId 1412] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:20.788281554 [ThreadId 1413] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:20.788331074 [ThreadId 1414] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:20.788439443 [ThreadId 1415] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:20.788488073 [ThreadId 1416] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:20.788538123 [ThreadId 1417] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:20.788586083 [ThreadId 1418] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:20.788621533 [ThreadId 1419] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:20.788805637 [ThreadId 1421] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:20.788855427 [ThreadId 1422] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:20.788754318 [ThreadId 1420] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:20.788915497 [ThreadId 1423] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:20.788982187 [ThreadId 1424] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:20.78918664 [ThreadId 1425] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:20.78923777 [ThreadId 1426] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:20.78928852 [ThreadId 1427] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:20.78934524 [ThreadId 1428] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:20.7893955 [ThreadId 1429] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:20.789614159 [ThreadId 1430] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:20.789663989 [ThreadId 1431] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-14 16:34:20.789737198 [ThreadId 1432] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-14 16:34:20.789788488 [ThreadId 1433] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-12-14 16:34:20.789838198 [ThreadId 1434] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:23.018380057 [ThreadId 1445] INFO hls:	finish: eval.GetParsedModuleWithComments (took 0.00s)
2021-12-14 16:34:23.018426397 [ThreadId 1446] INFO hls:	finish: codeLens.TypeCheck (took 0.00s)
2021-12-14 16:34:23.0185004 [ThreadId 1447] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:23.018523122 [ThreadId 1450] INFO hls:	finish: ModuleName.ghcSession (took 0.00s)
2021-12-14 16:34:23.018463202 [ThreadId 1448] INFO hls:	finish:  (took 0.00s)
2021-12-14 16:34:23.018567786 [ThreadId 1449] INFO hls:	finish: RefineImports (took 0.00s)
2021-12-14 16:34:23.018576186 [ThreadId 1452] INFO hls:	finish: Wingman.codeLensProvider.GetAnnotatedParsedSource (took 0.00s)
2021-12-14 16:34:23.018616847 [ThreadId 1451] INFO hls:	finish: codeLens.GetBindings (took 0.00s)
2021-12-14 16:34:23.01862469 [ThreadId 1453] INFO hls:	finish: Wingman.codeLensProvider.GetBindings (took 0.00s)
2021-12-14 16:34:23.018769336 [ThreadId 1454] INFO hls:	finish: Wingman.emptyCaseScrutinees.TypeCheck (took 0.00s)
2021-12-14 16:34:23.018733799 [ThreadId 1455] INFO hls:	finish: codeLens.GetGlobalBindingTypeSigs (took 0.00s)
2021-12-14 16:34:23.018772519 [ThreadId 1456] INFO hls:	finish: Wingman.emptyCaseScrutinees.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:23.018829729 [ThreadId 1457] INFO hls:	finish: ModuleName.GetParsedModule (took 0.00s)
2021-12-14 16:34:23.024758478 [ThreadId 1469] INFO hls:	finish: codeLens.TypeCheck (took 0.00s)
2021-12-14 16:34:23.024748382 [ThreadId 1468] INFO hls:	finish: eval.GetParsedModuleWithComments (took 0.00s)
2021-12-14 16:34:23.024864771 [ThreadId 1471] INFO hls:	finish:  (took 0.00s)
2021-12-14 16:34:23.024910762 [ThreadId 1470] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-14 16:34:23.024948047 [ThreadId 1473] INFO hls:	finish: ModuleName.ghcSession (took 0.00s)
2021-12-14 16:34:23.025109871 [ThreadId 1472] INFO hls:	finish: RefineImports (took 0.00s)
2021-12-14 16:34:23.025133761 [ThreadId 1474] INFO hls:	finish: codeLens.GetBindings (took 0.00s)
2021-12-14 16:34:23.02519877 [ThreadId 1475] INFO hls:	finish: Wingman.codeLensProvider.GetAnnotatedParsedSource (took 0.00s)
2021-12-14 16:34:23.02538498 [ThreadId 1476] INFO hls:	finish: codeLens.GetGlobalBindingTypeSigs (took 0.00s)
2021-12-14 16:34:23.025407535 [ThreadId 1478] INFO hls:	finish: ModuleName.GetParsedModule (took 0.00s)
2021-12-14 16:34:23.025503755 [ThreadId 1477] INFO hls:	finish: Wingman.codeLensProvider.GetBindings (took 0.00s)
2021-12-14 16:34:23.025531361 [ThreadId 1480] INFO hls:	finish: Wingman.emptyCaseScrutinees.GhcSessionDeps (took 0.00s)
2021-12-14 16:34:23.025533498 [ThreadId 1479] INFO hls:	finish: Wingman.emptyCaseScrutinees.TypeCheck (took 0.00s)

Several processes taking well over 4 minutes. For example:

2021-12-14 16:34:08.102729866 [ThreadId 955] INFO hls: finish: codeLens.TypeCheck (took 4m03s)
2021-12-14 16:34:08.102727016 [ThreadId 936] INFO hls: finish: codeLens.TypeCheck (took 4m03s)
2021-12-14 16:34:08.102884641 [ThreadId 975] INFO hls: finish: codeLens.TypeCheck (took 4m03s)
2021-12-14 16:34:08.102934496 [ThreadId 649] INFO hls: finish: codeLens.TypeCheck (took 4m26s)
2021-12-14 16:34:08.10305079 [ThreadId 584] INFO hls: finish: codeLens.TypeCheck (took 4m26s)
2021-12-14 16:34:08.103223504 [ThreadId 613] INFO hls: finish: codeLens.TypeCheck (took 4m26s)

@pepeiborra
Copy link
Collaborator

pepeiborra commented Dec 14, 2021

I can't glean much useful information from that log, but I could use an open telemetry log:

  1. Build HLS with -eventlog
  2. Run HLS with +RTS -l -ol/tmp/hls.eventlog
  3. Run nix-shell in the HLS repo or:
    a. Install tracy.
    b. Install opentelemetry-extra (with cabal install).
  4. Generate the trace: eventlog-to-tracy /tmp/hls.eventlog
  5. Upload the resulting hls.tracy file.

@mpscholten
Copy link

I've kicked off a build for HLS with -eventlog enabled at digitallyinduced/ihp#1274.

To get this running in IHP this is needed in the default.nix:

    ihp = builtins.fetchGit {
        url = "https://github.com/digitallyinduced/ihp.git";
        rev = "3111ba4e8597f627ee7f551a244416adace794a6";
        allRefs = true;
    };

After that a make -B .envrc should do it.

@mpscholten
Copy link

@barnabasmolnar could you give the above steps a try with the eventlog build?

@barnabasmolnar
Copy link
Author

Yeah sure, I'll definitely have a look. It might well be only after the holidays though.

@djfm
Copy link

djfm commented Jan 15, 2022

I have a similar issue, I think it has to do with the SemiQuotes extension.

I'm very unfamiliar with the Haskell ecosystem, I'll just present here the results of my investigation.

Context: use of HLS within IHP (latest at time of writing)
OS: ubuntu 21.10
VSCode: 1.63.2

Proper Haskell extensions have been installed, and I've set the debug output level of "Haskell" to "info".

EDIT: "solved" by un-installing system-wide GHC, which is not the appropriate solution
EDIT 2: Actually not solved, need to restart HLS very often.

Out of the box

You can see the example project on GitHub.

When I open a file that doesn't contain hsx

I have basic intellisense working in the sense that hovering a variable name tells me where it is defined:

image

And I see in the log info requests being made to the HLS.

But as soon as I edit the file I lose that intellisense and I no longer see any messages in the debug output of the Haskell extension.

When I open a file that contains hsx

I loose intellisense immediately. If I restart the HLS and VSCode, I can see in the status bar that the Haskell extension gets stuck on "Processing 20/27". Messages are sent to the HLS until I start editing something.

image

Enabling QuasiQuotes on files containing hsx

When I enable QuasiQuotes on the 2 files containing hsx, then:

  • if I have no file containing hsx open I can edit one file once and then intellisense dies
  • HLS still gets stuck at 20/27

removing hie.yaml

When I remove hie.yaml , I get a new behaviour:

  • HLS no longer gets stuck
  • INFO messages from the Haskell extension keep being displayed whatever the file I edit (with or without hsx)
  • but no intellisense information is displayed

Any cues please?

@zacwood9
Copy link

zacwood9 commented Jan 16, 2022

@pepeiborra I ran HLS with eventlog enabled on a single view file in a small IHP project. Here is the tracy file: hls.zip. 7 minutes in the typecheck phase!

The project this was ran on can be found here, and the command run for HLS was

haskell-language-server --debug Web/View/Dogs/Index.hs +RTS -l -ol/tmp/hls.eventlog

Running on WSL Ubuntu.

Probe tools:

haskell-language-server version: 1.5.1.0 (GHC: 8.10.7) (PATH: /nix/store/s6laz4m40wf1b4d8nc7ixlwkikmf4a7i-haskell-language-server-1.5.1.0/bin/haskell-language-server)
Tool versions found on the $PATH
cabal:          3.6.2.0
stack:          Not found
ghc:            8.10.7

Reproduceable environment including HLS can be produced running nix-shell in the project repo.

Running on a file without the "hsx" quasiquoter loads almost instantly, e.g. Application/Helper/Controller.hs.

@zacwood9
Copy link

zacwood9 commented Jan 16, 2022

UPDATE: compiling HLS with --enable-executable-dynamic appears to solve the issue in my repo at least.

@barnabasmolnar
Copy link
Author

Just did a quick check with IHP v0.18.0 and can confirm that HLS now seems to be working almost instantaneously. Great work and a big thank you to everyone involved. 🎉 👍

@jneira
Copy link
Member

jneira commented Jan 25, 2022

Just did a quick check with IHP v0.18.0 and can confirm that HLS now seems to be working almost instantaneously. Great work and a big thank you to everyone involved. tada +1

great! thanks for confirming it, i guess it works with building with --enable-executable-dynamic workaround, right?

@mpscholten
Copy link

great! thanks for confirming it, i guess it works with building with --enable-executable-dynamic workaround, right?

yes exactly 👍 That flag is now enabled for all IHP users that run v0.18

@jneira
Copy link
Member

jneira commented Jan 31, 2022

I am gonna close this issue as all compiler crashes seems to have the same root cause:

If any of you think the issue should not be included generically feel free to reopen it (with a brief explanation if possible)
Thanks all!

@djfm
Copy link

djfm commented Feb 2, 2022

I know it's bad etiquette to comment post issue closure, but since many of us were here because of IHP I thought relevant to confirm that it now works out of the box just following the 3 command install instructions from IHP's official website.

Excellent work everyone! What a pleasure to see a lively community at work!

@inspectiontopic
Copy link

@mpscholten suggested that I open an issue in this repo.

Processing 31/32 or something similar appears, and the Haskell extension hangs.
The issue occurs multiple times in an hour while editing code in a newly created project with ihp-new.
I use pkill to kill HLS.
Here is the environment.

IHP v0.19.0
Haskell for Visual Studio Code v2.2.0
Visual Studio Code 1.68.1
Ubuntu 20.04

Here is a log.

2022-06-21 09:36:03.158685019 [ThreadId 17134] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2022-06-21 09:36:03.158789395 [ThreadId 17135] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2022-06-21 09:36:03.158872665 [ThreadId 17136] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2022-06-21 09:36:03.158941029 [ThreadId 17137] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2022-06-21 09:36:03.159005734 [ThreadId 17138] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2022-06-21 09:36:03.325814303 [ThreadId 17167] INFO hls:	finish: Completion (took 0.00s)
2022-06-21 09:36:03.501385144 [ThreadId 17382] INFO hls:	finish: Completion (took 0.00s)
[Info  - 9:37:15 AM] Connection to server got closed. Server will restart.

The troubleshooting guide didn't help.
https://ihp.digitallyinduced.com/Guide/editors.html#vscode-haskell-language-server-troubleshooting

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
performance Issues about memory consumption, responsiveness, etc. type: bug Something isn't right: doesn't work as intended, documentation is missing/outdated, etc..
Projects
None yet
Development

No branches or pull requests

8 participants