Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

x/tools/imports: slow on relative paths #22139

Closed
muirdm opened this issue Oct 5, 2017 · 3 comments
Closed

x/tools/imports: slow on relative paths #22139

muirdm opened this issue Oct 5, 2017 · 3 comments
Labels
FrozenDueToAge Tools This label describes issues relating to any tools in the x/tools repository. WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.
Milestone

Comments

@muirdm
Copy link

muirdm commented Oct 5, 2017

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

go version go1.9 linux/amd64

Does this issue reproduce with the latest release?

Yes, I reproduced after fetching latest goimports and imports.

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

(docker)

GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/Users/muir/projects/<repo>/go"
GORACE=""
GOROOT="/usr/local/go"
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="gcc"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build035181199=/tmp/go-build -gno-record-gcc-switches"
CXX="g++"
CGO_ENABLED="1"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"

What did you do?

I ran goimports -w relative/path/to/code. We run this after a code generation step, so there are many (~150) files that need fixing by goimports. Our repo has ~1800 packages under vendor/.

What did you expect to see?

I expected it to complete reasonably quickly relative to the number of files to be fixed.

What did you see instead?

It took a suspiciously long time.

$ time bin/goimports -w <our/path>

real    0m47.176s
user    0m18.280s
sys     0m32.570s

CPU profile (from a different run than above):

$ go tool pprof /tmp/prof
File: goimports
Type: cpu
Time: Oct 4, 2017 at 11:18pm (UTC)
Duration: 47.23s, Total samples = 30.93s (65.49%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top15 -cum
Showing nodes accounting for 20.62s, 66.67% of 30.93s total
Dropped 341 nodes (cum <= 0.15s)
Showing top 15 nodes out of 164
      flat  flat%   sum%        cum   cum%
     0.04s  0.13%  0.13%     23.76s 76.82%  vendor/golang.org/x/tools/imports.findImportGoPath <...>/go/src/vendor/golang.org/x/tools/imports/fix.go
         0     0%  0.13%     23.76s 76.82%  vendor/golang.org/x/tools/imports.fixImports.func2 <...>/go/src/vendor/golang.org/x/tools/imports/fix.go
     0.14s  0.45%  0.58%     23.58s 76.24%  vendor/golang.org/x/tools/imports.pkgIsCandidate <...>/go/src/vendor/golang.org/x/tools/imports/fix.go
     0.02s 0.065%  0.65%     23.22s 75.07%  vendor/golang.org/x/tools/imports.canUse <...>/go/src/vendor/golang.org/x/tools/imports/fix.go
     0.01s 0.032%  0.68%     22.06s 71.32%  path/filepath.Abs /usr/local/go/src/path/filepath/path.go
     0.02s 0.065%  0.74%     22.05s 71.29%  path/filepath.abs /usr/local/go/src/path/filepath/path_unix.go
     0.01s 0.032%  0.78%     21.99s 71.10%  path/filepath.unixAbs /usr/local/go/src/path/filepath/path.go
     0.02s 0.065%  0.84%     21.15s 68.38%  os.Getwd /usr/local/go/src/os/getwd.go
         0     0%  0.84%     20.88s 67.51%  os.Stat /usr/local/go/src/os/stat_unix.go
    20.32s 65.70% 66.54%     20.58s 66.54%  syscall.Syscall /usr/local/go/src/syscall/asm_linux_amd64.s
     0.03s 0.097% 66.63%     20.44s 66.08%  syscall.Stat /usr/local/go/src/syscall/zsyscall_linux_amd64.go
         0     0% 66.63%      3.29s 10.64%  go/parser.ParseFile /usr/local/go/src/go/parser/interface.go
         0     0% 66.63%      3.09s  9.99%  vendor/golang.org/x/tools/imports.findImportGoPath.func1.1 <...>/go/src/vendor/golang.org/x/tools/imports/fix.go
         0     0% 66.63%      3.09s  9.99%  vendor/golang.org/x/tools/imports.loadExportsGoPath <...>/go/src/vendor/golang.org/x/tools/imports/fix.go
     0.01s 0.032% 66.67%      3.08s  9.96%  go/parser.(*parser).parseFile /usr/local/go/src/go/parser/parser.go

We seem to be calling os.Getwd() a lot via filepath.Abs(). I patched imports/fix.go to "pre-abs" the provided path to avoid expensive os.Getcwd() call in filepath.Abs(), and that sped it up:

$ time bin/goimports -w <our/path>

real    0m5.884s
user    0m10.340s
sys     0m1.530s
@@ -153,13 +153,14 @@ func fixImports(fset *token.FileSet, f *ast.File, filename string) (added []stri
        // decls are the current package imports. key is base package or renamed package.
        decls := make(map[string]*ast.ImportSpec)

-       abs, err := filepath.Abs(filename)
+       origFilename := filename
+       filename, err = filepath.Abs(filename)
        if err != nil {
                return nil, err
        }
-       srcDir := filepath.Dir(abs)
+       srcDir := filepath.Dir(filename)
        if Debug {
-               log.Printf("fixImports(filename=%q), abs=%q, srcDir=%q ...", filename, abs, srcDir)
+               log.Printf("fixImports(filename=%q), abs=%q, srcDir=%q ...", origFilename, filename, srcDir)
        }

        var packageInfo *packageInfo

This approach probably won't help on windows since filepath.Abs() always makes a syscall. Maybe a better approach is to just reduce the calls to filepath.Abs() through some other cleverness in "imports".

@gopherbot gopherbot added this to the Unreleased milestone Oct 5, 2017
@muirdm muirdm changed the title x/tools/cmd/goimports: slow on relative paths x/tools/imports: slow on relative paths Oct 5, 2017
@muirdm
Copy link
Author

muirdm commented Oct 5, 2017

For others experiencing this slowness, an easy workaround is to pass absolute paths to goimports or imports.Process().

@gopherbot gopherbot added the Tools This label describes issues relating to any tools in the x/tools repository. label Sep 12, 2019
@heschi heschi added the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Nov 7, 2019
@heschi
Copy link
Contributor

heschi commented Nov 7, 2019

I think this might have gotten fixed incidentally along the way. Is this still happening?

@muirdm
Copy link
Author

muirdm commented Nov 7, 2019

Seems to be fixed. Thanks!

@muirdm muirdm closed this as completed Nov 7, 2019
@golang golang locked and limited conversation to collaborators Nov 6, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge Tools This label describes issues relating to any tools in the x/tools repository. WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.
Projects
None yet
Development

No branches or pull requests

3 participants