Skip to content

Characterize eval plugin race leading to GetLinkable errors #4185

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.

Sign up for GitHub

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

Closed
wants to merge 3 commits into from
Closed

Characterize eval plugin race leading to GetLinkable errors #4185

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
c266ee8
Characterize eval plugin race leading to GetLinkable errors
jhrcek Apr 21, 2024
8852d4d
wip
jhrcek Apr 22, 2024
6216417
Trace closer to root cause
jhrcek Apr 24, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
6 changes: 5 additions & 1 deletion ghcide/src/Development/IDE/Core/Compile.hs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -72,7 +72,7 @@
import Data.Tuple.Extra (dupe)
import Data.Unique as Unique
import Debug.Trace
import Development.IDE.Core.FileStore (resetInterfaceStore)

Check warning on line 75 in ghcide/src/Development/IDE/Core/Compile.hs

View workflow job for this annotation

GitHub Actions / Hlint check run 

Warning in module Development.IDE.Core.Compile: Use fewer imports ▫︎ Found: "import Development.IDE.Core.FileStore ( resetInterfaceStore )\nimport Development.IDE.Core.FileStore ( shareFilePath )\n" ▫︎ Perhaps: "import Development.IDE.Core.FileStore\n ( resetInterfaceStore, shareFilePath )\n"
import Development.IDE.Core.Preprocessor
import Development.IDE.Core.RuleTypes
import Development.IDE.Core.Shake
Expand All @@ -91,7 +91,7 @@
import Development.IDE.Types.Diagnostics
import Development.IDE.Types.Location
import Development.IDE.Types.Options
import GHC (ForeignHValue,

Check warning on line 94 in ghcide/src/Development/IDE/Core/Compile.hs

View workflow job for this annotation

GitHub Actions / Hlint check run 

Warning in module Development.IDE.Core.Compile: Use fewer imports ▫︎ Found: "import GHC ( ForeignHValue, GetDocsFailure(..), parsedSource )\nimport qualified GHC as G\nimport GHC ( ModuleGraph )\nimport GHC ( GhcException(..) )\n" ▫︎ Perhaps: "import qualified GHC as G\nimport GHC\n ( ForeignHValue,\n GetDocsFailure(..),\n parsedSource,\n ModuleGraph,\n GhcException(..) )\n"
GetDocsFailure (..),
parsedSource)
import qualified GHC.LanguageExtensions as LangExt
Expand Down Expand Up @@ -529,7 +529,8 @@
core_file = codeGutsToCoreFile iface_hash guts
iface_hash = getModuleHash final_iface
core_hash1 <- atomicFileWrite se core_fp $ \fp ->
writeBinCoreFile fp core_file

trace ("TRACE: writeBinCoreFile: core_fp=" <> core_fp) $ writeBinCoreFile fp core_file
-- We want to drop references to guts and read in a serialized, compact version
-- of the core file from disk (as it is deserialised lazily)
-- This is because we don't want to keep the guts in memory for every file in
Expand Down Expand Up @@ -1448,6 +1449,9 @@
ml_core_file :: ModLocation -> FilePath
ml_core_file ml = ml_hi_file ml <.> "core"

ts :: Show a => String -> a -> a
ts label x = trace ("TRACE: " <> label <> "=" <> show x) x

-- | Returns an up-to-date module interface, regenerating if needed.
-- Assumes file exists.
-- Requires the 'HscEnv' to be set up with dependencies
Expand Down
7 changes: 5 additions & 2 deletions ghcide/src/Development/IDE/Core/FileStore.hs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -71,7 +71,7 @@ import Language.LSP.VFS
import System.FilePath
import System.IO.Error
import System.IO.Unsafe

import Debug.Trace

data Log
= LogCouldNotIdentifyReverseDeps !NormalizedFilePath
Expand Down Expand Up @@ -250,7 +250,10 @@ setSomethingModified vfs state keys reason = do
atomically $ do
writeTQueue (indexQueue $ hiedbWriter $ shakeExtras state) (\withHieDb -> withHieDb deleteMissingRealFiles)
modifyTVar' (dirtyKeys $ shakeExtras state) $ \x ->
foldl' (flip insertKeySet) x keys
foldl' (\xs k ->
--trace ("TRACE: insertDirkyKey: " <> show k) $

insertKeySet k xs) x keys
void $ restartShakeSession (shakeExtras state) vfs reason []

