Optimise module to filename

[guibou]

(only latests commit are relevant, the other are from other MR which should be merged before this work is merged. Or we can rebase)

This is related to #4598.

This changes the file to module associating logic done during dependency
graph building.

Before, each time a module Foo.Bar is found, HLS is testing inside all
the import path for the existence of a relevant fiel.. It means that for
i import paths and m modules to locate, m * n filesystem
operations are done. Note also that this involves a lot of complex
string concatenation primitive to build the FilePath.

A module is tested for each import for each of the file of the
project. We also test for boot files, doubling the number of test.

In #4598 we have a project with 1100 modules, in more than 250 import
paths and we count more than 17000 import statments, resulting on
over 6 millions test for file existences. This project was blocking for
more than 3 minutes during HLS startup.

This commit changes the way this is computed:

• At startup, a Map ModuleName FilePath (the real type is a bit more
  involved for performance, multiples unit and boot files handling) is
  built by scanning all the import paths for files representing the
  different modules.
• Directory scanning is efficient and if import path only contains
  haskell module, this will never do more job that listing the files of
  the project.
• The lookup is now simplify a Map lookup.

The performance improvement is as follows:

• The number of IO operation is dramatically reduced, from multiples
  millions to a few recursive directories listing.
• A lot of the boilerplate of converting path had be removed.
• TODO: add an RTS stats before / after with number of allocations
• On my project, the graph building time is reduced from a few minutes
  to 3s.

Limitations:

• How to rebuild the Map if the content of one directory change?
• If one directory is filled with millions of files which are not of
  interested, performance can be damaged. TODO: add a diagnostic during
  this phase so the user can learn about this issue.

Code status:

• The lookup is not fully restored, especially it does not include the
  handling of home unit as well as reexport.
• The initialisation phase is cached inside a TVar stored as a top
  level identifier using unsafePerformIO. This is to be improved.

[guibou]

I'm running this code in production on our large codebase for the 3rd day.

a) My users are super happy, a few quotes:

(it was more than 5 minutes before ;)

Ok, that's all for the shameless plug ;)

I think I observed a few reload / performance issues which are not related and would definitely do some followup issues. I'm investigating (this is difficult to describe right now. Looks like HLS is not able to give diagnostic back if it is typechecking a file which depends on the file I just modified and if this typechecking takes time).

I also observed a surprising behavior, I need to investigate if that's linked to my MR or to something else:

• I had started HLS in a context where one of the dependencies (from the package db) was version X (which actually exposes a reexported symbol. e.g. Database.Selda which reexports Text).
• I then had changed my working copy to a version of my code which uses a new version of Database.Selda, without the reexport of Text, and my code was updated to import Data.Text (Text) everywhere it was previously using the reexport.
• From my editor, I restarted hls
• Warnings started to appear in HLS about redundant import for import Data.Text (Text) (which was true with the previous version of Selda). Note that the warning appeared on files which are NOT open in the editor, but HLS got notified about the change and reevaluated them.
• Opening the file in the editor, the warning disappears.

It looks like a multi-home issue, see. #3237, which would make sense considering that I had done nothing to fix multiple home. But this is still rather surprising because HLS was supposed to restart and hence should have completely ignored the old selda version. Maybe it picked some information from the cache.

[soulomoon]

Maybe it picked some information from the cache

We handle FOI(File of interest) and none-FOI differently.
See getModIfaceRule. This might be causing what you see @guibou

[guibou]

We handle FOI(File of interest) and none-FOI differently.
See getModIfaceRule. This might be causing what you see @guibou

@soulomoon Thank you. This is indeed interesting. I will confirm that the bug I'm observing is not linked to my change and open an issue. This is not a dramatic issue (e.g. it is not everyday that you restart the editor with breaking changes in the packages from the package database), but it is not convenient and can be confusing.

[guibou]

I've found a bug, when looking for module in the import path, an exception is raised if the import path is empty.

[guibou]

I've found a bug, when looking for module in the import path, an exception is raised if the import path is empty.

Fixed in latest commit.

[guibou]

Improved the support for currently edit files but not yet saved to the disk. The implementation will be improved for performance but that's a good first draft.

This fixs a lot of unit test, so it is good.

I do have a few (around 20) tests faliling in ghcide-tests, but otherwise, most of the tests are ok.

Still todo:

