golang / vscode-go

Go extension for Visual Studio Code
https://marketplace.visualstudio.com/items?itemName=golang.Go
Other
3.79k stars 729 forks source link

Extension not yet activated - Unexpected end of JSON input #3160

Closed elminster-aom closed 5 months ago

elminster-aom commented 5 months ago

What version of Go, VS Code & VS Code Go extension are you using?

Version Information
* Run `go version` to get version of Go from _the VS Code integrated terminal_. - `go version go1.21.4 linux/amd64` * Run `gopls -v version` to get version of Gopls from _the VS Code integrated terminal_. ``` Build info ---------- golang.org/x/tools/gopls v0.14.2 golang.org/x/tools/gopls@v0.14.2 h1:sIw6vjZiuQ9S7s0auUUkHlWgsCkKZFWDHmrge8LYsnc= github.com/BurntSushi/toml@v1.2.1 h1:9F2/+DoOYIOksmaJFPw1tGFy1eDnIJXg+UHjuD8lTak= github.com/google/go-cmp@v0.5.9 h1:O2Tfq5qg4qc4AmwVlvv0oLiVAGB7enBSJ2x2DqQFi38= github.com/sergi/go-diff@v1.1.0 h1:we8PVUC3FE2uYfodKH/nBHMSetSfHDR6scGdBi+erh0= golang.org/x/exp/typeparams@v0.0.0-20221212164502-fae10dda9338 h1:2O2DON6y3XMJiQRAS1UWU+54aec2uopH3x7MAiqGW6Y= golang.org/x/mod@v0.14.0 h1:dGoOF9QVLYng8IHTm7BAyWqCqSheQ5pYWGhzW00YJr0= golang.org/x/sync@v0.4.0 h1:zxkM55ReGkDlKSM+Fu41A+zmbZuaPVbGMzvvdUPznYQ= golang.org/x/sys@v0.14.0 h1:Vz7Qs629MkJkGyHxUlRHizWJRG2j8fbQKjELVSNhy7Q= golang.org/x/telemetry@v0.0.0-20231114163143-69313e640400 h1:brbkEFfGwNGAEkykUOcryE/JiHUMMJouzE0fWWmz/QU= golang.org/x/text@v0.13.0 h1:ablQoSUd0tRdKxZewP80B+BaqeKJuVhuRxj/dkrun3k= golang.org/x/tools@v0.14.1-0.20231114185516-c9d3e7de13fd h1:Oku7E+OCrXHyst1dG1z10etCTxewCHXNFLRlyMPbh3w= golang.org/x/vuln@v1.0.1 h1:KUas02EjQK5LTuIx1OylBQdKKZ9jeugs+HiqO5HormU= honnef.co/go/tools@v0.4.5 h1:YGD4H+SuIOOqsyoLOpZDWcieM28W47/zRO7f+9V3nvo= mvdan.cc/gofumpt@v0.4.0 h1:JVf4NN1mIpHogBj7ABpgOyZc65/UUOkKQFkoURsz4MM= mvdan.cc/xurls/v2@v2.4.0 h1:tzxjVAj+wSBmDcF6zBB7/myTy3gX9xvi8Tyr28AuQgc= go: go1.21.4 ``` * Run `code -v` or `code-insiders -v` to get version of VS Code or VS Code Insiders. ``` 1.86.0 05047486b6df5eb8d44b2ecd70ea3bdf775fd937 x64 ``` * Check your installed extensions to get the version of the VS Code Go extension - `0.40.3` * Run Ctrl+Shift+P (Cmd+Shift+P on Mac OS) > `Go: Locate Configured Go Tools` command. - _No output_

Share the Go related settings you have added/edited

Run Preferences: Open Settings (JSON) command to open your settings.json file. Share all the settings with the go. or ["go"] or gopls prefixes. No preferences, everything to default

Describe the bug

The extension fails to initialize with error:

Not yet activated. Uncaught Errors (1) Unexpected end of JSON input

On logs (~/.vscode-server/data/logs/20240205T140416/exthost1/remoteexthost.log) you can find:

2024-02-05 16:02:50.368 [info] ExtensionService#_doActivateExtension golang.go, startup: false, activationEvent: 'onLanguage:go'
2024-02-05 16:02:50.679 [error] SyntaxError: Unexpected end of JSON input
        at JSON.parse (<anonymous>)
        at /home/****/.vscode-server/extensions/golang.go-0.40.3/dist/goMain.js:72845:32
        at ChildProcess.exithandler (node:child_process:411:7)
        at ChildProcess.emit (node:events:514:28)
        at maybeClose (node:internal/child_process:1091:16)
        at Socket.<anonymous> (node:internal/child_process:449:11)
        at Socket.emit (node:events:514:28)
        at Pipe.<anonymous> (node:net:323:12)

