Solution to the typescript issue (hopefully)

[bockstaller]

This is more of an investigation report than a bug report, so please excuse me for not using the template.

Issue Description

The gauge ecosystem (gauge, gauge-vscode) has its issues 1, 2 and 3 with the inofficial gauge-ts plugin.

The common theme across these issues is these three lines.

2021/09/13 15:56:41 jsonrpc2: protocol error: read /dev/stdin: resource temporarily unavailable
2021/09/13 15:56:41 jsonrpc2 handler: sending response 0: jsonrpc2: connection is closed
[Info  - 3:56:41 PM] Connection to server got closed. Server will restart.

Which are repeated in lsp.log for each plugin reload.
This is only an issue for projects using @BugDiver gauge-ts plugin.
In previous cases, this behaviour was fixed by tuning the templates package.json, which pinned the typescript/ts-node dependencies to old versions.

Motivation

The blessed configuration got quite old; maybe it is time to upgrade.
So, I set up a test project with current versions and dug in.

Investigation

Taking a look at the log lines above and this

architecture drawing points towards an issue between gauge and gauge-vscode. It is the only part where the systems communicate via stdio and use jsonrpc2.
This means that for some reason, gauge isn't able to connect to its stdin.
But this is only the case for ts projects.

Dead End / Tangent 1 -> Upgrading `gauge-vscode`

