diff --git a/ghcide/exe/Main.hs b/ghcide/exe/Main.hs index b9e3637068..4c3e1a00cd 100644 --- a/ghcide/exe/Main.hs +++ b/ghcide/exe/Main.hs @@ -53,12 +53,14 @@ data Log = LogIDEMain IDEMain.Log | LogRules Rules.Log | LogGhcIde GhcIde.Log + | LogEkg EKG.Log instance Pretty Log where pretty = \case LogIDEMain log -> pretty log LogRules log -> pretty log LogGhcIde log -> pretty log + LogEkg log -> pretty log ghcideVersion :: IO String ghcideVersion = do @@ -148,5 +150,5 @@ main = withTelemetryLogger $ \telemetryLogger -> do , optRunSubset = not argsConservativeChangeTracking , optVerifyCoreFile = argsVerifyCoreFile } - , IDEMain.argsMonitoring = OpenTelemetry.monitoring <> EKG.monitoring logger argsMonitoringPort + , IDEMain.argsMonitoring = OpenTelemetry.monitoring <> EKG.monitoring (cmapWithPrio LogEkg recorder) argsMonitoringPort } diff --git a/ghcide/src/Development/IDE/Core/OfInterest.hs b/ghcide/src/Development/IDE/Core/OfInterest.hs index 950c27bcbb..90c9cc4345 100644 --- a/ghcide/src/Development/IDE/Core/OfInterest.hs +++ b/ghcide/src/Development/IDE/Core/OfInterest.hs @@ -45,7 +45,8 @@ import Ide.Logger (Pretty (pretty), Recorder, WithPriority, cmapWithPrio, - logDebug) + Priority(..), + logWith) import qualified Language.LSP.Protocol.Message as LSP import qualified Language.LSP.Server as LSP @@ -110,16 +111,17 @@ addFileOfInterest state f v = do pure (new, (prev, new)) when (prev /= Just v) $ do join $ atomically $ recordDirtyKeys (shakeExtras state) IsFileOfInterest [f] - logDebug (ideLogger state) $ - "Set files of interest to: " <> T.pack (show files) + logWith (ideLogger state) Debug $ + LogSetFilesOfInterest (HashMap.toList files) + -- "Set files of interest to: " <> T.pack (show files) deleteFileOfInterest :: IdeState -> NormalizedFilePath -> IO () deleteFileOfInterest state f = do OfInterestVar var <- getIdeGlobalState state files <- modifyVar' var $ HashMap.delete f join $ atomically $ recordDirtyKeys (shakeExtras state) IsFileOfInterest [f] - logDebug (ideLogger state) $ "Set files of interest to: " <> T.pack (show files) - + logWith (ideLogger state) Debug $ + LogSetFilesOfInterest (HashMap.toList files) scheduleGarbageCollection :: IdeState -> IO () scheduleGarbageCollection state = do GarbageCollectVar var <- getIdeGlobalState state diff --git a/ghcide/src/Development/IDE/Core/RuleTypes.hs b/ghcide/src/Development/IDE/Core/RuleTypes.hs index fc977cea8a..5e2333d7d4 100644 --- a/ghcide/src/Development/IDE/Core/RuleTypes.hs +++ b/ghcide/src/Development/IDE/Core/RuleTypes.hs @@ -43,6 +43,7 @@ import Development.IDE.Types.Diagnostics import GHC.Serialized (Serialized) import Language.LSP.Protocol.Types (Int32, NormalizedFilePath) +import Ide.Logger (Pretty(..), viaShow) data LinkableType = ObjectLinkable | BCOLinkable deriving (Eq,Ord,Show, Generic) @@ -340,6 +341,9 @@ data FileOfInterestStatus instance Hashable FileOfInterestStatus instance NFData FileOfInterestStatus +instance Pretty FileOfInterestStatus where + pretty = viaShow + data IsFileOfInterestResult = NotFOI | IsFOI FileOfInterestStatus deriving (Eq, Show, Typeable, Generic) instance Hashable IsFileOfInterestResult diff --git a/ghcide/src/Development/IDE/Core/Shake.hs b/ghcide/src/Development/IDE/Core/Shake.hs index 2791dcfc2d..c576239f93 100644 --- a/ghcide/src/Development/IDE/Core/Shake.hs +++ b/ghcide/src/Development/IDE/Core/Shake.hs @@ -174,7 +174,7 @@ import qualified StmContainers.Map as STM import System.FilePath hiding (makeRelative) import System.IO.Unsafe (unsafePerformIO) import System.Time.Extra - +import qualified Prettyprinter as Pretty -- See Note [Guidelines For Using CPP In GHCIDE Import Statements] #if !MIN_VERSION_ghc(9,3,0) @@ -193,6 +193,12 @@ data Log | LogDiagsDiffButNoLspEnv ![FileDiagnostic] | LogDefineEarlyCutoffRuleNoDiagHasDiag !FileDiagnostic | LogDefineEarlyCutoffRuleCustomNewnessHasDiag !FileDiagnostic + | LogCancelledAction !T.Text + | LogSessionInitialised + | LogLookupPersistentKey !T.Text + | LogShakeGarbageCollection !T.Text !Int !Seconds + -- * OfInterest Log messages + | LogSetFilesOfInterest ![(NormalizedFilePath, FileOfInterestStatus)] deriving Show instance Pretty Log where @@ -226,6 +232,16 @@ instance Pretty Log where LogDefineEarlyCutoffRuleCustomNewnessHasDiag fileDiagnostic -> "defineEarlyCutoff RuleWithCustomNewnessCheck - file diagnostic:" <+> pretty (showDiagnosticsColored [fileDiagnostic]) + LogCancelledAction action -> + pretty action <+> "was cancelled" + LogSessionInitialised -> "Shake session initialized" + LogLookupPersistentKey key -> + "LOOKUP PERSISTENT FOR:" <+> pretty key + LogShakeGarbageCollection label number duration -> + pretty label <+> "of" <+> pretty number <+> "keys (took " <+> pretty (showDuration duration) <> ")" + LogSetFilesOfInterest ofInterest -> + "Set files of interst to" <> Pretty.line + <> indent 4 (pretty $ fmap (first fromNormalizedFilePath) ofInterest) -- | We need to serialize writes to the database, so we send any function that -- needs to write to the database over the channel, where it will be picked up by @@ -256,7 +272,7 @@ data ShakeExtras = ShakeExtras { --eventer :: LSP.FromServerMessage -> IO () lspEnv :: Maybe (LSP.LanguageContextEnv Config) ,debouncer :: Debouncer NormalizedUri - ,logger :: Logger + ,shakeRecorder :: Recorder (WithPriority Log) ,idePlugins :: IdePlugins IdeState ,globals :: TVar (HMap.HashMap TypeRep Dynamic) -- ^ Registry of global state used by rules. @@ -441,7 +457,7 @@ lastValueIO s@ShakeExtras{positionMapping,persistentKeys,state} k file = do | otherwise = do pmap <- readTVarIO persistentKeys mv <- runMaybeT $ do - liftIO $ Logger.logDebug (logger s) $ T.pack $ "LOOKUP PERSISTENT FOR: " ++ show k + liftIO $ logWith (shakeRecorder s) Debug $ LogLookupPersistentKey (T.pack $ show k) f <- MaybeT $ pure $ lookupKeyMap (newKey k) pmap (dv,del,ver) <- MaybeT $ runIdeAction "lastValueIO" s $ f file MaybeT $ pure $ (,del,ver) <$> fromDynamic dv @@ -662,7 +678,7 @@ shakeOpen recorder lspEnv defaultConfig idePlugins logger debouncer dirtyKeys <- newTVarIO mempty -- Take one VFS snapshot at the start vfsVar <- newTVarIO =<< vfsSnapshot lspEnv - pure ShakeExtras{..} + pure ShakeExtras{shakeRecorder = recorder, ..} shakeDb <- shakeNewDatabase opts { shakeExtra = newShakeExtra shakeExtras } @@ -709,7 +725,7 @@ shakeSessionInit recorder ide@IdeState{..} = do vfs <- vfsSnapshot (lspEnv shakeExtras) initSession <- newSession recorder shakeExtras (VFSModified vfs) shakeDb [] "shakeSessionInit" putMVar shakeSession initSession - logDebug (ideLogger ide) "Shake session initialized" + logWith recorder Debug LogSessionInitialised shakeShut :: IdeState -> IO () shakeShut IdeState{..} = do @@ -777,7 +793,7 @@ shakeRestart recorder IdeState{..} vfs reason acts = -- -- Appropriate for user actions other than edits. shakeEnqueue :: ShakeExtras -> DelayedAction a -> IO (IO a) -shakeEnqueue ShakeExtras{actionQueue, logger} act = do +shakeEnqueue ShakeExtras{actionQueue, shakeRecorder} act = do (b, dai) <- instantiateDelayedAction act atomicallyNamed "actionQueue - push" $ pushQueue dai actionQueue let wait' barrier = @@ -786,7 +802,7 @@ shakeEnqueue ShakeExtras{actionQueue, logger} act = do fail $ "internal bug: forever blocked on MVar for " <> actionName act) , Handler (\e@AsyncCancelled -> do - logPriority logger Debug $ T.pack $ actionName act <> " was cancelled" + logWith shakeRecorder Debug $ LogCancelledAction (T.pack $ actionName act) atomicallyNamed "actionQueue - abort" $ abortQueue dai actionQueue throw e) @@ -910,13 +926,12 @@ garbageCollectDirtyKeysOlderThan maxAge checkParents = otTracedGarbageCollection garbageCollectKeys :: String -> Int -> CheckParents -> [(Key, Int)] -> Action [Key] garbageCollectKeys label maxAge checkParents agedKeys = do start <- liftIO offsetTime - ShakeExtras{state, dirtyKeys, lspEnv, logger, ideTesting} <- getShakeExtras + ShakeExtras{state, dirtyKeys, lspEnv, shakeRecorder, ideTesting} <- getShakeExtras (n::Int, garbage) <- liftIO $ foldM (removeDirtyKey dirtyKeys state) (0,[]) agedKeys t <- liftIO start when (n>0) $ liftIO $ do - logDebug logger $ T.pack $ - label <> " of " <> show n <> " keys (took " <> showDuration t <> ")" + logWith shakeRecorder Debug $ LogShakeGarbageCollection (T.pack label) n t when (coerce ideTesting) $ liftIO $ mRunLspT lspEnv $ LSP.sendNotification (SMethod_CustomMethod (Proxy @"ghcide/GC")) (toJSON $ mapMaybe (fmap showKey . fromKeyType) garbage) @@ -1312,13 +1327,11 @@ newtype Priority = Priority Double setPriority :: Priority -> Action () setPriority (Priority p) = reschedule p -ideLogger :: IdeState -> Logger -ideLogger IdeState{shakeExtras=ShakeExtras{logger}} = logger +ideLogger :: IdeState -> Recorder (WithPriority Log) +ideLogger IdeState{shakeExtras=ShakeExtras{shakeRecorder}} = shakeRecorder -actionLogger :: Action Logger -actionLogger = do - ShakeExtras{logger} <- getShakeExtras - return logger +actionLogger :: Action (Recorder (WithPriority Log)) +actionLogger = shakeRecorder <$> getShakeExtras -------------------------------------------------------------------------------- type STMDiagnosticStore = STM.Map NormalizedUri StoreItem diff --git a/ghcide/src/Development/IDE/LSP/HoverDefinition.hs b/ghcide/src/Development/IDE/LSP/HoverDefinition.hs index c561243bf7..ecb63b73a2 100644 --- a/ghcide/src/Development/IDE/LSP/HoverDefinition.hs +++ b/ghcide/src/Development/IDE/LSP/HoverDefinition.hs @@ -4,9 +4,9 @@ -- | Display information on hover. module Development.IDE.LSP.HoverDefinition - ( + ( Log(..) -- * For haskell-language-server - hover + , hover , gotoDefinition , gotoTypeDefinition , documentHighlight @@ -18,8 +18,8 @@ import Control.Monad.Except (ExceptT) import Control.Monad.IO.Class import Data.Maybe (fromMaybe) import Development.IDE.Core.Actions -import Development.IDE.Core.Rules -import Development.IDE.Core.Shake +import qualified Development.IDE.Core.Rules as Shake +import Development.IDE.Core.Shake (IdeState(..), ideLogger, runIdeAction, IdeAction) import Development.IDE.Types.Location import Ide.Logger import Ide.Plugin.Error @@ -30,26 +30,39 @@ import qualified Language.LSP.Server as LSP import qualified Data.Text as T -gotoDefinition :: IdeState -> TextDocumentPositionParams -> ExceptT PluginError (LSP.LspM c) (MessageResult Method_TextDocumentDefinition) -hover :: IdeState -> TextDocumentPositionParams -> ExceptT PluginError (LSP.LspM c) (Hover |? Null) -gotoTypeDefinition :: IdeState -> TextDocumentPositionParams -> ExceptT PluginError (LSP.LspM c) (MessageResult Method_TextDocumentTypeDefinition) -documentHighlight :: IdeState -> TextDocumentPositionParams -> ExceptT PluginError (LSP.LspM c) ([DocumentHighlight] |? Null) + +data Log + = LogWorkspaceSymbolRequest !T.Text + | LogRequest !T.Text !Position !NormalizedFilePath + | LogEnterHover + deriving (Show) + +instance Pretty Log where + pretty = \case + LogWorkspaceSymbolRequest query -> "" + LogRequest label pos nfp -> + pretty label <+> "request at position" <+> pretty (showPosition pos) <+> + "in file:" <+> pretty (fromNormalizedFilePath nfp) + LogEnterHover -> "GhcIde.hover entered (ideLogger)" + +gotoDefinition :: Recorder (WithPriority Log) -> IdeState -> TextDocumentPositionParams -> ExceptT PluginError (LSP.LspM c) (MessageResult Method_TextDocumentDefinition) +hover :: Recorder (WithPriority Log) -> IdeState -> TextDocumentPositionParams -> ExceptT PluginError (LSP.LspM c) (Hover |? Null) +gotoTypeDefinition :: Recorder (WithPriority Log) -> IdeState -> TextDocumentPositionParams -> ExceptT PluginError (LSP.LspM c) (MessageResult Method_TextDocumentTypeDefinition) +documentHighlight :: Recorder (WithPriority Log) -> IdeState -> TextDocumentPositionParams -> ExceptT PluginError (LSP.LspM c) ([DocumentHighlight] |? Null) gotoDefinition = request "Definition" getDefinition (InR $ InR Null) (InL . Definition. InR) gotoTypeDefinition = request "TypeDefinition" getTypeDefinition (InR $ InR Null) (InL . Definition. InR) hover = request "Hover" getAtPoint (InR Null) foundHover documentHighlight = request "DocumentHighlight" highlightAtPoint (InR Null) InL -references :: PluginMethodHandler IdeState Method_TextDocumentReferences -references ide _ (ReferenceParams (TextDocumentIdentifier uri) pos _ _ _) = do +references :: Recorder (WithPriority Log) -> PluginMethodHandler IdeState Method_TextDocumentReferences +references recorder ide _ (ReferenceParams (TextDocumentIdentifier uri) pos _ _ _) = do nfp <- getNormalizedFilePathE uri - liftIO $ logDebug (ideLogger ide) $ - "References request at position " <> T.pack (showPosition pos) <> - " in file: " <> T.pack (show nfp) - InL <$> (liftIO $ runAction "references" ide $ refsAtPoint nfp pos) + liftIO $ logWith recorder Debug $ LogRequest "References" pos nfp + InL <$> (liftIO $ Shake.runAction "references" ide $ refsAtPoint nfp pos) -wsSymbols :: PluginMethodHandler IdeState Method_WorkspaceSymbol -wsSymbols ide _ (WorkspaceSymbolParams _ _ query) = liftIO $ do - logDebug (ideLogger ide) $ "Workspace symbols request: " <> query +wsSymbols :: Recorder (WithPriority Log) -> PluginMethodHandler IdeState Method_WorkspaceSymbol +wsSymbols recorder ide _ (WorkspaceSymbolParams _ _ query) = liftIO $ do + logWith recorder Debug $ LogWorkspaceSymbolRequest query runIdeAction "WorkspaceSymbols" (shakeExtras ide) $ InL . fromMaybe [] <$> workspaceSymbols query foundHover :: (Maybe Range, [T.Text]) -> Hover |? Null @@ -62,19 +75,18 @@ request -> (NormalizedFilePath -> Position -> IdeAction (Maybe a)) -> b -> (a -> b) + -> Recorder (WithPriority Log) -> IdeState -> TextDocumentPositionParams -> ExceptT PluginError (LSP.LspM c) b -request label getResults notFound found ide (TextDocumentPositionParams (TextDocumentIdentifier uri) pos) = liftIO $ do +request label getResults notFound found recorder ide (TextDocumentPositionParams (TextDocumentIdentifier uri) pos) = liftIO $ do mbResult <- case uriToFilePath' uri of - Just path -> logAndRunRequest label getResults ide pos path + Just path -> logAndRunRequest recorder label getResults ide pos path Nothing -> pure Nothing pure $ maybe notFound found mbResult -logAndRunRequest :: T.Text -> (NormalizedFilePath -> Position -> IdeAction b) -> IdeState -> Position -> String -> IO b -logAndRunRequest label getResults ide pos path = do +logAndRunRequest :: Recorder (WithPriority Log) -> T.Text -> (NormalizedFilePath -> Position -> IdeAction b) -> IdeState -> Position -> String -> IO b +logAndRunRequest recorder label getResults ide pos path = do let filePath = toNormalizedFilePath' path - logDebug (ideLogger ide) $ - label <> " request at position " <> T.pack (showPosition pos) <> - " in file: " <> T.pack path + logWith recorder Debug $ LogRequest label pos filePath runIdeAction (T.unpack label) (shakeExtras ide) (getResults filePath pos) diff --git a/ghcide/src/Development/IDE/LSP/LanguageServer.hs b/ghcide/src/Development/IDE/LSP/LanguageServer.hs index 5663165f02..8ae52fae94 100644 --- a/ghcide/src/Development/IDE/LSP/LanguageServer.hs +++ b/ghcide/src/Development/IDE/LSP/LanguageServer.hs @@ -51,6 +51,7 @@ data Log | LogCancelledRequest !SomeLspId | LogSession Session.Log | LogLspServer LspServerLog + | LogServerShutdownMessage deriving Show instance Pretty Log where @@ -74,6 +75,7 @@ instance Pretty Log where "Cancelled request" <+> viaShow requestId LogSession msg -> pretty msg LogLspServer msg -> pretty msg + LogServerShutdownMessage -> "Received shutdown message" -- used to smuggle RankNType WithHieDb through dbMVar newtype WithHieDbShield = WithHieDbShield WithHieDb @@ -170,7 +172,7 @@ setupLSP recorder getHieDbLoc userHandlers getIdeState clientMsgVar = do [ userHandlers , cancelHandler cancelRequest , exitHandler exit - , shutdownHandler stopReactorLoop + , shutdownHandler recorder stopReactorLoop ] -- Cancel requests are special since they need to be handled -- out of order to be useful. Existing handlers are run afterwards. @@ -261,10 +263,10 @@ cancelHandler cancelRequest = LSP.notificationHandler SMethod_CancelRequest $ \T toLspId (InL x) = IdInt x toLspId (InR y) = IdString y -shutdownHandler :: IO () -> LSP.Handlers (ServerM c) -shutdownHandler stopReactor = LSP.requestHandler SMethod_Shutdown $ \_ resp -> do +shutdownHandler :: Recorder (WithPriority Log) -> IO () -> LSP.Handlers (ServerM c) +shutdownHandler recorder stopReactor = LSP.requestHandler SMethod_Shutdown $ \_ resp -> do (_, ide) <- ask - liftIO $ logDebug (ideLogger ide) "Received shutdown message" + liftIO $ logWith recorder Debug LogServerShutdownMessage -- stop the reactor to free up the hiedb connection liftIO stopReactor -- flush out the Shake session to record a Shake profile if applicable diff --git a/ghcide/src/Development/IDE/LSP/Notifications.hs b/ghcide/src/Development/IDE/LSP/Notifications.hs index 91a518800c..74e63c78e5 100644 --- a/ghcide/src/Development/IDE/LSP/Notifications.hs +++ b/ghcide/src/Development/IDE/LSP/Notifications.hs @@ -41,12 +41,25 @@ import Numeric.Natural data Log = LogShake Shake.Log | LogFileStore FileStore.Log + | LogOpenTextDocument !Uri + | LogOpenedTextDocument !Uri + | LogModifiedTextDocument !Uri + | LogSavedTextDocument !Uri + | LogClosedTextDocument !Uri + | LogWatchedFileEvents !Text.Text + | LogWarnNoWatchedFilesSupport deriving Show instance Pretty Log where pretty = \case LogShake msg -> pretty msg LogFileStore msg -> pretty msg + LogOpenedTextDocument uri -> "Opened text document:" <+> pretty (getUri uri) + LogModifiedTextDocument uri -> "Modified text document:" <+> pretty (getUri uri) + LogSavedTextDocument uri -> "Saved text document:" <+> pretty (getUri uri) + LogClosedTextDocument uri -> "Closed text document:" <+> pretty (getUri uri) + LogWatchedFileEvents msg -> "Watched file events:" <+> pretty msg + LogWarnNoWatchedFilesSupport -> "Warning: Client does not support watched files. Falling back to OS polling" whenUriFile :: Uri -> (NormalizedFilePath -> IO ()) -> IO () whenUriFile uri act = whenJust (LSP.uriToFilePath uri) $ act . toNormalizedFilePath' @@ -61,7 +74,7 @@ descriptor recorder plId = (defaultPluginDescriptor plId desc) { pluginNotificat -- For example, vscode restores previously unsaved contents on open addFileOfInterest ide file Modified{firstOpen=True} setFileModified (cmapWithPrio LogFileStore recorder) (VFSModified vfs) ide False file - logDebug (ideLogger ide) $ "Opened text document: " <> getUri _uri + logWith recorder Debug $ LogOpenedTextDocument _uri , mkPluginNotificationHandler LSP.SMethod_TextDocumentDidChange $ \ide vfs _ (DidChangeTextDocumentParams identifier@VersionedTextDocumentIdentifier{_uri} changes) -> liftIO $ do @@ -69,14 +82,14 @@ descriptor recorder plId = (defaultPluginDescriptor plId desc) { pluginNotificat whenUriFile _uri $ \file -> do addFileOfInterest ide file Modified{firstOpen=False} setFileModified (cmapWithPrio LogFileStore recorder) (VFSModified vfs) ide False file - logDebug (ideLogger ide) $ "Modified text document: " <> getUri _uri + logWith recorder Debug $ LogModifiedTextDocument _uri , mkPluginNotificationHandler LSP.SMethod_TextDocumentDidSave $ \ide vfs _ (DidSaveTextDocumentParams TextDocumentIdentifier{_uri} _) -> liftIO $ do whenUriFile _uri $ \file -> do addFileOfInterest ide file OnDisk setFileModified (cmapWithPrio LogFileStore recorder) (VFSModified vfs) ide True file - logDebug (ideLogger ide) $ "Saved text document: " <> getUri _uri + logWith recorder Debug $ LogSavedTextDocument _uri , mkPluginNotificationHandler LSP.SMethod_TextDocumentDidClose $ \ide vfs _ (DidCloseTextDocumentParams TextDocumentIdentifier{_uri}) -> liftIO $ do @@ -85,7 +98,7 @@ descriptor recorder plId = (defaultPluginDescriptor plId desc) { pluginNotificat let msg = "Closed text document: " <> getUri _uri scheduleGarbageCollection ide setSomethingModified (VFSModified vfs) ide [] $ Text.unpack msg - logDebug (ideLogger ide) msg + logWith recorder Debug $ LogClosedTextDocument _uri , mkPluginNotificationHandler LSP.SMethod_WorkspaceDidChangeWatchedFiles $ \ide vfs _ (DidChangeWatchedFilesParams fileEvents) -> liftIO $ do @@ -102,7 +115,7 @@ descriptor recorder plId = (defaultPluginDescriptor plId desc) { pluginNotificat ] unless (null fileEvents') $ do let msg = show fileEvents' - logDebug (ideLogger ide) $ "Watched file events: " <> Text.pack msg + logWith recorder Debug $ LogWatchedFileEvents (Text.pack msg) modifyFileExists ide fileEvents' resetFileStore ide fileEvents' setSomethingModified (VFSModified vfs) ide [] msg @@ -133,7 +146,7 @@ descriptor recorder plId = (defaultPluginDescriptor plId desc) { pluginNotificat let globs = watchedGlobs opts success <- registerFileWatches globs unless success $ - liftIO $ logDebug (ideLogger ide) "Warning: Client does not support watched files. Falling back to OS polling" + liftIO $ logWith recorder Debug LogWarnNoWatchedFilesSupport ], -- The ghcide descriptors should come last'ish so that the notification handlers diff --git a/ghcide/src/Development/IDE/Main.hs b/ghcide/src/Development/IDE/Main.hs index 2359b4a18a..2a597194b5 100644 --- a/ghcide/src/Development/IDE/Main.hs +++ b/ghcide/src/Development/IDE/Main.hs @@ -140,6 +140,7 @@ data Log | LogLspStartDuration !Seconds | LogShouldRunSubset !Bool | LogSetInitialDynFlagsException !SomeException + | LogConfigurationChange T.Text | LogService Service.Log | LogShake Shake.Log | LogGhcIde GhcIde.Log @@ -147,6 +148,7 @@ data Log | LogSession Session.Log | LogPluginHLS PluginHLS.Log | LogRules Rules.Log + | LogEkg EKG.Log deriving Show instance Pretty Log where @@ -164,6 +166,7 @@ instance Pretty Log where "shouldRunSubset:" <+> pretty shouldRunSubset LogSetInitialDynFlagsException e -> "setInitialDynFlags:" <+> pretty (displayException e) + LogConfigurationChange msg -> "Configuration changed:" <+> pretty msg LogService msg -> pretty msg LogShake msg -> pretty msg LogGhcIde msg -> pretty msg @@ -171,6 +174,7 @@ instance Pretty Log where LogSession msg -> pretty msg LogPluginHLS msg -> pretty msg LogRules msg -> pretty msg + LogEkg msg -> pretty msg data Command = Check [FilePath] -- ^ Typecheck some paths and print diagnostics. Exit code is the number of failures @@ -259,7 +263,7 @@ defaultArguments recorder logger plugins = Arguments -- the language server tests without the redirection. putStr " " >> hFlush stdout return newStdout - , argsMonitoring = OpenTelemetry.monitoring <> EKG.monitoring logger 8999 + , argsMonitoring = OpenTelemetry.monitoring <> EKG.monitoring (cmapWithPrio LogEkg recorder) 8999 } @@ -366,7 +370,7 @@ defaultMain recorder Arguments{..} = withHeapStats (cmapWithPrio LogHeapStats re Nothing -> pure () Just ide -> liftIO $ do let msg = T.pack $ show cfg - logDebug (Shake.ideLogger ide) $ "Configuration changed: " <> msg + logWith recorder Debug $ LogConfigurationChange msg modifyClientSettings ide (const $ Just cfgObj) setSomethingModified Shake.VFSUnmodified ide [toKey Rules.GetClientSettings emptyFilePath] "config change" diff --git a/ghcide/src/Development/IDE/Monitoring/EKG.hs b/ghcide/src/Development/IDE/Monitoring/EKG.hs index 26414fdf04..b9c8c58bfd 100644 --- a/ghcide/src/Development/IDE/Monitoring/EKG.hs +++ b/ghcide/src/Development/IDE/Monitoring/EKG.hs @@ -1,21 +1,35 @@ {-# LANGUAGE CPP #-} -module Development.IDE.Monitoring.EKG(monitoring) where +module Development.IDE.Monitoring.EKG(Log, monitoring) where import Development.IDE.Types.Monitoring (Monitoring (..)) -import Ide.Logger (Logger) +import Ide.Logger #ifdef MONITORING_EKG import Control.Concurrent (killThread) import Control.Concurrent.Async (async, waitCatch) import Control.Monad (forM_) import Data.Text (pack) -import Ide.Logger (logInfo) +import Ide.Logger (Pretty(..), logWith) import qualified System.Metrics as Monitoring import qualified System.Remote.Monitoring.Wai as Monitoring +#endif + +data Log + = LogServerStartup Int + | LogServerStop + | LogServerBindError Int String + deriving Show +instance Pretty Log where + pretty = \case + LogServerStartup port -> "Started monitoring server on port" <+> viaShow port + LogServerStop -> "Stopping monitoring server" + LogServerBindError port e -> "Unable to bind monitoring server on port" <+> viaShow port <> ":" <+> pretty e + +#ifdef MONITORING_EKG -- | Monitoring using EKG -monitoring :: Logger -> Int -> IO Monitoring -monitoring logger port = do +monitoring :: Recorder (WithPriority Log) -> Int -> IO Monitoring +monitoring recorder port = do store <- Monitoring.newStore Monitoring.registerGcMetrics store let registerCounter name read = Monitoring.registerCounter name read store @@ -28,22 +42,19 @@ monitoring logger port = do mb_server <- async startServer >>= waitCatch case mb_server of Right s -> do - logInfo logger $ pack $ - "Started monitoring server on port " <> show port + logWith recorder Info $ LogServerStartup port return $ Just s Left e -> do - logInfo logger $ pack $ - "Unable to bind monitoring server on port " - <> show port <> ":" <> show e + logWith recorder Info $ LogServerBindError port (show e) return Nothing return $ forM_ server $ \s -> do - logInfo logger "Stopping monitoring server" + logWith recorder Info LogServerStop killThread $ Monitoring.serverThreadId s return $ Monitoring {..} #else -monitoring :: Logger -> Int -> IO Monitoring +monitoring :: Recorder (WithPriority Log) -> Int -> IO Monitoring monitoring _ _ = mempty #endif diff --git a/ghcide/src/Development/IDE/Plugin/HLS/GhcIde.hs b/ghcide/src/Development/IDE/Plugin/HLS/GhcIde.hs index b3c7457275..93fd71a24d 100644 --- a/ghcide/src/Development/IDE/Plugin/HLS/GhcIde.hs +++ b/ghcide/src/Development/IDE/Plugin/HLS/GhcIde.hs @@ -9,7 +9,7 @@ module Development.IDE.Plugin.HLS.GhcIde ) where import Control.Monad.IO.Class import Development.IDE -import Development.IDE.LSP.HoverDefinition +import qualified Development.IDE.LSP.HoverDefinition as Hover import qualified Development.IDE.LSP.Notifications as Notifications import Development.IDE.LSP.Outline import qualified Development.IDE.Plugin.Completions as Completions @@ -23,6 +23,7 @@ data Log = LogNotifications Notifications.Log | LogCompletions Completions.Log | LogTypeLenses TypeLenses.Log + | LogHover Hover.Log deriving Show instance Pretty Log where @@ -33,7 +34,7 @@ instance Pretty Log where descriptors :: Recorder (WithPriority Log) -> [PluginDescriptor IdeState] descriptors recorder = - [ descriptor "ghcide-hover-and-symbols", + [ descriptor (cmapWithPrio LogHover recorder) "ghcide-hover-and-symbols", Completions.descriptor (cmapWithPrio LogCompletions recorder) "ghcide-completions", TypeLenses.descriptor (cmapWithPrio LogTypeLenses recorder) "ghcide-type-lenses", Notifications.descriptor (cmapWithPrio LogNotifications recorder) "ghcide-core" @@ -41,18 +42,18 @@ descriptors recorder = -- --------------------------------------------------------------------- -descriptor :: PluginId -> PluginDescriptor IdeState -descriptor plId = (defaultPluginDescriptor plId desc) - { pluginHandlers = mkPluginHandler SMethod_TextDocumentHover hover' +descriptor :: Recorder (WithPriority Hover.Log) -> PluginId -> PluginDescriptor IdeState +descriptor recorder plId = (defaultPluginDescriptor plId desc) + { pluginHandlers = mkPluginHandler SMethod_TextDocumentHover (hover' recorder) <> mkPluginHandler SMethod_TextDocumentDocumentSymbol moduleOutline <> mkPluginHandler SMethod_TextDocumentDefinition (\ide _ DefinitionParams{..} -> - gotoDefinition ide TextDocumentPositionParams{..}) + Hover.gotoDefinition recorder ide TextDocumentPositionParams{..}) <> mkPluginHandler SMethod_TextDocumentTypeDefinition (\ide _ TypeDefinitionParams{..} -> - gotoTypeDefinition ide TextDocumentPositionParams{..}) + Hover.gotoTypeDefinition recorder ide TextDocumentPositionParams{..}) <> mkPluginHandler SMethod_TextDocumentDocumentHighlight (\ide _ DocumentHighlightParams{..} -> - documentHighlight ide TextDocumentPositionParams{..}) - <> mkPluginHandler SMethod_TextDocumentReferences references - <> mkPluginHandler SMethod_WorkspaceSymbol wsSymbols, + Hover.documentHighlight recorder ide TextDocumentPositionParams{..}) + <> mkPluginHandler SMethod_TextDocumentReferences (Hover.references recorder) + <> mkPluginHandler SMethod_WorkspaceSymbol (Hover.wsSymbols recorder), pluginConfigDescriptor = defaultConfigDescriptor } @@ -61,7 +62,7 @@ descriptor plId = (defaultPluginDescriptor plId desc) -- --------------------------------------------------------------------- -hover' :: PluginMethodHandler IdeState Method_TextDocumentHover -hover' ideState _ HoverParams{..} = do - liftIO $ logDebug (ideLogger ideState) "GhcIde.hover entered (ideLogger)" -- AZ - hover ideState TextDocumentPositionParams{..} +hover' :: Recorder (WithPriority Hover.Log) -> PluginMethodHandler IdeState Method_TextDocumentHover +hover' recorder ideState _ HoverParams{..} = do + liftIO $ logWith recorder Debug Hover.LogEnterHover + Hover.hover recorder ideState TextDocumentPositionParams{..} diff --git a/plugins/hls-eval-plugin/src/Ide/Plugin/Eval.hs b/plugins/hls-eval-plugin/src/Ide/Plugin/Eval.hs index 7a02214589..eaf97e4a58 100644 --- a/plugins/hls-eval-plugin/src/Ide/Plugin/Eval.hs +++ b/plugins/hls-eval-plugin/src/Ide/Plugin/Eval.hs @@ -8,16 +8,15 @@ Eval Plugin entry point. -} module Ide.Plugin.Eval ( descriptor, - Log(..) + Eval.Log(..) ) where import Development.IDE (IdeState) -import Ide.Logger (Pretty (pretty), Recorder, - WithPriority, cmapWithPrio) +import Ide.Logger (Recorder, WithPriority) import qualified Ide.Plugin.Eval.CodeLens as CL import Ide.Plugin.Eval.Config import Ide.Plugin.Eval.Rules (rules) -import qualified Ide.Plugin.Eval.Rules as EvalRules +import qualified Ide.Plugin.Eval.Types as Eval import Ide.Types (ConfigDescriptor (..), PluginDescriptor (..), PluginId, defaultConfigDescriptor, @@ -25,19 +24,13 @@ import Ide.Types (ConfigDescriptor (..), mkCustomConfig, mkPluginHandler) import Language.LSP.Protocol.Message -newtype Log = LogEvalRules EvalRules.Log deriving Show - -instance Pretty Log where - pretty = \case - LogEvalRules log -> pretty log - -- |Plugin descriptor -descriptor :: Recorder (WithPriority Log) -> PluginId -> PluginDescriptor IdeState +descriptor :: Recorder (WithPriority Eval.Log) -> PluginId -> PluginDescriptor IdeState descriptor recorder plId = (defaultPluginDescriptor plId "Provies a code lens to evaluate expressions in doctest comments") - { pluginHandlers = mkPluginHandler SMethod_TextDocumentCodeLens CL.codeLens - , pluginCommands = [CL.evalCommand plId] - , pluginRules = rules (cmapWithPrio LogEvalRules recorder) + { pluginHandlers = mkPluginHandler SMethod_TextDocumentCodeLens (CL.codeLens recorder) + , pluginCommands = [CL.evalCommand recorder plId] + , pluginRules = rules recorder , pluginConfigDescriptor = defaultConfigDescriptor { configCustomConfig = mkCustomConfig properties } diff --git a/plugins/hls-eval-plugin/src/Ide/Plugin/Eval/CodeLens.hs b/plugins/hls-eval-plugin/src/Ide/Plugin/Eval/CodeLens.hs index ecadce4d03..7ef4a19563 100644 --- a/plugins/hls-eval-plugin/src/Ide/Plugin/Eval/CodeLens.hs +++ b/plugins/hls-eval-plugin/src/Ide/Plugin/Eval/CodeLens.hs @@ -119,29 +119,29 @@ import Ide.Plugin.Eval.Rules (queueForEvaluatio import Ide.Plugin.Eval.Types import Ide.Plugin.Eval.Util (gStrictTry, isLiterate, - logWith, - response', timed) + response', timed, prettyWarnings) import Ide.Types import qualified Language.LSP.Protocol.Lens as L import Language.LSP.Protocol.Message import Language.LSP.Protocol.Types import Language.LSP.Server import Language.LSP.VFS (virtualFileText) +import Ide.Logger (Recorder, WithPriority, Priority(..), logWith) {- | Code Lens provider NOTE: Invoked every time the document is modified, not just when the document is saved. -} -codeLens :: PluginMethodHandler IdeState Method_TextDocumentCodeLens -codeLens st plId CodeLensParams{_textDocument} = - let dbg = logWith st - perf = timed dbg +codeLens :: Recorder (WithPriority Log) -> PluginMethodHandler IdeState Method_TextDocumentCodeLens +codeLens recorder st plId CodeLensParams{_textDocument} = + let dbg = logWith recorder Debug + perf = timed (\lbl duration -> dbg $ LogExecutionTime lbl duration) in perf "codeLens" $ do let TextDocumentIdentifier uri = _textDocument fp <- uriToFilePathE uri let nfp = toNormalizedFilePath' fp isLHS = isLiterate fp - dbg "fp" fp + dbg $ LogCodeLensFp fp (comments, _) <- runActionE "eval.GetParsedModuleWithComments" st $ useWithStaleE GetEvalComments nfp -- dbg "excluded comments" $ show $ DL.toList $ @@ -152,7 +152,7 @@ codeLens st plId CodeLensParams{_textDocument} = -- _ -> DL.singleton (a, b) -- ) -- $ apiAnnComments' pm_annotations - dbg "comments" $ show comments + dbg $ LogCodeLensComments comments -- Extract tests from source code let Sections{..} = commentsToSections isLHS comments @@ -174,17 +174,11 @@ codeLens st plId CodeLensParams{_textDocument} = ] perf "tests" $ - dbg "Tests" $ - unwords - [ show (length tests) - , "tests in" - , show (length nonSetupSections) - , "sections" - , show (length setupSections) - , "setups" - , show (length lenses) - , "lenses." - ] + dbg $ LogTests + (length tests) + (length nonSetupSections) + (length setupSections) + (length lenses) return $ InL lenses where @@ -193,15 +187,15 @@ codeLens st plId CodeLensParams{_textDocument} = evalCommandName :: CommandId evalCommandName = "evalCommand" -evalCommand :: PluginId -> PluginCommand IdeState -evalCommand plId = PluginCommand evalCommandName "evaluate" (runEvalCmd plId) +evalCommand :: Recorder (WithPriority Log) -> PluginId -> PluginCommand IdeState +evalCommand recorder plId = PluginCommand evalCommandName "evaluate" (runEvalCmd recorder plId) type EvalId = Int -runEvalCmd :: PluginId -> CommandFunction IdeState EvalParams -runEvalCmd plId st mtoken EvalParams{..} = - let dbg = logWith st - perf = timed dbg +runEvalCmd :: Recorder (WithPriority Log) -> PluginId -> CommandFunction IdeState EvalParams +runEvalCmd recorder plId st mtoken EvalParams{..} = + let dbg = logWith recorder Debug + perf = timed (\lbl duration -> dbg $ LogExecutionTime lbl duration) cmd :: ExceptT PluginError (LspM Config) WorkspaceEdit cmd = do let tests = map (\(a,_,b) -> (a,b)) $ testsBySection sections @@ -226,7 +220,7 @@ runEvalCmd plId st mtoken EvalParams{..} = perf "edits" $ liftIO $ evalGhcEnv final_hscEnv $ do - runTests evalCfg (st, fp) tests + runTests recorder evalCfg fp tests let workspaceEditsMap = Map.singleton _uri (addFinalReturn mdlText edits) let workspaceEdits = WorkspaceEdit (Just workspaceEditsMap) Nothing Nothing @@ -313,7 +307,7 @@ testsBySection sections = , test <- sectionTests section ] -type TEnv = (IdeState, String) +type TEnv = String -- |GHC declarations required for expression evaluation evalSetup :: Ghc () evalSetup = do @@ -321,26 +315,26 @@ evalSetup = do context <- getContext setContext (IIDecl preludeAsP : context) -runTests :: EvalConfig -> TEnv -> [(Section, Test)] -> Ghc [TextEdit] -runTests EvalConfig{..} e@(_st, _) tests = do +runTests :: Recorder (WithPriority Log) -> EvalConfig -> TEnv -> [(Section, Test)] -> Ghc [TextEdit] +runTests recorder EvalConfig{..} e tests = do df <- getInteractiveDynFlags evalSetup - when (hasQuickCheck df && needsQuickCheck tests) $ void $ evals True e df propSetup + when (hasQuickCheck df && needsQuickCheck tests) $ void $ evals recorder True e df propSetup mapM (processTest e df) tests where processTest :: TEnv -> DynFlags -> (Section, Test) -> Ghc TextEdit - processTest e@(st, fp) df (section, test) = do - let dbg = logWith st + processTest fp df (section, test) = do + let dbg = logWith recorder Debug let pad = pad_ $ (if isLiterate fp then ("> " `T.append`) else id) $ padPrefix (sectionFormat section) rs <- runTest e df test - dbg "TEST RESULTS" rs + dbg $ LogRunTestResults rs let checkedResult = testCheck eval_cfg_diff (section, test) rs let resultLines = concatMap T.lines checkedResult let edit = asEdit (sectionFormat section) test (map pad resultLines) - dbg "TEST EDIT" edit + dbg $ LogRunTestEdits edit return edit -- runTest :: String -> DynFlags -> Loc Test -> Ghc [Text] @@ -349,7 +343,7 @@ runTests EvalConfig{..} e@(_st, _) tests = do return $ singleLine "Add QuickCheck to your cabal dependencies to run this test." - runTest e df test = evals (eval_cfg_exception && not (isProperty test)) e df (asStatements test) + runTest e df test = evals recorder (eval_cfg_exception && not (isProperty test)) e df (asStatements test) asEdit :: Format -> Test -> [Text] -> TextEdit asEdit (MultiLine commRange) test resultLines @@ -425,27 +419,26 @@ Or for a value that does not have a Show instance and can therefore not be displ >>> V No instance for (Show V) arising from a use of ‘evalPrint’ -} -evals :: Bool -> TEnv -> DynFlags -> [Statement] -> Ghc [Text] -evals mark_exception (st, fp) df stmts = do +evals :: Recorder (WithPriority Log) -> Bool -> TEnv -> DynFlags -> [Statement] -> Ghc [Text] +evals recorder mark_exception fp df stmts = do er <- gStrictTry $ mapM eval stmts return $ case er of Left err -> errorLines err Right rs -> concat . catMaybes $ rs where - dbg = logWith st + dbg = logWith recorder Debug eval :: Statement -> Ghc (Maybe [Text]) eval (Located l stmt) | -- GHCi flags Just (words -> flags) <- parseSetFlags stmt = do - dbg "{:SET" flags + dbg $ LogEvalFlags flags ndf <- getInteractiveDynFlags - dbg "pre set" $ showDynFlags ndf + dbg $ LogEvalPreSetDynFlags ndf eans <- liftIO $ try @GhcException $ parseDynamicFlagsCmdLine ndf (map (L $ UnhelpfulSpan unhelpfulReason) flags) - dbg "parsed flags" $ eans - <&> (_1 %~ showDynFlags >>> _3 %~ prettyWarnings) + dbg $ LogEvalParsedFlags eans case eans of Left err -> pure $ Just $ errorLines $ show err Right (df', ignoreds, warns) -> do @@ -459,7 +452,7 @@ evals mark_exception (st, fp) df stmts = do ["Some flags have not been recognized: " <> T.pack (intercalate ", " $ map SrcLoc.unLoc ignoreds) ] - dbg "post set" $ showDynFlags df' + dbg $ LogEvalPostSetDynFlags df' setSessionAndInteractiveDynFlags df' pure $ warnings <> igns | -- A type/kind command @@ -468,23 +461,23 @@ evals mark_exception (st, fp) df stmts = do | -- A statement isStmt pf stmt = do - dbg "{STMT " stmt + dbg $ LogEvalStmtStart stmt res <- exec stmt l let r = case res of Left err -> Just . (if mark_exception then exceptionLines else errorLines) $ err Right x -> singleLine <$> x - dbg "STMT} -> " r + dbg $ LogEvalStmtResult r return r | -- An import isImport pf stmt = do - dbg "{IMPORT " stmt + dbg $ LogEvalImport stmt _ <- addImport stmt return Nothing | -- A declaration otherwise = do - dbg "{DECL " stmt + dbg $ LogEvalDeclaration stmt void $ runDecls stmt return Nothing pf = initParserOpts df @@ -493,19 +486,6 @@ evals mark_exception (st, fp) df stmts = do let opts = execOptions{execSourceFile = fp, execLineNumber = l} in myExecStmt stmt opts -#if MIN_VERSION_ghc(9,8,0) -prettyWarnings :: Messages DriverMessage -> String -prettyWarnings = printWithoutUniques . pprMessages (defaultDiagnosticOpts @DriverMessage) -#else -prettyWarnings :: [Warn] -> String -prettyWarnings = unlines . map prettyWarn - -prettyWarn :: Warn -> String -prettyWarn Warn{..} = - T.unpack (printOutputable $ SrcLoc.getLoc warnMsg) <> ": warning:\n" - <> " " <> SrcLoc.unLoc warnMsg -#endif - needsQuickCheck :: [(Section, Test)] -> Bool needsQuickCheck = any (isProperty . snd) diff --git a/plugins/hls-eval-plugin/src/Ide/Plugin/Eval/Rules.hs b/plugins/hls-eval-plugin/src/Ide/Plugin/Eval/Rules.hs index fbc69b30e0..8c9725a90f 100644 --- a/plugins/hls-eval-plugin/src/Ide/Plugin/Eval/Rules.hs +++ b/plugins/hls-eval-plugin/src/Ide/Plugin/Eval/Rules.hs @@ -33,22 +33,15 @@ import Development.IDE.Core.Shake (IsIdeGlobal, addIdeGlobal, getIdeGlobalAction, getIdeGlobalState) -import qualified Development.IDE.Core.Shake as Shake import Development.IDE.GHC.Compat import qualified Development.IDE.GHC.Compat as SrcLoc import qualified Development.IDE.GHC.Compat.Util as FastString import Development.IDE.Graph (alwaysRerun) import GHC.Parser.Annotation -import Ide.Logger (Pretty (pretty), - Recorder, WithPriority, +import Ide.Logger (Recorder, WithPriority, cmapWithPrio) import Ide.Plugin.Eval.Types -newtype Log = LogShake Shake.Log deriving Show - -instance Pretty Log where - pretty = \case - LogShake shakeLog -> pretty shakeLog rules :: Recorder (WithPriority Log) -> Rules () rules recorder = do diff --git a/plugins/hls-eval-plugin/src/Ide/Plugin/Eval/Types.hs b/plugins/hls-eval-plugin/src/Ide/Plugin/Eval/Types.hs index 23fe6fe732..e78285bc77 100644 --- a/plugins/hls-eval-plugin/src/Ide/Plugin/Eval/Types.hs +++ b/plugins/hls-eval-plugin/src/Ide/Plugin/Eval/Types.hs @@ -2,11 +2,14 @@ {-# LANGUAGE DerivingStrategies #-} {-# LANGUAGE RecordWildCards #-} {-# LANGUAGE TypeFamilies #-} +{-# LANGUAGE OverloadedStrings #-} {-# LANGUAGE UndecidableInstances #-} {-# OPTIONS_GHC -Wwarn #-} +{-# LANGUAGE LambdaCase #-} module Ide.Plugin.Eval.Types - ( locate, + ( Log(..), + locate, locate0, Test (..), isProperty, @@ -39,8 +42,65 @@ import Data.String (IsString (..)) import Development.IDE (Range, RuleResult) import Development.IDE.Graph.Classes import GHC.Generics (Generic) -import Language.LSP.Protocol.Types (TextDocumentIdentifier) +import Language.LSP.Protocol.Types (TextDocumentIdentifier, TextEdit) import qualified Text.Megaparsec as P +import qualified Data.Text as T +import qualified System.Time.Extra as Extra +import Ide.Logger +import qualified Development.IDE.GHC.Compat.Core as Core +import Ide.Plugin.Eval.GHC (showDynFlags) +import Control.Lens +import Control.Arrow ((>>>)) +import Ide.Plugin.Eval.Util +import qualified Development.IDE.Core.Shake as Shake + +data Log + = LogShake Shake.Log + | LogCodeLensFp FilePath + | LogCodeLensComments Comments + | LogExecutionTime T.Text Extra.Seconds + | LogTests !Int !Int !Int !Int + | LogRunTestResults [T.Text] + | LogRunTestEdits TextEdit + | LogEvalFlags [String] + | LogEvalPreSetDynFlags Core.DynFlags + | LogEvalParsedFlags + (Either + Core.GhcException + (Core.DynFlags, [Core.Located String], [Core.Warn])) + | LogEvalPostSetDynFlags Core.DynFlags + | LogEvalStmtStart String + | LogEvalStmtResult (Maybe [T.Text]) + | LogEvalImport String + | LogEvalDeclaration String + +instance Pretty Log where + pretty = \case + LogShake shakeLog -> pretty shakeLog + LogCodeLensFp fp -> "fp" <+> pretty fp + LogCodeLensComments comments -> "comments" <+> viaShow comments + LogExecutionTime lbl duration -> pretty lbl <> ":" <+> pretty (Extra.showDuration duration) + LogTests nTests nNonSetupSections nSetupSections nLenses -> "Tests" <+> fillSep + [ pretty nTests + , "tests in" + , pretty nNonSetupSections + , "sections" + , pretty nSetupSections + , "setups" + , pretty nLenses + , "lenses." + ] + LogRunTestResults results -> "TEST RESULTS" <+> viaShow results + LogRunTestEdits edits -> "TEST EDIT" <+> viaShow edits + LogEvalFlags flags -> "{:SET" <+> pretty flags + LogEvalPreSetDynFlags dynFlags -> "pre set" <+> pretty (showDynFlags dynFlags) + LogEvalParsedFlags eans -> "parsed flags" <+> viaShow (eans + <&> (_1 %~ showDynFlags >>> _3 %~ prettyWarnings)) + LogEvalPostSetDynFlags dynFlags -> "post set" <+> pretty (showDynFlags dynFlags) + LogEvalStmtStart stmt -> "{STMT" <+> pretty stmt + LogEvalStmtResult result -> "STMT}" <+> pretty result + LogEvalImport stmt -> "{IMPORT" <+> pretty stmt + LogEvalDeclaration stmt -> "{DECL" <+> pretty stmt -- | A thing with a location attached. data Located l a = Located {location :: l, located :: a} @@ -49,7 +109,7 @@ data Located l a = Located {location :: l, located :: a} -- | Discard location information. unLoc :: Located l a -> a unLoc (Located _ a) = a - + instance (NFData l, NFData a) => NFData (Located l a) where rnf (Located loc a) = loc `deepseq` a `deepseq` () diff --git a/plugins/hls-eval-plugin/src/Ide/Plugin/Eval/Util.hs b/plugins/hls-eval-plugin/src/Ide/Plugin/Eval/Util.hs index 0979e13e81..2205dc475e 100644 --- a/plugins/hls-eval-plugin/src/Ide/Plugin/Eval/Util.hs +++ b/plugins/hls-eval-plugin/src/Ide/Plugin/Eval/Util.hs @@ -1,6 +1,7 @@ {-# LANGUAGE CPP #-} {-# LANGUAGE NoMonomorphismRestriction #-} {-# OPTIONS_GHC -Wno-orphans -Wno-unused-imports #-} +{-# LANGUAGE RecordWildCards #-} -- |Debug utilities module Ide.Plugin.Eval.Util ( @@ -8,7 +9,7 @@ module Ide.Plugin.Eval.Util ( isLiterate, response', gStrictTry, - logWith, + prettyWarnings, ) where import Control.Exception (SomeException, evaluate, @@ -22,8 +23,7 @@ import Data.Aeson (Value) import Data.Bifunctor (second) import Data.String (IsString (fromString)) import qualified Data.Text as T -import Development.IDE (IdeState, Priority (..), - ideLogger, logPriority) +import Development.IDE (IdeState, printOutputable) import qualified Development.IDE.Core.PluginUtils as PluginUtils import Development.IDE.GHC.Compat.Outputable import Development.IDE.GHC.Compat.Util (MonadCatch, bagToList, @@ -40,33 +40,33 @@ import Language.LSP.Server import System.FilePath (takeExtension) import System.Time.Extra (duration, showDuration) import UnliftIO.Exception (catchAny) +import Development.IDE.GHC.Compat.Core (Warn(..)) +import qualified Development.IDE.GHC.Compat.Core as SrcLoc (HasSrcSpan (getLoc), + unLoc) +import qualified System.Time.Extra as Extra -timed :: MonadIO m => (t -> String -> m a) -> t -> m b -> m b +timed :: MonadIO m => (t -> Extra.Seconds -> m a) -> t -> m b -> m b timed out name op = do (secs, r) <- duration op - _ <- out name (showDuration secs) + _ <- out name secs return r -- | Log using hie logger, reports source position of logging statement -logWith :: (HasCallStack, MonadIO m, Show a1, Show a2) => IdeState -> a1 -> a2 -> m () -logWith state key val = - liftIO . logPriority (ideLogger state) logLevel $ - T.unwords - [T.pack logWithPos, asT key, asT val] - where - logWithPos = - let stk = toList callStack - pr pos = concat [srcLocFile pos, ":", show . srcLocStartLine $ pos, ":", show . srcLocStartCol $ pos] - in case stk of - [] -> "" - (x:_) -> pr $ snd x +-- logWith :: (HasCallStack, MonadIO m, Show a1, Show a2) => IdeState -> a1 -> a2 -> m () +-- logWith state key val = +-- liftIO . logPriority undefined logLevel $ +-- T.unwords +-- [T.pack logWithPos, asT key, asT val] +-- where +-- logWithPos = +-- let stk = toList callStack +-- pr pos = concat [srcLocFile pos, ":", show . srcLocStartLine $ pos, ":", show . srcLocStartCol $ pos] +-- in case stk of +-- [] -> "" +-- (x:_) -> pr $ snd x - asT :: Show a => a -> T.Text - asT = T.pack . show - --- | Set to Info to see extensive debug info in hie log, set to Debug in production -logLevel :: Priority -logLevel = Debug -- Info +-- asT :: Show a => a -> T.Text +-- asT = T.pack . show isLiterate :: FilePath -> Bool isLiterate x = takeExtension x `elem` [".lhs", ".lhs-boot"] @@ -109,3 +109,16 @@ showErr e = _ -> #endif return . show $ e + +#if MIN_VERSION_ghc(9,8,0) +prettyWarnings :: Messages DriverMessage -> String +prettyWarnings = printWithoutUniques . pprMessages (defaultDiagnosticOpts @DriverMessage) +#else +prettyWarnings :: [Warn] -> String +prettyWarnings = unlines . map prettyWarn + +prettyWarn :: Warn -> String +prettyWarn Warn{..} = + T.unpack (printOutputable $ SrcLoc.getLoc warnMsg) <> ": warning:\n" + <> " " <> SrcLoc.unLoc warnMsg +#endif diff --git a/plugins/hls-retrie-plugin/src/Ide/Plugin/Retrie.hs b/plugins/hls-retrie-plugin/src/Ide/Plugin/Retrie.hs index f5871d9d73..48d2886ff0 100644 --- a/plugins/hls-retrie-plugin/src/Ide/Plugin/Retrie.hs +++ b/plugins/hls-retrie-plugin/src/Ide/Plugin/Retrie.hs @@ -11,7 +11,7 @@ {-# OPTIONS -Wno-orphans #-} -module Ide.Plugin.Retrie (descriptor) where +module Ide.Plugin.Retrie (descriptor, Log) where import Control.Concurrent.STM (readTVarIO) import Control.Exception.Safe (Exception (..), @@ -135,11 +135,18 @@ import System.Directory (makeAbsolute) import GHC.Types.PkgQual #endif -descriptor :: PluginId -> PluginDescriptor IdeState -descriptor plId = +data Log + = LogParsingModule FilePath + +instance Pretty Log where + pretty = \case + LogParsingModule fp -> "Parsing module:" <+> pretty fp + +descriptor :: Recorder (WithPriority Log) -> PluginId -> PluginDescriptor IdeState +descriptor recorder plId = (defaultPluginDescriptor plId "Provides code actions to inline Haskell definitions") { pluginHandlers = mkPluginHandler SMethod_TextDocumentCodeAction provider, - pluginCommands = [retrieCommand, retrieInlineThisCommand] + pluginCommands = [retrieCommand recorder, retrieInlineThisCommand recorder] } retrieCommandId :: CommandId @@ -148,14 +155,14 @@ retrieCommandId = "retrieCommand" retrieInlineThisCommandId :: CommandId retrieInlineThisCommandId = "retrieInlineThisCommand" -retrieCommand :: PluginCommand IdeState -retrieCommand = - PluginCommand retrieCommandId "run the refactoring" runRetrieCmd +retrieCommand :: Recorder (WithPriority Log) -> PluginCommand IdeState +retrieCommand recorder = + PluginCommand retrieCommandId "run the refactoring" (runRetrieCmd recorder) -retrieInlineThisCommand :: PluginCommand IdeState -retrieInlineThisCommand = +retrieInlineThisCommand :: Recorder (WithPriority Log) -> PluginCommand IdeState +retrieInlineThisCommand recorder = PluginCommand retrieInlineThisCommandId "inline function call" - runRetrieInlineThisCmd + (runRetrieInlineThisCmd recorder) -- | Parameters for the runRetrie PluginCommand. data RunRetrieParams = RunRetrieParams @@ -166,8 +173,8 @@ data RunRetrieParams = RunRetrieParams } deriving (Eq, Show, Generic, FromJSON, ToJSON) -runRetrieCmd :: CommandFunction IdeState RunRetrieParams -runRetrieCmd state token RunRetrieParams{originatingFile = uri, ..} = ExceptT $ +runRetrieCmd :: Recorder (WithPriority Log) -> CommandFunction IdeState RunRetrieParams +runRetrieCmd recorder state token RunRetrieParams{originatingFile = uri, ..} = ExceptT $ withIndefiniteProgress description token Cancellable $ \_updater -> do _ <- runExceptT $ do nfp <- getNormalizedFilePathE uri @@ -179,6 +186,7 @@ runRetrieCmd state token RunRetrieParams{originatingFile = uri, ..} = ExceptT $ let importRewrites = concatMap (extractImports ms binds) rewrites (errors, edits) <- liftIO $ callRetrie + recorder state (hscEnv session) (map Right rewrites <> map Left importRewrites) @@ -201,8 +209,8 @@ data RunRetrieInlineThisParams = RunRetrieInlineThisParams } deriving (Eq, Show, Generic, FromJSON, ToJSON) -runRetrieInlineThisCmd :: CommandFunction IdeState RunRetrieInlineThisParams -runRetrieInlineThisCmd state _token RunRetrieInlineThisParams{..} = do +runRetrieInlineThisCmd :: Recorder (WithPriority Log) -> CommandFunction IdeState RunRetrieInlineThisParams +runRetrieInlineThisCmd recorder state _token RunRetrieInlineThisParams{..} = do nfp <- getNormalizedFilePathE $ getLocationUri inlineIntoThisLocation nfpSource <- getNormalizedFilePathE $ getLocationUri inlineFromThisLocation -- What we do here: @@ -219,7 +227,7 @@ runRetrieInlineThisCmd state _token RunRetrieInlineThisParams{..} = do when (null inlineRewrite) $ throwError $ PluginInternalError "Empty rewrite" (session, _) <- runActionE "retrie" state $ useWithStaleE GhcSessionDeps nfp - (fixityEnv, cpp) <- liftIO $ getCPPmodule state (hscEnv session) $ fromNormalizedFilePath nfp + (fixityEnv, cpp) <- liftIO $ getCPPmodule recorder state (hscEnv session) $ fromNormalizedFilePath nfp result <- liftIO $ try @_ @SomeException $ runRetrie fixityEnv (applyWithUpdate myContextUpdater inlineRewrite) cpp case result of @@ -506,13 +514,14 @@ instance Show CallRetrieError where instance Exception CallRetrieError callRetrie :: + Recorder (WithPriority Log) -> IdeState -> HscEnv -> [Either ImportSpec RewriteSpec] -> NormalizedFilePath -> Bool -> IO ([CallRetrieError], WorkspaceEdit) -callRetrie state session rewrites origin restrictToOriginatingFile = do +callRetrie recorder state session rewrites origin restrictToOriginatingFile = do knownFiles <- toKnownFiles . unhashed <$> readTVarIO (knownTargetsVar $ shakeExtras state) let -- TODO cover all workspaceFolders @@ -540,7 +549,7 @@ callRetrie state session rewrites origin restrictToOriginatingFile = do targets <- getTargetFiles retrieOptions (getGroundTerms retrie) results <- forM targets $ \t -> runExceptT $ do - (fixityEnv, cpp) <- ExceptT $ try $ getCPPmodule state session t + (fixityEnv, cpp) <- ExceptT $ try $ getCPPmodule recorder state session t -- TODO add the imports to the resulting edits (_user, _ast, change@(Change _replacements _imports)) <- lift $ runRetrie fixityEnv retrie cpp @@ -751,8 +760,8 @@ reuseParsedModule state f = do (fixities, pm') <- fixFixities state f (fixAnns pm) return (fixities, pm') -getCPPmodule :: IdeState -> HscEnv -> FilePath -> IO (FixityEnv, CPP AnnotatedModule) -getCPPmodule state session t = do +getCPPmodule :: Recorder (WithPriority Log) -> IdeState -> HscEnv -> FilePath -> IO (FixityEnv, CPP AnnotatedModule) +getCPPmodule recorder state session t = do nt <- toNormalizedFilePath' <$> makeAbsolute t let getParsedModule f contents = do modSummary <- msrModSummary <$> @@ -762,7 +771,7 @@ getCPPmodule state session t = do { ms_hspp_buf = Just (stringToStringBuffer contents) } - logPriority (ideLogger state) Info $ T.pack $ "Parsing module: " <> t + logWith recorder Info $ LogParsingModule t parsed <- evalGhcEnv session (GHCGHC.parseModule ms') `catch` \e -> throwIO (GHCParseError nt (show @SomeException e)) (fixities, parsed) <- fixFixities state f (fixAnns parsed) diff --git a/plugins/hls-retrie-plugin/test/Main.hs b/plugins/hls-retrie-plugin/test/Main.hs index 21fae51642..ecf509a22f 100644 --- a/plugins/hls-retrie-plugin/test/Main.hs +++ b/plugins/hls-retrie-plugin/test/Main.hs @@ -1,27 +1,38 @@ {-# LANGUAGE DisambiguateRecordFields #-} {-# LANGUAGE OverloadedStrings #-} {-# LANGUAGE PartialTypeSignatures #-} +{-# LANGUAGE LambdaCase #-} module Main (main) where import Control.Monad (void) import qualified Data.Map as M import Data.Text (Text) -import qualified Development.IDE.GHC.ExactPrint +import qualified Development.IDE.GHC.ExactPrint as ExactPrint import qualified Development.IDE.Plugin.CodeAction as Refactor import Ide.Plugin.Config import qualified Ide.Plugin.Retrie as Retrie import System.FilePath import Test.Hls +import Ide.Logger + +data LogWrap + = RetrieLog Retrie.Log + | ExactPrintLog ExactPrint.Log + +instance Pretty LogWrap where + pretty = \case + RetrieLog msg -> pretty msg + ExactPrintLog msg -> pretty msg main :: IO () main = defaultTestRunner tests -retriePlugin :: PluginTestDescriptor a -retriePlugin = mkPluginTestDescriptor' Retrie.descriptor "retrie" +retriePlugin :: PluginTestDescriptor LogWrap +retriePlugin = mkPluginTestDescriptor (Retrie.descriptor . cmapWithPrio RetrieLog) "retrie" -refactorPlugin :: PluginTestDescriptor Development.IDE.GHC.ExactPrint.Log -refactorPlugin = mkPluginTestDescriptor Refactor.iePluginDescriptor "refactor" +refactorPlugin :: PluginTestDescriptor LogWrap +refactorPlugin = mkPluginTestDescriptor (Refactor.iePluginDescriptor . cmapWithPrio ExactPrintLog) "refactor" tests :: TestTree tests = testGroup "Retrie" @@ -79,7 +90,7 @@ goldenWithRetrie title path act = runWithRetrie :: Session a -> IO a runWithRetrie = runSessionWithServer def testPlugins testDataDir -testPlugins :: PluginTestDescriptor Development.IDE.GHC.ExactPrint.Log +testPlugins :: PluginTestDescriptor LogWrap testPlugins = retriePlugin <> refactorPlugin -- needed for the GetAnnotatedParsedSource rule diff --git a/plugins/hls-stylish-haskell-plugin/src/Ide/Plugin/StylishHaskell.hs b/plugins/hls-stylish-haskell-plugin/src/Ide/Plugin/StylishHaskell.hs index 795b3e7172..3eeb05683c 100644 --- a/plugins/hls-stylish-haskell-plugin/src/Ide/Plugin/StylishHaskell.hs +++ b/plugins/hls-stylish-haskell-plugin/src/Ide/Plugin/StylishHaskell.hs @@ -1,9 +1,11 @@ {-# LANGUAGE CPP #-} {-# LANGUAGE OverloadedStrings #-} {-# LANGUAGE ViewPatterns #-} +{-# LANGUAGE LambdaCase #-} module Ide.Plugin.StylishHaskell ( descriptor , provider + , Log ) where @@ -26,9 +28,17 @@ import Language.LSP.Protocol.Types as LSP import System.Directory import System.FilePath -descriptor :: PluginId -> PluginDescriptor IdeState -descriptor plId = (defaultPluginDescriptor plId desc) - { pluginHandlers = mkFormattingHandlers provider +data Log + = LogLanguageExtensionFromDynFlags + +instance Pretty Log where + pretty = \case + LogLanguageExtensionFromDynFlags -> "stylish-haskell uses the language extensions from DynFlags" + + +descriptor :: Recorder (WithPriority Log) -> PluginId -> PluginDescriptor IdeState +descriptor recorder plId = (defaultPluginDescriptor plId desc) + { pluginHandlers = mkFormattingHandlers (provider recorder) } where desc = "Provides formatting of Haskell files via stylish-haskell. Built with stylish-haskell-" <> VERSION_stylish_haskell @@ -36,8 +46,8 @@ descriptor plId = (defaultPluginDescriptor plId desc) -- | Formatter provider of stylish-haskell. -- Formats the given source in either a given Range or the whole Document. -- If the provider fails an error is returned that can be displayed to the user. -provider :: FormattingHandler IdeState -provider ide _token typ contents fp _opts = do +provider :: Recorder (WithPriority Log) -> FormattingHandler IdeState +provider recorder ide _token typ contents fp _opts = do (msrModSummary -> ms_hspp_opts -> dyn) <- runActionE "stylish-haskell" ide $ useE GetModSummary fp let file = fromNormalizedFilePath fp config <- liftIO $ loadConfigFrom file @@ -53,7 +63,7 @@ provider ide _token typ contents fp _opts = do getMergedConfig dyn config | null (configLanguageExtensions config) = do - logInfo (ideLogger ide) "stylish-haskell uses the language extensions from DynFlags" + logWith recorder Info LogLanguageExtensionFromDynFlags pure $ config { configLanguageExtensions = getExtensions dyn } diff --git a/plugins/hls-stylish-haskell-plugin/test/Main.hs b/plugins/hls-stylish-haskell-plugin/test/Main.hs index f8e55e8913..22e9499947 100644 --- a/plugins/hls-stylish-haskell-plugin/test/Main.hs +++ b/plugins/hls-stylish-haskell-plugin/test/Main.hs @@ -10,8 +10,8 @@ import Test.Hls main :: IO () main = defaultTestRunner tests -stylishHaskellPlugin :: PluginTestDescriptor () -stylishHaskellPlugin = mkPluginTestDescriptor' StylishHaskell.descriptor "stylishHaskell" +stylishHaskellPlugin :: PluginTestDescriptor StylishHaskell.Log +stylishHaskellPlugin = mkPluginTestDescriptor StylishHaskell.descriptor "stylishHaskell" tests :: TestTree tests = testGroup "stylish-haskell" diff --git a/src/HlsPlugins.hs b/src/HlsPlugins.hs index 1f5d091dc5..f08ae187cd 100644 --- a/src/HlsPlugins.hs +++ b/src/HlsPlugins.hs @@ -178,13 +178,13 @@ idePlugins recorder = pluginDescToIdePlugins allPlugins let pId = "ormolu" in Ormolu.descriptor (pluginRecorder pId) pId : #endif #if hls_stylishHaskell - StylishHaskell.descriptor "stylish-haskell" : + let pId = "stylish-haskell" in StylishHaskell.descriptor (pluginRecorder pId) pId : #endif #if hls_rename let pId = "rename" in Rename.descriptor (pluginRecorder pId) pId: #endif #if hls_retrie - Retrie.descriptor "retrie" : + let pId = "retrie" in Retrie.descriptor (pluginRecorder pId) pId : #endif #if hls_callHierarchy CallHierarchy.descriptor "callHierarchy" :