registerFileWatches :: [String] -> LSP.LspT Config IO Bool
Expand Down
12 changes: 9 additions & 3 deletions ghcide/src/Development/IDE/Core/Rules.hs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -181,7 +181,7 @@
import qualified Data.IntMap as IM
#endif


import Debug.Trace

data Log
= LogShake Shake.Log
Expand Down Expand Up @@ -823,7 +823,7 @@
{ source_version = ver
, old_value = m_old
, get_file_version = use GetModificationTime_{missingFileDiagnostics = False}
, get_linkable_hashes = \fs -> map (snd . fromJust . hirCoreFp) <$> uses_ GetModIface fs

Check warning on line 826 in ghcide/src/Development/IDE/Core/Rules.hs

View workflow job for this annotation

GitHub Actions / Hlint check run 

Suggestion in getModIfaceFromDiskRule in module Development.IDE.Core.Rules: Use fmap ▫︎ Found: "\\ fs -> map (snd . fromJust . hirCoreFp) <$> uses_ GetModIface fs" ▫︎ Perhaps: "fmap (map (snd . fromJust . hirCoreFp)) . uses_ GetModIface"
, regenerate = regenerateHiFile session f ms
}
r <- loadInterface (hscEnv session) ms linkableType recompInfo
Expand Down Expand Up @@ -951,7 +951,7 @@
hsc <- hscEnv <$> use_ GhcSessionDeps f
let compile = fmap ([],) $ use GenerateCore f
se <- getShakeExtras
(diags, !mbHiFile) <- writeCoreFileIfNeeded se hsc linkableType compile tmr
(diags, !mbHiFile) <- writeCoreFileIfNeeded se hsc (ts2 "linkableType" f linkableType) compile tmr
let fp = hiFileFingerPrint <$> mbHiFile
hiDiags <- case mbHiFile of
Just hiFile
Expand Down Expand Up @@ -980,6 +980,12 @@
count <- getRebuildCountVar <$> getIdeGlobalAction
liftIO $ atomically $ modifyTVar' count (+1)

ts :: Show a => String -> a -> a
ts label x = trace ("TRACE: " <> label <> "=" <> show x) x

Check failure on line 984 in ghcide/src/Development/IDE/Core/Rules.hs

View workflow job for this annotation

GitHub Actions / Hlint check run 

Error in ts in module Development.IDE.Core.Rules: Avoid restricted function ▫︎ Found: "trace" ▫︎ Note: may break the code

ts2 :: Show a => String -> NormalizedFilePath -> a -> a
ts2 label nfp x = trace ("TRACE: " <> label <> "=" <> show x <> " (" <> show nfp <> ")") x

Check failure on line 987 in ghcide/src/Development/IDE/Core/Rules.hs

View workflow job for this annotation

GitHub Actions / Hlint check run 

Error in ts2 in module Development.IDE.Core.Rules: Avoid restricted function ▫︎ Found: "trace" ▫︎ Note: may break the code

-- | Also generates and indexes the `.hie` file, along with the `.o` file if needed
-- Invariant maintained is that if the `.hi` file was successfully written, then the
-- `.hie` and `.o` file (if needed) were also successfully written
Expand All @@ -1005,7 +1011,7 @@
se <- getShakeExtras

-- Bang pattern is important to avoid leaking 'tmr'
(diags'', !res) <- writeCoreFileIfNeeded se hsc compNeeded compile tmr
(diags'', !res) <- writeCoreFileIfNeeded se hsc (ts2 "compNeeded" f compNeeded) compile tmr

-- Write hi file
hiDiags <- case res of
Expand Down Expand Up @@ -1095,7 +1101,7 @@
-- thus bump its modification time, forcing this rule to be rerun every time.
exists <- liftIO $ doesFileExist obj_file
mobj_time <- liftIO $
if exists

Check warning on line 1104 in ghcide/src/Development/IDE/Core/Rules.hs

View workflow job for this annotation

GitHub Actions / Hlint check run 

Warning in getLinkableRule in module Development.IDE.Core.Rules: Use whenMaybe ▫︎ Found: "if exists then Just <$> getModTime obj_file else pure Nothing" ▫︎ Perhaps: "whenMaybe exists (getModTime obj_file)"
then Just <$> getModTime obj_file
else pure Nothing
case mobj_time of
Expand Down
5 changes: 4 additions & 1 deletion ghcide/src/Development/IDE/Core/Shake.hs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -123,7 +123,7 @@
import Development.IDE.Core.ProgressReporting
import Development.IDE.Core.RuleTypes
import Development.IDE.Core.Tracing
import Development.IDE.GHC.Compat (NameCache,

Check warning on line 126 in ghcide/src/Development/IDE/Core/Shake.hs

View workflow job for this annotation

GitHub Actions / Hlint check run 

Warning in module Development.IDE.Core.Shake: Use fewer imports ▫︎ Found: "import Development.IDE.GHC.Compat\n ( NameCache, NameCacheUpdater(..), initNameCache, knownKeyNames )\nimport Development.IDE.GHC.Compat\n ( mkSplitUniqSupply, upNameCache )\n" ▫︎ Perhaps: "import Development.IDE.GHC.Compat\n ( NameCache,\n NameCacheUpdater(..),\n initNameCache,\n knownKeyNames,\n mkSplitUniqSupply,\n upNameCache )\n"
NameCacheUpdater (..),
initNameCache,
knownKeyNames)
Expand Down Expand Up @@ -172,6 +172,7 @@
import System.FilePath hiding (makeRelative)
import System.IO.Unsafe (unsafePerformIO)
import System.Time.Extra
import Debug.Trace
-- See Note [Guidelines For Using CPP In GHCIDE Import Statements]

#if !MIN_VERSION_ghc(9,3,0)
Expand Down Expand Up @@ -1234,7 +1235,9 @@
(if eq then ChangedRecomputeSame else ChangedRecomputeDiff)
(encodeShakeValue bs) $
A res
liftIO $ atomicallyNamed "define - dirtyKeys" $ modifyTVar' dirtyKeys (deleteKeySet $ toKey key file)
liftIO $ atomicallyNamed "define - dirtyKeys" $ modifyTVar' dirtyKeys (
trace ("TRACE: delete dirty key " <> show key <> " file " <> show file) $

Check failure on line 1239 in ghcide/src/Development/IDE/Core/Shake.hs

View workflow job for this annotation

GitHub Actions / Hlint check run 

Error in defineEarlyCutoff' in module Development.IDE.Core.Shake: Avoid restricted function ▫︎ Found: "trace" ▫︎ Note: may break the code
deleteKeySet $ toKey key file)
return res
where
-- Highly unsafe helper to compute the version of a file
Expand Down
15 changes: 9 additions & 6 deletions plugins/hls-eval-plugin/src/Ide/Plugin/Eval/Rules.hs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -41,7 +41,7 @@
import Ide.Logger (Recorder, WithPriority,
cmapWithPrio)
import Ide.Plugin.Eval.Types

import Debug.Trace

Check warning on line 44 in plugins/hls-eval-plugin/src/Ide/Plugin/Eval/Rules.hs

View workflow job for this annotation

GitHub Actions / flags (9.2, ubuntu-latest) 

The import of ‘Debug.Trace’ is redundant

Check warning on line 44 in plugins/hls-eval-plugin/src/Ide/Plugin/Eval/Rules.hs

View workflow job for this annotation

GitHub Actions / test (9.2, macOS-latest, false) 

The import of ‘Debug.Trace’ is redundant

Check warning on line 44 in plugins/hls-eval-plugin/src/Ide/Plugin/Eval/Rules.hs

View workflow job for this annotation

GitHub Actions / test (9.2, ubuntu-latest, true) 

The import of ‘Debug.Trace’ is redundant

rules :: Recorder (WithPriority Log) -> Rules ()
rules recorder = do
Expand All @@ -56,13 +56,13 @@
queueForEvaluation :: IdeState -> NormalizedFilePath -> IO ()
queueForEvaluation ide nfp = do
EvaluatingVar var <- getIdeGlobalState ide
atomicModifyIORef' var (\fs -> (Set.insert nfp fs, ()))
atomicModifyIORef' var (\fs -> (trace ("TRACE: queueForEvaluation: " <> show nfp ) $ Set.insert nfp fs, ()))

Check failure on line 59 in plugins/hls-eval-plugin/src/Ide/Plugin/Eval/Rules.hs

View workflow job for this annotation

GitHub Actions / Hlint check run 

Error in queueForEvaluation in module Ide.Plugin.Eval.Rules: Avoid restricted function ▫︎ Found: "trace" ▫︎ Note: may break the code
Copy link
Collaborator

