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

Server hangs after a burst of editing followed by a period of inactivity, emacs client #2431

Closed
gnuemacscoin opened this issue Feb 2, 2023 · 9 comments

Comments

@gnuemacscoin
Copy link

Since I upgraded to java 11, and then later 17, every jdtls version I try tends to hang after editing a little bit of code, and then leaving the editor idle for around 10 minutes. First it'll stop responding to textDocument/hovers, textDocument/codeActions and textDocument/documentHighlights, but will keep responding to their cancelRequests. Then it'll process and send diagnostics for one final textDocument/didChange, and after that it'll stop reading from standard input, eventually hanging my editor.

Launched with

/usr/bin/java -Declipse.application=org.eclipse.jdt.ls.core.id1 -Dosgi.bundles.defaultStartLevel=4 -Declipse.product=org.eclipse.jdt.ls.core.product -Dosgi.checkConfiguration=true -Dosgi.sharedConfiguration.area.readOnly=true -Dosgi.configuration.cascaded=true -Xms1G -jar /home/my/.emacs.d/.cache/lsp/eclipse.jdt.ls/plugins/org.eclipse.equinox.launcher_1.6.400.v20210924-0641.jar -configuration /home/my/.emacs.d/.cache/lsp/eclipse.jdt.ls/config_linux -data /home/my/.emacs.d/workspace/ --add-modules=ALL-SYSTEM --add-opens java.base/java.util=ALL-UNNAMED --add-opens java.base/java.lang=ALL-UNNAMED

Taken from https://download.eclipse.org/jdtls/snapshots/jdt-language-server-1.20.0-202302020244.tar.gz, but also occurs under https://download.eclipse.org/jdtls/milestones/1.12.0/jdt-language-server-1.12.0-202206011637.tar.gz.

@rgrunber
Copy link
Contributor

rgrunber commented Feb 2, 2023

1.12.0 was the last language server version to support starting up with a Java 11 runtime. If you're running 1.12.0 under Java 17, there might be some issues. I would maybe try the same with 1.13.0 if possible, or even the more recent 1.19.0.

Also, is there a file at /home/my/.emacs.d/workspace/.metadata/.log that gives any relevant information. Could be some hints in there regarding why this happens.

@gnuemacscoin
Copy link
Author

Unfortunately I found nothing unusual in the .log, but here it is, along with a more informative log that emacs (lsp-mode) made about one such session.

jdtls-1.19.log.txt
jdtls-1.19.emacs.log.txt

  • java: OpenJDK Temurin-17.0.6+10
  • kernel: Linux version 6.1.6-artix1-1
java -Declipse.application=org.eclipse.jdt.ls.core.id1 -Dosgi.bundles.defaultStartLevel=4 -Declipse.product=org.eclipse.jdt.ls.core.product -Dlog.protocol=true -Dlog.level=ALL -Dosgi.checkConfiguration=true -Dosgi.sharedConfiguration.area.readOnly=true -Dosgi.configuration.cascaded=true -Xms1G -jar /home/username/.emacs.d/.cache/lsp/eclipse.jdt.ls/plugins/org.eclipse.equinox.launcher_1.6.400.v20210924-0641.jar -configuration /home/username/.emacs.d/.cache/lsp/eclipse.jdt.ls/config_linux -data /home/username/.emacs.d/workspace/ --add-modules=ALL-SYSTEM --add-opens java.base/java.util=ALL-UNNAMED --add-opens java.base/java.lang=ALL-UNNAMED

@snjeza
Copy link
Contributor

snjeza commented Feb 2, 2023

@gnuemacscoin Are you using maven? If so, can you show your pom.xml?

@rgrunber
Copy link
Contributor

rgrunber commented Feb 2, 2023

From the client/server communication, it looks like the client initiated a shutdown, followed by an exit. It doesn't look like the server responded to the shutdown request, but I don't think that's necessarily required. Once a shutdown is sent, and processed the server will not respond to any requests, except exit. See https://microsoft.github.io/language-server-protocol/specifications/lsp/3.17/specification/#shutdown .

[Trace - 07:29:20 PM] Sending request 'shutdown - (44391)'.
Params: {}


[Trace - 07:29:21 PM] Sending notification '$/cancelRequest'.
Params: {
  "id": 44391
}