• remove the unsafePerformIO
• Handle multi home units (some tests are failing, that's a good news)
• Handle reexport (same, some tests are failing, that's a good news)
• Handle reloading of the cache if files are added / removed

[guibou]

Multiple-home-unit seems to be fixed now (maybe I've not pushed the MR), but the tests are fine. I have 3 failing tests related to -boot files and then tests will be ok.

I'll work on removing the unsafePerformIO cache (which breaks hlint test, this is great ;), maybe this cache is also responsible for the remainirg failing tests.

[guibou]

Latest push should fix hlint and actually remove the unsafePerformIO: the cache is now stored in the ShakeExtras.

I have 3 (2 are flaky) remaining issues with -boot tests:

    cyclic module dependency with hs-boot:                             FAIL (0.63s)
      ghcide-test/exe/DiagnosticTests.hs:246:
      Got diagnostics for Uri {getUri = "file:///tmp/nix-shell.1Fwv9H/hls-test-root/extra-dir-80836663907422/ModuleA.hs"} but only expected diagnostics for [NormalizedUri 5530269853045372639 "
file:///tmp/nix-shell.1Fwv9H/hls-test-root/extra-dir-80836663907422/ModuleB.hs"] got [Diagnostic {_range = Range {_start = Position {_line = 1, _character = 22}, _end = Position {_line = 1, _c
haracter = 29}}, _severity = Just DiagnosticSeverity_Error, _code = Nothing, _codeDescription = Nothing, _source = Just "not found", _message = "Could not find module \8216ModuleB\8217.\nIt is
 not a module in the current program, or in any known package.", _tags = Nothing, _relatedInformation = Just [DiagnosticRelatedInformation {_location = Location {_uri = Uri {getUri = "file:///
tmp/nix-shell.1Fwv9H/hls-test-root/extra-dir-80836663907422/ModuleA.hs"}, _range = Range {_start = Position {_line = 1, _character = 22}, _end = Position {_line = 1, _character = 29}}}, _messa
ge = "GetLocatedImports"}], _data_ = Nothing}]
      Use -p '/cyclic module dependency with hs-boot/' to rerun this test only.
    bidirectional module dependency with hs-boot:                      FAIL (0.63s)
      ghcide-test/exe/DiagnosticTests.hs:269:
      Got diagnostics for Uri {getUri = "file:///tmp/nix-shell.1Fwv9H/hls-test-root/extra-dir-80836663907424/ModuleA.hs"} but only expected diagnostics for [NormalizedUri 5396647782368786105 "
file:///tmp/nix-shell.1Fwv9H/hls-test-root/extra-dir-80836663907424/ModuleB.hs"] got [Diagnostic {_range = Range {_start = Position {_line = 1, _character = 22}, _end = Position {_line = 1, _c
haracter = 29}}, _severity = Just DiagnosticSeverity_Error, _code = Nothing, _codeDescription = Nothing, _source = Just "not found", _message = "Could not find module \8216ModuleB\8217.\nIt is
 not a module in the current program, or in any known package.", _tags = Nothing, _relatedInformation = Just [DiagnosticRelatedInformation {_location = Location {_uri = Uri {getUri = "file:///
tmp/nix-shell.1Fwv9H/hls-test-root/extra-dir-80836663907424/ModuleA.hs"}, _range = Range {_start = Position {_line = 1, _character = 22}, _end = Position {_line = 1, _character = 29}}}, _messa
ge = "GetLocatedImports"}], _data_ = Nothing}]
      Use -p '/bidirectional module dependency with hs-boot/' to rerun this test only.
    correct reference used with hs-boot:                               FAIL (0.84s)
      ghcide-test/exe/DiagnosticTests.hs:295:
      Got diagnostics for Uri {getUri = "file:///tmp/nix-shell.1Fwv9H/hls-test-root/extra-dir-80836663907426/ModuleB.hs"} but only expected diagnostics for [NormalizedUri 4327465349865231065 "
file:///tmp/nix-shell.1Fwv9H/hls-test-root/extra-dir-80836663907426/ModuleC.hs"] got [Diagnostic {_range = Range {_start = Position {_line = 1, _character = 22}, _end = Position {_line = 1, _c
haracter = 29}}, _severity = Just DiagnosticSeverity_Error, _code = Nothing, _codeDescription = Nothing, _source = Just "not found", _message = "Could not find module \8216ModuleA\8217.\nIt is
 not a module in the current program, or in any known package.", _tags = Nothing, _relatedInformation = Just [DiagnosticRelatedInformation {_location = Location {_uri = Uri {getUri = "file:///
