Skip to content

x/tools/cmd/godoc: memory increase even when no files are added to index #32692

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.

Sign up for GitHub

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

Jump to bottom
Closed
cdang1234 opened this issue Jun 19, 2019 · 8 comments
Closed

x/tools/cmd/godoc: memory increase even when no files are added to index #32692

cdang1234 opened this issue Jun 19, 2019 · 8 comments
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. Tools This label describes issues relating to any tools in the x/tools repository.
Milestone
Unreleased

Comments

@cdang1234
Copy link

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

$ go version
1.12.0

Does this issue reproduce with the latest release?

Yes

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

go env Output
$ go env

GOARCH="amd64"

GOBIN=""

GOCACHE="/root/.cache/go-build"

GOEXE=""

GOFLAGS=""

GOHOSTARCH="amd64"

GOHOSTOS="linux"

GOOS="linux"

GOPATH="/go"

GOPROXY=""

GORACE=""

GOROOT="/usr/local/go"

GOTMPDIR=""

GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"

GCCGO="gccgo"

CC="gcc"

CXX="g++"

CGO_ENABLED="1"

GOMOD=""

CGO_CFLAGS="-g -O2"

CGO_CPPFLAGS=""

CGO_CXXFLAGS="-g -O2"

CGO_FFLAGS="-g -O2"

CGO_LDFLAGS="-g -O2"

PKG_CONFIG="pkg-config"

GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build219332237=/tmp/go-build -gno-record-gcc-switches"

What did you do?

I ran godoc -index -index_interval=1m -v -maxresults=0 from within a docker image using golang:latest. I ran until 96 re-indexing events had passed.

If you want to recreate this issue, run godoc on your host machine with the following command:

godoc -index -index_interval=1m -maxresults=0 -v

After each re-indexing event the process will consume more memory.

What did you expect to see?

I expected the memory allocated to godoc to stop increasing if no new files were added to the filesystem

What did you see instead?

The memory usage growth is unbounded. The following graphs show the growth of memory over 96 re-indexing events on a 8 GiB machine. This experiment was run on a docker, but I've replicated it on my host machine and seen similar results. Notice that memory usage is nearly 80% by end of the experiment. I've attached a pdf with the log dump from godoc below as well.

image
image
godocWebServiceSample.pdf
@gopherbot gopherbot added this to the Unreleased milestone Jun 19, 2019
@agnivade
Copy link
Contributor

Directly pasting the pruned logs here -