[Trace - 07:29:21 PM] Sending notification 'exit'.
Params: null


[Trace - 07:30:20 PM] Sending notification '$/cancelRequest'.
Params: {
  "id": 44390
}

There's an attempt to cancel the shutdown but I don't think the protocol would support that. If you didn't close your client window, then I think it's an issue of figuring out what triggered the shutdown, since it looks to have come from the client.

@gnuemacscoin
Copy link
Author

gnuemacscoin commented Feb 2, 2023

Here's pom along with logs from a brand new session, complete from start to finish this time.
So I open some java file, navigate around for a bit, then type out this snippet

    @Bean
    protected IntegrationFlow someFlow() {
        return IntegrationFlow
            .from("someinput")
            .log()
            .channel("someOutput")
            .get();
    }

then I wait for 15 minutes (starting with [Trace - 09:15:34 PM] in the emacs log), check back on it to find that diagnostics are gone, insert a single space in the middle of some symbol ([Trace - 09:16:03 PM]), get the final diagnostic back, and then the server stops responding.

Note that using gradle doesn't fix anything.
logs-and-pom.tar.gz

@snjeza
Copy link
Contributor

snjeza commented Feb 2, 2023

@gnuemacscoin Could you reproduce the issue when opening your project with VS Code?

@gnuemacscoin
Copy link
Author

I couldn't reproduce it with VS Code, though I'm not too familiar with the editor. On Emacs side I'm confident that v1.7.0 is the milestone release that introduced this bug, v1.6.0 works fine (with JRE 17). Will try to bisect further.

@gnuemacscoin
Copy link
Author

gnuemacscoin commented Feb 9, 2023

Here's an update. Commit 238b06f7632213e3be32dec53ee17d619b8d5a2c reduced the delay until jdt would be sent document changes from a fixed 400ms to a computed average, which stabilises to around 21ms on my machine, which is usually less than the interval between two keystrokes.

I went and tried to debug this using vscode to attach to jdt.ls in emacs (with -Xdebug -Xrunjdwp:transport=dt_socket,server=y,suspend=y,address=1044), and what I found was a bunch of lsp4j futures hanging the common-pool threads

While executing

	// id: "_java.reloadBundles.command"
	// params: []
	public Object executeClientCommand(String id, Object... params) {
		return this.client.executeClientCommand(new ExecuteCommandParams(id, ImmutableList.copyOf(params))).join();
	}

one thread hangs with trace

