bug: unable to determine `go version` with Go installed using Snap

[eqinox76]

trafficstars

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

• Run go version to get version of Go
  • go version go1.14.4 linux/amd64
• Run code -v or code-insiders -v to get version of VS Code or VS Code Insiders
  • 1.45.1 5763d909d5f12fe19f215cbfdd29a91c0fa9208a x64
• Check your installed extensions to get the version of the VS Code Go extension
  • 0.14.3
• Run go env to get the go development environment details
  • GO111MODULE="" GOARCH="amd64" GOBIN="" GOCACHE="/home/carsten/.cache/go-build" GOENV="/home/carsten/.config/go/env" GOEXE="" GOFLAGS="" GOHOSTARCH="amd64" GOHOSTOS="linux" GOINSECURE="" GONOPROXY="" GONOSUMDB="" GOOS="linux" GOPATH="/home/carsten/go" GOPRIVATE="" GOPROXY="https://proxy.golang.org,direct" GOROOT="/snap/go/5830" GOSUMDB="sum.golang.org" GOTMPDIR="" GOTOOLDIR="/snap/go/5830/pkg/tool/linux_amd64" GCCGO="gccgo" AR="ar" CC="gcc" CXX="g++" CGO_ENABLED="1" GOMOD="/home/carsten/projects/TickImporter/go.mod" CGO_CFLAGS="-g -O2" CGO_CPPFLAGS="" CGO_CXXFLAGS="-g -O2" CGO_FFLAGS="-g -O2" CGO_LDFLAGS="-g -O2" PKG_CONFIG="pkg-config" GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build126575450=/tmp/go-build -gno-record-gcc-switches"

Share the Go related settings you have added/edited

    "go.gopath": "~/go",
    "go.useLanguageServer": true,
    "go.addTags": {
    },
    "[go]": {
        "editor.formatOnSave": true,
        "editor.codeActionsOnSave": {
            "source.organizeImports": true,
        },
        // Optional: Disable snippets, as they conflict with completion ranking.
        "editor.snippetSuggestions": "none",
    },
    "[go.mod]": {
        "editor.formatOnSave": true,
        "editor.codeActionsOnSave": {
            "source.organizeImports": true,
        },
    },
    "gopls": {
         // Add parameter placeholders when completing a function.
        "usePlaceholders": true,
    
        // If true, enable additional analyses with staticcheck.
        // Warning: This will significantly increase memory usage.
        "staticcheck": false,
    },
    "go.lintTool": "golangci-lint",
    "go.testFlags": ["-v"]

Describe the bug

Using the 'run test' annotation or the Go: Test Package does nothing.

Steps to reproduce the behavior:

1. Open any file with unittests
2. Click on 'run test'
3. See Output in Go Tests

Running tool: /snap/bin/go test -timeout 30s -coverprofile=/tmp/vscode-go5Q7PrY/go-code-cover -v

The output of gopls and go show no issues.

Running this exact command via the commandline works fine. Also from the terminal within vscode.

Checking the developer tools i only see the following warning:

[Extension Host] console.ts:137
Not able to determine version from the output of the command "/snap/bin/go version": 

When i watch the Process Explorer closely i see the the go test process starting and a subprocess for the linker for a very short time. I did not manage to capture a screenshot.

I am running ubuntu 20.04 and have go and vscode installed via snap. I am using gopls as can be seen in the config above.

Any hints how i can debug this issue further?

[hyangah]

@eqinox76 What is the output of /snap/bin/go version if you run it from the command line?

[eqinox76]

Hey @hyangah

$ /snap/bin/go version
go version go1.14.4 linux/amd64
$ which go
/snap/bin/go

[eqinox76]

I am not sure if snap is the issue here. Checking the version string from the official docker container is looks the same:

$ docker run --rm golang go version
go version go1.14.4 linux/amd64

The log message may be a red hering. As the tooling installation, code completion, etc. is working fine.

[stamblerre]

We've actually had a few reports of people using Snap and having issues with the go version check. It's strange because it does look like the correct output. I'll spend some time investigating this when I have a chance.

[dim]

Does it maybe have something to do with the way snap is aliasing binaries?

