More logs to debug suspend issue

app/ydoc-server-nodejs/src/main.ts

@@ -3,13 +3,15 @@
 import './cjs-shim' // must be imported first
 
 import * as http from 'node:http'
-import { createGatewayServer } from 'ydoc-server'
+import { createGatewayServer,  configureAllDebugLogs} from 'ydoc-server'
 
 const DEFAULT_PORT = 5976
 const PORT = (process.env.PORT != null && parseInt(process.env.PORT, 10)) || DEFAULT_PORT
 const HOSTNAME = process.env.GUI_HOSTNAME ?? 'localhost'
 const LANGUAGE_SERVER_URL = process.env.LANGUAGE_SERVER_URL
 
+configureAllDebugLogs(process.env.ENSO_YDOC_LS_DEBUG === 'true')
+
 await runServer()
 
 /** Start http server that handles ydoc websocket connections. */

app/ydoc-server/src/index.ts

@@ -8,7 +8,7 @@
  * server. It is not yet deployed to any other environment.
  */
 
-import debug from 'debug'
+import { default as createDebug, default as debug } from 'debug'
 import type { Server } from 'http'
 import type { Http2SecureServer } from 'http2'
 import type { WebSocket } from 'isomorphic-ws'
@@ -17,14 +17,21 @@ import { ConnectionData, docName } from './auth'
 import { deserializeIdMap } from './serialization'
 import { setupGatewayClient } from './ydoc'
 
+const debugLogIndex = createDebug('ydoc-server:index')
+
 export { deserializeIdMap, docName, setupGatewayClient }
 
 /** @param customLogger Optional external logger to use for all debug logs. */
 export function configureAllDebugLogs(
   forceEnable: boolean,
   customLogger?: (...args: any[]) => any,
 ) {
-  for (const debugModule of ['ydoc-server:session', 'ydoc-shared:languageServer']) {
+  for (const debugModule of [
+    'ydoc-server:session',
+    'ydoc-shared:languageServer',
+    'ydoc-server:index',
+    'ydoc-server:ydoc',
+  ]) {
     const instance = debug(debugModule)
     if (forceEnable) instance.enabled = true
     if (customLogger) instance.log = customLogger
@@ -41,7 +48,11 @@ export async function createGatewayServer(
 
   const wss = new WebSocketServer({ noServer: true })
   wss.on('connection', (ws: WebSocket, _request: IncomingMessage, data: ConnectionData) => {
+    ws.onclose = function close() {
+      debugLogIndex('websocket disconnected @' + data.lsUrl + ' for ' + data.doc)
+    }
     ws.on('error', onWebSocketError)
+    debugLogIndex('new connection: ' + data.doc + ' @ ' + data.lsUrl)
     setupGatewayClient(ws, overrideLanguageServerUrl ?? data.lsUrl, data.doc)
   })
 

app/ydoc-server/src/languageServerSession.ts

@@ -71,7 +71,7 @@
     this.docs = new Map()
     this.retainCount = 0
     this.url = url
-    console.log('new session with', url)
+    debugLog('new session with', url)
     this.indexDoc = new WSSharedDoc()
     this.docs.set('index', this.indexDoc)
     this.model = new DistributedProject(this.indexDoc.doc)
@@ -87,29 +87,31 @@
       }
     })
     this.ls = new LanguageServer(this.clientId, new ReconnectingWebSocketTransport(this.url))
-    this.clientScope.onAbort(() => this.ls.release())
+    this.clientScope.onAbort(() => this.ls.release('unknown'))
     this.setupClient()
   }
 
   static sessions = new Map<string, LanguageServerSession>()
 
   /** Get a {@link LanguageServerSession} by its URL. */
