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

how to reliably catch rejected LanguageClient onReady promise? #825

Closed
lovettchris opened this issue Oct 6, 2021 · 9 comments
Closed

how to reliably catch rejected LanguageClient onReady promise? #825

lovettchris opened this issue Oct 6, 2021 · 9 comments
Milestone

Comments

@lovettchris
Copy link
Member

See leanclient.ts

I'm trying to catch the exception thrown if my client fails to start using try catch, like this:

        this.client = new LanguageClient(
            'lean4',
            'Lean 4',
            serverOptions,
            clientOptions
        )
        try {
            this.client.onDidChangeState((s) =>{
                if (s.newState === State.Starting) {
                    console.log('client starting');
                } else if (s.newState === State.Running) {
                    console.log('client running');
                } else if (s.newState === State.Stopped) {
                    console.log('client has stopped or it failed to start');
                }
            })
            this.client.start()
            await this.client.onReady();
            // if we got this far then the client is happy so we are running!
            this.running = true;
        } catch (error) {
            console.log(error);
            ...
            return;
        }

But it only works sometimes. If I do a clean "Developer: Reload Window" on a project that loads my extension then it fails to work and I see this output in my console log:

client starting
client has stopped or it failed to start
rejected promise not handled within 1 second: Error: write EPIPE
stack trace: Error: write EPIPE
	at afterWriteDispatched (internal/stream_base_commons.js:156:25)
	at writeGeneric (internal/stream_base_commons.js:147:3)
	at Socket._writeGeneric (net.js:785:11)
	at Socket._write (net.js:797:8)
	at writeOrBuffer (internal/streams/writable.js:358:12)
	at Socket.write (internal/streams/writable.js:303:10)
	at d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:13932:29
	at new Promise (<anonymous>)
	at WritableStreamWrapper.write (d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:13922:16)
	at StreamMessageWriter.doWrite (d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:13187:33)
	at d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:13178:29

rejected promise not handled within 1 second: Error [ERR_STREAM_DESTROYED]: Cannot call write after a stream was destroyed
stack trace: Error [ERR_STREAM_DESTROYED]: Cannot call write after a stream was destroyed
	at Socket.write (internal/streams/writable.js:294:11)
	at d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:13932:29
	at new Promise (<anonymous>)
	at WritableStreamWrapper.write (d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:13922:16)
	at StreamMessageWriter.doWrite (d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:13187:33)
	at d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:13178:29

The vscode instance I'm debuggin has this expected output window:

[Error - 10:10:31 PM] Connection to server is erroring. Shutting down server.
'lean' is not recognized as an internal or external command,
operable program or batch file.

If I run this same code to start my LanguageClient from my own command the try/catch works fine and I get this console log output:

client starting
client has stopped or it failed to start
client starting
client has stopped or it failed to start
client starting
client has stopped or it failed to start
client starting
client has stopped or it failed to start
client starting
client has stopped or it failed to start
Error: Connection to server got closed. Server will not be restarted.
	at LanguageClient.handleConnectionClosed (d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:16610:47)
	at LanguageClient.handleConnectionClosed (d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:20462:15)
	at closeHandler (d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:16579:18)
	at CallbackList.invoke (d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:12178:39)
	at Emitter.fire (d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:12240:36)
	at closeHandler (d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:11254:26)
	at CallbackList.invoke (d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:12178:39)
	at Emitter.fire (d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:12240:36)
	at StreamMessageReader.fireClose (d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:12924:27)
	at Socket.<anonymous> (d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:13009:42)
	at Socket.emit (events.js:327:22)
	at Pipe.<anonymous> (net.js:673:12)
	at Pipe.callbackTrampoline (internal/async_hooks.js:131:14)

This is the better expected output and you can see vscode tries to launch my client 5 times as expected and so on. I tried looking at all exceptions thrown but didn't see anything obviously wrong in my code. I also tried setting all breakpoints in my code to see if it is something else responding to some event that did something wrong, but I can't find anything.

Any ideas how to debug this? The unhandled exception seems to be coming from a reject call in WritableStreamWrapper write method:

    write(data, encoding) {
        return new Promise((resolve, reject) => {
            const callback = (error) => {
                if (error === undefined || error === null) {
                    resolve();
                }
                else {
                    reject(error);
                }
            };
            if (typeof data === 'string') {
                this.stream.write(data, encoding, callback);
            }
            else {
                this.stream.write(data, callback);
            }
        });
    }

and this seems to be deep inside the vscode-languageserver implementation to do with rpc or something.
I think the key might be this part of the error:

rejected promise not handled within 1 second: Error: write EPIPE

but I don't know why is not handling it in 1 second...

@dbaeumer
Copy link
Member

dbaeumer commented Oct 6, 2021

@lovettchris which version are you on? 7.0.x.

This version had quite some unhandled promise code (which resulted in this). I fixed this and the new 8.0.x version will handle this a lot better, but is breaking in terms of return values (more methods return a promise and not directly the value). I will post a next version of the library this week after VS Code has shipped stable. I would like to ask you to give it a try and let me know if this improved.

@dbaeumer dbaeumer added the info-needed Issue requires more information from poster label Oct 6, 2021
@lovettchris
Copy link
Member Author

