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/godoc: memory grows exponentially if symlink loop exists in $GOPATH #21061

Closed
kevinburke opened this issue Jul 18, 2017 · 24 comments
Closed
Labels
FrozenDueToAge NeedsDecision Feedback is required from experts, contributors, and/or the community before a change can be made.
Milestone

Comments

@kevinburke
Copy link
Contributor

kevinburke commented Jul 18, 2017

Please answer these questions before submitting your issue. Thanks!

What did you do?

Compile and run godoc as godoc -http=:6060.

What did you expect to see?

I expected the program to use a reasonable amount of memory; on my machine it gets to about 200 MB and then remains constant.

What did you see instead?

The program's memory consumption grew in an unbounded way; up to 30 GB RAM before I killed it. In addition, a number of error output lines (thousands) were streamed to the console:

$ godoc -http=:6060
2017/07/17 22:51:20 ignoring symlink: stat /Users/kevin/src/chromium.googlesource.com/infra/infra/appengine_module/gae_event_mon/checkouts.py: no such file or directory
2017/07/17 22:51:20 ignoring symlink: stat /Users/kevin/src/chromium.googlesource.com/infra/infra/appengine_module/gae_event_mon/config.py: no such file or directory
2017/07/17 22:51:20 ignoring symlink: stat /Users/kevin/src/chromium.googlesource.com/infra/infra/appengine_module/gae_event_mon/httplib2_utils.py: no such file or direct

Does this issue reproduce with the latest release (go1.8.3)?

Yes

System details

go version devel +e9b9dfe3f7 Tue Jul 18 04:42:09 2017 +0000 darwin/amd64
GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/kevin"
GORACE=""
GOROOT="/Users/kevin/go"
GOTOOLDIR="/Users/kevin/go/pkg/tool/darwin_amd64"
GCCGO="gccgo"
CC="clang"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/sf/fsn3_vgd0n98r0jb86bgp83r0000gn/T/go-build558191022=/tmp/go-build -gno-record-gcc-switches -fno-common"
CXX="clang++"
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"
GOROOT/bin/go version: go version devel +e9b9dfe3f7 Tue Jul 18 04:42:09 2017 +0000 darwin/amd64
GOROOT/bin/go tool compile -V: compile version devel +e9b9dfe3f7 Tue Jul 18 04:42:09 2017 +0000
uname -v: Darwin Kernel Version 16.6.0: Fri Apr 14 16:21:16 PDT 2017; root:xnu-3789.60.24~6/RELEASE_X86_64
ProductName:	Mac OS X
ProductVersion:	10.12.5
BuildVersion:	16F73
lldb --version: lldb-370.0.42
  Swift-3.1

I've bisected the commits in x/tools and https://go-review.googlesource.com/c/45096/ is the first one where the program's memory begins growing.

@gopherbot gopherbot added this to the Unreleased milestone Jul 18, 2017
@kevinburke
Copy link
Contributor Author

Reading over that CL I don't see anything obvious causing the problem... maybe ReadDir is calling itself in a loop?

So I think the next step may be to back it out, or run the program with -benchmem on and see where the allocations are occurring.

@mvdan
Copy link
Member

mvdan commented Jul 18, 2017

Is there a symlink loop anywhere?

@RLH
Copy link
Contributor

RLH commented Jul 18, 2017 via email

@kevinburke
Copy link
Contributor Author

@kevinburke
Copy link
Contributor Author

kevinburke commented Jul 18, 2017

I think there's a symlink loop somewhere because if I do this:

diff --git a/godoc/corpus.go b/godoc/corpus.go
index f2c7ebbf..61408745 100644
--- a/godoc/corpus.go
+++ b/godoc/corpus.go
@@ -147,7 +147,7 @@ func (c *Corpus) Init() error {
 }
 
 func (c *Corpus) initFSTree() error {
-	dir := c.newDirectory(pathpkg.Join("/", c.testDir), -1)
+	dir := c.newDirectory(pathpkg.Join("/", c.testDir), 30)
 	if dir == nil {
 		return errors.New("godoc: corpus fstree is nil")
 	}

The memory usage settles at ~500 MB.

That said, is a symlink loop that uncommon, and can we have godoc error (instead of growing RAM use infinitely) if it finds one?

@bradfitz
Copy link
Contributor

Did https://go-review.googlesource.com/c/45096/ help or hurt?

@kevinburke
Copy link
Contributor Author

Oh, interesting, these are pretty common Go libraries, I think.

gfind: File system loop detected; ‘./src/github.com/coreos/etcd/cmd/etcd’ is part of the same file system loop as ‘./src/github.com/coreos/etcd’.
gfind: File system loop detected; ‘./src/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd’ is part of the same file system loop as ‘./src/github.com/coreos/etcd’.
gfind: File system loop detected; ‘./src/github.com/jteeuwen/go-bindata/testdata/symlinkRecursiveParent/symlinkTarget’ is part of the same file system loop as ‘./src/github.com/jteeuwen/go-bindata/testdata/symlinkRecursiveParent’.
gfind: File system loop detected; ‘./src/github.com/kubernetes/kops/vendor/github.com/jteeuwen/go-bindata/testdata/symlinkRecursiveParent/symlinkTarget’ is part of the same file system loop as ‘./src/github.com/kubernetes/kops/vendor/github.com/jteeuwen/go-bindata/testdata/symlinkRecursiveParent’.

@kevinburke
Copy link
Contributor Author

That change hurt. Running godoc on the commit immediately before it, memory settles at 200MB. Recompiling with that change and it grows exponentially.

@kevinburke kevinburke changed the title x/tools/godoc: memory leak with default options x/tools/godoc: memory grows exponentially if symlink loop exists in $GOPATH Jul 18, 2017
@kevinburke
Copy link
Contributor Author

I can take a go at fixing this... does anyone have any ideas about a solution? The dumb one would be to create a map of symlinks, e.g. map[existing]new. Any time we come across a new symlink, if the file it points to is in the "existing" map, we have a loop, and should stop following those links, and/or panic. I don't think we should panic because there are legitimate reasons to have symlink loops in your file tree, see above.

Another (much easier to implement) solution would be to cap godoc directory recursion at, say, a depth of 20 or 30.

@bradfitz
Copy link
Contributor

How can I repro?

For any given directory, we should only read it once, regardless of the path we got to it. Subsequent reads can just return empty results probably.

@kevinburke
Copy link
Contributor Author

kevinburke commented Jul 19, 2017

It should be enough to clone the most recent version of go-bindata into your GOPATH, then recompile godoc with the tip of x/tools master, and restart it, you should see the memory just grow and grow. go-bindata contains a recursive symlink in the testdata directory.

gfind: File system loop detected; ‘./src/github.com/jteeuwen/go-bindata/testdata/symlinkRecursiveParent/symlinkTarget’ is part of the same file system loop as ‘./src/github.com/jteeuwen/go-bindata/testdata/symlinkRecursiveParent’.

@ALTree
Copy link
Member

ALTree commented Jul 19, 2017

I think this may be a dup of #17344. There are memprofiles too, there.

@kevinburke
Copy link
Contributor Author

kevinburke commented Jul 19, 2017 via email

@ALTree
Copy link
Member

ALTree commented Jul 19, 2017

@kevinburke sorry for the noise. I overlooked the fact that the commit you bisected this to was very recent.

@bradfitz
Copy link
Contributor

I can't reproduce.

I go got go-bindata and ran godoc before & after.

I see no change in memory. Definitely nothing growing "exponentially".

What am I doing wrong?

@kevinburke
Copy link
Contributor Author

Okay, I removed the symlinks as well as chromium.googlesource.com/infra and now godoc settles at 300MB of memory usage - previously it settled at about 17. Still trying to repro the "exponential growth" section, though maybe it was just that with my old repo Godoc would prevously "settle" at, say, 10GB and I never actually got to that point.

@syscrusher
Copy link

I can reproduce with an otherwise empty $GOPATH. Instead of go-bindata, try etcd.

According to their docs, you can get it either vendored or not. I can reproduce with both.

  • go get github.com/coreos/etcd/cmd/etcd (vendored)
  • go get github.com/coreos/etcd (not vendored)

Confirmed to be caused by CL 45096. Prior to commit, memory use is <30MB. After commit, memory grows to >15GB. I quit because I was about to start rapidly swapping to my fragile SSD. Memory growth appears to be arithmetic and unbounded. Web server doesn't start because it is continually scanning. In verbose mode, no info or errors are generated.

I think go-bindata doesn't cause the issue because it only has one recursive symlink.

etcd has two recursive symlinks:

If I remove the cmd/etcd symlink, memory use is ~130MB and stable. I get 28 errors of the following form:

2017/08/07 15:47:51 newDirTree reading /src/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/tools/functional-tester/etcd-tester: open /usr/local/opt/go/libexec/src/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/tools/functional-tester/etcd-tester: no such file or directory

If I remove the cmd/vendor/github.com/coreos/etcd symlink, memory use is ~80MB and stable. I get 4 errors of the following form:

2017/08/07 15:59:19 ignoring symlink: stat $GOPATH/src/github.com/coreos/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/etcd: too many levels of symbolic links

etcd is the only package in my 1.5GB $GOPATH/src that exhibits this behavior. I have not searched for others.

@bradfitz bradfitz modified the milestones: Go1.9, Unreleased Aug 7, 2017
@bradfitz
Copy link
Contributor

bradfitz commented Aug 7, 2017

@broady, @ianlancetaylor, you probably want to revert https://go-review.googlesource.com/c/45096 for Go 1.9.

@bradfitz bradfitz added the NeedsFix The path to resolution is known, but the work has not been done. label Aug 7, 2017
@gopherbot
Copy link

Change https://golang.org/cl/53634 mentions this issue: godoc: don't try to follow all symlinks

@ianlancetaylor
Copy link
Contributor

Reopening to port over to 1.9 release branch.

@ianlancetaylor ianlancetaylor reopened this Aug 7, 2017
@cstockton
Copy link

cstockton commented Aug 21, 2017

I can confirm this as well to be caused by symlinks - in go1.9rc2

Memory:

15669 cstockt+  20   0 11.587g 8.686g   1320 D 155.1 55.8   7:24.76 godoc                                                             
15694 cstockt+  20   0 9637792 6.002g   1440 S  79.5 38.6   5:45.18 godoc 

Strace on either pid shows:

[pid 15850] lstat("/ws/go/src/github.com/coreos/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/vendor/github.com/coreos/etcd/cmd/etcd/cmd/etcd/cmd/vendor/github.com/coreos/etcd/cmd/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/etcd/cmd/etcd/cmd/etcd/pkg/transport",  <unfinished ...>
[pid 15838] lstat("/ws/go/src/github.com/coreos/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/vendor/github.com/coreos/etcd/cmd/etcd/cmd/etcd/cmd/vendor/github.com/coreos/etcd/cmd/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/etcd/cmd/etcd/cmd/etcd/Documentation/v2/faq.md",  <unfinished ...>
[pid 15715] lstat("/ws/go/src/github.com/coreos/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/vendor/github.com/coreos/etcd/cmd/etcd/cmd/etcd/cmd/vendor/github.com/coreos/etcd/cmd/etcd/cmd/vendor/github.com/coreos/etcd/cmd/etcd/cmd/vendor/github.com/coreos/etcd/cmd/etcd/cmd/etcd/Documentation/v2/other_apis.md",  <unfinished ...>
[pid 15879] lstat("/ws/go/src/github.com/coreos/etcd/cmd/etcd/cmd/etcd/cmd/etcd/cmd/vendor/github.com/coreos/etcd/cmd/etcd/cmd/etcd/cmd/vendor/github.com/coreos/etcd/cmd/etcd/cmd/vendor/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd/cmd/etcd/cmd/etcd/cmd/etcd/mvcc/metrics_txn.go",  <unfinished ...>

@gopherbot
Copy link

Change https://golang.org/cl/57870 mentions this issue: [release-branch.go1.9] godoc: don't try to follow all symlinks

gopherbot pushed a commit to golang/tools that referenced this issue Aug 24, 2017
Revert https://golang.org/cl/45096.

Original change description:
    godoc: follow symbolic links to folders in GOROOT

    Directory walking in godoc relies on ReadDir which returns the result
    of os.Lstat.

    Instead make the the OS VFS's ReadDir use os.Stat on symlinks before
    returning.

Updates golang/go#15049
Fixes golang/go#21061

Change-Id: Ieaa7923d85842f3da5696a7f46134d16407dae66
Reviewed-on: https://go-review.googlesource.com/53634
Run-TryBot: Ian Lance Taylor <iant@golang.org>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
Reviewed-on: https://go-review.googlesource.com/57870
Reviewed-by: Russ Cox <rsc@golang.org>
@aclements aclements modified the milestones: Go1.9, Go1.9.1 Aug 25, 2017
@rsc rsc modified the milestones: Go1.9.1, Go1.9.2 Oct 4, 2017
@ianlancetaylor ianlancetaylor added NeedsDecision Feedback is required from experts, contributors, and/or the community before a change can be made. and removed NeedsFix The path to resolution is known, but the work has not been done. labels Oct 13, 2017
@rsc
Copy link
Contributor

rsc commented Oct 13, 2017

It looks like @broady cherry-picked the "don't follow symlinks" fix into the x/tools release-branch.go1.9 an hour before tagging go1.9 in the main repo. I assume that means this is fixed in Go 1.9 and we just forgot to close the issue?

Can someone check and see if the blowup still exists? If so we need to figure out why - either we used a stale release-branch from x/tools or we didn't fix the bug.

@rsc rsc added NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. and removed NeedsDecision Feedback is required from experts, contributors, and/or the community before a change can be made. labels Oct 13, 2017
@ianlancetaylor ianlancetaylor added NeedsDecision Feedback is required from experts, contributors, and/or the community before a change can be made. and removed NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Oct 13, 2017
@rsc
Copy link
Contributor

rsc commented Oct 15, 2017

I did this ($HOME/go1.9 is an unpacked go1.9.1 binary distribution, to make sure I'm using the godoc as built in the distribution).

r$ mkdir /tmp/gp
r$ export GOPATH=/tmp/gp
r$ go get -d github.com/coreos/etcd/cmd/etcd
r$ ls -l $GOPATH/src/github.com/coreos/etcd/cmd/etcd
lrwxr-xr-x  1 rsc  wheel  3 Oct 14 22:22 /tmp/gp/src/github.com/coreos/etcd/cmd/etcd -> ../
r$ ls -l $GOPATH/src/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd
lrwxr-xr-x  1 rsc  wheel  12 Oct 14 22:22 /tmp/gp/src/github.com/coreos/etcd/cmd/vendor/github.com/coreos/etcd -> ../../../../
r$ export GOROOT=$HOME/go1.9
r$ $GOROOT/bin/godoc -http=localhost:6060 -v

And then I visited http://localhost:6060/pkg/github.com/coreos/etcd/ and it does not show an infinite tree as described above. So I am going to conclude that godoc is fixed as of Go 1.9.1. It was probably also fixed as of Go 1.9, and the fact that the fix was in a subrepo just meant that this issue never got closed.

Closing now.

@rsc rsc closed this as completed Oct 15, 2017
@rsc rsc modified the milestones: Go1.9.2, Go1.9 Oct 15, 2017
@golang golang locked and limited conversation to collaborators Oct 15, 2018
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge NeedsDecision Feedback is required from experts, contributors, and/or the community before a change can be made.
Projects
None yet
Development

No branches or pull requests