Leaking 10GB memory per minute with wrong type alias def type Foo = Foo for some ghc versions

[anka-213]

Opening this file in vs code

import Control.Monad.State
import Control.Applicative
import Data.List

data T = T [T] deriving (Show)
type Parser = Parser

ch :: Char -> Parser Char
ch c = mfilter (== c) $ StateT uncons

parens :: Parser T
parens = T <$ ch '(' <*> many parens <* ch ')'

parse :: Parser a -> String -> Maybe (a, String)
parse = runStateT

causes HLS to consume a lot of ram quickly. This is the result after just a few minutes of having the file open.

Log

[client] run command: "/Users/anka/Library/Application Support/Code/User/globalStorage/haskell.haskell/haskell-language-server-0.3.0-darwin-8.8.3 --lsp"
[client] debug command: "/Users/anka/Library/Application Support/Code/User/globalStorage/haskell.haskell/haskell-language-server-0.3.0-darwin-8.8.3 --lsp"
[client] server cwd: /Users/anka/projekt/haskell/bug
haskell-language-server version: 0.3.0.0 (GHC: 8.8.3) (PATH: /Users/anka/Library/Application Support/Code/User/globalStorage/haskell.haskell/haskell-language-server-0.3.0-darwin-8.8.3) (GIT hash: d36bb9929fdd0df76f86d3635067400272f68497)
Starting (haskell-language-server)LSP server...
  with arguments: LspArguments {argLSP = True, argsCwd = Nothing, argFiles = [], argsShakeProfiling = Nothing, argsTesting = False, argsExamplePlugin = False, argsDebugOn = False, argsLogFile = Nothing, argsThreads = 0, argsProjectGhcVersion = False}
  with plugins: [PluginId "brittany",PluginId "eval",PluginId "floskell",PluginId "fourmolu",PluginId "ghcide",PluginId "ormolu",PluginId "pragmas",PluginId "retrie",PluginId "stylish-haskell"]
  in directory: /Users/anka/projekt/haskell/bug
If you are seeing this in a terminal, you probably should have run ghcide WITHOUT the --lsp option!
 Started LSP server in 0.00s
2020-08-25 22:14:15.349258 [ThreadId 31] - Opened text document: file:///Users/anka/projekt/haskell/bug/ParserInTweet.hs
2020-08-25 22:14:15.350402 [ThreadId 90] - Data.HashMap.Internal.(!): key not found
CallStack (from HasCallStack):
  error, called at ./Data/HashMap/Internal.hs:753:16 in nrdrd-cntnrs-0.2.12.0-a2bf77ff:Data.HashMap.Internal
  !, called at src/Development/IDE/Import/DependencyInformation.hs:107:40 in ghcide-0.2.0-inplace:Development.IDE.Import.DependencyInformation
2020-08-25 22:14:15.350857 [ThreadId 87] - Consulting the cradle for "/Users/anka/projekt/haskell/bug/ParserInTweet.hs"
Output from setting up the cradle Cradle {cradleRootDir = "/Users/anka/projekt/haskell/bug", cradleOptsProg = CradleAction: Default}
2020-08-25 22:14:15.496314 [ThreadId 87] - Using interface files cache dir: /Users/anka/.cache/ghcide/main-da39a3ee5e6b4b0d3255bfef95601890afd80709
2020-08-25 22:14:15.496422 [ThreadId 87] - Making new HscEnv[main]
2020-08-25 22:14:17.522717 [ThreadId 202] - Plugin.makeCodeLens (ideLogger)

---

Regardless of if this specific bug is fixed, we should probably add some limit, so HLS won't consume all available memory on the system when problems arise.

[anka-213]

I can reproduce it consistently on my machine, so if there is a good way for me to debug it locally, let me know.

[ndmitchell]

Thanks for the report, that seems brutal!

I just tried the simplest reproduction - create a new buffer, paste that in, toggle to Haskell mode. It uses 20.4Mb for me, with no visible change over 5 minutes. I was using 8.6.5 in VS Code. Therefore, I imagine there's some other factor involved.

Did you have that file saved? With a .cabal project? With a .stack project? Or just the raw file? Did you edit it somehow? Did RAM increase even when you were doing nothing? If you kept having to do something, what was it? Is this just the first file you tried, and thus all files are likely buggy? Or has it worked with other files?

As for setting a limit, certainly easy to do with the GHC heap settings. But I don't have any idea how to chose a good limit. For a big project I might want to dedicate 100Gb to the IDE. For my home machine, that would kill everything. There's no good solution I can think of...

[pepeiborra]

Could you share a full project including a hie.yaml file?
Have you tested with ghcide HEAD?

[pepeiborra]

I can reproduce it consistently on my machine, so if there is a good way for me to debug it locally, let me know.

We have an automated benchmark suite in the ghcide repo which loads a project and runs experiments. The first step would be to set this up as a benchmark that reproduces the leak that you are seeing.

[anka-213]

I can reproduce without having it in a project. Just a bare HS file.

Ram usage increases constantly, even when I do nothing. (was over 200GB when I had forgotten about it for a while)

I think it might be caused by some impurity, where some remnants of an older version still affects the current version, maybe?

