search

eclipse / lsp4e

Language Server Protocol support in Eclipse IDE
Eclipse Public License 2.0
57 stars 54 forks source link

Could not get trigger characters due to timeout after 50 milliseconds #993

Open kohlschuetter opened 2 months ago

kohlschuetter commented 2 months ago

Seen about 14 times in the log

Could not get trigger characters due to timeout after 50 milliseconds

java.util.concurrent.TimeoutException
    at java.base/java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1960)
    at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2095)
    at org.eclipse.lsp4e.operations.completion.LSContentAssistProcessor.getFuture(LSContentAssistProcessor.java:330)
    at org.eclipse.lsp4e.operations.completion.LSContentAssistProcessor.getCompletionProposalAutoActivationCharacters(LSContentAssistProcessor.java:366)
    at org.eclipse.jface.text.contentassist.IContentAssistProcessorExtension$1.isCompletionProposalAutoActivation(IContentAssistProcessorExtension.java:115)
    at org.eclipse.jface.text.contentassist.ContentAssistant.getAutoActivationTriggerType(ContentAssistant.java:1249)
    at org.eclipse.jface.text.contentassist.ContentAssistant$AutoAssistListener.keyPressed(ContentAssistant.java:346)
    at org.eclipse.jface.text.contentassist.ContentAssistant$InternalListener.verifyKey(ContentAssistant.java:835)
    at org.eclipse.jface.text.TextViewer$VerifyKeyListenersManager.verifyKey(TextViewer.java:482)
    at org.eclipse.swt.custom.StyledTextListener.handleEvent(StyledTextListener.java:68)
    at org.eclipse.swt.widgets.EventTable.sendEvent(EventTable.java:91)
    at org.eclipse.swt.widgets.Display.sendEvent(Display.java:4660)
    at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:1622)
    at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:1645)
    at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:1630)
    at org.eclipse.swt.widgets.Widget.notifyListeners(Widget.java:1392)
    at org.eclipse.swt.custom.StyledText.handleKeyDown(StyledText.java:5736)
    at org.eclipse.swt.custom.StyledText.lambda$28(StyledText.java:5420)
    at org.eclipse.swt.widgets.EventTable.sendEvent(EventTable.java:91)
    at org.eclipse.swt.widgets.Display.sendEvent(Display.java:4660)
    at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:1622)
    at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:1645)
    at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:1630)
    at org.eclipse.swt.widgets.Widget.sendKeyEvent(Widget.java:1659)
    at org.eclipse.swt.widgets.Control.insertText(Control.java:2090)
    at org.eclipse.swt.widgets.Canvas.insertText(Canvas.java:291)
    at org.eclipse.swt.widgets.Display.windowProc(Display.java:6441)
    at org.eclipse.swt.internal.cocoa.OS.objc_msgSend(Native Method)
    at org.eclipse.swt.internal.cocoa.NSResponder.interpretKeyEvents(NSResponder.java:59)
    at org.eclipse.swt.widgets.Composite.keyDown(Composite.java:607)
    at org.eclipse.swt.widgets.Display.windowProc(Display.java:6289)
    at org.eclipse.swt.internal.cocoa.OS.objc_msgSendSuper(Native Method)
    at org.eclipse.swt.widgets.Widget.callSuper(Widget.java:239)
    at org.eclipse.swt.widgets.Widget.windowSendEvent(Widget.java:2362)
    at org.eclipse.swt.widgets.Shell.windowSendEvent(Shell.java:2502)
    at org.eclipse.swt.widgets.Display.windowProc(Display.java:6401)
    at org.eclipse.swt.internal.cocoa.OS.objc_msgSendSuper(Native Method)
    at org.eclipse.swt.widgets.Display.applicationSendEvent(Display.java:5705)
    at org.eclipse.swt.widgets.Display.applicationProc(Display.java:5845)
    at org.eclipse.swt.internal.cocoa.OS.objc_msgSend(Native Method)
    at org.eclipse.swt.internal.cocoa.NSApplication.sendEvent(NSApplication.java:117)
    at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:4000)
    at org.eclipse.e4.ui.internal.workbench.swt.PartRenderingEngine$5.run(PartRenderingEngine.java:1151)
    at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:339)
    at org.eclipse.e4.ui.internal.workbench.swt.PartRenderingEngine.run(PartRenderingEngine.java:1042)
    at org.eclipse.e4.ui.internal.workbench.E4Workbench.createAndRunUI(E4Workbench.java:152)
    at org.eclipse.ui.internal.Workbench.lambda$3(Workbench.java:639)
    at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:339)
    at org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:546)
    at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:173)
    at org.eclipse.ui.internal.ide.application.IDEApplication.start(IDEApplication.java:152)
    at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:208)
    at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:143)
    at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:109)
    at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:439)
    at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:271)
    at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
    at java.base/java.lang.reflect.Method.invoke(Method.java:580)
    at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:679)
    at org.eclipse.equinox.launcher.Main.basicRun(Main.java:616)
    at org.eclipse.equinox.launcher.Main.run(Main.java:1492)

