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

Language Server breaks on page refresh. #8689

Closed
farmaazon opened this issue Jan 5, 2024 · 15 comments · Fixed by #9057
Closed

Language Server breaks on page refresh. #8689

farmaazon opened this issue Jan 5, 2024 · 15 comments · Fixed by #9057
Assignees

Comments

@farmaazon
Copy link
Contributor

To reproduce

  1. Open any project locally
  2. Refresh page (ctrl/cmd+r in electron works)

Expected: page refreshes and loads project properly
Actual: language server reports exception, no node is colored.

The reported exception is

java.lang.NullPointerException: Cannot invoke "java.util.UUID.toString()" because "a" is null
	at org.enso.IsolatedClassLoader//io.circe.Encoder$$anon$20.apply(Encoder.scala:307)
	at org.enso.IsolatedClassLoader//io.circe.Encoder$$anon$20.apply(Encoder.scala:306)
	at org.enso.IsolatedClassLoader//org.enso.languageserver.protocol.json.JsonRpc$anon$importedEncoder$macro$6386$1$$anon$515.encodeObject(JsonRpc.scala:124)
	at org.enso.IsolatedClassLoader//org.enso.languageserver.protocol.json.JsonRpc$anon$importedEncoder$macro$6386$1$$anon$515.encodeObject(JsonRpc.scala:124)
	at org.enso.IsolatedClassLoader//io.circe.generic.encoding.DerivedAsObjectEncoder$$anon$1.encodeObject(DerivedAsObjectEncoder.scala:13)
	at org.enso.IsolatedClassLoader//io.circe.Encoder$AsObject.apply(Encoder.scala:839)
	at org.enso.IsolatedClassLoader//io.circe.Encoder$AsObject.apply$(Encoder.scala:839)
	at org.enso.IsolatedClassLoader//io.circe.generic.encoding.DerivedAsObjectEncoder.apply(DerivedAsObjectEncoder.scala:6)
	at org.enso.IsolatedClassLoader//io.circe.MidPriorityEncoders$IterableAsArrayEncoder.encodeArray(Encoder.scala:934)
	at org.enso.IsolatedClassLoader//io.circe.Encoder$AsArray.apply(Encoder.scala:759)
	at org.enso.IsolatedClassLoader//io.circe.Encoder$AsArray.apply$(Encoder.scala:759)
	at org.enso.IsolatedClassLoader//io.circe.MidPriorityEncoders$IterableAsArrayEncoder.apply(Encoder.scala:926)
	at org.enso.IsolatedClassLoader//org.enso.languageserver.protocol.json.JsonRpc$anon$importedEncoder$macro$6386$1$$anon$514.encodeObject(JsonRpc.scala:124)
	at org.enso.IsolatedClassLoader//org.enso.languageserver.protocol.json.JsonRpc$anon$importedEncoder$macro$6386$1$$anon$514.encodeObject(JsonRpc.scala:124)
	at org.enso.IsolatedClassLoader//io.circe.generic.encoding.DerivedAsObjectEncoder$$anon$1.encodeObject(DerivedAsObjectEncoder.scala:13)
	at org.enso.IsolatedClassLoader//io.circe.Encoder$AsObject.apply(Encoder.scala:839)
	at org.enso.IsolatedClassLoader//io.circe.Encoder$AsObject.apply$(Encoder.scala:839)
	at org.enso.IsolatedClassLoader//io.circe.generic.encoding.DerivedAsObjectEncoder.apply(DerivedAsObjectEncoder.scala:6)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.Protocol.org$enso$jsonrpc$Protocol$$$anonfun$registerNotification$1(Protocol.scala:293)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.Protocol$$anonfun$5.apply(Protocol.scala:292)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.Protocol.org$enso$jsonrpc$Protocol$$$anonfun$registerNotification$1(Protocol.scala:294)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.Protocol$$anonfun$5.apply(Protocol.scala:292)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.Protocol.org$enso$jsonrpc$Protocol$$$anonfun$registerNotification$1(Protocol.scala:294)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.Protocol$$anonfun$5.apply(Protocol.scala:292)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.Protocol.org$enso$jsonrpc$Protocol$$$anonfun$registerNotification$1(Protocol.scala:294)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.Protocol$$anonfun$5.apply(Protocol.scala:292)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.Protocol.org$enso$jsonrpc$Protocol$$$anonfun$registerNotification$1(Protocol.scala:294)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.Protocol$$anonfun$5.apply(Protocol.scala:292)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.Protocol.org$enso$jsonrpc$Protocol$$$anonfun$registerNotification$1(Protocol.scala:294)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.Protocol$$anonfun$5.apply(Protocol.scala:292)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.Protocol.org$enso$jsonrpc$Protocol$$$anonfun$registerNotification$1(Protocol.scala:294)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.Protocol$$anonfun$5.apply(Protocol.scala:292)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.Protocol.org$enso$jsonrpc$Protocol$$$anonfun$registerNotification$1(Protocol.scala:294)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.Protocol$$anonfun$5.apply(Protocol.scala:292)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.Protocol.org$enso$jsonrpc$Protocol$$$anonfun$registerNotification$1(Protocol.scala:294)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.Protocol$$anonfun$5.apply(Protocol.scala:292)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.Protocol.org$enso$jsonrpc$Protocol$$$anonfun$registerNotification$1(Protocol.scala:294)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.Protocol$$anonfun$5.apply(Protocol.scala:292)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.MessageHandler.org$enso$jsonrpc$MessageHandler$$issueNotification(MessageHandler.scala:94)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.MessageHandler$$anonfun$org$enso$jsonrpc$MessageHandler$$established$1.applyOrElse(MessageHandler.scala:51)
	at org.enso.IsolatedClassLoader//akka.actor.Actor.aroundReceive(Actor.scala:537)
	at org.enso.IsolatedClassLoader//akka.actor.Actor.aroundReceive$(Actor.scala:535)
	at org.enso.IsolatedClassLoader//org.enso.jsonrpc.MessageHandler.aroundReceive(MessageHandler.scala:13)
	at org.enso.IsolatedClassLoader//akka.actor.ActorCell.receiveMessage(ActorCell.scala:579)
	at org.enso.IsolatedClassLoader//akka.actor.ActorCell.invoke(ActorCell.scala:547)
	at org.enso.IsolatedClassLoader//akka.dispatch.Mailbox.processMailbox(Mailbox.scala:270)
	at org.enso.IsolatedClassLoader//akka.dispatch.Mailbox.run(Mailbox.scala:231)
	at org.enso.IsolatedClassLoader//akka.dispatch.Mailbox.exec(Mailbox.scala:243)
	at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:387)
	at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1312)
	at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1843)
	at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1808)
	at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:188)

It always appears when the problem occurs. Here is full log from several launches, some reproducing the issue.

enso-project-manager-2024-01-05.0.log

@hubertp
Copy link
Collaborator

hubertp commented Jan 7, 2024

Kazam_screencast_00028.webm
Are these the right instructions @farmaazon ? This is what I'm getting after reloading.

@farmaazon
Copy link
Contributor Author

This is what I get:

Screencast.from.2024-01-08.10-25-50.webm

I think I don't see login screen, because I'm already logged in.

You can try "continue without logging" option and then reopen same project.

Logs:

enso-project-manager-2024-01-08.0.log

@hubertp
Copy link
Collaborator

hubertp commented Feb 2, 2024

Kazam_screencast_00036.webm

Still can't reproduce. When logged in. When logged out things become a bit unstable, yes.
(the video somehow doesn't show the nodes at the end, but they are there)

@hubertp hubertp moved this from 📤 Backlog to 🔧 Implementation in Issues Board Feb 5, 2024
@enso-bot
Copy link

enso-bot bot commented Feb 5, 2024

Hubert Plociniczak reports a new STANDUP for the provided date (2024-02-02):

Progress: Added a fix for leaking FileSystemService. Apparently LibrariesTest will still timeout, so increased the timeout as we run out of other options. Started investigating restat issues, still having problem with reproducing the issue. Also investigating memory leaks when running runtime/test. It should be finished by 2024-02-05.

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

@enso-bot
Copy link

enso-bot bot commented Feb 5, 2024

Hubert Plociniczak reports a new STANDUP for yesterday (2024-02-04):

Progress: Still trying to figure out the memory leaks in tests but no success so far. It should be finished by 2024-02-05.

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

@hubertp
Copy link
Collaborator

hubertp commented Feb 5, 2024

Did more tweaks and looks like I can reproduce now. Investigating.

@enso-bot
Copy link

enso-bot bot commented Feb 6, 2024

Hubert Plociniczak reports a new STANDUP for yesterday (2024-02-05):

Progress: Finally managed to reproduce the issue, debugging. Reviewed #8924, planning language-server work, dealing with CI hiccups. It should be finished by 2024-02-05.

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

@enso-bot
Copy link

enso-bot bot commented Feb 7, 2024

Hubert Plociniczak reports a new 🔴 DELAY for yesterday (2024-02-06):

Summary: There is 4 day delay in implementation of the Language Server breaks on page refresh. (#8689) task.
It will cause 0 days delay for the delivery of this weekly plan.

Delay Cause: Unfamiliar with that part of the codebase + underestimated the randomness of the problem.

@enso-bot
Copy link

enso-bot bot commented Feb 7, 2024

Hubert Plociniczak reports a new STANDUP for yesterday (2024-02-06):

Progress: No progress in debugging the issue even though it happens consistently. Consulting with Dmitry on potential reasons. It should be finished by 2024-02-09.

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

@jdunkerley jdunkerley removed the triage label Feb 8, 2024
mergify bot pushed a commit that referenced this issue Feb 8, 2024
related #8689

Fixes the NPE during the serialization of update messages.

```
java.lang.NullPointerException: Cannot invoke "java.util.UUID.toString()" because "a" is null
```
@enso-bot
Copy link

enso-bot bot commented Feb 8, 2024

Hubert Plociniczak reports a new STANDUP for yesterday (2024-02-07):

Progress: Still investigating. Apparently it could be related to invalidating modules request, similar to #7413. It should be finished by 2024-02-09.

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

mergify bot pushed a commit that referenced this issue Feb 9, 2024
related #8689

Clean up the client's execution contexts when it disconnects from the language server. Dangling execution contexts may slow down the execution when the user reconnects to the language server.
@enso-bot
Copy link

enso-bot bot commented Feb 13, 2024

Hubert Plociniczak reports a new 🔴 DELAY for today (2024-02-13):

Summary: There is 5 day delay in implementation of the Language Server breaks on page refresh. (#8689) task.
It will cause 0 days delay for the delivery of this weekly plan.

Delay Cause: Didn't manage to find the root of the problem before going on holiday, the problem is also tricky to identify.

@enso-bot
Copy link

enso-bot bot commented Feb 13, 2024

Hubert Plociniczak reports a new STANDUP for yesterday (2024-02-12):

Progress: Continued investigation. Still unable to locate the root of the problem. Catching up after a break. It should be finished by 2024-02-14.

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

mergify bot pushed a commit that referenced this issue Feb 13, 2024
related #8689

Fixes a race between the language server SQL updating logic and the engine `DeserializeLibrarySuggestionsJob`s when the library suggestions may start loading before the database is properly cleaned up after the reconnect.
@hubertp hubertp moved this from 🔧 Implementation to 👁️ Code review in Issues Board Feb 14, 2024
@enso-bot
Copy link

enso-bot bot commented Feb 15, 2024

Hubert Plociniczak reports a new STANDUP for the provided date (2024-02-13):

Progress: The root of the problem appears to be in the IR loaded from the cache. It looks like nodes are missing either source or UUIDs once the information is loaded on restart. This results in missing instrumentation. It should be finished by 2024-02-14.

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

@enso-bot
Copy link

enso-bot bot commented Feb 15, 2024

Hubert Plociniczak reports a new STANDUP for yesterday (2024-02-14):

Progress: PR with a fix is ready, turned out to be a smal problem with UUID not being serialized. Providing a test case is again problematic since it seems that we a) don't serialize ids of IRs b) don't generate UUIDs for IdentifierLocation in our tests. Various planning meetings. It should be finished by 2024-02-14.

Next Day: Next day I will be working on the #8689 task. Address PR review, try to figure out a test case, if any, pick up next item on the list.

@mergify mergify bot closed this as completed in #9057 Feb 15, 2024
mergify bot pushed a commit that referenced this issue Feb 15, 2024
Missing ID's in IR meant that instrumentation wouldn't be applied for loaded modules. This is the reason why after a restart engine wouldn't send **any** expression updates.

Closes #8689.

# Important Notes
After the change
[Kazam_screencast_00038.webm](https://github.com/enso-org/enso/assets/292128/4249287b-6c41-4c9d-b138-e7af59512566)

The video somehow doesn't show that all nodes are loaded after the restart, but once I moved the screen they are there. This appears to be a bug in the recording somehow.
@github-project-automation github-project-automation bot moved this from 👁️ Code review to 🟢 Accepted in Issues Board Feb 15, 2024
@enso-bot
Copy link

enso-bot bot commented Feb 21, 2024

Hubert Plociniczak reports a new 🔴 DELAY for the provided date (2024-02-19):

Summary: There is 4 days delay in implementation of the Language Server breaks on page refresh. (#8689) task.
It will cause 0 days delay for the delivery of this weekly plan.

Delay Cause: Adding more tweaks, dealing with licensing

4e6 added a commit that referenced this issue Feb 22, 2024
related #8689

Fixes a race between the language server SQL updating logic and the engine `DeserializeLibrarySuggestionsJob`s when the library suggestions may start loading before the database is properly cleaned up after the reconnect.
mergify bot pushed a commit that referenced this issue Feb 23, 2024
related #8689, #9072

Fixes a race between the language server SQL updating logic and the engine `DeserializeLibrarySuggestionsJob`s when the library suggestions may start loading before the database is properly cleaned up after the reconnect.

# Important Notes
As a side effect, arguments are showing slightly (~1 second) faster due to the lower contention between the engine jobs.

#### Before
https://github.com/enso-org/enso/assets/357683/cbda2da4-9080-4b9b-b836-81e54694d468

#### After
https://github.com/enso-org/enso/assets/357683/bf442284-47be-456d-b1dd-2413b6ad8244
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