Characterize eval plugin race leading to GetLinkable errors

Author: jhrcek

ghcide/src/Development/IDE/Core/Compile.hs

@@ -529,7 +529,8 @@ mkHiFileResultCompile se session' tcm simplified_guts = catchErrs $ do
             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
@@ -1448,6 +1449,9 @@ instance NFData IdeLinkable where
 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

ghcide/src/Development/IDE/Core/Rules.hs

@@ -181,7 +181,7 @@ import           GHC                                          (mgModSummaries)
 import qualified Data.IntMap                                  as IM
 #endif
 
-
+import Debug.Trace
 
 data Log
   = LogShake Shake.Log
@@ -951,7 +951,7 @@ getModIfaceRule recorder = defineEarlyCutoff (cmapWithPrio LogShake recorder) $
       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
@@ -980,6 +980,12 @@ incrementRebuildCount = do
   count <- getRebuildCountVar <$> getIdeGlobalAction
   liftIO $ atomically $ modifyTVar' count (+1)
 
+ts :: Show a => String -> a -> a
+ts label x = trace ("TRACE: " <> label <> "=" <> show x) x
+
+ts2 :: Show a => String -> NormalizedFilePath -> a -> a
+ts2 label nfp x = trace ("TRACE: " <> label <> "=" <> show x <> " (" <> show nfp <> ")") x
+
 -- | 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
@@ -1005,7 +1011,7 @@ regenerateHiFile sess f ms compNeeded = do
                 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

plugins/hls-eval-plugin/src/Ide/Plugin/Eval/Rules.hs

@@ -41,7 +41,7 @@ import           GHC.Parser.Annotation
 import           Ide.Logger                           (Recorder, WithPriority,
                                                        cmapWithPrio)
 import           Ide.Plugin.Eval.Types
-
+import Debug.Trace
 
 rules :: Recorder (WithPriority Log) -> Rules ()
 rules recorder = do
@@ -56,13 +56,13 @@ instance IsIdeGlobal EvaluatingVar
 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, ()))
 
 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, ())
 
 apiAnnComments' :: ParsedModule -> [SrcLoc.RealLocated EpaCommentTok]
 apiAnnComments' pm = do
@@ -110,7 +110,7 @@ isEvaluatingRule :: Recorder (WithPriority Log) -> Rules ()
 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 _
@@ -120,12 +120,15 @@ isEvaluatingRule recorder = defineEarlyCutoff (cmapWithPrio LogShake recorder) $
 -- 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