We expect the extension to successfully initialize when the first .go file is opened in the editor

Steps to reproduce the behavior:

  1. Open VSCode and connect to Microsoft WSLv2, see Developing in WSL
  2. Open a Golang file
  3. Confirm that Go language support features are not working
  4. Confirm that Go Extension did not initialize correctly

Screenshots or recordings

image

findleyr commented 5 months ago

CC @hyangah -- I've not seen this one before. Any ideas what this could be?

hyangah commented 5 months ago

Thanks for the report. Interesting -

@elminster-aom Can you run the following command go env -json GOPATH GOROOT GOPROXY GOBIN GOMODCACHE ?

If the result doesn't seem suspicious, can you also set "go.logging.level": "verbose" setting, restart vscode, and see what's printed in the developer console? Thanks!

elminster-aom commented 5 months ago

Here the information you requested:

# go env -json GOPATH GOROOT GOPROXY GOBIN GOMODCACHE
{
        "GOBIN": "",
        "GOMODCACHE": "/home/****/go/pkg/mod",
        "GOPATH": "/home/****/go",
        "GOPROXY": "https://proxy.golang.org,direct",
        "GOROOT": "/usr/local/go"
}

About go.logging.level, I couldn't find the generated logs (Maybe because the setting is deprecrated?)

Instead, I set Developer: Set Log Level... command and select log level Trace. On Extension Host (Remote), I found:

...
2024-02-07 08:00:53.627 [info] ExtensionService#_doActivateExtension golang.go, startup: false, activationEvent: 'onLanguage:go'
2024-02-07 08:00:53.627 [trace] ExtensionService#loadCommonJSModule file:///home/****/.vscode-server/extensions/golang.go-0.40.3/dist/goMain.js
2024-02-07 08:00:53.627 [trace] ExtensionService#loadExtensionContext golang.go
2024-02-07 08:00:53.821 [trace] [vscode.git] INVOKE provider 'V=>V.provideLinks(C.URI.revive(Z),te)'
2024-02-07 08:00:53.824 [trace] [streetsidesoftware.code-spell-checker] INVOKE provider 'he=>he.provideCodeActions(C.URI.revive(Z),te,V,ae)'
2024-02-07 08:00:53.825 [trace] [vscode.git] provider DONE after 4ms
2024-02-07 08:00:53.837 [trace] CommandsConverter#CREATE _json.showAssociatedSchemaList _json.showAssociatedSchemaList /13
2024-02-07 08:00:53.838 [trace] ExtHostSCM#$provideOriginalResource 0 file:///home/****/gitRepo/myKube/pkg/k8s/kubeconfig.go
2024-02-07 08:00:53.845 [trace] [streetsidesoftware.code-spell-checker] provider DONE after 21ms
2024-02-07 08:00:53.865 [trace] ExtensionService#_callActivateOptional golang.go
2024-02-07 08:00:53.866 [trace] ExtHostCommands#registerCommand go.welcome
2024-02-07 08:00:53.998 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:53.998 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.003 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.003 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.017 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.017 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.018 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.018 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.023 [error] SyntaxError: Unexpected end of JSON input
    at JSON.parse (<anonymous>)
    at /home/****/.vscode-server/extensions/golang.go-0.40.3/dist/goMain.js:72845:32
    at ChildProcess.exithandler (node:child_process:411:7)
    at ChildProcess.emit (node:events:514:28)
    at maybeClose (node:internal/child_process:1091:16)
    at Socket.<anonymous> (node:internal/child_process:449:11)
    at Socket.emit (node:events:514:28)
    at Pipe.<anonymous> (node:net:323:12)