Thread[Worker-0: Checking Project Encoding]
  Unsafe.park(boolean,long)[native method] (Unknown Source:-1)
  LockSupport.park(Object) (Unknown Source:211)
  CompletableFuture$Signaller.block() (Unknown Source:1864)
  ForkJoinPool.unmanagedBlock(ForkJoinPool$ManagedBlocker) (Unknown Source:3463)
  ForkJoinPool.managedBlock(ForkJoinPool$ManagedBlocker) (Unknown Source:3434)
  CompletableFuture.waitingGet(boolean) (Unknown Source:1898)
  CompletableFuture.join() (Unknown Source:2117)
  JavaClientConnection.executeClientCommand(String,Object[]) (/home/username/alien/code/java/.eval/eclipse.jdt.ls/org.eclipse.jdt.ls.core/src/org/eclipse/jdt/ls/core/internal/JavaClientConnection.java:101)
  JDTLanguageServer.synchronizeBundles() (/home/username/alien/code/java/.eval/eclipse.jdt.ls/org.eclipse.jdt.ls.core/src/org/eclipse/jdt/ls/core/internal/handlers/JDTLanguageServer.java:391)
  JDTLanguageServer$2.run(IProgressMonitor) (/home/username/alien/code/java/.eval/eclipse.jdt.ls/org.eclipse.jdt.ls.core/src/org/eclipse/jdt/ls/core/internal/handlers/JDTLanguageServer.java:286)
  Worker.run() (/org.eclipse.core.jobs_3.13.300.v20230111-0823.jar/org.eclipse.core.internal.jobs/Worker.class:63)```

Similarly, at least 3 threads hang while executing

	// configurationParams:
	//   items:
	//     - scopeUri: "file:///home/username/alien/code/java/.eval/eval-messaging-and-integration/src/main/java/me/abcdef/eval/EvalMessagingAndIntegrationApplication.java"
	//       section: "java.format.tabSize"
	//     - scopeUri: "file:///home/username/alien/code/java/.eval/eval-messaging-and-integration/src/main/java/me/abcdef/eval/EvalMessagingAndIntegrationApplication.java"
	//       section: "java.format.insertSpaces"
	public List<Object> configuration(ConfigurationParams configurationParams) {
        	this.client.configuration(configurationParams).join();
	}

with traces like

Thread[ForkJoinPool.commonPool-worker-<n>]
  Unsafe.park(boolean,long)[native method] (Unknown Source:-1)
  LockSupport.park(Object) (Unknown Source:211)
  CompletableFuture$Signaller.block() (Unknown Source:1864)
  ForkJoinPool.compensatedBlock(ForkJoinPool$ManagedBlocker) (Unknown Source:3449)
  ForkJoinPool.managedBlock(ForkJoinPool$ManagedBlocker) (Unknown Source:3432)
  CompletableFuture.waitingGet(boolean) (Unknown Source:1898)
  CompletableFuture.join() (Unknown Source:2117)
  JavaClientConnection.configuration(ConfigurationParams) (/home/username/alien/code/java/.eval/eclipse.jdt.ls/org.eclipse.jdt.ls.core/src/org/eclipse/jdt/ls/core/internal/JavaClientConnection.java:221)
  ConfigurationHandler.getFormattingOptions(String) (/home/username/alien/code/java/.eval/eclipse.jdt.ls/org.eclipse.jdt.ls.core/src/org/eclipse/jdt/ls/core/internal/handlers/ConfigurationHandler.java:56)
  CodeActionHandler.getCodeActionCommands(CodeActionParams,IProgressMonitor) (/home/username/alien/code/java/.eval/eclipse.jdt.ls/org.eclipse.jdt.ls.core/src/org/eclipse/jdt/ls/core/internal/handlers/CodeActionHandler.java:103)
  JDTLanguageServer.lambda$15(CodeActionHandler,CodeActionParams,IProgressMonitor) (/home/username/alien/code/java/.eval/eclipse.jdt.ls/org.eclipse.jdt.ls.core/src/org/eclipse/jdt/ls/core/internal/handlers/JDTLanguageServer.java:705)
  0x00000008006077f0.apply(Object) (Unknown Source:-1)
  BaseJDTLanguageServer.Obsolete method()[native method] (/home/username/alien/code/java/.eval/eclipse.jdt.ls/org.eclipse.jdt.ls.core/src/org/eclipse/jdt/ls/core/internal/BaseJDTLanguageServer.java:-1)
  0x00000008005968c0.apply(Object) (Unknown Source:-1)
  CompletableFuture$UniApply.tryFire(int) (Unknown Source:646)
  CompletableFuture$Completion.exec() (Unknown Source:483)
  ForkJoinTask.doExec() (Unknown Source:373)
  ForkJoinPool$WorkQueue.topLevelExec(ForkJoinTask,ForkJoinPool$WorkQueue) (Unknown Source:1182)
  ForkJoinPool.scan(ForkJoinPool$WorkQueue,int,int) (Unknown Source:1655)
  ForkJoinPool.runWorker(ForkJoinPool$WorkQueue) (Unknown Source:1622)

Then, 13 minutes later, I'm guessing this blockage catches up with the pool, causing CompletableFutures.computeAsync to fail to execute its code lambda argument (as evidenced by breakpoints on JobHelpers.waitForJobs not triggering).

To reproduce, try M-: (setf lsp-idle-delay 0 company-idle-delay 0 company-tooltip-idle-delay 0 lsp-ui-doc-delay 0 lsp-ui-sideline-delay 0) on top of the standard lsp-java configuration in emacs.

@gnuemacscoin gnuemacscoin changed the title Server hangs on java 11 and java 17 after a period of inactivity Server hangs after a burst of editing followed by a period of inactivity, emacs client Feb 9, 2023
@gnuemacscoin
Copy link
Author

Closing as this is on lsp-mode for sometimes dropping server sent requests, leaving .join() calls hanging, and breaking compliance with the jsonrpc spec.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants