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

InterruptedException can "escape" LS without being printed #5070

Closed
1 task
wdanilo opened this issue Feb 5, 2023 · 3 comments · Fixed by #5871
Closed
1 task

InterruptedException can "escape" LS without being printed #5070

wdanilo opened this issue Feb 5, 2023 · 3 comments · Fixed by #5871
Assignees
Milestone

Comments

@wdanilo
Copy link
Member

wdanilo commented Feb 5, 2023

This task is automatically imported from the old Task Issue Board and it was originally created by jaroslavtulach.
Original issue is here.


Investigating problems with ConnectException I realized that when InterruptedException is thrown from language server, it may remain unnoticed due to the way Scala deals with (checked) exceptions and classifies them to NonFatal and other.

The issue was discovered when searching for reasons why the connection between IDE/engine breaks. One of the hypothesis was: there is an exception in the engine, but we don't know about it as it is "swallowed". Then it doesn't appear in the logs and we cannot fix it, as we don't have any trace of it. This pivotal demonstrates such a situation can really happen - at least with InterruptedException.

To reproduce use following modification to simulate InterruptedException somewhere in the engine/language server code:

-- a/engine/language-server/src/main/scala/org/enso/languageserver/runtime/RuntimeKiller.scala
+++ b/engine/language-server/src/main/scala/org/enso/languageserver/runtime/RuntimeKiller.scala
@@ -68,9 +68,13 @@
         truffleContext,
         retryCount + 1
       )
+      if (true) {
+        throw new InterruptedException() 
+      } else {
       truffleContext.close()
       replyTo ! RuntimeGracefullyStopped
       context.stop(self)
+      }
     } catch {
       case NonFatal(ex) =>
         logger.error(

connect to the LS with IDE and then kill the IDE. The InterruptedException gets yielded, but it doesn't appear anywhere in the logs.

Tasks:

  • Make sure all exceptions are printed including InterruptedException

Blockers:

#184340534 blocked

Comments:

Isn't it logged in https://github.com/enso-org/enso/blob/develop/engine/runtime/src/main/scala/org/enso/interpreter/instrument/job/ProgramExecutionSupport.scala#L239 (Hubert Plociniczak - Feb 1, 2023)


The `InterruptedException` is not logged. I've got just: ``` [info] [2023-02-01T17:23:04.681Z] [org.enso.languageserver.protocol.binary.BinaryConnectionController] Connection closed [127.0.0.1:41502]. [info] [2023-02-01T17:23:04.683Z] [org.enso.languageserver.runtime.RuntimeKiller] Shutting down the runtime server [Actor[akka://language-server/user/runtime-connector#-183675620]]. [info] [2023-02-01T17:23:04.695Z] [org.enso.languageserver.runtime.RuntimeKiller] Shutting down the Truffle context [org.graalvm.polyglot.Context@75c86d65]. Attempt #1. [internal-logger-error] One of the printers failed to write a message: java.lang.NullPointerException [internal-logger-error] The dropped message was: [error] [2023-02-01T17:23:04.702Z] [akka.actor.OneForOneStrategy] null [error] [2023-02-01T17:23:16.695Z] [org.enso.languageserver.boot.LanguageServerComponent] An error occurred during stopping server [info] [2023-02-01T17:23:16.696Z] [org.enso.languageserver.boot.LanguageServerComponent] Terminated truffle context [info] [2023-02-01T17:23:16.702Z] [org.enso.languageserver.boot.LanguageServerComponent] Terminated json connections [info] [2023-02-01T17:23:16.703Z] [org.enso.languageserver.boot.LanguageServerComponent] Terminated binary connections [info] [2023-02-01T17:23:16.717Z] [akka.actor.CoordinatedShutdown] Running CoordinatedShutdown with reason [ActorSystemTerminateReason] [info] [2023-02-01T17:23:16.738Z] [org.enso.languageserver.boot.LanguageServerComponent] Terminated actor system [info] [2023-02-01T17:23:16.846Z] [org.enso.languageserver.boot.LanguageServerComponent] Terminated main module ``` (jaroslavtulach - Feb 1, 2023)
@jdunkerley jdunkerley added this to the Beta Release milestone Feb 7, 2023
@jdunkerley jdunkerley moved this to ❓New in Issues Board Feb 7, 2023
@jdunkerley jdunkerley moved this from ❓New to 📤 Backlog in Issues Board Feb 7, 2023
@jdunkerley jdunkerley moved this from 📤 Backlog to 🔧 Implementation in Issues Board Mar 7, 2023
@enso-bot
Copy link

enso-bot bot commented Mar 8, 2023

Dmitry Bushev reports a new STANDUP for yesterday (2023-03-07):

Progress: Started working on the task. Started updating the log statements. Found a quirk in the language server initialization. The initial ping handler saves all the senders and replies then once the language server is initialized, while the project manager retries the initial ping attempts every 100 millis. While it is a suboptimal behavior, it doesn't break the initialization. It should be finished by 2023-03-09.

Next Day: Next day I will be working on the #5068 task. Continue working on the task

@enso-bot
Copy link

enso-bot bot commented Mar 8, 2023

Dmitry Bushev reports a new STANDUP for today (2023-03-08):

Progress: Continue working on the task. Updated the language server log statements. Started working on the runtime. It should be finished by 2023-03-09.

Next Day: Next day I will be working on the #5068 task. Continue working on the task

@enso-bot
Copy link

enso-bot bot commented Mar 9, 2023

Dmitry Bushev reports a new STANDUP for today (2023-03-09):

Progress: Continue working on the task. Updated runtime log statements, added debug logging for the Akka actor's lifecycle, and lowered the log level for interruption events. Created PR with the task. Created PR adding the formatting check of SBT build definition. It should be finished by 2023-03-09.

Next Day: Next day I will be working on the #5070 task. Continue working on the task

@mergify mergify bot closed this as completed in #5871 Mar 11, 2023
mergify bot pushed a commit that referenced this issue Mar 11, 2023
close #5070

Changelog:
- Include the original exception to log expressions
- Enable logging of Akka Actors' lifecycle events on debug logging level
- Decrease the severity of interruption log messages because interruptions are part of the workflow. The computation can be interrupted at any time, and still be recomputed after. Warnings are just misleading in this case.
@github-project-automation github-project-automation bot moved this from 🔧 Implementation to 🟢 Accepted in Issues Board Mar 11, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
Archived in project
Development

Successfully merging a pull request may close this issue.

3 participants