along with

Could get code actions due to timeout after 300 milliseconds in textDocument/codeAction

java.util.concurrent.TimeoutException
    at java.base/java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1960)
    at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2095)
    at org.eclipse.lsp4e.operations.codeactions.LSPCodeActionMarkerResolution.checkMarkerResolution(LSPCodeActionMarkerResolution.java:154)
    at org.eclipse.lsp4e.operations.codeactions.LSPCodeActionMarkerResolution.hasResolutions(LSPCodeActionMarkerResolution.java:208)
    at org.eclipse.ui.internal.ide.registry.MarkerHelpRegistry.hasResolution(MarkerHelpRegistry.java:263)
    at org.eclipse.ui.internal.ide.registry.MarkerHelpRegistry.hasResolutions(MarkerHelpRegistry.java:236)
    at org.eclipse.ui.views.markers.MarkerField.annotateImage(MarkerField.java:86)
    at org.eclipse.ui.internal.views.markers.MarkerProblemSeverityAndMessageField.update(MarkerProblemSeverityAndMessageField.java:78)
    at org.eclipse.ui.internal.views.markers.MarkerColumnLabelProvider.update(MarkerColumnLabelProvider.java:54)
    at org.eclipse.jface.viewers.ViewerColumn.refresh(ViewerColumn.java:149)
    at org.eclipse.jface.viewers.AbstractTreeViewer.doUpdateItem(AbstractTreeViewer.java:1000)
    at org.eclipse.ui.internal.views.markers.MarkersTreeViewer.doUpdateItem(MarkersTreeViewer.java:62)
    at org.eclipse.jface.viewers.AbstractTreeViewer$UpdateItemSafeRunnable.run(AbstractTreeViewer.java:158)
    at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:47)
    at org.eclipse.jface.util.SafeRunnable.run(SafeRunnable.java:174)
    at org.eclipse.jface.viewers.AbstractTreeViewer.doUpdateItem(AbstractTreeViewer.java:1073)
    at org.eclipse.jface.viewers.StructuredViewer$UpdateItemSafeRunnable.run(StructuredViewer.java:426)
    at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:47)
    at org.eclipse.jface.util.SafeRunnable.run(SafeRunnable.java:174)
    at org.eclipse.jface.viewers.StructuredViewer.updateItem(StructuredViewer.java:2111)
    at org.eclipse.jface.viewers.AbstractTreeViewer.createTreeItem(AbstractTreeViewer.java:894)
    at org.eclipse.jface.viewers.AbstractTreeViewer.createChildren(AbstractTreeViewer.java:872)
    at org.eclipse.jface.viewers.TreeViewer.createChildren(TreeViewer.java:611)
    at org.eclipse.jface.viewers.AbstractTreeViewer.internalConditionalExpandToLevel(AbstractTreeViewer.java:1858)
    at org.eclipse.jface.viewers.AbstractTreeViewer.internalExpandToLevel(AbstractTreeViewer.java:1892)
    at org.eclipse.jface.viewers.AbstractTreeViewer.expandToLevel(AbstractTreeViewer.java:1167)
    at org.eclipse.jface.viewers.AbstractTreeViewer.expandToLevel(AbstractTreeViewer.java:1139)
    at org.eclipse.ui.internal.views.markers.ExtendedMarkersView.reexpandCategories(ExtendedMarkersView.java:1172)
    at org.eclipse.ui.internal.views.markers.UIUpdateJob.runInUIThread(UIUpdateJob.java:105)
    at org.eclipse.ui.progress.UIJob.lambda$0(UIJob.java:148)
    at org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:40)
    at org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:132)
    at org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:4382)
    at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:4005)
    at org.eclipse.e4.ui.internal.workbench.swt.PartRenderingEngine$5.run(PartRenderingEngine.java:1151)
    at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:339)
    at org.eclipse.e4.ui.internal.workbench.swt.PartRenderingEngine.run(PartRenderingEngine.java:1042)
    at org.eclipse.e4.ui.internal.workbench.E4Workbench.createAndRunUI(E4Workbench.java:152)
    at org.eclipse.ui.internal.Workbench.lambda$3(Workbench.java:639)
    at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:339)
    at org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:546)
    at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:173)
    at org.eclipse.ui.internal.ide.application.IDEApplication.start(IDEApplication.java:152)
    at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:208)
    at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:143)
    at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:109)
    at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:439)
    at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:271)
    at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
    at java.base/java.lang.reflect.Method.invoke(Method.java:580)
    at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:679)
    at org.eclipse.equinox.launcher.Main.basicRun(Main.java:616)
    at org.eclipse.equinox.launcher.Main.run(Main.java:1492)