[anka-213]

I'm not entirely sure how I would reproduce it in terms of the benchmark suite's commands

[pepeiborra]

I have no idea and I have very little time. Without a reproducer that I can run myself, I am unable to help

[googleson78]

just noting that there is something missing from the example:

type Parser = Parser

Isn't valid.

[anka-213]

I have no idea and I have very little time. Without a reproducer that I can run myself, I am unable to help
I understand. I'll see what I can do for reproduction.

I have not yet tested in ghcide HEAD. But the problem is still there when selecting ghcide as a backend.

[anka-213]

just noting that there is something missing from the example:

type Parser = Parser

Isn't valid.

Oh, right! That's probably the issue!

I was using the retrie plugin to "fold" Parser (possibly in another file) and it seems like it replaced it in such a way to cause an infinite loop in the type alias.

[anka-213]

Maybe it is already fixed on a newer version of ghcide, which is why people had trouble reproducing. This is my version:

 $ "/Users/anka/Library/Application Support/Code/User/globalStorage/haskell.haskell/haskell-language-server-0.3.0-darwin-8.8.3" --version
haskell-language-server version: 0.3.0.0 (GHC: 8.8.3) (PATH: /Users/anka/Library/Application Support/Code/User/globalStorage/haskell.haskell/haskell-language-server-0.3.0-darwin-8.8.3) (GIT hash: d36bb9929fdd0df76f86d3635067400272f68497)`

If so, the issue that needs fixing is to place some memory limit so the process can't consume arbitrarily much memory if a similar issue arises.

[pepeiborra]

Retrie folds can be very memory hungry. I submitted a related PR a few days ago: #321

To be sure, try to repro with the retrie command line tool

[anka-213]

To clarify, it wasn't retrie that caused the memory leak, it was retire that caused my code to have an infinite type alias loop, which in turn triggered the unbounded memory usage in ghcide.

[pepeiborra]

Is that a theory or something you have confirmed beyond doubt?

[googleson78]

But how does type A = A trigger a memory leak in ghcide? ghc directly reports an error. I've seen a memory leak with ghcide infinitely trying to run on something that crashes ghc, but this doesn't. 🤔

[anka-213]

Is that a theory or something you have confirmed beyond doubt?

I know beyond doubt that retire has nothing to do with it, since it triggers without using retrie at all, from just opening a file with the content above (with just ghcide, no HLS extensions).
Also, if I fix that line, the problem goes away.

[anka-213]

Now I know beyond doubt. This file is a minimal reproducing example:

type Foo = Foo

[ndmitchell]

I just reproduced - seems we have a bug that we don't check files which are not yet saved which meant my test wasn't valid.

To reproduce:

1. Create an empty file, save it.
2. Type type X = - observe diagnostics are present.
3. Type X leaving the full program as type X = X

For me, Windows, VS Code, GHC 8.6.5, it sits at 1 CPU working full trottle. Memory is increasing (currently 2Gb after 2 mins). So confirmed, and very serious!

[anka-213]

I was also able to reproduce by running

$ cat >> Bug.hs
type Foo = Foo
$ ghcide Bug.hs

in a terminal.

[pepeiborra]

I was also able to reproduce by running

$ cat >> Bug.hs
type Foo = Foo
$ ghcide Bug.hs

in a terminal.

Very cool, I can repro this too

[pepeiborra]

Bisected it back to 373c406 * Multi Component (#522)

[wz1000]

Seems like the issue occurs in a call to GHC.typecheckModule.

[wz1000]

This simple ghc-api program fails to reproduce

import GHC

main = runGhc (Just "***libdir***") $ do
  addTarget $ Target (TargetFile "mem.hs" Nothing) False Nothing
  mg <- depanal [] False
  let [ms] = mgModSummaries mg
  pm <- parseModule ms
  tm <- typecheckModule pm
  return ()

hie-bios check also fails to reproduce (even with -fdefer-type-errors and -fdefer-out-of-scope-variables).

[codygman]

I don't think it gets to typechecking @wz1000. I can confirm as @pepeiborra said, it happened with the multi-component commit.

The reason is if you go back to multi-component (373c406), then one commit behind it to 51907fe and run ghcide you'll see:

[cody@nixos:/tmp/blah]$ /nix/store/7fii3y3a981cpsc2lcah0vaynrnd57ky-ghcide-exe-ghcide-0.1.0/bin//ghcide 
ghcide version: 0.1.0 (GHC: 8.8.4) (PATH: /nix/store/7fii3y3a981cpsc2lcah0vaynrnd57ky-ghcide-exe-ghcide-0.1.0/bin/ghcide)
Ghcide setup tester in /tmp/blah.
Report bugs at https://github.com/digital-asset/ghcide/issues

Step 1/6: Finding files to test in /tmp/blah
Found 1 files

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

Step 3/6, Cradle 1/1: Implicit cradle for /tmp/blah
Cradle {cradleRootDir = "/tmp/blah", cradleOptsProg = CradleAction: Default}

Step 4/6, Cradle 1/1: Loading GHC Session
Interface files cache dir: /home/cody/.cache/ghcide/da39a3ee5e6b4b0d3255bfef95601890afd80709

Step 5/6: Initializing the IDE

Step 6/6: Type checking the files
File:     /tmp/blah/Bug.hs
Hidden:   no
Range:    1:0-1:14
Source:   typecheck
Severity: DsError
Message:  Cycle in type synonym declarations:/tmp/blah/Bug.hs:1:1-14: type Foo = Foo
Files that failed:
 * /tmp/blah/Bug.hs

Completed (0 files worked, 1 file failed)

Where type-checking shows there is a cycle.

If you go back to 373c406 though it never gets passed log message Making new HscEnv[main]:

[cody@nixos:/tmp/blah]$ /nix/store/hqgl28vs5kjyl18bjjh0gqv40b4r0288-ghcide-exe-ghcide-0.1.0/bin/ghcide 
ghcide version: 0.1.0 (GHC: 8.8.4) (PATH: /nix/store/hqgl28vs5kjyl18bjjh0gqv40b4r0288-ghcide-exe-ghcide-0.1.0/bin/ghcide)
Ghcide setup tester in /tmp/blah.
Report bugs at https://github.com/digital-asset/ghcide/issues

Step 1/4: Finding files to test in /tmp/blah
Found 1 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 "/tmp/blah/Bug.hs"
[INFO] Using interface files cache dir: /home/cody/.cache/ghcide/main-da39a3ee5e6b4b0d3255bfef95601890afd80709
[INFO] Making new HscEnv[main]
  C-c C-c

[codygman]

To be more specific, this is the last line that gets logged: https://github.com/codygman/ghcide/blob/cc287b6e3a532499b35845e189c987ce79394f49/exe/Main.hs#L351

This is when the fileToFlags Var gets inserted into if that means anything to anyone. It reminds me of a video I saw by mpickering talking about I think... weak references to maps and using a lot of memory. This feels different from that maybe? Will have to explore more.

[codygman]

I was led to newComponentCache which has a comment eerily close to our scenario 😆

    logDebug logger ("New Component Cache HscEnvEq: " <> T.pack (show res))

    let is = importPaths df
    ctargets <- concatMapM (targetToFile is  . targetId) (componentTargets ci)
    -- A special target for the file which caused this wonderful
    -- component to be created. In case the cradle doesn't list all the targets for
    -- the component, in which case things will be horribly broken anyway.
    -- Otherwise, we will immediately attempt to reload this module which
    -- **causes an infinite loop and high CPU usage**.  <============= this one right here
    let special_target = (componentFP ci, res)
    let xs = map (,res) ctargets
    return (special_target:xs, res)

[codygman]

So apparently the component dynamic flags being updated causes this? A minimum change to trigger things is removing that piece in:

newComponentCache logger hsc_env uids ci = do
    let df = componentDynFlags ci
    let hscEnv' = hsc_env  -- Does not allocate GBs of ram
    let hscEnv' = hsc_env { hsc_dflags = df } -- allocates GBs of ram

That is, don't do the record update and you'll get the pre multli-component behavior where tyepchecking happens and says "cycle in type synonym declarations". I don't know enough about the underlying pieces such as DynFlags to understand this better yet.

[codygman]

Could makeDynFlagsAbsolute from hie-bios be evaluating too much of the DynFlags? They seem pretty huge... That's probably not it though because this doesn't happen in "normal" situations. Oh well, hopefully some of this hacking around helps.

[fendor]

According to the comment, not evaluation but a cache fail causes the high CPU usage, e.g. ghcide is not aware of the target that it just tried to load. So, I doubt that makeDynFlagsAbsolute can force evaluation since it itself is lazy as well, afaict.

[pepeiborra]

Does the problem go away with a proper hie.yaml file that declares all the targets?

One way to check that is create a Cabal project with this module alone, and use a Cabal cradle.

[codygman]

Does the problem go away with a proper hie.yaml file that declares all the targets?

One way to check that is create a Cabal project with this module alone, and use a Cabal cradle.

I can't reproduce with a cabal project in this format:

[cody@nixos:/tmp/blah-cabal]$ tree 
.
├── blah-cabal.cabal
├── CHANGELOG.md
├── Main.hs
└── Setup.hs

0 directories, 4 files

[cody@nixos:/tmp/blah-cabal]$ cat Main.hs
module Main where

type Foo = Foo

So multi-component breaks in the case of a bare file without a project or hie.yaml. Maybe adding a direct cradle fixes it?

Can anyone explain why exactly this is? I'm very interested in knowing and will continue figuring it out on my own regardless, but I bet someone can weigh in more here.

[RCout1nho]

Já foi resolvido? Estou com o mesmo problema no ubuntu 20.04 quando abro arquivos haskell no vs code

[jneira]

This would need a issue in ghcide

[anka-213]

I tried it on a recent version of hls and it returns

  Cycle in type synonym declarations:
  /.../loop.hs:2:1-14: type Foo = Foo

now.

If there is also a test case for this (with a timeout, so a regression wouldn't hang ci) we can probably close this now.

Edit: Or maybe it is only fixed on recent ghc versions? I didn't check.