-  static get(url: string): LanguageServerSession {
-    const session = map.setIfUndefined(
-      LanguageServerSession.sessions,
-      url,
-      () => new LanguageServerSession(url),
-    )
-    session.retain()
+  static get(url: string, docName: String): LanguageServerSession {
+    const session = map.setIfUndefined(LanguageServerSession.sessions, url, () => {
+      debugLog('getting a new session for ' + url)
+      return new LanguageServerSession(url)
+    })
+    debugLog('LanguageServerSession.get(' + docName + ')')
+    session.retain(docName)
     return session
   }
 
   private restartClient() {
+    debugLog('Restarting LS session client')
     this.ls.reconnect()
     return exponentialBackoff(() => this.readInitialState())
   }
 
   private setupClient() {
+    debugLog('Setup client')
     this.ls.on('file/event', async event => {
       debugLog('file/event %O', event)
       const result = await this.handleFileEvent(event)
@@ -195,9 +197,10 @@
         if (!files.ok) return files
         moduleOpenPromises = this.indexDoc.doc.transact(
           () =>
-            files.value.map(file =>
-              this.getModuleModel(pushPathSegment(file.path, file.name)).open(),
-            ),
+            files.value.map(file => {
+              debugLog('Reading initial state of ' + file.path + ' @ ' + file.name)
+              return this.getModuleModel(pushPathSegment(file.path, file.name)).open()
+            }),
           this,
         )
         const results = await Promise.all(moduleOpenPromises)
@@ -225,13 +228,16 @@
 
   /** TODO: Add docs */
   getModuleModel(path: Path): ModulePersistence {
+    debugLog('get module model ' + path)
     const name = pathToModuleName(path)
     return map.setIfUndefined(this.authoritativeModules, name, () => {
       const wsDoc = new WSSharedDoc()
+      debugLog('set module model ' + wsDoc.doc.guid + ' for name ' + name)
       this.docs.set(wsDoc.doc.guid, wsDoc)
       this.model.createUnloadedModule(name, wsDoc.doc)
       const mod = new ModulePersistence(this.ls, path, wsDoc.doc)
       mod.once('removed', () => {
+        debugLog('deleting module ' + wsDoc.doc.guid)
         const index = this.model.findModuleByDocId(wsDoc.doc.guid)
         this.docs.delete(wsDoc.doc.guid)
         this.authoritativeModules.delete(name)
@@ -242,19 +248,22 @@
   }
 
   /** TODO: Add docs */
-  retain() {
+  retain(docName: String) {
     this.retainCount += 1
+    debugLog('retain ' + docName + ': ' + this.retainCount)
   }
 
   /** TODO: Add docs */
-  async release(): Promise<void> {
+  async release(docName: String): Promise<void> {
+    debugLog('LanguageServerSession.release() for ' + docName + ', retain: ' + this.retainCount)
     this.retainCount -= 1
     if (this.retainCount !== 0) return
+    debugLog('LanguageServerSession.release(): full cleanup')
     const modules = this.authoritativeModules.values()
     const moduleDisposePromises = Array.from(modules, mod => mod.dispose())
     this.authoritativeModules.clear()
     this.model.doc.destroy()
-    this.clientScope.dispose('LangueServerSession disposed.')
+    this.clientScope.dispose('LanguageServerSession disposed.')
     LanguageServerSession.sessions.delete(this.url)
     await Promise.all(moduleDisposePromises)
   }
@@ -826,13 +835,14 @@
   }
 
   async dispose(): Promise<void> {
+    debugLog('ModulePersistence.dispose() ' + this.doc + ', path: ' + this.path)
     this.cleanup()
     const alreadyClosed = this.inState(LsSyncState.Closing, LsSyncState.Closed)
     this.setState(LsSyncState.Disposed)
     if (alreadyClosed) return Promise.resolve()
-    const closing = await this.ls.closeTextFile(this.path)
-    if (!closing.ok) {
-      closing.error.log(`Closing text file ${this.path}`)
-    }
+    //const closing = await this.ls.closeTextFile(this.path)
+    //if (!closing.ok) {
+    //  closing.error.log(`Closing text file ${this.path}`)
+    //}
   }
 }

app/ydoc-server/src/ydoc.ts

@@ -7,6 +7,7 @@ import {
 import { readSyncMessage, writeSyncStep1, writeUpdate } from 'y-protocols/sync'
 import * as Y from 'yjs'
 
+import createDebug from 'debug'
 import WebSocket from 'isomorphic-ws'
 import * as decoding from 'lib0/decoding'
 import * as encoding from 'lib0/encoding'
@@ -26,6 +27,8 @@ interface AwarenessUpdate {
 
 type ConnectionId = YjsConnection | string
 
+const debugLog = createDebug('ydoc-server:ydoc')
+
 /** A Yjs document that is shared over multiple websocket connections. */
 export class WSSharedDoc {
   doc: Y.Doc
@@ -92,17 +95,19 @@ export class WSSharedDoc {
  * document is considered to be the root document of the `DistributedProject` data model.
  */
 export function setupGatewayClient(ws: WebSocket, lsUrl: string, docName: string) {
-  const lsSession = LanguageServerSession.get(lsUrl)
+  const lsSession = LanguageServerSession.get(lsUrl, docName)
   const wsDoc = lsSession.getYDoc(docName)
   if (wsDoc == null) {
     console.error(`Document '${docName}' not found in language server session '${lsUrl}'.`)
     ws.close()
     return
   }
+  debugLog('Setup gateway for ' + docName + ' @ ' + lsUrl)
   const connection = new YjsConnection(ws, wsDoc)
   connection.once('close', async () => {
     try {
-      await lsSession.release()
+      debugLog('Closing yjs connection to ' + docName)
+      await lsSession.release(docName)
     } catch (error) {
       console.error('Session release failed.\n', error)
     }

app/ydoc-shared/src/languageServer.ts

@@ -590,7 +590,7 @@ export class LanguageServer extends ObservableV2<Notifications & TransportEvents
    * Decrement the reference count of this {@link LanguageServer},
    * disposing it if there are no longer any references to this {@link LanguageServer}.
    */
-  release() {
+  release(docName: String) {
     if (this.retainCount > 0) {
       this.retainCount -= 1
       // Equivalent to `this.isDisposed`, but written out explicitly here to avoid confusion,

engine/language-server/src/main/java/org/enso/languageserver/boot/LanguageServerRunner.java

@@ -2,6 +2,7 @@
 
 import java.util.UUID;
 import org.apache.commons.cli.CommandLine;
+import org.enso.languageserver.boot.config.ApplicationConfig;
 import org.enso.runner.common.LanguageServerApi;
 import org.enso.runner.common.ProfilingConfig;
 import org.enso.runner.common.WrongOption;
@@ -80,6 +81,7 @@ private static LanguageServerConfig parseServerOptions(
             rootPath,
             profilingConfig,
             new StartupConfig(graalVMUpdater),
+            ApplicationConfig.load(),
             "language-server",
             ExecutionContext.global());
     return config;

engine/language-server/src/main/resources/application.conf

@@ -7,6 +7,18 @@ akka {
           idle-timeout = infinite
           remote-address-header = on
           websocket.periodic-keep-alive-max-idle = 1 second
+          linger-timeout = infinite
+      }
+      client {
+          idle-timeout = infinite
+      }
+      host-connection-pool {
+          client {
+              idle-timeout = infinite
+          }
+          idle-timeout = infinite
+          max-connection-lifetime = infinite
+          keep-alive-timeout = infinite
       }
   }
   https {
@@ -75,4 +87,9 @@ language-server {
     port = 1234
     port = ${?LANGUAGE_SERVER_YDOC_PORT}
   }
+
+
+  timeout {
+    delayed-shutdown-timeout = 10 seconds
+  }
 }

engine/language-server/src/main/scala/org/enso/languageserver/boot/LanguageServerApp.scala

@@ -41,8 +41,10 @@ object LanguageServerApp {
         lock.wait()
       }
     } else {
-      StdIn.readLine()
-      stop(server, "stopped by the user")(config.computeExecutionContext)
+      val line = StdIn.readLine()
+      stop(server, "stopped by the user: " + line)(
+        config.computeExecutionContext
+      )
     }
   }
 

engine/language-server/src/main/scala/org/enso/languageserver/boot/LanguageServerComponent.scala

@@ -131,6 +131,7 @@ class LanguageServerComponent(config: LanguageServerConfig, logLevel: Level)
         Future.successful(ComponentStopped)
 
       case Some(serverContext) =>
+        logger.trace("Language Server is terminating")
         for {
           _ <- stopSampling(serverContext)
           _ <- terminateTruffle(serverContext)

engine/language-server/src/main/scala/org/enso/languageserver/boot/LanguageServerConfig.scala

@@ -1,8 +1,10 @@
 package org.enso.languageserver.boot
 
-import java.util.UUID
+import org.enso.languageserver.boot.config.ApplicationConfig
 
+import java.util.UUID
 import org.enso.runner.common.ProfilingConfig
+
 import scala.concurrent.{ExecutionContext, ExecutionContextExecutor}
 
 /**  The config of the running Language Server instance.
@@ -27,6 +29,7 @@ case class LanguageServerConfig(
   contentRootPath: String,
   profilingConfig: ProfilingConfig,
   startupConfig: StartupConfig,
+  appConfig: ApplicationConfig,
   name: String                                      = "language-server",
   computeExecutionContext: ExecutionContextExecutor = ExecutionContext.global
 )

engine/language-server/src/main/scala/org/enso/languageserver/boot/MainModule.scala

@@ -105,6 +105,7 @@ class MainModule(serverConfig: LanguageServerConfig, logLevel: Level) {
     directoriesConfig,
     serverConfig.profilingConfig,
     serverConfig.startupConfig,
+    serverConfig.appConfig,
     openAiCfg
   )
   log.trace("Created Language Server config [{}]", languageServerConfig)
@@ -247,7 +248,8 @@ class MainModule(serverConfig: LanguageServerConfig, logLevel: Level) {
         vcsManager,
         runtimeConnector,
         contentRootManagerWrapper,
-        TimingsConfig.default().withAutoSave(6.seconds)
+        TimingsConfig.default().withAutoSave(6.seconds),
+        languageServerConfig.appConfig.timeout
       ),
       "buffer-registry"
     )

engine/language-server/src/main/scala/org/enso/languageserver/boot/config/ApplicationConfig.scala

@@ -4,23 +4,26 @@ import pureconfig.ConfigSource
 import pureconfig.generic.auto._
 
 /** An `application.conf` configuration. */
-case class ApplicationConfig(ydoc: YdocConfig)
+case class ApplicationConfig(ydoc: YdocConfig, timeout: TimeoutConfig)
 
 object ApplicationConfig {
 
   private val ConfigFilename  = "application.conf"
   private val ConfigNamespace = "language-server"
 
-  def load(): ApplicationConfig = {
+  def load(configFileName: String): ApplicationConfig = {
     val contextClassLoader = Thread.currentThread().getContextClassLoader
     try {
       Thread.currentThread().setContextClassLoader(getClass.getClassLoader)
       ConfigSource
-        .resources(ConfigFilename)
+        .resources(configFileName)
         .withFallback(ConfigSource.systemProperties)
         .at(ConfigNamespace)
         .loadOrThrow[ApplicationConfig]
     } finally Thread.currentThread().setContextClassLoader(contextClassLoader)
   }
 
+  def load(): ApplicationConfig =
+    load(ConfigFilename)
+
 }

engine/language-server/src/main/scala/org/enso/languageserver/boot/config/TimeoutConfig.scala

@@ -0,0 +1,9 @@
+package org.enso.languageserver.boot.config
+
+import scala.concurrent.duration.FiniteDuration
+
+/** A configuration object for timeout properties.
+  *
+  * @param delayedShutdownTimeout a timeout when shutdown, caused by lack of clients, can be cancelled
+  */
+case class TimeoutConfig(delayedShutdownTimeout: FiniteDuration)

engine/language-server/src/main/scala/org/enso/languageserver/data/Config.scala

@@ -2,12 +2,12 @@ package org.enso.languageserver.data
 
 import org.enso.runner.common.ProfilingConfig
 import org.enso.languageserver.boot.StartupConfig
+import org.enso.languageserver.boot.config.ApplicationConfig
 import org.enso.languageserver.filemanager.ContentRootWithFile
 import org.enso.logger.masking.{MaskedPath, ToLogString}
 
 import java.io.File
 import java.nio.file.{Files, Path}
-
 import scala.concurrent.duration._
 
 /** Configuration of the path watcher.
@@ -157,6 +157,7 @@ case class Config(
   directories: ProjectDirectoriesConfig,
   profiling: ProfilingConfig,
   startup: StartupConfig,
+  appConfig: ApplicationConfig,
   aiCompletionConfig: Option[AICompletionConfig]
 ) extends ToLogString {