2024-02-07 08:00:54.024 [trace] forwarded error to extension? false {"extensionIdentifier":{"value":"golang.go","_lower":"golang.go"},"stack":"SyntaxError: Unexpected end of JSON input\n\tat JSON.parse (<anonymous>)\n\tat /home/****/.vscode-server/extensions/golang.go-0.40.3/dist/goMain.js:72845:32\n\tat ChildProcess.exithandler (node:child_process:411:7)\n\tat ChildProcess.emit (node:events:514:28)\n\tat maybeClose (node:internal/child_process:1091:16)\n\tat Socket.<anonymous> (node:internal/child_process:449:11)\n\tat Socket.emit (node:events:514:28)\n\tat Pipe.<anonymous> (node:net:323:12)"}
2024-02-07 08:00:54.027 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.027 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.076 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.076 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.083 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.083 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.136 [trace] [eamodio.gitlens] INVOKE provider 'V=>V.provideCodeLenses(C.URI.revive(Z),te)'
2024-02-07 08:00:54.136 [trace] [vscode.merge-conflict] INVOKE provider 'V=>V.provideCodeLenses(C.URI.revive(Z),te)'
2024-02-07 08:00:54.137 [trace] [eamodio.gitlens] provider DONE after 2ms
2024-02-07 08:00:54.138 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.139 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.139 [trace] [vscode.merge-conflict] provider DONE after 3ms
2024-02-07 08:00:54.591 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.591 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.592 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.592 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.592 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.592 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.592 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.592 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.592 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.592 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.592 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.592 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.592 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.592 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.592 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.592 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.592 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.592 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.593 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.593 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.593 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.593 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.593 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.593 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.593 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.593 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.593 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.593 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.593 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.593 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.593 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.593 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.593 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.593 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.593 [trace] ExtHostCommands#executeCommand setContext
2024-02-07 08:00:54.593 [trace] ExtHostCommands#executeCommand _setContext
2024-02-07 08:00:54.599 [trace] [DiagnosticCollection] change many (extension, owner, uris) streetsidesoftware.code-spell-checker cSpell [[{"$mid":1,"external":"file:///home/****/gitRepo/myKube/pkg/k8s/kubeconfig.go","path":"/home/****/gitRepo/myKube/pkg/k8s/kubeconfig.go","scheme":"file"},[]]]
hyangah commented 5 months ago

goMain.js:72845 corresponds to https://github.com/golang/vscode-go/blob/b72c071d683bcd4e3480cea3794e5b41e7e548e6/src/goInstallTools.ts#L462

We could make this catch exception and handle unexpected go env output more gracefully. However, this pattern is used in various places and eventually break the extension. So understanding the root cause is still beneficial.

go.logging.level is still an active setting in v0.40.3. (Yeap, we are removing it in the upcoming release) Unless you are using webIDE, I think you can access the log from the developer console.

"Developer: Toggle Developer Console" --> Click the "Console" tab and see if you have logs like this. Screenshot 2024-02-07 at 12 09 38 PM

Can you try it? Thank you so much!

gopherbot commented 5 months ago

Change https://go.dev/cl/561997 mentions this issue: extension/src/goMain: remove unnecessary env var update

elminster-aom commented 5 months ago

Thank you, I was looking in the wrong direction. Here is the output from console: capture01

And I think, I understand what the problem is: VSCode is running go from the Windows host path (/mnt/c/eplatform/tools/go/bin/go) rather than from the WSL Ubuntu image (/usr/local/go/bin/go).

How can I fix this? How can I point to the right binaries path? My actual settings are:

# which go
/usr/local/go/bin/go

# set | egrep 'GOROOT|PATH'
GOROOT=/usr/local/go
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/lib/wsl/lib:/usr/local/go/bin:/home/****/.local/bin:/home/****/go/bin

# ls /mnt/c/eplatform/tools/go/bin/go /usr/local/go/bin/go
/mnt/c/eplatform/tools/go/bin/go  /usr/local/go/bin/go
elminster-aom commented 5 months ago

I got it solved, adding "go.goroot": "/usr/local/go/" in settings:

See new console output: image

hyangah commented 5 months ago

Thanks @elminster-aom for following up.

Can you share how you set up and use WSL? When I tested a while ago, I used the WSL extension as recommended in https://code.visualstudio.com/docs/remote/remote-overview and that did all the path translation and setup seamlessly. If the setup doesn't work out of the box, I think we need to document and report the issue upstream too.

elminster-aom commented 5 months ago

Hi @hyangah,

What I found out from the vscode console output was that the vscode PATH variable included all these /mnt/c/* directories (Windows appends its own %PATH% to WSL path by default (see How do I access my C: drive? and Interop settings).

In my specific environment, these factors where involved in triggering the issue here reported:

cat /etc/environment

PATH="/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin"

grep PATH ~/.bashrc

PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin export PATH=${PATH}:${GOROOT}/bin:~/.local/bin:~/go/bin

* It looks like that vscode doesn't invoke a login shell when it starts, therefore my `~/.bashrc` settings (trying to overwrite the Windows path appending) are ignored, and the directory `/usr/local/go/bin/` was not included in the vscode environment value of `PATH` (see my previous screenshot)

Thus, vscode was not running the Linux binary version of Go `/usr/local/go/bin/go` but the Windows one `/mnt/c/eplatform/tools/go/bin/go`... which it has a weird behavior by the way:
```bash
# /mnt/c/eplatform/tools/go/bin/go version ; echo $?
0

# /mnt/c/eplatform/tools/go/bin/go env ; echo $?
0

# /mnt/c/eplatform/tools/go/bin/go ; echo $?
0

# /usr/local/go/bin/go version ; echo $?
go version go1.21.4 linux/amd64
0
# C:\>\eplatform\tools\go\bin\go version
go version go1.21.4 windows/amd64

My solution:

Let me know if you need me to run additional tests or provide further information.

Kind regards