$ whereis go
go: /snap/bin/go /snap/bin/go.gofmt
$ go version
go version go1.14.7 linux/amd64
$ ls -l /snap/bin/go
lrwxrwxrwx 1 root root 13 Aug 12 15:45 /snap/bin/go -> /usr/bin/snap

[gopherbot]

Change https://golang.org/cl/248858 mentions this issue: src/util.ts: log go version output

[hyangah]

Do you still see the issue with the latest version of the extension? From the log included in the original report, it looks like when the go extension ran /snap/bin/go version command, it got an empty result but no stderr or error that triggered an exception. Not sure how to repro this case. Added the logging back that was removed at some point.

[dim]

I have manually applied your patch above to my local instance, here are the outputs:

[2020-08-18 09:13:23.931] [exthost] [info] ExtensionService#_doActivateExtension golang.go {"startup":true,"extensionId":{"value":"golang.go","_lower":"golang.go"},"activationEvent":"workspaceContains:**/*.go"}
[2020-08-18 09:13:23.931] [exthost] [info] ExtensionService#loadCommonJSModule file:///home/dim/.vscode/extensions/golang.go-0.16.1/dist/goMain.js
[2020-08-18 09:13:23.999] [exthost] [info] eager extensions activated

[Extension Host] unable to determine version from the output of "/snap/bin/go version": ""
t.log @ /snap/code/40/usr/share/code/resources/app/out/vs/workbench/workbench.desktop.main.js:266
[Extension Host] cached Go version ({"binaryPath":"/snap/bin/go","version":""}) is invalid, recomputing
t.log @ /snap/code/40/usr/share/code/resources/app/out/vs/workbench/workbench.desktop.main.js:266
[Extension Host] unable to determine version from the output of "/snap/bin/go version": ""

[dim]

I am not sure how the version outputs differ:

$ /snap/bin/go version
go version go1.14.7 linux/amd64
$ /usr/local/go/bin/go version
go version go1.15 linux/amd64

Could it be because both go and vscode are both installed as snaps that one cannot exec the other?

[dim]

Sorry, any leads on that one? It's really quite an annoying bug.

[hyangah]

@dim Sorry, I am not familiar with Snap's permission and security model.

We can disable all the go version related logic when go version is empty. But I am afraid this is just the tip of the iceberg.

In the original report -

The output of gopls and go show no issues. --> What does that mean? Do you see the gopls trace from the OUTPUT > gopls (server) channel?

Running this exact command via the commandline works fine. Also from the terminal within vscode. --> Does it mean the go test output is empty, and test didn't run?

I suspect the extension is not able to run the go command at all. If the command worked fine in the vscode integrated terminal, can you check

1. is invoking other tools from a vscode extension host permitted in Snap's security model?
2. Are the vscode's integrated terminal and the extension host seeing the same set of environment variables? They may differ because when starting integrated terminal, vscode may run .profile, .bash_profile, .bashrc, ... For the integrated terminal, the usual command env. For the vscode extension host, open the developer window by running Developers: Toggle Developer Tools -> From 'Console', enter "process.env".

[dim]

@hyangah sorry, I may not have all the answers on the snap security model as I am neither particularly familiar with it, but following your advise:

1. none of the other tools seem to be affected
2. output of process.env is the same as the output of env in a non vscode terminal, I doubt that's the culprit

As explained before, in the Go channel, I can only see this:

unable to determine version from the output of "/snap/bin/go version": ""
cached Go version ({"binaryPath":"/snap/bin/go","version":""}) is invalid, recomputing

Running version command manually inside the vscode terminal seems to yield correct results:

$ go version
go version go1.14.7 linux/amd64
$ /snap/bin/go version
go version go1.14.7 linux/amd64

I am not sure what else I should check. If it helps, I am more than happy to apply another manual patch to ~/.vscode/extensions/golang.go-0.16.1/dist/goMain.js to extract more debug info?

[dim]

OK, looks like there is more to it:

$ node -e 'require("child_process").execFile("/snap/bin/go", ["version"], (err, stdout, stderr) => { console.log(err, stdout, stderr) })'
null  
$ node -e 'require("child_process").execFile("/usr/local/go/bin/go", ["version"], (err, stdout, stderr) => { console.log(err, stdout, stderr) })'
null go version go1.15 linux/amd64

Seems to be related to https://github.com/nodesource/distributions/issues/663

[gildas]

So until we get a fix (I guess similar to what the code-sync guys did), we can use this workaround in our settings:

"go.alternateTools": {
    "go": "/snap/go/current/bin/go"
}

[ozzono]

So until we get a fix (I guess similar to what the code-sync guys did), we can use this workaround in our settings:

"go.alternateTools": {
    "go": "/snap/go/current/bin/go"
}

That was the missing needed miracle.

[eqinox76]

Thank you for the workaround!

[diiimo1973]

in settings.json

{ "go.goroot": "/snap/go/current" }

[mreynolds]

https://github.com/snapcore/snapd/blob/master/cmd/snap/main.go#L478

Snap cares about calling it from a symlink, since it uses the symlink name to determine the command to run. I can't confirm this in vscode-go, but if it's resolving the alias before exec'ing it, it's likely losing the alias required to make 'snap' work correctly (which is why vscode reports snap, not the alias for go in the error).