I am using "vscode-languageclient": "^7.0.0". I will try upgrading when your new version comes out, thanks.

@lovettchris
Copy link
Member Author

I was on 7.0.0, so I moved to "vscode-languageclient": "^8.0.0-next.2", and the problem seems to be fixed. My try/catch works reliably now when my server cannot be started. But an interesting thing happens now when my server does start properly, sometimes I get this console output later on when everything is up and running. Perhaps you delayed reporting of the actual rejected promise? How do I find out what promise this is? I guess this is more of a typescript debugging question... How does one find out what (if any) operation my extension initiated that resulted in these stack traces? I suspect it is the StreamMessageReader(serverProcess.stdout) and StreamMessageWriter(serverProcess.stdin) of LanguageClient.createMessageTransports... and I can repro this more easily when I "restart" my client, calling client.stop() on the old one and creating a new LanguageClient to call start and onReady. My server is up and running, and everything seems to be working fine, so perhaps this is just a spurious error from when I closed the old client?

rejected promise not handled within 1 second: Error [ERR_STREAM_WRITE_AFTER_END]: write after end
stack trace: Error [ERR_STREAM_WRITE_AFTER_END]: write after end
	at Socket.write (internal/streams/writable.js:292:11)
	at d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:13994:29
	at new Promise (<anonymous>)
	at WritableStreamWrapper.write (d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:13984:16)
	at StreamMessageWriter.doWrite (d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:13249:33)
	at d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:13240:29

rejected promise not handled within 1 second: Error: Language client is not ready yet
stack trace: Error: Language client is not ready yet
	at LanguageClient.onNotification (d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:16120:19)
	at LeanClient.<anonymous> (d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:10169:25)
	at Generator.next (<anonymous>)
	at fulfilled (d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:9986:58)

@dbaeumer
Copy link
Member

dbaeumer commented Oct 7, 2021

That looks strange. I do the same in my language server (stop and then a start) and didn't see that. Do you have any easy steps to reproduce?

@lovettchris
Copy link
Member Author

I reverted my upgrade to 8.0.0 because some other things stopped working, I probably need to adjust to some LSP api changes or something. But if you want to repro the issue you can get these bits and run them in the vscode debugger with F5, and open a folder containing a file named "Hello.lean" where the file contains this text:

import Leanpkg
#eval Leanpkg.leanVersionString

First you will see this prompt:
image

Click "Install Lean" and you should see some options, press "1" and ENTER, and "ENTER" a couple more times and you should see the Lean server come up with a message "Lean (version 4.0.0-nightly-2021-10-07, commit 7f660af4c6d3, Release)".

Cool, so boot strapping worked, but now run: Ctrl+sHIFT+P , "Lean 4: Select Interpreter", leave the string "lean" and hit ENTER. and you will see the client has stopped, starting, running, but then after that this error appears:

rejected promise not handled within 1 second: Error [ERR_STREAM_WRITE_AFTER_END]: write after end
c:\Users\clovett\AppData\Local\Programs\Microsoft VS Code\resources\app\out\bootstrap-fork.js:5
stack trace: Error [ERR_STREAM_WRITE_AFTER_END]: write after end
	at Socket.write (internal/streams/writable.js:292:11)
	at d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:14070:29
	at new Promise (<anonymous>)
	at WritableStreamWrapper.write (d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:14060:16)
	at StreamMessageWriter.doWrite (d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:13325:33)
	at d:\git\leanprover\vscode-lean4\vscode-lean4\out\extension.js:13316:29
	at runNextTicks (internal/process/task_queues.js:58:5)
	at processImmediate (internal/timers.js:434:9)
	at process.callbackTrampoline (internal/async_hooks.js:131:14)

PS: windows defender started a false positive attack on our github zip file today, (which I'm looking into) but you can override the quarantine using an admin command prompt if you run

"%ProgramFiles%\Windows Defender\MpCmdRun.exe" -Restore -Name "Trojan:Script/Oneeva.A!ml" -ALL

@lovettchris
Copy link
Member Author

lovettchris commented Oct 7, 2021

Oh, man, never mind, I did the upgrade to 8.0.0 properly this time and added some missing 'void' to some client.sendNotification calls, as per the release notes, and now this error is gone! So it looks like 8.0.0 is the fix, can you resolve this open issue after you post the official 8.0.0 release?

@dbaeumer dbaeumer added this to the 3.17 milestone Oct 8, 2021
@dbaeumer dbaeumer removed the info-needed Issue requires more information from poster label Oct 8, 2021
@dbaeumer
Copy link
Member

dbaeumer commented Oct 8, 2021

Thanks for getting back. I will close it and label for 3.17 which is the LSP release number

@dbaeumer dbaeumer closed this as completed Oct 8, 2021
@lovettchris
Copy link
Member Author

@dbaeumer, any idea why this version of the LSP requires such a recent version of vscode (only 13 days old)? my customers are complaining my extension wont work on their version of vscode...?

@dbaeumer
Copy link
Member

@lovettchris the extension has support for type hierarchies which are available since that latest version of VS Code. That is why it prereqs 1.61.0

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

No branches or pull requests

2 participants