govet can produce false-positive without running go install first

[shuLhan]

Environment

• Go v1.10.2
• Golangci-lint v1.2.1

Reproduction Steps

• Create Go file with the following content,

package main

import "fmt"

func main() {
	format := fmt.Sprintf("%%-%ds %%s", 20)
	fmt.Println("format:", format)
	fmt.Printf(format+"\n", "golangci-lint", "test")
}

• Run golangci-lint run

Expected Result

Congrats! No issues were found.

Actual Result

master ms 0 % golangci-lint run ./...
Run this tool in cloud on every github pull request in https://golangci.com for free (public repos)
govet.go:8: Printf call has arguments but no formatting directives (govet)
        fmt.Printf(format+"\n", "golangci-lint", "test")

Thank you for report!
Can't reproduce on the same version. We've inserted debug logs into vendored govet. Please do the following:

cd $GOPATH/src/github.com/golangci/golangci-lint
git checkout support/debug-govet-print-false-positive
go install ./cmd/...
golangci-lint run -v test_file.go
go tool vet -v t/main.go

and attach the output

[shuLhan]

Output for golangci-lint run from branch support/debug-govet-print-false-positive,

16:17 ~/tmp/sandbox/go/src/bug/golangci-lint
master ms 0 % golangci-lint run -v govet.go
INFO[0000] Active linters: [gas structcheck ineffassign varcheck deadcode typecheck govet errcheck megacheck]
INFO[0000] Found paths for analysis for 21.294µs: [govet.go]
INFO[0000] Program loading took 448.099458ms
INFO[0000] SSA repr building took 182.239078ms
INFO[0000] worker.8 took 93.077µs with stages: deadcode: 82.554µs
INFO[0000] worker.2 took 92.648µs with stages: varcheck: 77.894µs
INFO[0000] worker.1 took 287.884µs with stages: ineffassign: 269.885µs
INFO[0000] worker.5 took 267.984µs with stages: errcheck: 184.012µs, structcheck: 67.357µs, typecheck: 1.114µs
INFO[0000] worker.7 took 357.425µs with stages: gas: 353.209µs
WARN[0000] govet debug: call type is <nil>
WARN[0000] govet debug: fall back to scanning for the first string constant in the call
INFO[0000] worker.4 took 6.314µs
WARN[0000] govet debug: format is constant string: &{ValuePos:66 Kind:STRING Value:"%%-%ds %%s"}, "%%-%ds %%s", '\x02', map[0xc4290143a0:{mode:4 Type:untyped string Value:"test"} 0xc429014160:{mode:4 Type:untyped string Value:"%%-%ds %%s"} 0xc429014180:{mode:4 Type:untyped int Value:20} 0xc429014220:{mode:4 Type:untyped string Value:"format:"} 0xc429014340:{mode:4 Type:untyped string Value:"\n"} 0xc429014360:{mode:4 Type:untyped string Value:"golangci-lint"}]
WARN[0000] govet debug: call &{Fun:0xc429014140 Lparen:65 Args:[0xc429014160 0xc429014180] Ellipsis:0 Rparen:82} arg #0 is string constant
WARN[0000] govet debug: formatString(&{Fun:0xc429014140 Lparen:65 Args:[0xc429014160 0xc429014180] Ellipsis:0 Rparen:82}) = "%%-%ds %%s", 0
WARN[0000] govet debug: call type is <nil>
WARN[0000] govet debug: fall back to scanning for the first string constant in the call
WARN[0000] govet debug: format isn't constant string: &{X:format OpPos:134 Op:+ Y:0xc429014340}, <nil>
WARN[0000] govet debug: format is constant string: &{ValuePos:141 Kind:STRING Value:"golangci-lint"}, "golangci-lint", '\x02', map[0xc429014160:{mode:4 Type:untyped string Value:"%%-%ds %%s"} 0xc429014180:{mode:4 Type:untyped int Value:20} 0xc429014220:{mode:4 Type:untyped string Value:"format:"} 0xc429014340:{mode:4 Type:untyped string Value:"\n"} 0xc429014360:{mode:4 Type:untyped string Value:"golangci-lint"} 0xc4290143a0:{mode:4 Type:untyped string Value:"test"}]
WARN[0000] govet debug: call &{Fun:0xc429014300 Lparen:127 Args:[0xc427940240 0xc429014360 0xc4290143a0] Ellipsis:0 Rparen:164} arg #1 is string constant
WARN[0000] govet debug: formatString(&{Fun:0xc429014300 Lparen:127 Args:[0xc427940240 0xc429014360 0xc4290143a0] Ellipsis:0 Rparen:164}) = "golangci-lint", 1
INFO[0000] worker.6 took 974.19µs with stages: govet: 961.396µs
govet.go:8:2: Printf call has arguments but no formatting directives (govet)
        fmt.Printf(format+"\n", "golangci-lint", "test")
        ^
INFO[0001] worker.3 took 560.843346ms with stages: megacheck: 560.831167ms
INFO[0001] Workers idle times: #1: 560.52897ms, #2: 560.608158ms, #4: 560.085669ms, #5: 560.492037ms, #6: 559.868569ms, #7: 560.471963ms, #8: 560.616016ms
INFO[0001] processing took 142.302µs with stages: nolint: 68.904µs, exclude: 54.751µs, path_prettifier: 10.66µs, max_same_issues: 1.992µs, max_from_linter: 1.79µs, uniq_by_line: 1.716µs, max_per_file_from_linter: 1.051µs, cgo: 920ns, diff: 518ns
INFO[0001] Found 1 issues
INFO[0001] Extracting issued lines took 22.514µs
INFO[0001] Memory: 12 samples, avg is 136.8MB, max is 199.8MB
INFO[0001] Execution took 1.191709398s

For the second command, I am not sure what is t/main.go, but I assume it was the input file to be checked. So, here is the output,

16:21 ~/tmp/sandbox/go/src/bug/golangci-lint
master ms 1 % go tool vet -v govet.go

vet: import failed: can't find import: "fmt"
vet: import failed: can't find import: "fmt"
govet.go:3:8: could not import fmt (can't find import: "fmt")
Checking file govet.go
govet.go:8: Printf call has arguments but no formatting directives

@shuLhan thank you, it's an interesting case. The most interesting part is:

vet: import failed: can't find import: "fmt"
vet: import failed: can't find import: "fmt"
govet.go:3:8: could not import fmt (can't find import: "fmt")

Does this program compile?

[shuLhan]

Does this program compile?

Yes.

19:36 ~/tmp/sandbox/go/src/bug/govet
master ms 1 % go run govet.go
format: %-20s %s
golangci-lint        test

When using go vet, it print the following output

19:36 ~/tmp/sandbox/go/src/bug/govet
master ms 0 % go vet -v .
bug/govet
# bug/govet
Checking file ./govet.go
./govet.go:8: can't check non-constant format in call to Printf

Seems like go vet did not check input format if it's not constant.

send a full output of next commands, please:

pwd
echo $GOPATH $GOROOT
cat govet.go
go tool vet -v govet.go
go vet -v .
go run govet.go
go get -u github.com/golangci/golangci-lint/cmd/golangci-lint
golangci-lint run -v -E typecheck govet.go

[shuLhan]

In previous comment I renamed the folder from tmp/sandbox/go/src/bug/golangci-lint to tmp/sandox/go/src/bug/govet, sorry if it's become confusion, my bad.

Here is the output of all commands,

16:58 ~/tmp/sandbox/go/src/bug/govet
master ms 1 % pwd
/home/ms/tmp/sandbox/go/src/bug/govet

16:58 ~/tmp/sandbox/go/src/bug/govet
master ms 0 % echo $GOPATH $GOROOT
/home/ms/tmp/sandbox/go /home/ms/Programs/go

16:59 ~/tmp/sandbox/go/src/bug/govet
master ms 0 % cat govet.go
package main

import "fmt"

func main() {
        format := fmt.Sprintf("%%-%ds %%s", 20)
        fmt.Println("format:", format)
        fmt.Printf(format+"\n", "golangci-lint", "test")
}

16:59 ~/tmp/sandbox/go/src/bug/govet
master ms 0 % go tool vet -v govet.go
vet: import failed: can't find import: "fmt"
vet: import failed: can't find import: "fmt"
govet.go:3:8: could not import fmt (can't find import: "fmt")
Checking file govet.go
govet.go:8: Printf call has arguments but no formatting directives

16:59 ~/tmp/sandbox/go/src/bug/govet
master ms 1 % go vet -v .
bug/govet
# bug/govet
Checking file ./govet.go
./govet.go:8: can't check non-constant format in call to Printf

16:59 ~/tmp/sandbox/go/src/bug/govet
master ms 0 % go run govet.go
format: %-20s %s
golangci-lint        test

16:59 ~/tmp/sandbox/go/src/bug/govet
master ms 0 % golangci-lint run -v govet.go
INFO[0000] Concurrency: 8, machine cpus count: 8
INFO[0000] Active linters: [typecheck structcheck gas varcheck ineffassign deadcode govet errcheck megacheck]
INFO[0000] Found paths for analysis for 9.695µs: [govet.go]
INFO[0000] Program loading took 814.977671ms
INFO[0001] SSA repr building took 164.374438ms
INFO[0001] worker.7 took 4.113µs
INFO[0001] worker.8 took 119.002µs with stages: errcheck: 64.702µs, structcheck: 29.517µs, varcheck: 14.937µs
INFO[0001] worker.6 took 69.045µs with stages: deadcode: 61.899µs
INFO[0001] worker.1 took 126.425µs with stages: typecheck: 119.426µs
INFO[0001] worker.3 took 205.652µs with stages: ineffassign: 199.485µs
INFO[0001] worker.5 took 254.667µs with stages: gas: 246.338µs
INFO[0001] worker.4 took 563.483µs with stages: govet: 544.584µs
govet.go:8:2: Printf call has arguments but no formatting directives (govet)
        fmt.Printf(format+"\n", "golangci-lint", "test")
        ^
INFO[0001] worker.2 took 565.063961ms with stages: megacheck: 565.05436ms
INFO[0001] Workers idle times: #1: 564.854513ms, #3: 564.849004ms, #4: 564.518057ms, #5: 564.807601ms, #6: 564.906788ms, #7: 564.923226ms, #8: 564.912271ms
INFO[0001] processing took 218.749µs with stages: nolint: 106.349µs, exclude: 77.304µs, path_prettifier: 14.445µs, uniq_by_line: 9.889µs, max_same_issues: 4.156µs, max_per_file_from_linter: 2.321µs, max_from_linter: 1.935µs, cgo: 1.494µs, diff: 856ns
INFO[0001] Found 1 issues
INFO[0001] Extracting issued lines took 16.468µs
INFO[0001] Memory: 16 samples, avg is 131.2MB, max is 213.8MB
INFO[0001] Execution took 1.544861173s

I use golangci-lint version 1.3.2 for above command.

For golangci-lint v1.3.4,

17:07 ~/tmp/sandbox/go/src/bug/govet
master ms 0 % golangci-lint run -v govet.go
INFO[0000] Concurrency: 8, machine cpus count: 8
INFO[0000] Active linters: [gas varcheck ineffassign typecheck errcheck deadcode govet megacheck structcheck]
INFO[0000] Found paths for analysis for 23.604µs: [govet.go]
INFO[0000] Program loading took 689.139542ms
INFO[0000] SSA repr building took 175.566847ms
INFO[0000] worker.3 took 150.444µs with stages: deadcode: 123.113µs, structcheck: 11.227µs
INFO[0000] worker.5 took 207.57µs with stages: errcheck: 195.48µs
INFO[0000] worker.8 took 212.722µs with stages: typecheck: 199.957µs
INFO[0000] worker.1 took 219.313µs with stages: varcheck: 211.856µs
INFO[0000] worker.7 took 323.635µs with stages: gas: 319.557µs
INFO[0000] worker.2 took 328.594µs with stages: ineffassign: 320.792µs
INFO[0000] worker.6 took 701.795µs with stages: govet: 683.791µs
govet.go:8:2: Printf call has arguments but no formatting directives (govet)
        fmt.Printf(format+"\n", "golangci-lint", "test")
        ^
INFO[0001] worker.4 took 557.131317ms with stages: megacheck: 557.117204ms
INFO[0001] Workers idle times: #1: 556.783084ms, #2: 556.764598ms, #3: 556.807596ms, #5: 556.798239ms, #6: 556.451844ms, #7: 556.776766ms, #8: 556.789877ms
INFO[0001] processing took 125.716µs with stages: nolint: 60.761µs, exclude: 35.838µs, max_same_issues: 12.377µs, path_prettifier: 10.983µs, uniq_by_line: 1.943µs, max_from_linter: 1.57µs, max_per_file_from_linter: 956ns, cgo: 740ns, diff: 548ns
INFO[0001] Found 1 issues
INFO[0001] Extracting issued lines took 19.144µs
INFO[0001] Memory: 15 samples, avg is 131.3MB, max is 221.0MB
INFO[0001] Execution took 1.422497667s

[shuLhan]

I think the go tool vet that can't find "fmt" is a bug in Go v1.10.2. I try to build Go from master branch, and there is no error when running go tool vet.

17:48 ~/tmp/sandbox/go/src/bug/govet
master ms 0 % go version
go version devel +5c36fdfd39 Tue May 29 03:16:17 2018 +0000 linux/amd64

17:49 ~/tmp/sandbox/go/src/bug/govet
master ms 0 % go tool vet -v govet.go
Checking file govet.go
govet.go:8: can't check non-constant format in call to Printf

17:49 ~/tmp/sandbox/go/src/bug/govet
master ms 0 % go vet -v govet.go
command-line-arguments
# command-line-arguments
Checking file ./govet.go
./govet.go:8: can't check non-constant format in call to Printf

Recompiling golangci-lint v1.3.4 with Go master, and running it again,

17:52 ~/tmp/sandbox/go/src/bug/govet
master ms 0 % golangci-lint run -v govet.go
INFO[0000] Concurrency: 8, machine cpus count: 8
INFO[0000] Active linters: [govet errcheck varcheck deadcode megacheck gas structcheck ineffassign typecheck]
INFO[0000] Found paths for analysis for 11.267µs: [govet.go]
INFO[0000] Program loading took 554.761577ms
INFO[0000] SSA repr building took 181.150492ms
INFO[0000] worker.1 took 102.806µs with stages: deadcode: 98.988µs
INFO[0000] worker.6 took 97.545µs with stages: structcheck: 88.409µs
INFO[0000] worker.2 took 122.522µs with stages: varcheck: 109.051µs, typecheck: 1.03µs
INFO[0000] worker.5 took 268.931µs with stages: ineffassign: 249.447µs
INFO[0000] worker.8 took 342.773µs with stages: gas: 339.58µs
INFO[0000] worker.3 took 689.748µs with stages: errcheck: 672.596µs
INFO[0000] worker.7 took 1.665956ms with stages: govet: 1.653788ms
INFO[0001] worker.4 took 565.249536ms with stages: megacheck: 565.234361ms
INFO[0001] Workers idle times: #1: 565.041153ms, #2: 565.024256ms, #3: 564.46298ms, #5: 564.958687ms, #6: 565.033031ms, #7: 563.581594ms, #8: 564.896172ms
INFO[0001] processing took 13.396µs with stages: max_same_issues: 11.023µs, path_prettifier: 581ns, max_from_linter: 333ns, nolint: 315ns, cgo: 258ns, max_per_file_from_linter: 243ns, diff: 240ns, exclude: 240ns, uniq_by_line: 163ns
Congrats! No issues were found.
INFO[0001] Extracting issued lines took 0s
INFO[0001] Memory: 14 samples, avg is 175.3MB, max is 271.4MB
INFO[0001] Execution took 1.301623595s

I think we can conclude that this is issue in Go. Should I close this?

@shuLhan I reproduced it by doing cross-compilation in another GOROOT. Fixed it in #35
Check please in master

[shuLhan]

This time I test it in clean GOPATH, no other packages except golangci-lint and test file. I am afraid this is something about cache. Using Go v1.10.2 and golangci-lint v1.3.5.

19:39 ~/tmp/sandbox/clean/src/bug/govet
master ms 1 % go version
go version go1.10.2 linux/amd64

19:39 ~/tmp/sandbox/clean/src/bug/govet
master ms 0 % echo $GOPATH $GOROOT
/home/ms/tmp/sandbox/clean /home/ms/Programs/go

19:39 ~/tmp/sandbox/clean/src/bug/govet
master ms 0 % tree -d -L 3 $GOPATH/src
/home/ms/tmp/sandbox/clean/src
├── bug
│   └── govet
└── github.com
    └── golangci
        └── golangci-lint

5 directories

19:39 ~/tmp/sandbox/clean/src/bug/govet
master ms 0 % go vet -v govet.go
command-line-arguments
# command-line-arguments
Checking file ./govet.go
./govet.go:8: can't check non-constant format in call to Printf

19:39 ~/tmp/sandbox/clean/src/bug/govet
master ms 0 % go tool vet -v govet.go
vet: import failed: can't find import: "fmt"
vet: import failed: can't find import: "fmt"
govet.go:3:8: could not import fmt (can't find import: "fmt")
Checking file govet.go
govet.go:8: Printf call has arguments but no formatting directives

19:39 ~/tmp/sandbox/clean/src/bug/govet
master ms 1 % golangci-lint run -v govet.go
INFO[0000] Concurrency: 8, machine cpus count: 8
INFO[0000] Active linters: [gas structcheck ineffassign deadcode govet errcheck megacheck varcheck typecheck]
INFO[0000] set GOROOT="/home/ms/Programs/go"
INFO[0000] Found paths for analysis for 10.582µs: [govet.go]
INFO[0000] Program loading took 638.470008ms
INFO[0000] SSA repr building took 176.29165ms
INFO[0000] worker.3 took 59.8µs with stages: deadcode: 50.032µs, typecheck: 2.133µs
INFO[0000] worker.6 took 51.204µs with stages: varcheck: 42.818µs
INFO[0000] worker.7 took 1.68µs
INFO[0000] worker.1 took 113.405µs with stages: errcheck: 72.739µs, structcheck: 32.897µs
INFO[0000] worker.8 took 176.366µs with stages: ineffassign: 170.01µs
INFO[0000] worker.5 took 253.149µs with stages: gas: 246.608µs
INFO[0000] worker.2 took 440.295µs with stages: govet: 431.26µs
govet.go:8:2: Printf call has arguments but no formatting directives (govet)
        fmt.Printf(format+"\n", "golangci-lint", "test")
        ^
INFO[0001] worker.4 took 554.944407ms with stages: megacheck: 554.932398ms
INFO[0001] Workers idle times: #1: 554.802843ms, #2: 554.513992ms, #3: 554.83425ms, #5: 554.695212ms, #6: 554.814664ms, #7: 554.80942ms, #8: 554.758914ms
INFO[0001] processing took 102.671µs with stages: nolint: 50.749µs, exclude: 35.004µs, path_prettifier: 6.807µs, max_same_issues: 3.29µs, uniq_by_line: 2.706µs, max_from_linter: 1.685µs, max_per_file_from_linter: 1.241µs, cgo: 785ns, diff: 404ns
INFO[0001] Found 1 issues
INFO[0001] Extracting issued lines took 11.463µs
INFO[0001] Memory: 14 samples, avg is 133.2MB, max is 224.5MB
INFO[0001] Execution took 1.370202727s

Are you sure this is not bug in go vet?

1. What if you export GOROOT="/home/ms/Programs/go" in shell? Does it work after that?
2. Run golangci-lint run -v -E typecheck govet.go please.
3. Maybe it's a bug in go or go vet, I will dig it.

@shuLhan try please branch support/debug-govet-print-false-positive-v2