I'm not enough of a node expert to tell, but if this ( https://github.com/golang/vscode-go/blob/master/src/util.ts#L358 ) is traversing the symlink to the binary and then (edit) NOT passing the traversed path as argv[0] ( https://opensource.com/article/19/5/how-write-good-c-main-function ) to snap, it will break snap's ability to lookup which command is being called. Looking at ( https://nodejs.org/api/child_process.html#child_process_child_process_fork_modulepath_args_options ), it appears you could pass in the ARGV name if it's a symlink, but not if it's a hardlink / process. Maybe?

A previous version of this was closed without resolution : https://github.com/microsoft/vscode/issues/75581

[hyangah]

@mreynolds I am not sure if I understand your comment correctly - Do you mean that the workaround suggested by @diiimo2k20 or @ozzono is not working? I was about to send a cl to automatically replace /snap/bin/go with /snap/go/current/bin/go, but if that doesn't work, this is a problem.

My understanding so far is that the underlying issue is https://github.com/nodesource/distributions/issues/663 and https://bugs.launchpad.net/snapd/+bug/1835805. The extension is passing whatever it finds from PATH to child_process.execFile (in snap's case, /snap/bin/go). It works for other symlink cases.

[mreynolds]

@hyangah I wasn't clear, I was meaning to say that the workaround is successful, because it's linking to a different binary than what Snap seems to install on the system path. The linked Snap code reads the ARGV to determine which code to actually run, and that seemed to be what's failing.

ls -la /snap/bin/go
lrwxrwxrwx 1 root root 13 Nov 10 04:43 /snap/bin/go -> /usr/bin/snap
ls -la /usr/bin/snap
-rwxr-xr-x 1 root root 23466672 Oct  8 00:30 /usr/bin/snap

vs

ls -la /snap/go/current/bin/go
-rwxr-xr-x 1 root root 14033856 Nov  5 15:36 /snap/go/current/bin/go

That work-around works A-OK, I was more suggesting (again, not a node expert) that the issue is the ARGV that Snap is expecting that's somehow not coming through the exec call linked. The workaround links to internals inside Snap ( https://snapcraft.io/docs/commands-and-aliases ), which appear to have differences across linux distros : A few Linux distributions use a path of /var/lib/snapd/snap/bin instead of the standard /snap/bin. You may need to experiment and update your path accordingly.

And there is a known issue in their forums about this topic (admittedly, from a different source) : https://forum.snapcraft.io/t/symlinks-and-snap-bin-structure/16532

Just a guess. I don't have the time or chops to try it myself. This is probably specific to the requirements of Snap, but Snap is super-popular... I used the workaround too.

[hyangah]

Thanks for the detailed explanation @mreynolds - that's fascinating and convincing. So I decided to try snap myself.

Strangely, things work without any issue out of box, so I am puzzled. I just installed snap

sudo apt install snapd
sudo snap install go --classic
sudo snap install vscode --classic

and which go is pointing at /snap/bin/go.
Snap/snapd version is 2.47.1.

Then, opened code (1.51.1) , installed the go extension (0.18.1), and so far I didn't observe any issue yet. 😕

[hyangah]

Looks like something somewhere is fixed now. 🤔

$ node -e 'require("child_process").execFile("/snap/bin/go", ["version"], (err, stdout, stderr) => { console.log(err, stdout, stderr) })'
null go version go1.15.4 linux/amd64

[mreynolds]

If I remove the workaround and try again, I get :

unable to determine version from the output of "/snap/bin/go version": "undefined"
cached Go version ({"binaryPath":"/snap/bin/go","version":""}) is invalid, recomputing
unable to determine version from the output of "/snap/bin/go version": "undefined"
unable to determine version from the output of "/snap/bin/go version": "undefined"
cached Go version ({"binaryPath":"/snap/bin/go","version":""}) is invalid, recomputing
unable to determine version from the output of "/snap/bin/go version": "undefined"
unable to determine version from the output of "/snap/bin/go version": "undefined"
unable to determine version from the output of "/snap/bin/go version": "undefined"
unable to determine version from the output of "/snap/bin/go version": "undefined"

and I see what you see :

node -e 'require("child_process").execFile("/snap/bin/go", ["version"], (err, stdout, stderr) => { console.log(err, stdout, stderr) })'
null 'go version go1.15.4 linux/amd64\n' ''

Looking at ( https://github.com/golang/vscode-go/blob/e6ab6f4461c10fd348f2a7165bc7c49cdb8353c7/src/util.ts#L358 ), it appears that if the call to resolve Go doesn't produce output on STDERR, the it considers the go path valid and tries to call it. Since the existing cached path appears to be passed in (otherwise we wouldn't see the "unable to determine..." warning), maybe this "FIXIT" is relevant ( https://github.com/golang/vscode-go/blob/e6ab6f4461c10fd348f2a7165bc7c49cdb8353c7/src/utils/pathUtils.ts#L63 )?

So, I agree, doesn't look like an exec issue, it might just be an invalid cache issue due to the combo of the FIXIT and the passed in path?

This logic seems to lack a check to recover from a broken invalid cache (it just warns and then returns the incorrect result, but never seems to invalidate the incorrect result) : https://github.com/golang/vscode-go/blob/e6ab6f4461c10fd348f2a7165bc7c49cdb8353c7/src/util.ts#L368-L376

Meaning, it appears you can leave getGoVersion() with an invalid cached version after a failed attempt to resolve the version.

[hyangah]

@mreynolds Thanks for taking a look - but the FIXIT note is relevant only if you change go.goroot or go.alternateTool setting in the middle - in that case, the extension asks to reload the window (for reset&recover purpose) currently. Do you still see the error message after running the vscode command Developer: Reload Window ?

[hyangah]

While debugging another issue, I let another people install Go using snap today (all latest version). The person didn't have this issue at all. We didn't try the vscode installed using snap yet.

[Aisuko]

I hit the same issue as below:

cached Go version ({"binaryPath":"/snap/bin/go","version":""}) is invalid, recomputing
unable to determine version from the output of "/snap/bin/go version": "undefined"
cached Go version ({"binaryPath":"/snap/bin/go","version":""}) is invalid, recomputing
unable to determine version from the output of "/snap/bin/go version": "undefined"
cached Go version ({"binaryPath":"/snap/bin/go","version":""}) is invalid, recomputing
unable to determine version from the output of "/snap/bin/go version": "undefined"
cached Go version ({"binaryPath":"/snap/bin/go","version":""}) is invalid, recomputing
unable to determine version from the output of "/snap/bin/go version": "undefined"
cached Go version ({"binaryPath":"/snap/bin/go","version":""}) is invalid, recomputing
unable to determine version from the output of "/snap/bin/go version": "undefined"
cached Go version ({"binaryPath":"/snap/bin/go","version":""}) is invalid, recomputing
unable to determine version from the output of "/snap/bin/go version": "undefined"

I'm using a new OS ubuntu 20.04, and use snap store install all the softwares, includes vscode and golang

➜  osm git:(feat/docs) ✗ code -v     
1.52.1
ea3859d4ba2f3e577a159bc91e3074c5d85c0523
x64
➜  osm git:(feat/docs) ✗ go version
go version go1.15.6 linux/amd64
➜  osm git:(feat/docs) ✗ uname -r
5.4.0-58-generic
➜  osm git:(feat/docs) ✗ snap version          
snap    2.48.2
snapd   2.48.2
series  16
ubuntu  20.04
kernel  5.4.0-58-generic

And the golang.go extension version is v0.20.1

[blinkinglight]

i installed vscode from original website (ubuntu 20.04) and it works. so problem is not with go but with snapd vscode package, i think.

[gigi214]

I've got the same issue on vscode 1.55.2 (installed by snap) and golang.go extension version 0.24.0 and 0.24.1

Everything works fine with extension 0.23.3.

os: Ubuntu 20.10

[hyangah]

Thanks @gigi214 - unfortunately, I don't use snap and have troubles reproducing this issue.

v0.24.x contains a relatively small number of changes (https://github.com/golang/vscode-go/compare/v0.23.3...v0.24.0). https://github.com/golang/vscode-go/pull/1344 is the only code that directly touching related code paths (instead of go env, use go env -json + json parsing).

Can you try to add "go.logging.level": "verbose" and share the log messages from Command Palette -> "Developer: Toggle Developer Tools" -> Console?

[gigi214]

Sure, @hyangah. I'm pretty noob of vscode and golang, here what's displayed on the console. I've used the version0.24.2for generating these logs:

notificationsAlerts.ts:40 Failed to run '/snap/bin/go env. The config change may not be applied correctly.
console.ts:137 [Extension Host] unable to determine version from the output of "/snap/bin/go version": "undefined"
console.ts:137 [Extension Host] cached Go version ({"binaryPath":"/snap/bin/go","version":""}) is invalid, recomputing
console.ts:137 [Extension Host] unable to determine version from the output of "/snap/bin/go version": "undefined"
console.ts:137 [Extension Host] rejected promise not handled within 1 second: undefined
log.ts:296   ERR An unknown error occurred. Please consult the log for more details.
suggestWidgetDetails.ts:136 [Violation] 'setTimeout' handler took 70ms
[Violation] Forced reflow while executing JavaScript took 64ms

here the /snap/bin/go env -json output

$ /snap/bin/go env -json
{
	"AR": "ar",
	"CC": "gcc",
	"CGO_CFLAGS": "-g -O2",
	"CGO_CPPFLAGS": "",
	"CGO_CXXFLAGS": "-g -O2",
	"CGO_ENABLED": "1",
	"CGO_FFLAGS": "-g -O2",
	"CGO_LDFLAGS": "-g -O2",
	"CXX": "g++",
	"GCCGO": "gccgo",
	"GO111MODULE": "",
	"GOARCH": "amd64",
	"GOBIN": "/home/luigi/go/bin",
	"GOCACHE": "/home/luigi/.cache/go-build",
	"GOENV": "/home/luigi/.config/go/env",
	"GOEXE": "",
	"GOFLAGS": "",
	"GOGCCFLAGS": "-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build1793511969=/tmp/go-build -gno-record-gcc-switches",
	"GOHOSTARCH": "amd64",
	"GOHOSTOS": "linux",
	"GOINSECURE": "",
	"GOMOD": "/dev/null",
	"GOMODCACHE": "/home/luigi/go/pkg/mod",
	"GONOPROXY": "",
	"GONOSUMDB": "",
	"GOOS": "linux",
	"GOPATH": "/home/luigi/go",
	"GOPRIVATE": "",
	"GOPROXY": "https://proxy.golang.org,direct",
	"GOROOT": "/snap/go/7360",
	"GOSUMDB": "sum.golang.org",
	"GOTMPDIR": "",
	"GOTOOLDIR": "/snap/go/7360/pkg/tool/linux_amd64",
	"GOVCS": "",
	"GOVERSION": "go1.16.3",
	"PKG_CONFIG": "pkg-config"
}

The issue is still present, and as side effect I haven't the lint, the autocompletition and all the advantages of the extension.