Project indexing doesn't finish, probably due to "type" import?

[jhrcek]

I'm using recent version of hls and I'm hitting this bug during indexing of my project.
It seems to be related to "type" imports.
I tried to find which head call in hls codebase could be behind this, but there are too many head calls to know for sure.
If you could help me identify which occurrence of head might be causing this issue, I could try to fix it

Your environment

Output of haskell-language-server --probe-tools or haskell-language-server-wrapper --probe-tools:

$ haskell-language-server-wrapper --probe-tools
haskell-language-server version: 1.2.0.0 (GHC: 8.8.4) (PATH: /home/jhrcek/.local/bin/haskell-language-server-wrapper) (GIT hash: 92e4bad5b6c5432938ae0842e9ddd569bf0cdff8)
Tool versions found on the $PATH
cabal:		3.4.0.0
stack:		2.7.1
ghc:		8.8.4

Which OS do you use:
Linux, Fedora 34
Which lsp-client do you use:
VS Code
Describe your project (alternative: link to the project):
N/A

Steps to reproduce

This screenshot should sum it up just fine

Expected behaviour

Project indexing should finish

Actual behaviour

Include debug information

Execute in the root of your project the command haskell-language-server --debug . and paste the logs here:

This command runs fine and doesn't print anything related. But nevertheless the VSCode ui gets stuck on indexing.

Paste the logs from the lsp-client, e.g. for VS Code

Pasting just few log lines that surround the Prelude.head: empty list error..

LSP logs:

2021-07-19 09:25:26.21620834 [ThreadId 1405] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
2021-07-19 09:25:26.219038669 [ThreadId 1405] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-07-19 09:25:26.351273507 [ThreadId 1741] INFO hls:	finish: Wingman.emptyCaseScrutinees.GhcSessionDeps (took 0.00s)
2021-07-19 09:25:26.352217492 [ThreadId 1741] INFO hls:	finish: codeLens.GetGlobalBindingTypeSigs (took 0.14s)
2021-07-19 09:25:27.356491874 [ThreadId 1742] INFO hls:	finish: GhcideCodeActions.GetAnnotatedParsedSource (took 0.00s)
2021-07-19 09:25:27.357057045 [ThreadId 1742] INFO hls:	finish: GhcideCodeActions.GetParsedModule (took 0.00s)
2021-07-19 09:25:27.35733881 [ThreadId 1742] INFO hls:	finish: GhcideCodeActions.GetFileContents (took 0.00s)
2021-07-19 09:25:27.441057756 [ThreadId 1742] INFO hls:	finish: GhcideCodeActions.TypeCheck (took 0.00s)
2021-07-19 09:25:27.444346666 [ThreadId 1405] INFO hls:	finish: GhcideCodeActions.GetHieAst (took 0.00s)
2021-07-19 09:25:27.445053112 [ThreadId 1405] INFO hls:	finish: GhcideCodeActions.getParsedModule (took 0.00s)
2021-07-19 09:25:27.996904126 [ThreadId 1742] INFO hls:	finish: RefineImports (took 8.76s)
2021-07-19 09:25:27.997052683 [ThreadId 1742] INFO hls:	finish: RefineImports (took 8.81s)
2021-07-19 09:25:27.997096856 [ThreadId 1742] INFO hls:	finish: RefineImports (took 2.35s)
haskell-language-server-8.8.4: Prelude.head: empty list
2021-07-19 09:25:28.824963259 [ThreadId 2045] INFO hls:	finish: RefineImports (took 9.63s)

[pepeiborra]

Does it reproduce if you use the hiedb binary to index the .hie files directly?

hiedb -D /tmp/hiedb index ~/.cache/ghcide/ghcide-1.4.0.2-inplace-24c29823fbe57a944e4cadeebf7d64ed73c305d2/       
Processing file 41/41: /Users/pepeiborra/.cache/ghcide/ghcide-1.4.0.2-inplace-24c29823fbe57a944e4cadeebf7d64ed73c305d2/Control/Concurrent/Strict.hie... done                                                                                                  
Completed! (41 indexed, 0 skipped in 1.12s + 0.00s gc)

[jhrcek]

I tried the following steps, there are no errors when running hiedb from command line..

$ stack install hiedb --resolver lts-16.17 # Our project is using this resolver, so I thought I should get hiedb compatible with it. Is this right?
$ cd ~/.cache/
$ rm ghcide -rf # remove all caches so I know what to index
# start vscode with the source code containing the "type (:.) ((:.))" import, wait for project being indexed (which doesn't finish)
$  hiedb -D /tmp/hiedb index ~/.cache/ghcide/main-77c95705da5d2c1b73361d5056a575ad309abac0/
Processing file 114/114: /home/jhrcek/.cache/ghcide/main-77c95705da5d2c1b73361d5056a575ad309abac0/PI.hie... done                                                                              
Completed! (4 indexed, 110 skipped in 0.18s + 0.00s gc)

[pepeiborra]

But it looks like hiedb skipped 110 of the files. Any idea why?

[wz1000]

skipped means they were aleady up to date in the database.

[jhrcek]

I think this is because they were indexed in the step when I opened vscode.

[pepeiborra]

Doesn't -D /tmp/hiedb force a new database?
Can you use -r to force a reindex?

[jhrcek]

Sorry, I missed that it's indexing in tmp dir, so that makes my explanation not-make-sense.
Tried again with:

$ rm -rf /tmp/hiedb
$ hiedb -r -D /tmp/hiedb index ~/.cache/ghcide/main-77c95705da5d2c1b73361d5056a575ad309abac0/
Re-indexing 0 files, deleting 0 files
Processing file 114/114: /home/jhrcek/.cache/ghcide/main-77c95705da5d2c1b73361d5056a575ad309abac0/PI.hie... done                                                                              
Completed! (114 indexed, 0 skipped in 1.17s + 0.00s gc)

114 exactly matches the number of files in our project

backend$ git ls-files 'src/*.hs' | wc -l
114

Could it be that I'm using old version of hiedb when trying to reproduce this on command line?
I failed to identify the vesion (hiedb doesn't seem to have any kind of version flag..)

[jhrcek]

Just managed to reproduce this like this:

1. open project (without the "type (:.) ((:.))" import), let it finish indexing
2. paste that import in and save the file -> Prelude.head appears in the logs

head-error.mp4

[pepeiborra]

The reason I am trying to repro with hiedb is so that we can scope down the issue and move it to the right project.

Alternatively, you can try to build HLS with profiling and run it with +RTS -xc to get a stack trace for the error.

[jhrcek]

Thanks, will try later today.

[jhrcek]

Can you maybe share a bit of info how you're building with profiling?
I usually do just stack ./build.hs hls-8.8.4 to install from master, so not sure how compilation with profiling would fall into using the script..

[pepeiborra]

I just build with cabal. To enable profiling, you can do cabal configure --enable-executable-profiling or add the below to the cabal.project.local:

profiling: True
profiling-detail: toplevel-functions
executable-profiling: True

[jhrcek]

I managed to compile hls with profiling and RTS flag -xc built in (via --with-rtsopts for hls executable in cabal file).
However running it produces soo much output, that I can't scroll back to the Prelude.head error.
My understanding is that the exceptions are printed to stderr.
Is there any way to redirect them to file when running hls from vscode?
Setting Haskell log file in hie settings only captures stdout, which doesn't contain any errors..

[pepeiborra]

You can point the IDE to a bash wrapper that calls the HLS binary and tees stderr to a temp file.

[jhrcek]

Ok, this was an interesting exercise 😆
I was totally surprised how MANY exceptions are being thrown all over the place.
But that approach didn't help me identify which head is causing the issue.

In the end I added debug traces to all usages of head and found that my reproducer triggers this head:

haskell-language-server/ghcide/src/Development/IDE/Plugin/CodeAction.hs

Line 1477 in 78381b8

wrapOperatorInParens x = if isAlpha (head x) then x else "(" <> x <> ")"

The input ":." to modifyBinding triggers the error. To generalize: the error will be triggered whenever you have unused import of something that ends with '.' BUT there are some other things imported from that module that you're using.
I'll open a PR with fix shortly.

[pepeiborra]

It sounds like there could be more than one problem: indexing runs in a background thread whereas code actions run in the LSP handler thread

[codygman]

I remember having an issue a long time ago with head seeming to mess up the session somehow, perhaps your patch to wrapOperatorInParens will fix that if it still exists.