Serving GoDoc. Check Exposed port.
2019/06/17 20:53:06 Go Documentation Server
2019/06/17 20:53:06 version = go1.12
2019/06/17 20:53:06 address = :6060
2019/06/17 20:53:06 goroot = /usr/local/go
2019/06/17 20:53:06 identifier search index enabled
name space {
	/:
		gated(os(/usr/local/go), 20) /
	/lib/godoc:
		mapfs /
	/src:
		gated(os(/usr/local/go), 20) /src
		gated(os(/go), 20) /src
}
2019/06/17 20:53:06 starting HTTP server
2019/06/17 20:53:06 updating index...
2019/06/17 20:53:36 index updated (30.309865804s, 76855462 bytes of source, 7680 files, 2627884 lines, 110784 unique words, 4007904 spots)
2019/06/17 20:53:36 before GC: bytes = 1030709744 footprint = 1133567224
2019/06/17 20:53:37 after  GC: bytes = 256985712 footprint = 1134615800
2019/06/17 20:54:37 updating index...
2019/06/17 20:55:07 index updated (30.096647603s, 77077000 bytes of source, 7751 files, 2636141 lines, 111447 unique words, 4020246 spots)
2019/06/17 20:55:07 before GC: bytes = 1269217968 footprint = 1630717688
2019/06/17 20:55:08 after  GC: bytes = 257971464 footprint = 1631241976
2019/06/17 20:56:08 updating index...
2019/06/17 20:56:41 index updated (32.968423274s, 77083506 bytes of source, 7755 files, 2636416 lines, 111487 unique words, 4020706 spots)
2019/06/17 20:56:41 before GC: bytes = 1084221248 footprint = 1841815288
2019/06/17 20:56:41 after  GC: bytes = 257956880 footprint = 1841815288
2019/06/17 20:57:41 updating index...
2019/06/17 20:58:14 index updated (32.42227478s, 77083506 bytes of source, 7755 files, 2636416 lines, 111487 unique words, 4020706 spots)
2019/06/17 20:58:14 before GC: bytes = 1097199200 footprint = 1843388152
2019/06/17 20:58:15 after  GC: bytes = 257988312 footprint = 1843388152
2019/06/17 20:59:15 updating index...
2019/06/17 20:59:45 index updated (30.85443324s, 77083506 bytes of source, 7755 files, 2636416 lines, 111487 unique words, 4020706 spots)
2019/06/17 20:59:45 before GC: bytes = 1270122776 footprint = 2051208952
2019/06/17 20:59:46 after  GC: bytes = 258027088 footprint = 2051208952
2019/06/17 21:00:46 updating index...
2019/06/17 21:01:17 index updated (31.164570793s, 77083506 bytes of source, 7755 files, 2636416 lines, 111487 unique words, 4020706 spots)
2019/06/17 21:01:17 before GC: bytes = 1031356960 footprint = 2051733240
2019/06/17 21:01:18 after  GC: bytes = 258017040 footprint = 2051733240
2019/06/17 21:02:18 updating index...
2019/06/17 21:02:50 index updated (31.72197225s, 77908644 bytes of source, 7991 files, 2664841 lines, 113077 unique words, 4066666 spots)
2019/06/17 21:02:50 before GC: bytes = 1104203328 footprint = 2052257528
2019/06/17 21:02:51 after  GC: bytes = 261183160 footprint = 2052257528
2019/06/17 21:03:51 updating index...
2019/06/17 21:04:23 index updated (32.214736498s, 78184432 bytes of source, 8115 files, 2674850 lines, 113996 unique words, 4082080 spots)
2019/06/17 21:04:23 before GC: bytes = 1282759704 footprint = 2052519672
2019/06/17 21:04:24 after  GC: bytes = 262472448 footprint = 2052519672
2019/06/17 21:05:24 updating index...
2019/06/17 21:05:57 index updated (33.274544458s, 78184432 bytes of source, 8115 files, 2674850 lines, 113996 unique words, 4082080 spots)
2019/06/17 21:05:57 before GC: bytes = 1283522176 footprint = 2053568248
2019/06/17 21:05:57 after  GC: bytes = 262471424 footprint = 2053568248
2019/06/17 21:06:57 updating index...
2019/06/17 21:07:33 index updated (35.969161707s, 78184432 bytes of source, 8115 files, 2674850 lines, 113996 unique words, 4082080 spots)
2019/06/17 21:07:33 before GC: bytes = 1283034848 footprint = 2054092536
2019/06/17 21:07:34 after  GC: bytes = 262466488 footprint = 2054092536
2019/06/17 21:08:34 updating index...
2019/06/17 21:09:06 index updated (32.502651325s, 78184432 bytes of source, 8115 files, 2674850 lines, 113996 unique words, 4082080 spots)
2019/06/17 21:09:06 before GC: bytes = 888479504 footprint = 2263027448
2019/06/17 21:09:07 after  GC: bytes = 262447528 footprint = 2263027448
2019/06/17 21:10:07 updating index...
2019/06/17 21:10:38 index updated (30.644192166s, 78184432 bytes of source, 8115 files, 2674850 lines, 113996 unique words, 4082080 spots)
2019/06/17 21:10:38 before GC: bytes = 1283953552 footprint = 2263551736
2019/06/17 21:10:39 after  GC: bytes = 262474968 footprint = 2263551736
2019/06/17 21:11:39 updating index...
2019/06/17 21:12:10 index updated (31.19152982s, 78184432 bytes of source, 8115 files, 2674850 lines, 113996 unique words, 4082080 spots)
2019/06/17 21:12:10 before GC: bytes = 1284741864 footprint = 2471372536
2019/06/17 21:12:10 after  GC: bytes = 262449192 footprint = 2471372536
2019/06/17 21:13:10 updating index...
2019/06/17 21:13:39 index updated (29.15489653s, 78184432 bytes of source, 8115 files, 2674850 lines, 113996 unique words, 4082080 spots)
2019/06/17 21:13:39 before GC: bytes = 1223102712 footprint = 2471634680
2019/06/17 21:13:40 after  GC: bytes = 262460872 footprint = 2471634680
2019/06/17 21:14:40 updating index...
2019/06/17 21:15:09 index updated (29.667567043s, 78184432 bytes of source, 8115 files, 2674850 lines, 113996 unique words, 4082080 spots)
2019/06/17 21:15:09 before GC: bytes = 967112888 footprint = 2472158968
2019/06/17 21:15:10 after  GC: bytes = 262468104 footprint = 2472158968
2019/06/17 21:16:10 updating index...
2019/06/17 21:16:41 index updated (30.944290606s, 78503947 bytes of source, 8197 files, 2686969 lines, 114765 unique words, 4100132 spots)
2019/06/17 21:16:41 before GC: bytes = 1293650728 footprint = 2472158968
2019/06/17 21:16:41 after  GC: bytes = 270748384 footprint = 2472158968
2019/06/17 21:17:41 updating index...
2019/06/17 21:18:13 index updated (31.224941201s, 79097720 bytes of source, 8439 files, 2708474 lines, 116083 unique words, 4139204 spots)
2019/06/17 21:18:13 before GC: bytes = 1060312664 footprint = 2472683256
2019/06/17 21:18:13 after  GC: bytes = 273291672 footprint = 2472683256
2019/06/17 21:19:13 updating index...
2019/06/17 21:20:24 index updated (70.003942919s, 167989200 bytes of source, 14395 files, 5297373 lines, 159144 unique words, 7588050 spots)
2019/06/17 21:20:24 before GC: bytes = 1656008352 footprint = 2833963512
2019/06/17 21:20:25 after  GC: bytes = 490144560 footprint = 2833963512
2019/06/17 21:21:25 updating index...
2019/06/17 21:22:45 index updated (80.463002367s, 184593857 bytes of source, 15331 files, 5728750 lines, 162835 unique words, 8107979 spots)
2019/06/17 21:22:46 before GC: bytes = 2854668232 footprint = 3270236792
2019/06/17 21:22:47 after  GC: bytes = 537566736 footprint = 3271023224
2019/06/17 21:23:47 updating index...
2019/06/17 21:25:05 index updated (77.443337363s, 186265064 bytes of source, 15743 files, 5779848 lines, 165000 unique words, 8195718 spots)
2019/06/17 21:25:05 before GC: bytes = 2143852208 footprint = 3621519992
2019/06/17 21:25:06 after  GC: bytes = 543880936 footprint = 3622044280
2019/06/17 21:26:07 updating index...
2019/06/17 21:27:27 index updated (80.073724187s, 188448828 bytes of source, 16147 files, 5847008 lines, 168783 unique words, 8293177 spots)
2019/06/17 21:27:27 before GC: bytes = 2146979368 footprint = 3622568568
2019/06/17 21:27:27 after  GC: bytes = 549101568 footprint = 3622568568
2019/06/17 21:28:28 updating index...
2019/06/17 21:29:59 index updated (91.574971353s, 211238397 bytes of source, 17402 files, 6529871 lines, 173708 unique words, 8990794 spots)
2019/06/17 21:29:59 before GC: bytes = 2625960744 footprint = 3977063032
2019/06/17 21:30:01 after  GC: bytes = 613964504 footprint = 3977063032
2019/06/17 21:31:01 updating index...
2019/06/17 21:32:33 index updated (91.608749527s, 211238397 bytes of source, 17402 files, 6529871 lines, 173708 unique words, 8990794 spots)
2019/06/17 21:32:33 before GC: bytes = 2330234624 footprint = 3980601976
2019/06/17 21:32:35 after  GC: bytes = 614058376 footprint = 3980864120
2019/06/17 21:33:35 updating index...
2019/06/17 21:35:02 index updated (87.624751509s, 211238397 bytes of source, 17402 files, 6529871 lines, 173708 unique words, 8990794 spots)
2019/06/17 21:35:02 before GC: bytes = 2373622824 footprint = 4328018552
2019/06/17 21:35:03 after  GC: bytes = 614031016 footprint = 4328018552
2019/06/17 21:36:03 updating index...
2019/06/17 21:37:33 index updated (90.15231397s, 211238397 bytes of source, 17402 files, 6529871 lines, 173708 unique words, 8990794 spots)
2019/06/17 21:37:33 before GC: bytes = 2185821920 footprint = 4328542840
2019/06/17 21:37:34 after  GC: bytes = 614039976 footprint = 4328804984
2019/06/17 21:38:34 updating index...
2019/06/17 21:39:58 index updated (83.875341156s, 211342913 bytes of source, 17421 files, 6533096 lines, 173980 unique words, 8997500 spots)
2019/06/17 21:39:58 before GC: bytes = 2462963832 footprint = 4675172984
2019/06/17 21:40:00 after  GC: bytes = 614321008 footprint = 4675172984
2019/06/17 21:41:00 updating index...
2019/06/17 21:42:27 index updated (86.842321845s, 211342913 bytes of source, 17421 files, 6533096 lines, 173980 unique words, 8997500 spots)
2019/06/17 21:42:27 before GC: bytes = 2401803184 footprint = 4678267704
2019/06/17 21:42:28 after  GC: bytes = 614288144 footprint = 4678267704
2019/06/17 21:43:29 updating index...
2019/06/17 21:44:54 index updated (85.48557741s, 211342913 bytes of source, 17421 files, 6533096 lines, 173980 unique words, 8997500 spots)
2019/06/17 21:44:54 before GC: bytes = 2392034880 footprint = 5024897848
2019/06/17 21:44:55 after  GC: bytes = 614315264 footprint = 5024897848
2019/06/17 21:45:55 updating index...
2019/06/17 21:47:20 index updated (85.386949034s, 211342913 bytes of source, 17421 files, 6533096 lines, 173980 unique words, 8997500 spots)
2019/06/17 21:47:20 before GC: bytes = 2468091672 footprint = 5025946424
2019/06/17 21:47:21 after  GC: bytes = 614301456 footprint = 5025946424
2019/06/17 21:48:21 updating index...
2019/06/17 21:49:47 index updated (85.896841759s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 21:49:47 before GC: bytes = 2418924840 footprint = 5026208568
2019/06/17 21:49:48 after  GC: bytes = 614339296 footprint = 5026208568
2019/06/17 21:50:49 updating index...
2019/06/17 21:52:16 index updated (87.471842175s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 21:52:16 before GC: bytes = 2413241504 footprint = 5026732856
2019/06/17 21:52:18 after  GC: bytes = 614318368 footprint = 5026732856
2019/06/17 21:53:18 updating index...
2019/06/17 21:54:40 index updated (82.007256264s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 21:54:40 before GC: bytes = 2340419408 footprint = 5027257144
2019/06/17 21:54:40 after  GC: bytes = 614342192 footprint = 5027781432
2019/06/17 21:55:40 updating index...
2019/06/17 21:57:05 index updated (84.884786722s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 21:57:05 before GC: bytes = 2366407056 footprint = 5028043576
2019/06/17 21:57:07 after  GC: bytes = 614345968 footprint = 5028043576
2019/06/17 21:58:07 updating index...
2019/06/17 21:59:32 index updated (84.646474662s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 21:59:32 before GC: bytes = 2357920704 footprint = 5374935864
2019/06/17 21:59:32 after  GC: bytes = 614323968 footprint = 5374935864
2019/06/17 22:00:33 updating index...
2019/06/17 22:02:01 index updated (88.549809582s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:02:01 before GC: bytes = 2394640272 footprint = 5375460152
2019/06/17 22:02:03 after  GC: bytes = 614387216 footprint = 5375460152
2019/06/17 22:03:03 updating index...
2019/06/17 22:04:31 index updated (88.262656619s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:04:31 before GC: bytes = 2443065120 footprint = 5375460152
2019/06/17 22:04:32 after  GC: bytes = 614334096 footprint = 5375460152
2019/06/17 22:05:32 updating index...
2019/06/17 22:06:59 index updated (86.769497884s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:06:59 before GC: bytes = 2458867760 footprint = 5375984440
2019/06/17 22:06:59 after  GC: bytes = 614303616 footprint = 5375984440
2019/06/17 22:07:59 updating index...
2019/06/17 22:09:27 index updated (87.84602316s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:09:27 before GC: bytes = 2108572576 footprint = 5379719992
2019/06/17 22:09:28 after  GC: bytes = 614349392 footprint = 5379719992
2019/06/17 22:10:28 updating index...
2019/06/17 22:11:50 index updated (82.284042208s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:11:50 before GC: bytes = 2411873440 footprint = 5380506424
2019/06/17 22:11:51 after  GC: bytes = 614394080 footprint = 5380506424
2019/06/17 22:12:51 updating index...
2019/06/17 22:14:18 index updated (86.771026812s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:14:18 before GC: bytes = 2393613168 footprint = 5380768568
2019/06/17 22:14:18 after  GC: bytes = 614324960 footprint = 5380768568
2019/06/17 22:15:18 updating index...
2019/06/17 22:16:43 index updated (84.19020479s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:16:43 before GC: bytes = 2403116024 footprint = 5381292856
2019/06/17 22:16:43 after  GC: bytes = 614353904 footprint = 5381292856
2019/06/17 22:17:43 updating index...
2019/06/17 22:19:12 index updated (88.898029237s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:19:12 before GC: bytes = 2358310872 footprint = 5381555000
2019/06/17 22:19:14 after  GC: bytes = 614356144 footprint = 5381555000
2019/06/17 22:20:14 updating index...
2019/06/17 22:21:49 index updated (94.687623541s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:21:49 before GC: bytes = 2445913136 footprint = 5381555000
2019/06/17 22:21:51 after  GC: bytes = 614329264 footprint = 5381555000
2019/06/17 22:22:51 updating index...
2019/06/17 22:24:25 index updated (93.557864122s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:24:25 before GC: bytes = 2366566816 footprint = 5382079288
2019/06/17 22:24:27 after  GC: bytes = 614371920 footprint = 5382079288
2019/06/17 22:25:27 updating index...
2019/06/17 22:27:00 index updated (93.486496221s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:27:00 before GC: bytes = 2440080912 footprint = 5728971576
2019/06/17 22:27:02 after  GC: bytes = 614289552 footprint = 5728971576
2019/06/17 22:28:03 updating index...
2019/06/17 22:28:56 172.17.0.1:60178	/
2019/06/17 22:28:56 172.17.0.1:60178	/lib/godoc/style.css
2019/06/17 22:28:56 172.17.0.1:60180	/lib/godoc/jquery.js
2019/06/17 22:28:56 172.17.0.1:60182	/lib/godoc/godocs.js
2019/06/17 22:28:58 172.17.0.1:60180	/pkg/
2019/06/17 22:28:58 172.17.0.1:60180	/lib/godoc/style.css
2019/06/17 22:28:58 172.17.0.1:60182	/lib/godoc/jquery.js
2019/06/17 22:28:58 172.17.0.1:60178	/lib/godoc/godocs.js
2019/06/17 22:29:39 index updated (96.186149706s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:29:39 before GC: bytes = 2321336528 footprint = 5728971576
2019/06/17 22:29:41 after  GC: bytes = 614372112 footprint = 5728971576
2019/06/17 22:30:41 updating index...
2019/06/17 22:32:15 index updated (93.882085533s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:32:15 before GC: bytes = 2555501328 footprint = 5729758008
2019/06/17 22:32:16 after  GC: bytes = 614397904 footprint = 5729758008
2019/06/17 22:33:16 updating index...
2019/06/17 22:34:51 index updated (95.505002534s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:34:51 before GC: bytes = 2369154552 footprint = 5729758008
2019/06/17 22:34:53 after  GC: bytes = 614392072 footprint = 5729758008
2019/06/17 22:35:53 updating index...
2019/06/17 22:37:30 index updated (96.614749001s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:37:30 before GC: bytes = 2446254648 footprint = 5730020152
2019/06/17 22:37:32 after  GC: bytes = 614379128 footprint = 5730020152
2019/06/17 22:38:32 updating index...
2019/06/17 22:40:07 index updated (95.343956087s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:40:07 before GC: bytes = 2115403216 footprint = 5730806584
2019/06/17 22:40:09 after  GC: bytes = 614386680 footprint = 5730806584
2019/06/17 22:41:10 updating index...
2019/06/17 22:42:37 index updated (87.153997071s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:42:37 before GC: bytes = 2436917752 footprint = 5731068728
2019/06/17 22:42:38 after  GC: bytes = 614390744 footprint = 5731068728
2019/06/17 22:43:39 updating index...
2019/06/17 22:45:06 index updated (87.075544292s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:45:06 before GC: bytes = 2464815976 footprint = 5731330872
2019/06/17 22:45:08 after  GC: bytes = 614437192 footprint = 5731330872
2019/06/17 22:46:08 updating index...
2019/06/17 22:47:42 index updated (93.976181989s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:47:42 before GC: bytes = 2587804736 footprint = 5731855160
2019/06/17 22:47:43 after  GC: bytes = 614439848 footprint = 5731855160
2019/06/17 22:48:44 updating index...
2019/06/17 22:50:15 index updated (91.35769597s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:50:15 before GC: bytes = 2621507008 footprint = 5732117304
2019/06/17 22:50:16 after  GC: bytes = 614353176 footprint = 5732117304
2019/06/17 22:51:16 updating index...
2019/06/17 22:52:44 index updated (88.404536768s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:52:44 before GC: bytes = 2298922904 footprint = 5732641592
2019/06/17 22:52:46 after  GC: bytes = 614356728 footprint = 5732641592
2019/06/17 22:53:47 updating index...
2019/06/17 22:55:11 index updated (84.936971796s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:55:11 before GC: bytes = 2258919472 footprint = 6079271736
2019/06/17 22:55:13 after  GC: bytes = 614380616 footprint = 6079271736
2019/06/17 22:56:13 updating index...
2019/06/17 22:57:47 index updated (93.747912123s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 22:57:47 before GC: bytes = 2437635952 footprint = 6079271736
2019/06/17 22:57:49 after  GC: bytes = 614357288 footprint = 6079271736
2019/06/17 22:58:49 updating index...
2019/06/17 23:00:16 index updated (87.136909923s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:00:16 before GC: bytes = 2253948120 footprint = 6079533880
2019/06/17 23:00:18 after  GC: bytes = 614348072 footprint = 6079533880
2019/06/17 23:01:18 updating index...
2019/06/17 23:02:53 index updated (94.288629565s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:02:53 before GC: bytes = 2370486192 footprint = 6080058168
2019/06/17 23:02:54 after  GC: bytes = 614416328 footprint = 6080058168
2019/06/17 23:03:55 updating index...
2019/06/17 23:05:33 index updated (98.73725214s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:05:33 before GC: bytes = 2625092872 footprint = 6080320312
2019/06/17 23:05:35 after  GC: bytes = 614372184 footprint = 6080320312
2019/06/17 23:06:35 updating index...
2019/06/17 23:08:21 index updated (105.161253605s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:08:21 before GC: bytes = 2651098472 footprint = 6080582456
2019/06/17 23:08:21 after  GC: bytes = 614386696 footprint = 6080582456
2019/06/17 23:09:21 updating index...
2019/06/17 23:10:58 index updated (96.650712287s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:10:58 before GC: bytes = 2324550192 footprint = 6080844600
2019/06/17 23:11:00 after  GC: bytes = 614371864 footprint = 6080844600
2019/06/17 23:12:00 updating index...
2019/06/17 23:13:33 index updated (92.673924281s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:13:33 before GC: bytes = 2402792296 footprint = 6081106744
2019/06/17 23:13:33 after  GC: bytes = 614394040 footprint = 6081106744
2019/06/17 23:14:33 updating index...
2019/06/17 23:16:05 index updated (92.187413396s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:16:05 before GC: bytes = 2300587328 footprint = 6081106744
2019/06/17 23:16:07 after  GC: bytes = 614318920 footprint = 6081106744
2019/06/17 23:17:07 updating index...
2019/06/17 23:18:34 index updated (87.036123711s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:18:34 before GC: bytes = 2580668920 footprint = 6427999032
2019/06/17 23:18:35 after  GC: bytes = 614358152 footprint = 6427999032
2019/06/17 23:19:35 updating index...
2019/06/17 23:21:04 index updated (89.393550659s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:21:04 before GC: bytes = 2423633336 footprint = 6428523320
2019/06/17 23:21:05 after  GC: bytes = 614374824 footprint = 6428523320
2019/06/17 23:21:23 172.17.0.1:60196	/pkg/
2019/06/17 23:21:24 172.17.0.1:60196	/lib/godoc/style.css
2019/06/17 23:21:24 172.17.0.1:60194	/lib/godoc/jquery.js
2019/06/17 23:21:24 172.17.0.1:60200	/lib/godoc/godocs.js
2019/06/17 23:21:24 172.17.0.1:60194	/favicon.ico
2019/06/17 23:22:05 updating index...
2019/06/17 23:23:28 index updated (82.328365605s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:23:28 before GC: bytes = 2621350512 footprint = 6428785464
2019/06/17 23:23:28 after  GC: bytes = 614391064 footprint = 6428785464
2019/06/17 23:24:28 updating index...
2019/06/17 23:25:57 index updated (88.383480512s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:25:57 before GC: bytes = 2394640088 footprint = 6429047608
2019/06/17 23:25:57 after  GC: bytes = 614327208 footprint = 6429047608
2019/06/17 23:26:58 updating index...
2019/06/17 23:28:26 index updated (88.264700559s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:28:26 before GC: bytes = 2385978984 footprint = 6429047608
2019/06/17 23:28:26 after  GC: bytes = 614368968 footprint = 6429047608
2019/06/17 23:29:26 updating index...
2019/06/17 23:30:56 index updated (89.62158804s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:30:56 before GC: bytes = 2316700056 footprint = 6429834040
2019/06/17 23:30:58 after  GC: bytes = 614354632 footprint = 6429834040
2019/06/17 23:31:58 updating index...
2019/06/17 23:33:21 index updated (83.129929565s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:33:21 before GC: bytes = 2251945160 footprint = 6429834040
2019/06/17 23:33:23 after  GC: bytes = 614388024 footprint = 6429834040
2019/06/17 23:34:23 updating index...
2019/06/17 23:35:50 index updated (87.091894826s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:35:50 before GC: bytes = 2399438552 footprint = 6430096184
2019/06/17 23:35:52 after  GC: bytes = 614355432 footprint = 6430096184
2019/06/17 23:36:52 updating index...
2019/06/17 23:38:21 index updated (88.997996079s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:38:21 before GC: bytes = 2398640952 footprint = 6430096184
2019/06/17 23:38:23 after  GC: bytes = 614413768 footprint = 6430096184
2019/06/17 23:39:23 updating index...
2019/06/17 23:40:55 index updated (91.723895969s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:40:55 before GC: bytes = 2384646080 footprint = 6430882616
2019/06/17 23:40:57 after  GC: bytes = 614428280 footprint = 6430882616
2019/06/17 23:41:57 updating index...
2019/06/17 23:43:20 index updated (82.805968909s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:43:20 before GC: bytes = 2373351600 footprint = 6430882616
2019/06/17 23:43:22 after  GC: bytes = 614358216 footprint = 6430882616
2019/06/17 23:44:22 updating index...
2019/06/17 23:45:39 index updated (76.409903679s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:45:39 before GC: bytes = 2408341168 footprint = 6430882616
2019/06/17 23:45:40 after  GC: bytes = 614373720 footprint = 6430882616
2019/06/17 23:46:40 updating index...
2019/06/17 23:48:00 index updated (79.244521835s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:48:00 before GC: bytes = 2440779160 footprint = 6431144760
2019/06/17 23:48:00 after  GC: bytes = 614350088 footprint = 6431144760
2019/06/17 23:49:00 updating index...
2019/06/17 23:50:36 index updated (95.551683905s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:50:36 before GC: bytes = 2432352760 footprint = 6431669048
2019/06/17 23:50:38 after  GC: bytes = 614380648 footprint = 6431669048
2019/06/17 23:51:38 updating index...
2019/06/17 23:53:04 index updated (85.654933664s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:53:04 before GC: bytes = 2295607592 footprint = 6431669048
2019/06/17 23:53:06 after  GC: bytes = 614364184 footprint = 6431669048
2019/06/17 23:53:34 172.17.0.1:60208	/pkg/
2019/06/17 23:53:34 172.17.0.1:60208	/lib/godoc/style.css
2019/06/17 23:53:34 172.17.0.1:60210	/lib/godoc/jquery.js
2019/06/17 23:53:34 172.17.0.1:60212	/lib/godoc/godocs.js
2019/06/17 23:53:34 172.17.0.1:60212	/favicon.ico
2019/06/17 23:54:06 updating index...
2019/06/17 23:55:43 index updated (96.522125145s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:55:43 before GC: bytes = 2583750728 footprint = 6431669048
2019/06/17 23:55:45 after  GC: bytes = 614425872 footprint = 6431669048
2019/06/17 23:56:45 updating index...
2019/06/17 23:58:09 index updated (83.769742672s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:58:09 before GC: bytes = 2381747464 footprint = 6432455480
2019/06/17 23:58:09 after  GC: bytes = 614408384 footprint = 6432455480
2019/06/17 23:59:09 updating index...
2019/06/18 00:00:40 index updated (91.122094591s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/18 00:00:40 before GC: bytes = 2337078232 footprint = 6432979768
2019/06/18 00:00:43 after  GC: bytes = 614365272 footprint = 6432979768
2019/06/18 00:01:43 updating index...
2019/06/18 00:03:05 index updated (82.042967604s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/18 00:03:05 before GC: bytes = 2417231592 footprint = 6432979768
2019/06/18 00:03:06 after  GC: bytes = 614389864 footprint = 6432979768
2019/06/18 00:04:07 updating index...
2019/06/18 00:05:40 index updated (93.801162558s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/18 00:05:40 before GC: bytes = 2314987800 footprint = 6432979768
2019/06/18 00:05:43 after  GC: bytes = 614340408 footprint = 6432979768
2019/06/18 00:06:43 updating index...
2019/06/18 00:08:07 index updated (84.200998519s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/18 00:08:07 before GC: bytes = 2339329816 footprint = 6433241912
2019/06/18 00:08:09 after  GC: bytes = 614400776 footprint = 6433241912
2019/06/18 00:09:09 updating index...
2019/06/18 00:10:27 index updated (78.414575523s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/18 00:10:27 before GC: bytes = 1963721560 footprint = 6433504056
2019/06/18 00:10:29 after  GC: bytes = 614383064 footprint = 6433504056
2019/06/18 00:11:29 updating index...
2019/06/18 00:12:59 index updated (89.645797776s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/18 00:12:59 before GC: bytes = 2560063000 footprint = 6433766200
2019/06/18 00:13:01 after  GC: bytes = 614405640 footprint = 6433766200
2019/06/18 00:14:01 updating index...
2019/06/18 00:15:35 index updated (93.831286025s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/18 00:15:35 before GC: bytes = 2403283800 footprint = 6433766200
2019/06/18 00:15:37 after  GC: bytes = 614346904 footprint = 6433766200
2019/06/18 00:16:37 updating index...
2019/06/18 00:18:03 index updated (86.07742832s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/18 00:18:03 before GC: bytes = 2277416960 footprint = 6434290488
2019/06/18 00:18:05 after  GC: bytes = 614350520 footprint = 6434290488
2019/06/18 00:19:05 updating index...
2019/06/18 00:20:31 index updated (86.136222798s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/18 00:20:31 before GC: bytes = 2571826088 footprint = 6781182776
2019/06/18 00:20:32 after  GC: bytes = 614384328 footprint = 6781182776
2019/06/18 00:21:32 updating index...
2019/06/18 00:23:10 index updated (97.951246623s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/18 00:23:10 before GC: bytes = 2593498688 footprint = 6781182776
2019/06/18 00:23:11 after  GC: bytes = 614345528 footprint = 6781182776
2019/06/18 00:24:12 updating index...
2019/06/18 00:25:39 index updated (87.517072273s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/18 00:25:39 before GC: bytes = 2643100216 footprint = 6781444920
2019/06/18 00:25:40 after  GC: bytes = 614364904 footprint = 6781444920
2019/06/18 00:26:40 updating index...
2019/06/18 00:28:10 index updated (90.007393545s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/18 00:28:10 before GC: bytes = 2273600536 footprint = 6781444920
2019/06/18 00:28:12 after  GC: bytes = 614354936 footprint = 6781444920
2019/06/18 00:29:12 updating index...
2019/06/18 00:30:44 index updated (92.050511632s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/18 00:30:44 before GC: bytes = 2373077336 footprint = 6781969208
2019/06/18 00:30:46 after  GC: bytes = 614381624 footprint = 6781969208
2019/06/18 00:31:46 updating index...
2019/06/18 00:33:10 index updated (84.077701609s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/18 00:33:10 before GC: bytes = 2403845448 footprint = 6782231352
2019/06/18 00:33:12 after  GC: bytes = 614422824 footprint = 6782231352
2019/06/18 00:34:12 updating index...
2019/06/18 00:35:41 index updated (88.384736226s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/18 00:35:41 before GC: bytes = 2389990936 footprint = 6782231352
2019/06/18 00:35:43 after  GC: bytes = 614399896 footprint = 6782231352

@agnivade agnivade changed the title x/tools/godoc x/tools/godoc: memory increase even when no files are added to index Jun 19, 2019
@agnivade agnivade added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Jun 19, 2019
@mknyszek
Copy link
Contributor

@cdang1234 What precisely are you measuring in your graphs? Also, can you try running with go1.12.5 instead of 1.12.0?

There's a known issue with 1.12.x where x < 5 that can cause unbounded virtual memory growth, which is precisely what I'm seeing in the log (the "footprint" number is growing, whereas the "bytes" number would be growing if there was a memory leak). See #31616.

@cdang1234
Copy link
Author

The X axis of my graphs are the number of re-indexing events. The graphs measure the size of memory usage and the rate memory usage changes for each re-indexing event.

Thanks for sharing the info on go1.12.5. I'll re-run my experiment with the most recent go version and I'll post the results here

@mknyszek
Copy link
Contributor

Sorry, I should've been more specific. When I asked "what precisely are you measuring" I meant what statistic are you looking at to build your graph? For example, are you using the log output (in which case, are you using "bytes", which measures how many objects are actually allocated, or "footprint", which is the amount of memory mapped by the Go runtime?), are you scraping top or ps (and if so, which fields?), etc.?

I apologize for being pedantic, I just want to be precise because memory use is measured in many different ways by many different parts of the system, and many don't actually correlate with how much memory you're actually using. Some do correlate but don't give you a direct measure. Few actually give you a direct measure.

In this particular case, it's important to me to understand where these numbers are coming from so I can be sure it's really just the regression I think it is and not something else.

@cdang1234
Copy link
Author

I'm running the godoc process from within a docker so I use three methods to measure the memory usage:
1.) I docker exec into the container and run top. The VSZ% is the stat I use to measure memory from inside the docker.
2.) I run docker stats on the container from my host process
3.) since I run godoc with the verbose flag I get logs that tell me how many bytes are consumed by godoc. Example:
2019/06/17 23:28:26 index updated (88.264700559s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:28:26 before GC: bytes = 2385978984 footprint = 6429047608
2019/06/17 23:28:26 after GC: bytes = 614368968 footprint = 6429047608

The charts above get their data points from godoc's footprint logs. I double check every now and then that footprint's output is accurate by comparing it against top and docker stats.

The docker image is golang:1.12.0-alpine3.9

@cdang1234
Copy link
Author

I re-ran godoc with go1.12.6 and still observed the issue
logs.pdf

@mknyszek
Copy link
Contributor

I'm running the godoc process from within a docker so I use three methods to measure the memory usage:
1.) I docker exec into the container and run top. The VSZ% is the stat I use to measure memory from inside the docker.
2.) I run docker stats on the container from my host process
3.) since I run godoc with the verbose flag I get logs that tell me how many bytes are consumed by godoc. Example:
2019/06/17 23:28:26 index updated (88.264700559s, 211342912 bytes of source, 17421 files, 6533095 lines, 173980 unique words, 8997500 spots)
2019/06/17 23:28:26 before GC: bytes = 2385978984 footprint = 6429047608
2019/06/17 23:28:26 after GC: bytes = 614368968 footprint = 6429047608

The charts above get their data points from godoc's footprint logs. I double check every now and then that footprint's output is accurate by comparing it against top and docker stats.

The docker image is golang:1.12.0-alpine3.9

FWIW, VSZ is measuring is virtual address space used and not physical memory used. That is, VSZ doesn't correlate with how much memory an application is actually using. An application running on a 64-bit machine could map 32 GiB of virtual memory (or more, it gets a bit complicated since how much you could do depends on the OS and architecture) even when you only have 8 GiB of physical memory. The OS won't count it against you unless you actually try to use (that is, access) or commit to using (some systems make you commit explicitly) all 32 GiB of memory.

What's generally more pertinent, because this is what the OS will actually start killing programs for, is RSS (in top and htop usually listed as RES), or the amount of physical memory the OS is dedicating to your process.

Based on the fact that bytes after GC (which is the amount of bytes used for heap-allocated objects after a GC, and isn't a measure of physical memory either, but in this case would help us know whether objects are being leaked) isn't increasing over time, I think we can rule out a heap-based memory leak. It's possible that goroutines are leaking though since none of the statistics above would indicate that directly. We'd have to look at the number of live goroutines and see if that was growing over time.

I re-ran godoc with go1.12.6 and still observed the issue
logs.pdf

I'm not sure it's been running long enough for me to agree, I can let it run over the weekend and see what happens. What we're looking for to confirm #31616 is a long trend of footprint growing such that is exceeds bytes before GC by a very large margin. The Go runtime never unmaps memory, so over the lifetime of a program, virtual memory use will never go down. In general, it should be proportional to the maximum physical memory used at any given point in the program's lifetime. It'll generally be higher because of fragmentation, but virtual memory use is generally not a concern.

On a final note, it's totally possible for godoc to actually require this much virtual memory because its workload results in a significant amount of fragmentation. I don't know many details about godoc, so perhaps someone else could chime in on that front. And like I mentioned before, I think it's also possible this is a goroutine leak; we don't have enough information at this point. There are other metrics that we could look at.

@gopherbot gopherbot added the Tools This label describes issues relating to any tools in the x/tools repository. label Sep 12, 2019
@dmitshur dmitshur changed the title x/tools/godoc: memory increase even when no files are added to index x/tools/cmd/godoc: memory increase even when no files are added to index Feb 18, 2020
@seankhliao
Copy link
Member

godoc is frozen.

@seankhliao seankhliao closed this as not planned Won't fix, can't repro, duplicate, stale Dec 3, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. Tools This label describes issues relating to any tools in the x/tools repository.
Projects
None yet
Milestone
Unreleased
Development

No branches or pull requests
5 participants
@mknyszek @agnivade @gopherbot @seankhliao @cdang1234