cmd/go: list -json prints finding module for package even in vendor and readonly mode

[nmiyake]

What version of Go are you using (go version)?

$ go version
go version go1.20 darwin/amd64

Does this issue reproduce with the latest release?

Yes

What operating system and processor architecture are you using (go env)?

go env Output

$ go env
GOOS="darwin"
GOARCH="amd64"

What did you do?

Run the following to create a module that vendors its dependencies and then run go list -e -json:

mkdir go-list-repro && cd $_
echo "module go-list-repro" > go.mod
echo 'package main; import _ "golang.org/x/tools/go/packages"; func main(){}' > main.go
go mod tidy
go mod vendor
go list -e -json golang.org/x/tools 

What did you expect to see?

Output of go list -e -json should just be JSON

What did you see instead?

go: finding module for package golang.org/x/tools
{
	"ImportPath": "golang.org/x/tools",
	"Match": [
		"golang.org/x/tools"
	],
	"Incomplete": true,
	"Error": {
		"ImportStack": [],
		"Pos": "",
		"Err": "cannot query module due to -mod=vendor\n\t(Go version in go.mod is at least 1.14 and vendor directory exists.)"
	}
}

Note the presence of the initial line "go: finding module for package golang.org/x/tools", which is not JSON. This causes other tooling that consumes this output and expects only JSON to fail.

Further information

This is a behavior change between Go 1.19 and Go 1.20. Here is the output using Go 1.19:

$ /usr/local/go-1.19.5/bin/go list -e -json golang.org/x/tools                                                                      
{
	"Dir": "/Volumes/git/go/src/github.com/nmiyake/go-list-test/testmod/go-list-repo/go-list-repro/vendor/golang.org/x/tools",
	"ImportPath": "golang.org/x/tools",
	"Target": "/Volumes/git/go/pkg/darwin_amd64/github.com/nmiyake/go-list-test/testmod/go-list-repo/go-list-repro/vendor/golang.org/x/tools.a",
	"Root": "/Volumes/git/go",
	"Match": [
		"golang.org/x/tools"
	],
	"Incomplete": true,
	"Error": {
		"ImportStack": [
			"golang.org/x/tools"
		],
		"Pos": "",
		"Err": "no Go files in /Volumes/git/go/src/github.com/nmiyake/go-list-test/testmod/go-list-repo/go-list-repro/vendor/golang.org/x/tools"
	}
}

This behavior only occurs when the module dependencies are vendored:

$ rm -r vendor
$ diff <(/usr/local/go-1.20/bin/go list -e -json golang.org/x/tools) <(/usr/local/go-1.19.5/bin/go list -e -json golang.org/x/tools)
$ go mod vendor
$ diff <(/usr/local/go-1.20/bin/go list -e -json golang.org/x/tools) <(/usr/local/go-1.19.5/bin/go list -e -json golang.org/x/tools)
go: finding module for package golang.org/x/tools
1a2
> 	"Dir": "/Volumes/git/go/src/github.com/nmiyake/go-list-test/testmod/go-list-repo/go-list-repro/vendor/golang.org/x/tools",
2a4,5
> 	"Target": "/Volumes/git/go/pkg/darwin_amd64/github.com/nmiyake/go-list-test/testmod/go-list-repo/go-list-repro/vendor/golang.org/x/tools.a",
> 	"Root": "/Volumes/git/go",
8c11,13
< 		"ImportStack": [],
---
> 		"ImportStack": [
> 			"golang.org/x/tools"
> 		],
10c15
< 		"Err": "cannot query module due to -mod=vendor\n\t(Go version in go.mod is at least 1.14 and vendor directory exists.)"
---
> 		"Err": "no Go files in /Volumes/git/go/src/github.com/nmiyake/go-list-test/testmod/go-list-repo/go-list-repro/vendor/golang.org/x/tools"

[seankhliao]

cc @bcmills @matloob

[bcmills]

Note the presence of the initial line "go: finding module for package golang.org/x/tools", which is not JSON. This causes other tooling that consumes this output and expects only JSON to fail.

That message is logged to stderr, not stdout (and you can see that in the diff output too). The JSON output goes to stdout; programs that want to parse the JSON output shouldn't intermingle the two streams.

[bcmills]

The change in the ImportStack output is plausibly a bug; it's not clear to me whether it should be populated when the missing package is named directly on the command line.

I see that you've filed #58418 for the other field differences, so I will comment on those there.

[bcmills]

I see this as a minor UX issue (a chatty go: finding module for package … message that isn't particularly useful in the context of -mod=vendor), but not a regression in correctness. Programs that run command-line tools cannot in general assume that those tools will not write anything at all to stderr.

We should fix the UX issue, but I don't think this is substantial enough to be particularly urgent or to merit a backport.

[nmiyake]

Thanks for the input, and apologies for not checking the output stream -- I agree with your assessment that this makes it squarely a UI issue and is easy to deal with on the consuming end by just consuming stdout (which is what should have been done on my end all along).

[gopherbot]

Change https://go.dev/cl/467516 mentions this issue: cmd/go: return an early error from queryImport when in vendor mode

[gopherbot]

Change https://go.dev/cl/467517 mentions this issue: cmd/go: return an early error from queryImport when in vendor mode