So maybe it is a weird interaction between the project under tests `node_modules` and the `gauge-vscode` plugin. So I upgraded the `gauge-vscode` plugin (I'll open a PR), got the tests running, and no luck

Projects using the python plugin run smoothly.
So maybe the plugins are launched differently...

Dead End / Tangent 2 -> Plugin launch method

The `launcher.js` script of the `gauge-ts` plugin is quite complicated in comparison to the straightforward shell script used by `gauge-python`. I wasted a lot of time investigating the minutia of `child_process.spawn`, the stdio blocking/non-blocking behavior of `node.js`, and rewriting `launcher.js` to a shell script,... No luck.

So it isn't gauge-vscode, and all plugins are launched the same way.
It's time to dive into gauge-ts and look at its startup procedure.

I added print statements to inspect the StaticLoader component and used the tracing options of grpc-node to get information about the communication between gauge and gauge-vscode.

...
25-10-2023 14:37:18.227 [ts] [INFO] /private/tmp/rep/fuse/src/rep/everest.base.test/test/e2e/steps/entity/EntityDeleteSteps.evertest.ts
25-10-2023 14:37:18.228 [ts] [INFO] /private/tmp/rep/fuse/src/rep/everest.base.test/test/e2e/steps/entity/EntityDetailedSteps.evertest.ts
25-10-2023 14:37:18.228 [ts] [INFO] /private/tmp/rep/fuse/src/rep/everest.base.test/test/e2e/steps/home/steps.evertest.ts
25-10-2023 14:37:18.229 [ts] [INFO] Loaded Implementations
25-10-2023 14:37:18.229 [ts] [ERROR] D 2023-10-25T12:37:18.229Z | v1.9.6 44954 | server | (1) Server constructed
25-10-2023 14:37:18.232 [ts] [ERROR] D 2023-10-25T12:37:18.232Z | v1.9.6 44954 | server | (1) Successfully bound 127.0.0.1:56139
25-10-2023 14:37:18.232 [Gauge] [DEBUG] Attempting to connect to grpc server at port: 56139
25-10-2023 14:37:18.234 [Gauge] [DEBUG] Successfully made the connection with runner with port: 56139
25-10-2023 14:37:18.234 [Gauge] [INFO] started
25-10-2023 14:37:18.234 [Gauge] [INFO] LangServer: reading on stdin, writing on stdout
25-10-2023 14:37:18.235 [Gauge] [DEBUG] jsonrpc2: --> request #0: initialize: {"capabilities": [... omitted]}
25-10-2023 14:37:18.235 [Gauge] [DEBUG] jsonrpc2: protocol error: read /dev/stdin: resource temporarily unavailable
25-10-2023 14:37:18.235 [Gauge] [DEBUG] jsonrpc2 handler: sending response 0: jsonrpc2: connection is closed
25-10-2023 14:37:18.236 [ts] [ERROR] D 2023-10-25T12:37:18.236Z | v1.9.6 44954 | server | (1) Received call to method /gauge.messages.Runner/Kill at address null
25-10-2023 14:37:18.236 [ts] [ERROR] D 2023-10-25T12:37:18.236Z | v1.9.6 44954 | server_call | Request to /gauge.messages.Runner/Kill received headers {"content-type":["application/grpc"],"user-agent":["grpc-go/1.59.0"],"te":["trailers"]}
25-10-2023 14:37:18.238 [ts] [ERROR] D 2023-10-25T12:37:18.238Z | v1.9.6 44954 | server_call | Request to method /gauge.messages.Runner/Kill ended with status code: OK details: OK
25-10-2023 14:37:18.238 [ts] [ERROR] D 2023-10-25T12:37:18.238Z | v1.9.6 44954 | server_call | Request to method /gauge.messages.Runner/Kill stream closed with rstCode 0
25-10-2023 14:37:18.238 [Gauge] [INFO] Connection closed
25-10-2023 14:37:18.238 [Gauge] [ERROR] Unable to log error 'Connection closed' to LSP: jsonrpc2: connection is closed
25-10-2023 14:37:18.892 [Gauge] [INFO] Initializing concepts cache with 45 concepts
...
[restart gauge-vscode]

We can see that the StaticLoader is doing its thing and loads the implementations successfully.
Then we see that gauge-ts is starting its grpc server and binding it to port 56139. (ignore the ERROR state of the tracing loglines).
gauge is connecting to this grpc server and reaches a state where it is started and reading on stdin, writing on stdout.
Then we get the already known three error lines:

25-10-2023 14:37:18.235 [Gauge] [DEBUG] jsonrpc2: --> request #0: initialize: {"capabilities": [...]}
25-10-2023 14:37:18.235 [Gauge] [DEBUG] jsonrpc2: protocol error: read /dev/stdin: resource temporarily unavailable
25-10-2023 14:37:18.235 [Gauge] [DEBUG] jsonrpc2 handler: sending response 0: jsonrpc2: connection is closed

Dead End / Tangent 3 -> Upgrading `gauge-ts`

I upgraded `gauge-ts` as well (I'll open a PR). Just to be safe... No luck

To recapitulate:

• it isn't gauge-vscode specific behaviour
• gauge-ts is launched the same way as the other plugins
• gauge-ts is launching without an issue and connects to gauge and is only killed afterward during the teardown of gauge after its crash.

So let's look at gauge...

The Smoking Gun

Where everything looks fine until we reach prepareCommand
with the culprit of the situation cmd.Stdin = os.Stdin.

Now everything makes sense:

1. gauge-vscode starts gauge and prepares to communicate with gauge using stdio.
2. gauge starts itself
3. gauge launches the gauge-ts plugin and uses prepareCommand in the process. The cmd.Stdin = os.Stdin statements connect the stdin of gauge, intended for the jsonrpc2 communication to vscode, to the gauge-ts process.
4. gauge is done with its initialization and wants to access its stdin to establish the connection to vscode. But - ruh roh - this stdin is already passed along to gauge-ts...

But Why

...is gauge-ts the only language plugin affected by this behavior.
My understanding is that node.js is the only runtime that interacts with the stdin file descriptor in a way that makes it not temporarily unavailable for go.

How to Solve the Problem

The cmd.Stdin = os.Stdin line was added by @sriv to getgauge/common in response to this issue getgauge/gauge-ruby#11

Nevertheless, the issue was solved in this commit getgauge/gauge-ruby@272b743 directly in the gauge-ruby repository without relying on getgauge/common.

Therefore, I think it is possible to remove the cmd.Stdin = os.Stdin line without breaking anything.

Way Forward

I'll verify the fix tomorrow with a fresh system and will create some PRs afterward across the different repositories.
@zabil, @sriv, @saikrishna321, @NivedhaSenthil, @BugDiver Feedback is more than welcome!

[sriv]

Thanks for the detailed report and more importantly the painful debugging. I remember having to make the change in common to allow cli based debugger such as Ruby pry to work within a gauge execution.

I don't recall offhand the reason gauge-ruby bypassed the use of common, but I think it's a safe change to make since AFAIK no other plugin uses stdin the way Ruby does.

Look forward to the results of your further changes. Thanks again!

[mholetzko]

@bockstaller thanks a lot for the detailed investigation 🙌

[mholetzko]

🫶

[zabil]

@bockstaller, this report made my day :)

[bockstaller]

Thank you very much for the great response!
I'll start on implementing the changes and will track my progress in this issue.

• Update getgauge/common Do not pass os.Stdin to launched command common#14
  • Apply patch
  • Integrate updated getgauge/common and test with
    • gauge-python in combination with gauge-vscode
    • gauge-ts in combination with gauge-vscode
    • gauge-ruby in combination with gauge-vscode (couldn't get a ruby project running on my machine Do not pass os.Stdin to launched command common#14 (comment)
  • Get getgauge/common released
    • @haroon-sheikh is reviewing
• Update the getgauge/common dependency used in getgauge/gauge
  • Get getgauge/gauge released
• Changes to update gauge-vscode
  • PR to explicitly handle vscode deactivation moves client disposal into deactivate method gauge-vscode#891
  • PR to upgrade all dependencies upgrades dependencies gauge-vscode#892
  • get gauge-vscode released
• Changes to gauge-ts
  • PR to upgrade all dependencies Upgrade dependencies gauge-ts#168
  • get gauge-ts released

[chadlwilson]

I don't really have my head around all the different combinations that need to be tested here, but not planning to specifically sanity-test anything on gauge-ruby more than what the functional test automation of the plugins already do.

Debugging in general for gauge-ruby probably isn't super high priority, as we dropped support for it from the IDE since I didn't know enough to get it working, and there also seems to be some other issue noted here. Personally I don't use it in such an involved/mature way, so it probably needs additional community help if debugging is a priority on ruby side, and made worse by this change somehow.

Nevertheless, gauge-ruby 0.7.1 now uses your "fixed" gauge-common version with the current 1.5.4 Gauge version and seemed to worked fine via automation. Can re-check after gauge-common is updated on Gauge itself if relevant.