tmp/nix-shell.1Fwv9H/hls-test-root/extra-dir-80836663907426/ModuleB.hs"}, _range = Range {_start = Position {_line = 1, _character = 22}, _end = Position {_line = 1, _character = 29}}}, _messa
ge = "GetLocatedImports"}], _data_ = Nothing}]
      Use -p '/correct reference used with hs-boot/' to rerun this test only.
      ```

[guibou]

I will need a bit of help here.

I'm blocked with the following errors locally:

cabal run test:ghcide-tests -- -p "hs-boot"
ghcide
  diagnostics
    cyclic module dependency with hs-boot:        OK (0.69s)
    bidirectional module dependency with hs-boot: OK (0.64s)
    correct reference used with hs-boot:          FAIL (0.99s)
      ghcide-test/exe/DiagnosticTests.hs:295:
      Got diagnostics for Uri {getUri = "file:///tmp/hls-test-root/extra-dir-35586222804939/ModuleB.hs"} but only expected diagnostics for [NormalizedUri 2644126075305381495 "file:///tmp/hls-test-root/extra-dir-35586222804939/ModuleC.hs"] got [Diagnostic {_range = Range {_start = Position {_line = 1, _character = 22}, _end = Position {_line = 1, _character = 29}}, _severity = Just DiagnosticSeverity_Error, _code = Nothing, _codeDescription = Nothing, _source = Just "not found", _message = "Could not find module \8216ModuleA\8217.\nIt is not a module in the current program, or in any known package.", _tags = Nothing, _relatedInformation = Just [DiagnosticRelatedInformation {_location = Location {_uri = Uri {getUri = "file:///tmp/hls-test-root/extra-dir-35586222804939/ModuleB.hs"}, _range = Range {_start = Position {_line = 1, _character = 22}, _end = Position {_line = 1, _character = 29}}}, _message = "GetLocatedImports"}], _data_ = Nothing}]
      Use -p '/hs-boot/&&/correct reference used with hs-boot/' to rerun this test only.

1 out of 3 tests failed (2.32s)

Note that out of the 3 tests related to -boot files, one seems to always fail, but 2 of them seems to be flaky.

In the context of this test, ModuleA cannot be found in the targetMap.

My understanding here is limited and especially, it is difficult for me to understand why my changes may have any impact on these tests. In such context, it is tempting to think that there is another problem such as a race condition / timing.

During my investigation, I found the code in sessionOpts:

          pPrint ("sessionOpts", cfp, v)
          case HM.lookup (toNormalizedFilePath' cfp) v of
            Just (opts, old_di) -> do
              deps_ok <- checkDependencyInfo old_di
              pPrint ("deps_ok", deps_ok, old_di)
              if not deps_ok
                then do
                  -- If the dependencies are out of date then clear both caches and start
                  -- again.
                  modifyVar_ fileToFlags (const (return Map.empty))
                  modifyVar_ filesMap (const (return HM.empty))
                  -- Keep the same name cache
                  modifyVar_ hscEnvs (return . Map.adjust (const []) hieYaml )
                  pPrint ("consultCradle not deps_ok", cfp)
                  consultCradle hieYaml cfp
                else return (opts, Map.keys old_di)
            Nothing -> do
              pPrint ("consultCradle Nothing", cfp)
              consultCradle hieYaml cfp

(the pPrint are my addition).

I observed that the pPrint("sessionOpts") is called multiple time for all the files in the "workspace" (for the test I care about, module{A, B}.hs[-boot].

However, consultCradle is only called once for any moduleX.hs[-boot], e.g. if called for ModuleA.hs, it won't be called for moduleA.hs-boot, or the opposite. Depending on for which "version" of the module it had been called, it will lead to a test success or failure.

It seems that constultCradle will populate the v map with both the .hs-boot and .hs when evaluating one module. For example, this is one trace (when I had a bit less pPrint), additionnal comments with #

# session opts is first called for ModuleB.hs-boot, followed by a consultCradle
( "sessionOpts"
, "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-80639723522145/ModuleB.hs-boot"
)
( "consultCradle Nothing"
, "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-80639723522145/ModuleB.hs-boot"
)
# Same for ModuleA.hs-boot
( "sessionOpts"
, "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-80639723522145/ModuleA.hs-boot"
)
( "consultCradle Nothing"
, "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-80639723522145/ModuleA.hs-boot"
)
# Then for "ModuleA.hs"
( "sessionOpts"
, "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-80639723522145/ModuleA.hs"
)
# Which does not call "consultCradle" because deps seems to be ok
( "deps_ok"
, True
, fromList []
)
# Same for ModuleB.hs
( "sessionOpts"
, "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-80639723522145/ModuleB.hs"
)
( "deps_ok"
, True
, fromList []
)
# Then the hs-boot files are called again due to the cyclic dependency...
( "sessionOpts"
, "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-80639723522145/ModuleB.hs-boot"
)
( "deps_ok"
, True
, fromList []
)
( "sessionOpts"
, "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-80639723522145/ModuleB.hs"
)
( "deps_ok"
, True
, fromList []
)
( "sessionOpts"
, "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-80639723522145/ModuleA.hs-boot"
)
( "deps_ok"
, True
, fromList []
)
( "sessionOpts"
, "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-80639723522145/ModuleA.hs"
)
( "deps_ok"
, True
, fromList []
)
( "sessionOpts"
, "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-80639723522145/ModuleB.hs-boot"
)
( "deps_ok"
, True
, fromList []
)
( "sessionOpts"
, "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-80639723522145/ModuleA.hs"
)
( "deps_ok"
, True
, fromList []
)
( "sessionOpts"
, "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-80639723522145/ModuleA.hs-boot"
)
( "deps_ok"
, True
, fromList []
)
( "sessionOpts"
, "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-80639723522145/ModuleB.hs"
)
( "deps_ok"
, True
, fromList []
)

The result of this is that when calling extendKnownTargets, only twice (for each ModuleX), it calls them with different targetTarget. See two trace here:

    [ TargetDetails
        { targetTarget = TargetFile NormalizedFilePath "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-73114015013655/ModuleA.hs-boot"
        , targetEnv =
            ( []
            , Just HscEnvEq 10
            )
        , targetDepends = fromList []
        , targetLocations =
            [ NormalizedFilePath "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-73114015013655/ModuleA.hs-boot"
            , NormalizedFilePath "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-73114015013655/ModuleA.hs"
            ]
        }
    , TargetDetails
        { targetTarget = TargetFile NormalizedFilePath "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-73114015013655/ModuleB.hs-boot"
        , targetEnv =
            ( []
            , Just HscEnvEq 10
            )
        , targetDepends = fromList []
        , targetLocations =
            [ NormalizedFilePath "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-73114015013655/ModuleB.hs-boot"
            , NormalizedFilePath "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-73114015013655/ModuleB.hs"
            ]
        }
    ]

And

  [ TargetDetails
        { targetTarget = TargetFile NormalizedFilePath "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-911475559555/ModuleB.hs"
        , targetEnv =
            ( []
            , Just HscEnvEq 10
            )
        , targetDepends = fromList []
        , targetLocations =
            [ NormalizedFilePath "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-911475559555/ModuleB.hs"
            , NormalizedFilePath "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-911475559555/ModuleB.hs-boot"
            ]
        }
    , TargetDetails
        { targetTarget = TargetFile NormalizedFilePath "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-911475559555/ModuleA.hs"
        , targetEnv =
            ( []
            , Just HscEnvEq 10
            )
        , targetDepends = fromList []
        , targetLocations =
            [ NormalizedFilePath "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-911475559555/ModuleA.hs"
            , NormalizedFilePath "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-911475559555/ModuleA.hs-boot"
            ]
        }
    ]

    [ TargetDetails
        { targetTarget = TargetFile NormalizedFilePath "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-26070923945755/ModuleB.hs-boot"
        , targetEnv =
            ( []
            , Just HscEnvEq 10
            )
        , targetDepends = fromList []
        , targetLocations =
            [ NormalizedFilePath "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-26070923945755/ModuleB.hs-boot"
            , NormalizedFilePath "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-26070923945755/ModuleB.hs"
            ]
        }
    , TargetDetails
        { targetTarget = TargetFile NormalizedFilePath "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-26070923945755/ModuleA.hs"
        , targetEnv =
            ( []
            , Just HscEnvEq 10
            )
        , targetDepends = fromList []
        , targetLocations =
            [ NormalizedFilePath "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-26070923945755/ModuleA.hs"
            , NormalizedFilePath "/tmp/nix-shell.hE81CE/hls-test-root/extra-dir-26070923945755/ModuleA.hs-boot"
            ]
        }
    ]
    ```
    
    So how each time there is only two entries for each Module, but the `targetTarget` contains either the `.hs` or the `.hs-boot` file, but `targetLocations` always contain boths.
    
    Later, in `extendKnownTargets`:
    
    ```
    let extendKnownTargets newTargets = do
          let checkAndLogFile path = do
                 exists' <- IO.doesFileExist (fromNormalizedFilePath path)
                 pure $ exists'
          knownTargets <- concatForM  newTargets $ \TargetDetails{..} ->
            case targetTarget of
              TargetFile f -> do
                -- If a target file has multiple possible locations, then we
                -- assume they are all separate file targets.
                -- This happens with '.hs-boot' files if they are in the root directory of the project.
                -- GHC reports options such as '-i. A' as 'TargetFile A.hs' instead of 'TargetModule A'.
                -- In 'fromTargetId', we dutifully look for '.hs-boot' files and add them to the
                -- targetLocations of the TargetDetails. Then we add everything to the 'knownTargetsVar'.
                -- However, when we look for a 'Foo.hs-boot' file in 'FindImports.hs', we look for either
                --
                --  * TargetFile Foo.hs-boot
                --  * TargetModule Foo
                --
                -- If we don't generate a TargetFile for each potential location, we will only have
                -- 'TargetFile Foo.hs' in the 'knownTargetsVar', thus not find 'TargetFile Foo.hs-boot'
                -- and also not find 'TargetModule Foo'.
                fs <- filterM checkAndLogFile targetLocations
                pure $ map (\fp -> (TargetFile fp, Set.singleton fp)) (nubOrd (f:fs))
              TargetModule _ -> do
                found <- filterM checkAndLogFile targetLocations
                return [(targetTarget, Set.fromList found)]
          hasUpdate <- atomically $ do
            known <- readTVar knownTargetsVar
            let known' = flip mapHashed known $ \k -> unionKnownTargets k (mkKnownTargets knownTargets)
                hasUpdate = if known /= known' then Just (unhashed known') else Nothing
            writeTVar knownTargetsVar known'
            pure hasUpdate
          for_ hasUpdate $ \x ->
            logWith recorder Debug $ LogKnownFilesUpdated (targetMap x)
          return $ toNoFileKey GetKnownTargets

For each targetfile, we will create a TargetFile associated with actually, 0 files because all files are filtered out by the file exist test.

I'll continue this investigation later.

[guibou]

@fendor

I've rebased and rerun the CI.

Latest run was showing only a segfault with GHC 9.10 on window and one failure in the call hierarchy plugin on window with ghc 9.6, which may hence be a flakyness.

The latest commit is a tentative fix for the issue described in #4600 (comment) and that I tried to describe and extract in #4754 (And really, I should answer the poor @soulomoon who tried to help me).

In order to be in a mergable state, I need to:

• Understand Race condition in -boot file setup #4754 and see if my fix is "correct"
• Handle reloading of the module cache when a file is added/removed. I still don't know how to handle that, but maybe it could be simply done "in case of failure": if we try to find the file associated with a module, but this file is not in the cache, instead of crashing, we could try to reload the cache one time.
• Test for reexport. I don't think I have done anything for reexport, but all tests are OK. I'm wondering if reexport are tested
• Finally, the most important: in order to merge the "KnownTarget" (which contains the not yet written on disk files) and the module cache, I currently do an O(nm) process which completely destroy the expected performances. However, the fix is simple: I can recompute the module cache each time the KnownTarget is updated

[guibou]

@fendor, this is the offending change.

When extendKnownTargets is called with files which are not yet available on disk, the TargetFile f contains a file (either .hs or .hs-boot) and targetLocations contains a list of files and it seems that it always contains the .hs and .hs-boot.

However, these file do not exist on the disk, so the filterM always filter them out.

This "fix" allows the file to be added.

The bug is certainly NOT here, see #4754 for more details.

My current understanding is that there is a caching process which, when a .hs or .hs-boot file is registered, it calls extendKnownTargets with both .hs and .hs-boot files listed in targetLocations, but only the .hs or .hs-boot in TargetFile f.

However, it seems that there is some sort of caching which once a .hs-boot file or .hs file is registered, it blocks registration for the other file.

It means that depending on the registration order, we may end up with only one or the other file in the knownTarget.

The result is that during module name to filename association (the target of this MR), we won't be able to find either the .hs or the .hs-boot file, because we look into the knownTarget map for them.

Note that I don't understand why it was not failing before, because the previous implementation was actually looking in the knownTarget too, and on the filesystem. But for files not on the filesystem (as it is the case for tests and newly created files), it seems that the previous implementation was behaving the same.

My guess is that, because it seems that it is a race, my change had an impact on the way extendKnownTargets is called concurrently and as a result the problem appears more often. But I had not been able to confirm that the issue was there before my MR.

[soulomoon]

If we want to extendKnownTargets, we should do so in the restart thread, see Note [Serializing runs in separate thread] . Otherwise we risk of destablizing the build system.
For the .hs or .hs-boot mess, one of the possible solution, we can update the sessionLoader to invalidate related cache and consult the cradle again if the missing .hs or .hs-boot is added.

[soulomoon]

Handle reloading of the module cache when a file is added/removed. I still don't know how to handle that, but maybe it could be simply done "in case of failure": if we try to find the file associated with a module, but this file is not in the cache, instead of crashing, we could try to reload the cache one time.

take a look at SMethod_TextDocumentDidOpen handler and setFileModified. You might be able to hook what you want there.

[guibou]

I think I had cleaned the module map logic initialisation:

a) Now only computed once, when a new file is added / removed. The performances are back and it also handle if a new file is added to the KnownTarget.
b) Still need to investigate the -boot flaky tests.
c) Still need to investagate / test for the reexport logic. Will do that next.

[guibou]

My latest commit broke everything, sorry, this was a mistake. I've removed it from the patch stack.

[guibou]

I'm doing another tentative at finishing this.

Many things are unclear for me.

@soulomoon, you suggested to hook/have a look at SMethod_TextDocumentDidOpen and restart thread, but I do have the feeling that my writing was interpreted as if I wanted to edit knownTargets.

However, I do not, instead, I'm reading knownTargets during the GetLocatedImports phase in order to know which files are already known by HLS (but may not exists on the drive yet).

And I'm doing that exactly at the some location as before in GetLocatedImports, but after calling another rule, GetModulesPaths that I introduced in this MR.

      716:   (notSourceModules, sourceModules) <- use_ GetModulesPaths file
      717:   KnownTargets targetsMap <- useNoFile_ GetKnownTargets

In my previous writings, here and in #4754, I claimed that it could be a race condition in the way knownTargets is populated.

However, I've today found another experience:

i=0
while cabal run ghcide-tests -- -p '/redundant import/&&/redundant import even without warning/'
do
    i=$(( $i + 1))
    echo $i
done;

It usually fails after a few iterations:

2
ghcide
  diagnostics
    redundant import even without warning: (TargetFile NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-85960977570265/ModuleB.hs",fromList [NormalizedFilePath "/tmp/nix-shell
.Vw1D6P/hls-test-root/extra-dir-85960977570265/ModuleB.hs"])
(TargetFile NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-85960977570265/ModuleB.hs",fromList [NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-85960977570
265/ModuleB.hs"])
    redundant import even without warning: FAIL (0.31s)
      ghcide-test/exe/DiagnosticTests.hs:319:
      Could not find (DiagnosticSeverity_Warning,(3,0),"Top-level binding",Just "GHC-38417",Nothing) in [Diagnostic {_range = Range {_start = Position {_line = 2, _character = 7}, _end = Posit
ion {_line = 2, _character = 14}}, _severity = Just DiagnosticSeverity_Error, _code = Nothing, _codeDescription = Nothing, _source = Just "not found", _message = "Could not find module \8216Mo
duleA\8217.\nIt is not a module in the current program, or in any known package.", _tags = Nothing, _relatedInformation = Just [DiagnosticRelatedInformation {_location = Location {_uri = Uri {
getUri = "file:///tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-85960977570265/ModuleB.hs"}, _range = Range {_start = Position {_line = 2, _character = 7}, _end = Position {_line = 2, _characte
r = 14}}}, _message = "GetLocatedImports"}], _data_ = Nothing}]

1 out of 1 tests failed (0.33s)

However, with the folliwng change, adding a threadDelay before calling the extendModuleMapWithKnownTargets (which does call the GetKnownTargets as depicted above, it does not crash so easilly, but it still fails, later, and with a timeout:

157
ghcide
  diagnostics
    redundant import even without warning: (TargetFile NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-14070387317865/ModuleA.hs",fromList [NormalizedFilePath "/tmp/nix-shell
.Vw1D6P/hls-test-root/extra-dir-14070387317865/ModuleA.hs"])
(TargetFile NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-14070387317865/ModuleA.hs",fromList [NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-14070387317
865/ModuleA.hs"])
(TargetFile NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-14070387317865/ModuleB.hs",fromList [NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-14070387317
865/ModuleB.hs"])
(TargetFile NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-14070387317865/ModuleA.hs",fromList [NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-14070387317
865/ModuleA.hs"])
(TargetFile NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-14070387317865/ModuleB.hs",fromList [NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-14070387317
865/ModuleB.hs"])
(TargetFile NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-14070387317865/ModuleA.hs",fromList [NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-14070387317
865/ModuleA.hs"])
(TargetFile NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-14070387317865/ModuleB.hs",fromList [NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-14070387317
865/ModuleB.hs"])
(TargetFile NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-14070387317865/ModuleA.hs",fromList [NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-14070387317
865/ModuleA.hs"])
(TargetFile NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-14070387317865/ModuleB.hs",fromList [NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-14070387317
865/ModuleB.hs"])
(TargetFile NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-14070387317865/ModuleA.hs",fromList [NormalizedFilePath "/tmp/nix-shell.Vw1D6P/hls-test-root/extra-dir-14070387317
865/ModuleA.hs"])



    redundant import even without warning: FAIL
      Exception: Timed out waiting to receive a message from the server.
      Last message received:
      {
          "jsonrpc": "2.0",
          "method": "$/progress",
          "params": {
              "token": 5,
              "value": {
                  "kind": "report",
                  "message": "3/3",
                  "percentage": 100
              }
          }
      }
      
      While handling Timed out waiting to receive a message from the server.
        | Last message received:
        | {
        |     "jsonrpc": "2.0",
        |     "method": "$/progress",
        |     "params": {
        |         "token": 5,
        |         "value": {
        |             "kind": "report",
        |             "message": "3/3",
        |             "percentage": 100
        |         }
        |     }
        | }
      
      HasCallStack backtrace:
        throwIO, called at libraries/exceptions/src/Control/Monad/Catch.hs:308:12 in exceptions-0.10.9-6f10:Control.Monad.Catch
        throwM, called at libraries/exceptions/src/Control/Monad/Catch.hs:318:7 in exceptions-0.10.9-6f10:Control.Monad.Catch
        generalBracket, called at src/Control/Exception/Safe.hs:468:16 in safe-exceptions-0.1.7.4-36e9aa35d7afb566b6972dd7fc456fbea3e84f9f9f58420a5170817b50a55c4a:Control.Exception.Safe
        finally, called at src/Test/Hls.hs:572:67 in hls-test-utils-2.14.0.0-inplace:Test.Hls

1 out of 1 tests failed (60.78s)

That's interesting, because it shows that:

a) The issue is clearly a race condition, adding 200ms of thread delay seems to fix the problem (e.g. it usually fails in less than 5 iterations, and this addition get no failure in 157 iteration).
b) There maybe another race condition somewhere else which generates a deadlock (after 157 iterations).

I'll try to understand if the race condition I clearly reproduced here is linked to a mistake on my side (highly probable) OR if it was already existing, but the previous code was robust to it.

As I described in #4754, I'm convinced that there is a race condition which depending on scheduling, the content of GetKnownTargets is different. However the previous code had the getTargetFor logic, which coupled with (removed in this MR) locateModuleFile and getFileExists (which uses the VFS and is something I completely ignored for now)... WAIT!

Stop.

I've got it.

 335     :         let getTargetFor modName nfp
 336     :                 | Just (TargetFile nfp') <- HM.lookupKey (TargetFile nfp) targets = do
 337     :                     -- reuse the existing NormalizedFilePath in order to maximize sharing
 338     :                     itExists <- getFileExists nfp'
 339     :                     return $ if itExists then Just nfp' else Nothing
 340     :                 | Just tt <- HM.lookup (TargetModule modName) targets = do
 341     :                     -- reuse the existing NormalizedFilePath in order to maximize sharing
 342     :                     let nfp' = fromMaybe nfp $ HashSet.lookupElement nfp tt
 343     :                     itExists <- getFileExists nfp'
 344     :                     return $ if itExists then Just nfp' else Nothing
 345     :                 | otherwise = do
 346     :                     itExists <- getFileExists nfp
 347  344:                     return $ if itExists then Just nfp else Nothing

The previous code was calling getTargetFor for each path it had manually created inside locateModuleFile. In the context I care about, this map is populated with TargetFile and the TargetFile may not have been correctly populated for my -boot file. HENCE the two initial cases are ignored and the otherwise matchs AND queries the VFS for the file.

So:

a) I think I can confirm that there is an issue in the way knowTargets is populated
b) However, in the context of TargetFile, the third case skips the lookup in knownTargets and instead do a lookup in the VFS and is happy. Hence this race condition had no impact on the previous implementation. Howveer my implementation treats a missing entry in knownTarget as an error, hence fails.
c) It is unclear for my why the threadDelay seems to help here. It will be for another investigation.

[guibou]

Actually, I'm wondering if instead of using knowTargets I could not use the vfs map vfsVar. I'll have a look.

[guibou]

Tentative with using the VFS instead of knownTargets pushed, test are running, but it immediatly fixs the issue on the few small tests I ran here.

This is not a version ready for review yet (e.g. the merge between the module cache and the VFS is done on every lookup for module, so that's still a process O(k * m) (k the number of entries in the vfs and m the number of import paths), but the fix for that is easier, and first I want to validate that tests are OK without.

[guibou]

I'm lost. The latest attempt, using the VFS instead of known targets, seems to works reliably on macos, but not on linux/window.

Pushing an attempt which merges the result of VFS and knownTargets, this is crazy, but we'll clean later during review once we'll have something reliable.

[guibou]

The ugly hack which uses the merge of VFS and known target content seems to work (tests 100% passes locally, and were just close to 100% green also in CI)

I've now pushed a change which move the costly module -> filepath extension from known_targets / vfs to the cached location. Hopefully CI will be green tomorrow (that's already too late for me).

Next steps:

• a) Implement the reexport part (But add tests for that, it is obvious at that point that this is not tested, this part of the code is now full of "variable not used" but no tests are failing. edit: I was not able to write a test for reexport, so instead I tried to copy the previous logic.
• b) Clarify the cache invalidation logic (I will ask explicit questions)
• c) There is one todo linked to a possible optimisation (on O(n) lookup on the import list for ALL import, which can be turned into a cached set. edit => Not related to this MR, the lookup is actually O(n) where n is the number of loaded unit. Definitively a possible optimisation if the project contains a lot of home module, but unlinked to the current MR.
• d) Clarify this VFS + known_target thing

[guibou]

The latest push is there check that CI is still OK. if green, I'll:

a) Squash everything
b) Do a pass of cleanup to remove the elements not relevant to this MR, add a few comments
c) Submit for review with explicit point of focus (the cache invalidation logic, or actually the absence of it, and the weird hack between knownTargets and VFS)

[guibou]

I've cleaned the MR and I'm ready for review.

See the commit message for guidance about the different changes. I'll also add two inline comments in the review to ask two questions related to:

a) Cache invalidation
b) The "hack" with knownTargets and VFS

[guibou]

This is the cache logic which is improper.

I would like the rule GetModulesPaths to be invalidated when:

• GetKnownTargets is invalidated (for this session). It is easy to do that by moving the call to extendModuleMapWithKnownTargets outside of the cache lookup here, but this operation is too costly to be redone for each file of the session.
• The cached value to be shared for all the file in the same session. I had not been able to implement that and this is why I've manually cached that inside ShakeExtras

So roughly, if there is a solution to cache GetModulesPaths for all files of the session and invalidate it when GetKnownTargets changes, it could solve most of my problems.

[guibou]

This is a place which is a bit fuzzy. If you look at the original getTargetFor (Removed elsewhere in this diff), it was actually taking into account the values from knownTargets and from the VFS, so it is coherent to use both, but it seems a bit overkill.

[guibou]

This tests:

ghcide
  diagnostics
    lower-case drive: FAIL (0.11s)

Fails in the CI, it was not failing this morning. I've broken something while cleaning up, I'm investigating, but I don't think this blocks the overall review process.

[guibou]

The regression should be fixed now.