Race condition in -boot file setup #4754
Description
While working on #4600 I discovered a race condition in the -boot file setup.
Note that I think that #4600 will fix it, so I'm mostly opening this issue for discussion, reference, and information gathering.
Depending on the order of the scheduling of the registration of new files to the knownTarget, it is possible that the knowTarget does not see the same environment and that hls is unable to see some module, especially when .hs-boot files are involved. See at the end of this bug report how this could have an impact on the result of the diagnostics.
I've first showed my investigation here: #4600 (comment) but here are an extract of what I consider as relevant:
In the sessionOpts code:
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(pPrint are my additions), we can see that the new cfp files added to the session while trigger a call to consultCradle only if the file is not in the cache v and if checkDependencyInfo returns False.
It seems (I had not investigated that) that when calling consultCradle with a .hs or .hs-boot, the function extendKnownTargets is called with the relevant file as targetTarget, but with both the .hs and .hs-boot in the targetLocations:
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 GetKnownTargetsFor example, here is one of the newTarget possibility:
[ 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"
]
}
]
```
You can see that ModuleB.hs-boot and ModuleA.hs are targetTarget, but actually, other combination can happen, such as ModuleB.hs and ModuleA.hs-boot.
The final result is that the knownTarget is only extended with the file from targetTarget (the ones from targetLocations are filtered out because they do not exists on disk. In this example, only ModuleB.hs-boot and ModuleA.hs will ends in the knownLocations.
However the cache v in sessionOpts is populated for both the .hs and .hs-boot. As a result, depending on the order of the call, knownTarget would be different.
Your environment
Which OS do you use?
Which version of GHC do you use and how did you install it?
How is your project built (alternative: link to the project)?
Which LSP client (editor/plugin) do you use?
Which version of HLS do you use and how did you install it?
Have you configured HLS in any way (especially: a hie.yaml file)?
Steps to reproduce
Take for example the test, bidirectional module dependency with hs-boot, where the setup is:
_ <- createDoc "ModuleA.hs" "haskell" contentA
_ <- createDoc "ModuleA.hs-boot" "haskell" contentAboot
_ <- createDoc "ModuleB.hs" "haskell" contentB
_ <- createDoc "ModuleB.hs-boot" "haskell" contentBboot
expectDiagnostics [("ModuleB.hs", [(DiagnosticSeverity_Warning, (3,0), "Top-level binding", Just "GHC-38417")])]
This test is sensible to timing and can fail. In order to show this, I've added a few threadDelay:
diff --git a/ghcide-test/exe/DiagnosticTests.hs b/ghcide-test/exe/DiagnosticTests.hs
index a0e9ae2768..6e3a849bca 100644
--- a/ghcide-test/exe/DiagnosticTests.hs
+++ b/ghcide-test/exe/DiagnosticTests.hs
@@ -42,6 +42,7 @@
import Test.Hls.FileSystem
import Test.Tasty
import Test.Tasty.HUnit
+import Control.Concurrent (threadDelay)
tests :: TestTree
tests = testGroup "diagnostics"
@@ -263,6 +264,7 @@
[ "module ModuleA where"
]
_ <- createDoc "ModuleA.hs" "haskell" contentA
+ liftIO $ threadDelay 1_000_000
_ <- createDoc "ModuleA.hs-boot" "haskell" contentAboot
_ <- createDoc "ModuleB.hs" "haskell" contentB
_ <- createDoc "ModuleB.hs-boot" "haskell" contentBbootThe result is a failure of the test:
cabal run test:ghcide-tests -- -p "bidirectional module dependency with hs-boot"
Configuration is affected by the following files:
- cabal.project
ghcide
diagnostics
bidirectional module dependency with hs-boot: FAIL (1.11s)
ghcide-test/exe/DiagnosticTests.hs:271:
Got diagnostics for Uri {getUri = "file:///tmp/nix-shell.hE81CE/hls-test-root/extra-dir-67388832384842/ModuleA.hs"} but only expected diagnostics for [NormalizedUri (-6471945026272365973) "file:///tmp/nix-shell.hE81CE/hls-test-root/extra-dir-67388832384842/ModuleB.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 \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.hE81CE/hls-test-root/extra-dir-67388832384842/ModuleA.hs"}, _range = Range {_start = Position {_line = 1, _character = 22}, _end = Position {_line = 1, _character = 29}}}, _message = "GetLocatedImports"}], _data_ = Nothing}]
1 out of 1 tests failed (1.12s)
However, with a different order, the test do not fail:
diff --git a/ghcide-test/exe/DiagnosticTests.hs b/ghcide-test/exe/DiagnosticTests.hs
index a0e9ae2768..64d36e1822 100644
--- a/ghcide-test/exe/DiagnosticTests.hs
+++ b/ghcide-test/exe/DiagnosticTests.hs
@@ -42,6 +42,7 @@
import Test.Hls.FileSystem
import Test.Tasty
import Test.Tasty.HUnit
+import Control.Concurrent (threadDelay)
tests :: TestTree
tests = testGroup "diagnostics"
@@ -262,8 +263,9 @@
let contentAboot = T.unlines
[ "module ModuleA where"
]
+ _ <- createDoc "ModuleA.hs-boot" "haskell" contentAboot
+ liftIO $ threadDelay 1_000_000
_ <- createDoc "ModuleA.hs" "haskell" contentA
- _ <- createDoc "ModuleA.hs-boot" "haskell" contentAboot
_ <- createDoc "ModuleB.hs" "haskell" contentB
_ <- createDoc "ModuleB.hs-boot" "haskell" contentBboot
expectDiagnostics [("ModuleB.hs", [(DiagnosticSeverity_Warning, (3,0), "Top-level binding", Just "GHC-38417")])]I claim that the test can fail without the threadDelay, however I had never been able to observe it.
I also claim that something similar could happen on the editor when many files are registered at the same time without being saved. We observed a bug similar to that at work since we are working on top of #4600. It is unclear for me, but it seems that this MR increased the chance for this race condition. However the test I'm depicting here are on the master branch of hls.
Debug information
In #4600 I've just decided to add all the files from targetLocations to the knownTarget. It seems to fix this bug (but it creates other regression, so I'm still investigating).