eclipse.buildId=4.32.0.20240502-0721
java.version=21.0.3
java.vendor=Eclipse Adoptium
BootLoader constants: OS=macosx, ARCH=aarch64, WS=cocoa, NL=en_US
Framework arguments:  -product org.eclipse.epp.package.jee.product -keyring /Users/ck/.eclipse_keyring
Command-line arguments:  -os macosx -ws cocoa -arch aarch64 -product org.eclipse.epp.package.jee.product -keyring /Users/ck/.eclipse_keyring
rubenporras commented 2 months ago

Hi @kohlschuetter ,

the logging of this warnings is the normal behavior if the language server is not fast enough to respond in the expected timeframe (50 and 300ms). What would you expect otherwise LSP4E to do, other than logging the problem, if the server does not respond?

Regards

kohlschuetter commented 2 months ago

Thanks for looking into this, @rubenporras!

How exactly actionable is this message? If it's not actionable or even considered normal, why log it in the first place?

Imagine you have a very slow system, and LSP4E always responds outside the expected timeframes. What gives? Does it still respond, or is the action discarded? If all we do is to fill the logs / the Error Log view with these messages, then we just make everything even slower. Or just more noisy (the Error Log view is usually empty for me, so this message just stood out)

In my case, I believe these errors showed up after resuming from a longer device sleep, so a different problem. Well, if the delay is not in the order of milliseconds but minutes, again, what gives?

I think that such conditions should be logged via incrementing counter and then be coalesced separately (for some kind of telemetry), if logged at all.

mickaelistria commented 2 months ago

If it's not actionable or even considered normal, why log it in the first place?

I don't think it's considered normal. The language server is expected to report promptly. When it's not the case, it can be perceived as a bug. But this is indeed not actionable by end-user (hence why it's a log, not a UI element)

LSP4E always responds outside the expected timeframes.

It's not LSP4E that responds, but the language server. Most of them are fast enough.

I think that such conditions should be logged via incrementing counter and then be coalesced separately (for some kind of telemetry)

Improving how things are logged would be welcome. What we want is that 1. curious users notice, interpret and report it as a bug of the underlying language server while 2. not breaking other bits of their workflow. Under those conditions, any improvement is welcome.

kohlschuetter commented 2 months ago

@mickaelistria

Without a reproducible code fragment at hand, it would be helpful to log the actual delay encountered when throwing/logging this exception.

These are really two different cases if the timeout is minutes versus milliseconds.