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

Initialize suggestions database only once in the presence of multiple clients #8033

Closed
hubertp opened this issue Oct 12, 2023 · 8 comments · Fixed by #8116
Closed

Initialize suggestions database only once in the presence of multiple clients #8033

hubertp opened this issue Oct 12, 2023 · 8 comments · Fixed by #8116
Assignees

Comments

@hubertp
Copy link
Collaborator

hubertp commented Oct 12, 2023

Once initialization problems have been fixed in #7985 I discovered that suggestion database would often crash for no apparent reason:

[INFO] [2023-10-11T18:11:11+02:00] [org.enso.languageserver.search.SuggestionsHandler] Initializing: got type graph response.
[INFO] [2023-10-11T18:11:11+02:00] [org.enso.languageserver.search.SuggestionsHandler] Initializing: got type graph response.
[WARN] [2023-10-11T18:11:11+02:00] [org.enso.languageserver.boot.resource.RepoInitialization] Failed to initialize the suggestions database [/home/hubert/enso/projects/Unnamed_9/.enso/suggestions.db].
org.sqlite.SQLiteException: [SQLITE_ERROR] SQL error or missing database (table "suggestions" already exists)
	at org.sqlite.core.DB.newSQLException(DB.java:1179)
	at org.sqlite.core.DB.newSQLException(DB.java:1190)
	at org.sqlite.core.DB.throwex(DB.java:1150)
	at org.sqlite.core.NativeDB.prepare_utf8(Native Method)
	at org.sqlite.core.NativeDB.prepare(NativeDB.java:126)
	at org.sqlite.core.DB.prepare(DB.java:264)
	at org.sqlite.core.CorePreparedStatement.<init>(CorePreparedStatement.java:46)
	at org.sqlite.jdbc3.JDBC3PreparedStatement.<init>(JDBC3PreparedStatement.java:32)
	at org.sqlite.jdbc4.JDBC4PreparedStatement.<init>(JDBC4PreparedStatement.java:25)
	at org.sqlite.jdbc4.JDBC4Connection.prepareStatement(JDBC4Connection.java:34)
	at org.sqlite.jdbc3.JDBC3Connection.prepareStatement(JDBC3Connection.java:226)
	at org.sqlite.jdbc3.JDBC3Connection.prepareStatement(JDBC3Connection.java:206)
	at slick.jdbc.JdbcBackend$SessionDef.prepareStatement(JdbcBackend.scala:376)
	at slick.jdbc.JdbcBackend$SessionDef.prepareStatement$(JdbcBackend.scala:365)
	at slick.jdbc.JdbcBackend$BaseSession.prepareStatement(JdbcBackend.scala:491)
	at slick.jdbc.JdbcBackend$SessionDef.withPreparedStatement(JdbcBackend.scala:426)
	at slick.jdbc.JdbcBackend$SessionDef.withPreparedStatement$(JdbcBackend.scala:422)
	at slick.jdbc.JdbcBackend$BaseSession.withPreparedStatement(JdbcBackend.scala:491)
	at slick.jdbc.JdbcActionComponent$SchemaActionExtensionMethodsImpl$$anon$5.$anonfun$run$4(JdbcActionComponent.scala:287)
	at slick.jdbc.JdbcActionComponent$SchemaActionExtensionMethodsImpl$$anon$5.$anonfun$run$4$adapted(JdbcActionComponent.scala:287)
	at scala.collection.immutable.Vector.foreach(Vector.scala:2122)
	at slick.jdbc.JdbcActionComponent$SchemaActionExtensionMethodsImpl$$anon$5.run(JdbcActionComponent.scala:287)
	at slick.jdbc.JdbcActionComponent$SchemaActionExtensionMethodsImpl$$anon$5.run(JdbcActionComponent.scala:285)
	at slick.jdbc.JdbcActionComponent$SimpleJdbcProfileAction.run(JdbcActionComponent.scala:28)
	at slick.jdbc.JdbcActionComponent$SimpleJdbcProfileAction.run(JdbcActionComponent.scala:25)
	at slick.basic.BasicBackend$DatabaseDef$$anon$3.liftedTree1$1(BasicBackend.scala:276)
	at slick.basic.BasicBackend$DatabaseDef$$anon$3.run(BasicBackend.scala:276)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.base/java.lang.Thread.run(Thread.java:833)
[INFO] [2023-10-11T18:11:11+02:00] [org.enso.languageserver.boot.resource.RepoInitialization] Clear database file. Attempt #1.
[WARN] [2023-10-11T18:11:11+02:00] [org.enso.languageserver.boot.resource.RepoInitialization] Failed to delete the database file. Attempt #1. File does not exist [/home/hubert/enso/projects/Unnamed_9/.enso/suggestions.db].
[WARN] [2023-10-11T18:11:11+02:00] [org.enso.languageserver.boot.resource.RepoInitialization] Failed to initialize the suggestions database [/home/hubert/enso/projects/Unnamed_9/.enso/suggestions.db].
java.util.concurrent.RejectedExecutionException: Task slick.basic.BasicBackend$DatabaseDef$$anon$3@7b87beaa rejected from slick.util.AsyncExecutor$$anon$1$$anon$2@16cd07ec[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 7]
	at java.base/java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2065)
	at java.base/java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:833)
	at java.base/java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1365)
	at slick.util.AsyncExecutor$$anon$1$$anon$4.execute(AsyncExecutor.scala:205)
	at slick.basic.BasicBackend$DatabaseDef.runSynchronousDatabaseAction(BasicBackend.scala:265)
	at slick.basic.BasicBackend$DatabaseDef.runSynchronousDatabaseAction$(BasicBackend.scala:263)
	at slick.jdbc.JdbcBackend$DatabaseDef.runSynchronousDatabaseAction(JdbcBackend.scala:37)
	at slick.basic.BasicBackend$DatabaseDef.slick$basic$BasicBackend$DatabaseDef$$runInContextInline(BasicBackend.scala:242)
	at slick.basic.BasicBackend$DatabaseDef.runInContextSafe(BasicBackend.scala:148)
	at slick.basic.BasicBackend$DatabaseDef.slick$basic$BasicBackend$DatabaseDef$$runInContextInline(BasicBackend.scala:172)
	at slick.basic.BasicBackend$DatabaseDef.runInContextSafe(BasicBackend.scala:148)
	at slick.basic.BasicBackend$DatabaseDef.runInContext(BasicBackend.scala:142)
	at slick.basic.BasicBackend$DatabaseDef.runInContext$(BasicBackend.scala:141)
	at slick.jdbc.JdbcBackend$DatabaseDef.runInContext(JdbcBackend.scala:37)
	at slick.basic.BasicBackend$DatabaseDef.$anonfun$runInContextInline$1(BasicBackend.scala:172)
	at scala.concurrent.impl.Promise$Transformation.run(Promise.scala:470)
	at akka.dispatch.BatchingExecutor$AbstractBatch.processBatch(BatchingExecutor.scala:63)
	at akka.dispatch.BatchingExecutor$BlockableBatch.$anonfun$run$1(BatchingExecutor.scala:100)
	at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.scala:18)
	at scala.concurrent.BlockContext$.withBlockContext(BlockContext.scala:94)
	at akka.dispatch.BatchingExecutor$BlockableBatch.run(BatchingExecutor.scala:100)
	at akka.dispatch.TaskInvocation.run(AbstractDispatcher.scala:49)
	at java.base/java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec(ForkJoinTask.java:1395)
	at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:373)
	at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1182)
	at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1655)
	at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1622)
	at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:165)
[INFO] [2023-10-11T18:11:11+02:00] [org.enso.languageserver.boot.resource.RepoInitialization] Clear database file. Attempt #1.
[WARN] [2023-10-11T18:11:11+02:00] [org.enso.languageserver.boot.resource.RepoInitialization] Failed to delete the database file. Attempt #1. File does not exist [/home/hubert/enso/projects/Unnamed_9/.enso/suggestions.db].
[INFO] [2023-10-11T18:11:11+02:00] [org.enso.languageserver.boot.resource.RepoInitialization] Retrying database initialization.
[INFO] [2023-10-11T18:11:11+02:00] [org.enso.languageserver.boot.resource.RepoInitialization] Retrying database initialization.
[ERROR] [2023-10-11T18:11:11+02:00] [org.enso.languageserver.boot.resource.RepoInitialization] Failed to initialize SQL suggestions repo [/home/hubert/enso/projects/Unnamed_9/.enso/suggestions.db].
org.sqlite.SQLiteException: [SQLITE_ERROR] SQL error or missing database (table "suggestions_version" already exists)
	at org.sqlite.core.DB.newSQLException(DB.java:1179)
	at org.sqlite.core.DB.newSQLException(DB.java:1190)

To reproduce:

  • start new GUI: npm --workspace=enso-gui2 run dev (and npm install if you haven't done it before)
  • start project manager the usual way
  • open [http://localhost:5173/](local browser)

The problem will occur either during a simple startup of a project or if you attempt to move around some of the nodes, causing edits.

@hubertp hubertp moved this from ❓New to 📤 Backlog in Issues Board Oct 12, 2023
@enso-bot
Copy link

enso-bot bot commented Oct 13, 2023

Dmitry Bushev reports a new STANDUP for yesterday (2023-10-12):

Progress: Starting working on the task. Reproduced the issue in a new IDE. Identified the issue with the initialization components. Finishing the work on PR with the panic visualizations It should be finished by 2023-10-17.

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

@enso-bot
Copy link

enso-bot bot commented Oct 13, 2023

Dmitry Bushev reports a new STANDUP for today (2023-10-13):

Progress: Continue working on the task. Implemented an execution flag for the initialization components. This caused an issue with a bunch of the language server tests because they re-use the same JSON controller for multiple tests in the suite that should be initialized each time. Started working on the fix It should be finished by 2023-10-17.

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

@4e6 4e6 moved this from 📤 Backlog to 🔧 Implementation in Issues Board Oct 16, 2023
@enso-bot
Copy link

enso-bot bot commented Oct 17, 2023

Dmitry Bushev reports a new STANDUP for yesterday (2023-10-16):

Progress: Continue working on the task. Fixed the tests. Implemented blocking initialization of resouces. Found an issue with applying the suggestion database update. Stared debugging the suggestions handler. It should be finished by 2023-10-17.

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

@enso-bot
Copy link

enso-bot bot commented Oct 17, 2023

Dmitry Bushev reports a new STANDUP for today (2023-10-17):

Progress: Continue working on the task. Found an issue with getSuggestionsDatabase command handling. Implemented unique background jobs. Fixed the logic of InvalidateModulesIndexCommand. Tested in a new ide. It should be finished by 2023-10-17.

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

@enso-bot
Copy link

enso-bot bot commented Oct 19, 2023

Dmitry Bushev reports a new 🔴 DELAY for yesterday (2023-10-18):

Summary: There is 3 days delay in implementation of the Initialize suggestions database only once in the presence of multiple clients (#8033) task.
It will cause 3 days delay for the delivery of this weekly plan.

Delay Cause: Fixed various issues with the asynchronous language server initialization and suggestions handling in the new IDE. Refactored the initialization logic to Java.

@enso-bot
Copy link

enso-bot bot commented Oct 19, 2023

Dmitry Bushev reports a new STANDUP for yesterday (2023-10-18):

Progress: Continue working on the task. Refactored blocking initialization component in Java. Refactored the initialization logic from Scala futures to Java. Fixed the message sequence when handling the getSuggestionsDatabase message. It should be finished by 2023-10-20.

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

@enso-bot
Copy link

enso-bot bot commented Oct 19, 2023

Dmitry Bushev reports a new STANDUP for today (2023-10-19):

Progress: Continue working on the task. End up refactoring the initialization logic to Java. Fixed the language server tests. Fixed the initialization of background processing in the new IDE. Fixed the language server tests. Started testing in the IDE. It should be finished by 2023-10-20.

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

@enso-bot
Copy link

enso-bot bot commented Oct 21, 2023

Dmitry Bushev reports a new STANDUP for yesterday (2023-10-20):

Progress: Continue working on the task. Fixed review comments. Fixed runtime tets. Tested once again in both IDEs. It should be finished by 2023-10-20.

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

@mergify mergify bot closed this as completed in #8116 Oct 21, 2023
mergify bot pushed a commit that referenced this issue Oct 21, 2023
close #8033

Changelog:
- update: run language server initialization once
- fix: issues with async `getSuggestionDatabase` message handling in new IDE
- update: implement unique background jobs
- refactor: initialization logic to Java
- refactor: `UniqueJob` to a marker interface
@github-project-automation github-project-automation bot moved this from 🔧 Implementation to 🟢 Accepted in Issues Board Oct 21, 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.

2 participants