@soulomoon soulomoon Apr 22, 2024 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It is odd that we are still seeing IsEvaluating: False, inbetween queueForEvaluation and unqueueForEvaluation
Maybe we can add the trace to runEvalCmd to make sure the restart session take effect.

              (do queueForEvaluation st nfp
                  setSomethingModified VFSUnmodified st [toKey IsEvaluating nfp] "Eval"
                  (trace ("TRACE: queueForEvaluation done")


unqueueForEvaluation :: IdeState -> NormalizedFilePath -> IO ()
unqueueForEvaluation ide nfp = do
EvaluatingVar var <- getIdeGlobalState ide
-- remove the module from the Evaluating state, so that next time it won't evaluate to True
atomicModifyIORef' var $ \fs -> (Set.delete nfp fs, ())
atomicModifyIORef' var $ \fs -> (trace ("TRACE: unqueueForEvaluation: " <> show nfp ) $ Set.delete nfp fs, ())

Check failure on line 65 in plugins/hls-eval-plugin/src/Ide/Plugin/Eval/Rules.hs

View workflow job for this annotation

GitHub Actions / Hlint check run 

Error in unqueueForEvaluation in module Ide.Plugin.Eval.Rules: Avoid restricted function ▫︎ Found: "trace" ▫︎ Note: may break the code

apiAnnComments' :: ParsedModule -> [SrcLoc.RealLocated EpaCommentTok]
apiAnnComments' pm = do
Expand Down Expand Up @@ -110,7 +110,7 @@
isEvaluatingRule recorder = defineEarlyCutoff (cmapWithPrio LogShake recorder) $ RuleNoDiagnostics $ \IsEvaluating f -> do
alwaysRerun
EvaluatingVar var <- getIdeGlobalAction
b <- liftIO $ (f `Set.member`) <$> readIORef var
b <- fmap (ts2 "isMemberEvaluatingVar" f) . liftIO $ (f `Set.member`) <$> readIORef var
return (Just (if b then BS.singleton 1 else BS.empty), Just b)

-- Redefine the NeedsCompilation rule to set the linkable type to Just _
Expand All @@ -120,12 +120,15 @@
-- leading to much better performance of the evaluate code lens
redefinedNeedsCompilation :: Recorder (WithPriority Log) -> Rules ()
redefinedNeedsCompilation recorder = defineEarlyCutoff (cmapWithPrio LogShake recorder) $ RuleWithCustomNewnessCheck (<=) $ \NeedsCompilation f -> do
isEvaluating <- use_ IsEvaluating f
isEvaluating <- ts2 "isEvaluating" f <$> use_ IsEvaluating f

if not isEvaluating then needsCompilationRule f else do
ms <- msrModSummary . fst <$> useWithStale_ GetModSummaryWithoutTimestamps f
let df' = ms_hspp_opts ms
linkableType = computeLinkableTypeForDynFlags df'
fp = encodeLinkableType $ Just linkableType

pure (Just fp, Just (Just linkableType))
pure (Just fp, ts2 "redefinedNeedsCompilation" f $ Just (Just linkableType))

ts2 :: Show a => String -> NormalizedFilePath -> a -> a
ts2 label nfp x = trace ("TRACE: " <> label <> "=" <> show x <> "(" <> show nfp <> ")") x

Check failure on line 134 in plugins/hls-eval-plugin/src/Ide/Plugin/Eval/Rules.hs

View workflow job for this annotation

GitHub Actions / Hlint check run 

Error in ts2 in module Ide.Plugin.Eval.Rules: Avoid restricted function ▫︎ Found: "trace" ▫︎ Note: may break the code
33 changes: 33 additions & 0 deletions tmp-notes.md
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,33 @@
HRK:|OK|FAIL|error

OK|FAIL|error|isEvaluating|queueForEvaluation|unqueueForEvaluation|writeBinCoreFile


(HRK: writeBinCoreFile)|(HRK: linkableType=Just BCOLinkable)|OK|FAIL|error

Theory:

Every test that succeeds has the following sequence:


HRK: linkableType=Just BCOLinkable
HRK: writeCoreFileIfNeeded: guts=modguts
HRK: writeBinCoreFile /tmp/hls-test-root/.cache/ghcide/test-0.1.0.0-inplace-1af041e620a747f3eee9125b6968276b7bf496d0/extra-file-30552027971537-267991-12








In order for `GetLinkable` rule to succeed, the

The core file is written [here](https://github.com/haskell/haskell-language-server/blob/9593d04a76e024942981b1333bfb2558a6ae0dab/ghcide/src/Development/IDE/Core/Compile.hs#L532)

But this core-file-writing code path is only triggered when is called with `linkableType == Just BCOLinkable`.

In the case when we get the `GetLinkable` error, the `linkableType` is always `Nothing`.



Loading
Loading