x/tools/go/analysis/passes/printf: catches dual use variable strings passed to fmt.Sprintf

[odeke-em]

Go version

go version devel go1.24-889abb17e1 Sat Oct 26 02:44:00 2024 +0000 linux/amd64

Output of go env in your module/workspace:

GO111MODULE=''
GOARCH='amd64'
GOAUTH='netrc'
GOBIN='/home/emmanuel/go/src/go.googlesource.com/go/bin'
GOCACHE='/home/emmanuel/.cache/go-build'
GOENV='/home/emmanuel/.config/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFLAGS=''
GOHOSTARCH='amd64'
GOHOSTOS='linux'
GOINSECURE=''
GOMODCACHE='/home/emmanuel/go/pkg/mod'
GONOPROXY=''
GONOSUMDB=''
GOOS='linux'
GOPATH='/home/emmanuel/go'
GOPRIVATE=''
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/home/emmanuel/go/src/go.googlesource.com/go'
GOSUMDB='sum.golang.org'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/home/emmanuel/go/src/go.googlesource.com/go/pkg/tool/linux_amd64'
GOVCS=''
GOVERSION='devel go1.24-889abb17e1 Sat Oct 26 02:44:00 2024 +0000'
GODEBUG=''
GOTELEMETRY='local'
GOTELEMETRYDIR='/home/emmanuel/.config/go/telemetry'
GCCGO='gccgo'
GOAMD64='v1'
AR='ar'
CC='gcc'
CXX='g++'
CGO_ENABLED='1'
GOMOD='/home/emmanuel/go/src/github.com/googleapis/google-cloud-go/spanner/go.mod'
GOWORK='/home/emmanuel/go/src/github.com/googleapis/google-cloud-go/go.work'
CGO_CFLAGS='-O2 -g'
CGO_CPPFLAGS=''
CGO_CXXFLAGS='-O2 -g'
CGO_FFLAGS='-O2 -g'
CGO_LDFLAGS='-O2 -g'
PKG_CONFIG='pkg-config'
GOGCCFLAGS='-fPIC -m64 -pthread -Wl,--no-gc-sections -fmessage-length=0 -ffile-prefix-map=/tmp/go-build3859058783=/tmp/go-build -gno-record-gcc-switches'

What did you do?

1. Git clone https://github.com/googleapis/google-cloud-go
2. Change directories into spanner, then try to run the tests

$ cd spanner && go test
# cloud.google.com/go/spanner
# [cloud.google.com/go/spanner]
./transaction.go:1342:70: non-constant format string in call to cloud.google.com/go/spanner.spannerErrorf
FAIL	cloud.google.com/go/spanner [build failed]

but let's examine that code https://github.com/googleapis/google-cloud-go/blob/255c6bfcdd3e844dcf602a829bfa2ce495bcd72e/spanner/transaction.go#L1351

        if resp.Status != nil && resp.Status.Code != 0 {
		return counts, spannerErrorf(codes.Code(uint32(resp.Status.Code)), resp.Status.Message)
	}

which calls

https://github.com/googleapis/google-cloud-go/blob/255c6bfcdd3e844dcf602a829bfa2ce495bcd72e/spanner/errors.go#L124-L132

func spannerErrorf(code codes.Code, format string, args ...interface{}) error {
	msg := fmt.Sprintf(format, args...)
	wrapped, _ := apierror.FromError(status.Error(code, msg))
	return &Error{
		Code: code,
		err:  wrapped,
		Desc: msg,
	}
}

The docs for (fmt.Sprintf)[https://pkg.go.dev/fmt#Sprintf] don't specify some strict requirement that the first argument has to be constant and never has over the past 23 Go releases

That code is valid because despite the dual usage, here they just passed in format and not args. It is a very common pattern to pass in errors generated by RPC systems as errors to observability spans.
But even if we passed in arguments to the format specifier, that isn't a fatal problem; instead it is going to break a whole lot of libraries widely used in the ecosystem for example:

• OpenTelemetry-Go https://github.com/open-telemetry/opentelemetry-go/blob/078b2dd0d4375114b5d4c660768ea99e33752e8d/exporters/zipkin/zipkin.go#L194
• gRPC-Go https://pkg.go.dev/google.golang.org/grpc@v1.67.1/status#Errorf

What did you see happen?

Failed testing and compilation!

What did you expect to see?

No problems at all.

Kindly cc-ing @alandonovan

[gabyhelp]

Related Issues and Documentation

• x/tools/go/analysis/passes/printf: panic analysing some wrong format pattern #54828 (closed)
• cmd/go: fix a bug printing error output from c compiler
• runtime: panic: runtime error: hash of unhashable type [2]string #67608 (closed)

_{(Emoji vote if this was helpful or unhelpful; more detailed feedback welcome in this discussion.)}

[ianlancetaylor]

One can of course use go test -vet=off. This does not break the Go compatibility guarantee.

While I haven't looked at the full source code, the code you show actually looks problematic.

spannerErrorf(codes.Code(uint32(resp.Status.Code)), resp.Status.Message)

That is going to pass some non-constant value as the first argument to fmt.Sprintf. You are of course correct that this is valid code. But if resp.Status.Message contains % character, this will almost certainly do the wrong thing. It would be safer to write that line as

    spannerErrorf(codes.Code(uint32(resp.Status.Code)), "%s", resp.Status.Message)

That is what the new vet check is encouraging.

The new vet check was added in #60529. In the discussion there the check reliably found potential bugs. And that is how I would describe this code as well.

[adonovan]

In this case the analyzer has found a genuine problem in the code: the call spannerErrorf(code, resp.Status.Message) behaves incorrectly if the value of Message contains a percent symbol, and as far as I can tell here, the value of Message can be any arbitrary string.

Perhaps the error message could be clarified, but this is not a false positive.

spannerErrorf(codes.Code(uint32(resp.Status.Code)), "%s", resp.Status.Message)
That is what the new vet check is encouraging.

Indeed, the use of "%s" is appropriate and correct, and I routinely make suggestions of this form in code reviews.

[Sorry, I failed to notice @ianlancetaylor already said this.]

[adonovan]

I'm going to close this as "working as intended". Feel free to reopen if you disagree.

[cagedmantis]

Closed as "working as intended."