Skip to content
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.

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

Log response errors returned from Plugins #2988

Merged
merged 12 commits into from
Jul 1, 2022

Conversation

drsooch
Copy link
Collaborator

@drsooch drsooch commented Jun 25, 2022

In certain scenarios, Clients do not display ResponseErrors from the server. This change will allow for ALL ResponseErrors to be visible in the logs for use in debugging.

Similarly, I've dropped the "who" "what" "where" when semantics of the throwPluginError function. There's no need to figure out where the ResponseError came from, just leave it up to the caller to supply a good message. I want to explore what I've dubbed (to myself) Logging Contexts.

@drsooch drsooch force-pushed the log-response-errors branch from e6e2cff to b9ce2ca Compare June 25, 2022 16:48
Copy link
Collaborator

@michaelpj michaelpj left a comment

Choose a reason for hiding this comment

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

Have you checked what happens when you us this? The one thing I'm a bit worried about is that I think we're calling window/showMessage for all error logs, so for a client that does show the ResponseError to users, we might get the message shown twice?

ghcide/src/Development/IDE/Plugin/HLS.hs Outdated Show resolved Hide resolved
Just fs -> do
let msg e pid = "Exception in plugin " <> T.pack (show pid) <> "while processing " <> T.pack (show m) <> ": " <> T.pack (show e)
handlers = fmap (\(plid,_,handler) -> (plid,handler)) fs
es <- runConcurrently msg (show m) handlers ide params
let (errs,succs) = partitionEithers $ toList es
unless (null errs) $ forM_ errs $ \err -> logWith recorder Warning $ LogPluginError err
Copy link
Collaborator

Choose a reason for hiding this comment

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

Why Warning here and Error elsewhere?

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

I think my reasoning was that in the event succs has responses we should just mark errors as Warnings but I guess ANY ResponseError should be classified as an error.

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

but yes I will update to Error

Copy link
Collaborator

Choose a reason for hiding this comment

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

Honestly, this code is kind of suspect. I'd be more comfortable with failing if any of them fail, rather than succeeding if any of them succeed 🤔

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

I guess the only thing I can thing of is if I trigger a code action, and a single code action fails, I don't want to fail ALL of the code actions. I'd rather get back the ones that succeed and ignore the failures

Copy link
Collaborator

Choose a reason for hiding this comment

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

I guess that's true. Hopefully that will still happen, they'll just get more obvious logs...

throwPluginError (PluginId who) what where' = throwE msg
where
msg = (T.unpack who) <> " failed with " <> what <> " at " <> where'
throwPluginError :: Monad m => String -> ExceptT String m b
Copy link
Collaborator

Choose a reason for hiding this comment

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

inline?

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

I plan on coming back to this (assuming people are ok with my suggestion). I want to come up with some way to tie back log messages to their context. So for instance I'm thinking this would eventually return ExceptT Context m b where Context can provide some information for what happened. This Context should be usable in all locations where we log (so internal to ghcide or shake etc.) This way plugins can just give an error message and the plugin id is automatically attached.

Copy link
Collaborator

Choose a reason for hiding this comment

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

Do you rather want ReaderT Context (ExceptT String m) b or something?

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

I'm not sure It would be in a follow up PR and the main detractor is whatever the solution is, has to cross ghcide and hls-plugin-api package barrier -- which I'm not sure how to deal with

Copy link
Collaborator

Choose a reason for hiding this comment

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

I think adding a ReaderT would not be too controversial. I wonder if there's a way we can sneak it into Recorder? So we'd do something like

let subcomponentRecorder = cmap (addContext "SubComponent") recorder

where addContext does... something.


-- various error message specific builders
pluginNotEnabled :: SMethod m -> [(PluginId, b, a)] -> Text
pluginNotEnabled method availPlugins = "No plugin enabled for " <> T.pack (show method) <> ", available: " <> T.pack (show $ map (\(plid,_,_) -> plid) availPlugins)
Copy link
Collaborator

Choose a reason for hiding this comment

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

use pretty for the plugin ids, define an instance if there isn't one? Could even do some layout so they appear on subsequent lines if that's useful.

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

Yeah, I hoisted these error message builders outside of the plugin handlers. Just wanted to clean up the surrounding code in the handlers. I'll go for the instance option and see if I can clean up some of these messages

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

use pretty for the plugin ids, define an instance if there isn't one? Could even do some layout so they appear on subsequent lines if that's useful.

I just realized that these build the response error messages so I don’t think there is any reason to add Pretty instances. They aren't usable in this context anyways

ghcide/src/Development/IDE/Plugin/HLS.hs Outdated Show resolved Hide resolved
@drsooch
Copy link
Collaborator Author

drsooch commented Jun 28, 2022

Have you checked what happens when you us this? The one thing I'm a bit worried about is that I think we're calling window/showMessage for all error logs, so for a client that does show the ResponseError to users, we might get the message shown twice?

I've tested using VSCode and EMacs and I've yet to see anything shown twice. I will however note that maybe Error is the wrong log level. In certain scenarios if We fail to build a project the user will get spammed with Error notifications. I'd propose to move back to Warning for any ResponseErrors coming from plugins directly.

@michaelpj
Copy link
Collaborator

I will however note that maybe Error is the wrong log level. In certain scenarios if We fail to build a project the user will get spammed with Error notifications.

Okay, so the question is "what does Error mean?". I think the things we see here are errors, and so we should be able to log them as such. Perhaps the problem is that we report all Error logs to the user now, so Error carries the additional connotation of "... and it's bad enough that the user should see". Perhaps that's a mistake, which we could fix by e.g. having a level above Error (say Critical) for errors that are bad enough they should be shown to the user.

@drsooch drsooch added the merge me Label to trigger pull request merge label Jul 1, 2022
@mergify mergify bot merged commit 73652d7 into haskell:master Jul 1, 2022
hololeap pushed a commit to hololeap/haskell-language-server that referenced this pull request Aug 26, 2022
* Log ResponseErrors when returned from Plugins

* Log  from Plugins

* Create 'logAndReturnError' that will log any failures in plugins

* Missed opportunity to use logAndReturnError

* Revert throwPluginError to throwE

This reverts a change made previously to try to make pluginErrors have a
common error format. This will be updated in the near future.

* Warning -> Error

* Fix Functional Test for Plugin Response Error

* Add orphan instances for

* Revert back to Warning

* Update log format in test suite
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
merge me Label to trigger pull request merge
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants