x/tools/go/analysis/unitchecker: test fail with "illegal byte sequence" (EILSEQ)

[gopherbot]

#!watchflakes
default <- pkg == "golang.org/x/tools/go/analysis/unitchecker" && `illegal byte sequence`

Issue created automatically to collect these failures.

Example (log):

=== RUN   TestExampleSeparateAnalysis
    invoke.go:268: 9.798123ms for GOROOT= GOPATH=/Users/swarming/.swarming/w/ir/x/w/gopath GO111MODULE=off GOPROXY=off PWD=/Users/swarming/.swarming/w/ir/x/t/TestExampleSeparateAnalysis3299946371/001 go list -e -f {{context.ReleaseTags}} -- unsafe
    invoke.go:268: 95.863536ms for GOROOT= GOPATH=/Users/swarming/.swarming/w/ir/x/w/gopath GO111MODULE= GOPROXY=off PWD=/Users/swarming/.swarming/w/ir/x/t/TestExampleSeparateAnalysis3299946371/001 go list -e -json=Name,ImportPath,Error,Dir,GoFiles,IgnoredGoFiles,IgnoredOtherFiles,CFiles,CgoFiles,CXXFiles,MFiles,HFiles,FFiles,SFiles,SwigFiles,SwigCXXFiles,SysoFiles,CompiledGoFiles,Export,DepOnly,Imports,ImportMap,Module -compiled=true -test=false -export=false -deps=true -find=false -pgo=off -- separate/main
unitchecker.test: failed to export type information: write /Users/swarming/.swarming/w/ir/x/t/TestExampleSeparateAnalysis3299946371/001/30.types: illegal byte sequence
    separate_test.go:188: exit status 1
--- FAIL: TestExampleSeparateAnalysis (1.38s)

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "golang.org/x/tools/go/analysis/unitchecker" && test == "TestExampleSeparateAnalysis"

2024-02-03 21:27 x_tools-go1.22-darwin-amd64_12 tools@a1fbc781 release-branch.go1.22@b0957cfc x/tools/go/analysis/unitchecker.TestExampleSeparateAnalysis (log)

=== RUN   TestExampleSeparateAnalysis
    invoke.go:268: 9.798123ms for GOROOT= GOPATH=/Users/swarming/.swarming/w/ir/x/w/gopath GO111MODULE=off GOPROXY=off PWD=/Users/swarming/.swarming/w/ir/x/t/TestExampleSeparateAnalysis3299946371/001 go list -e -f {{context.ReleaseTags}} -- unsafe
    invoke.go:268: 95.863536ms for GOROOT= GOPATH=/Users/swarming/.swarming/w/ir/x/w/gopath GO111MODULE= GOPROXY=off PWD=/Users/swarming/.swarming/w/ir/x/t/TestExampleSeparateAnalysis3299946371/001 go list -e -json=Name,ImportPath,Error,Dir,GoFiles,IgnoredGoFiles,IgnoredOtherFiles,CFiles,CgoFiles,CXXFiles,MFiles,HFiles,FFiles,SFiles,SwigFiles,SwigCXXFiles,SysoFiles,CompiledGoFiles,Export,DepOnly,Imports,ImportMap,Module -compiled=true -test=false -export=false -deps=true -find=false -pgo=off -- separate/main
unitchecker.test: failed to export type information: write /Users/swarming/.swarming/w/ir/x/t/TestExampleSeparateAnalysis3299946371/001/30.types: illegal byte sequence
    separate_test.go:188: exit status 1
--- FAIL: TestExampleSeparateAnalysis (1.38s)

— watchflakes

[adonovan]

This string is perror(EILSEQ), which is an errno that is never generated by the Go program, so it must be coming from macOS. The line number of the failure is a call to packagestest.Export, which means the real failure has been obscured by a not-so-helpful call to testing.T.Helper. Looking at all the calls to t.Fatal or t.Error within Export, most are related to os.Mkdir.

Hypothesis: we're attempting to create a directory entry that isn't a valid textual name, and macOS has forgotten that it's a UNIX and file names are just byte strings.

Experiment:

package main

import (
	"log"
	"os"
)

func main() {
	if err := os.Mkdir("ab\xff", 0755); err != nil {
		log.Fatal(err)
	}
}

Result:

$ go run a.go
2024/02/09 17:37:39 mkdir ab?: illegal byte sequence
exit status 1

But where are the non-textual strings coming from in the failing test? All the file system operations (Mkdir, WriteFile, etc) seem to derive the filename from either the testing.T.Name, or the test's tempdir, both of which must be valid text strings.

[adonovan]

Oh, it seems that hundreds of tests are failing for the same reason:
https://logs.chromium.org/logs/golang/buildbucket/cr-buildbucket/8757079028780343489/+/u/step/20/log/2
yet all of the filenames look innocuous. I think something is up with the builder.

@dmitshur

[dmitshur]

This might be a part of #65461 (comment).

I'm seeing only one watchflake report here (https://ci.chromium.org/b/8757079028780343489), and the bot it ran on is showing up as last seen 3 days 4 hours ago, the same timeline as another bot mentioned in #65461 (comment).

I think https://go.dev/cl/562399 (CC @prattmic) is expected to help with this in the future.

[bcmills]

Given darwin/amd64, this could be another symptom of #60449.