go icon indicating copy to clipboard operation
go copied to clipboard

cmd/compile: consumes 30GB memory

Open proof-nicholas opened this issue 1 year ago • 7 comments

Go version

go version go1.21.7 linux/amd64

Output of go env in your module/workspace:

GO111MODULE=''
GOARCH='amd64'
GOBIN=''
GOCACHE='/var/lib/buildkite-agent/.cache/go-build'
GOENV='/var/lib/buildkite-agent/.config/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFLAGS=''
GOHOSTARCH='amd64'
GOHOSTOS='linux'
GOINSECURE=''
GOMODCACHE='/var/lib/buildkite-agent/go/pkg/mod'
GONOPROXY=''
GONOSUMDB=''
GOOS='linux'
GOPATH='/var/lib/buildkite-agent/go'
GOPRIVATE=''
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/usr/local/go'
GOSUMDB='sum.golang.org'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/usr/local/go/pkg/tool/linux_amd64'
GOVCS=''
GOVERSION='go1.21.7'
GCCGO='gccgo'
GOAMD64='v1'
AR='ar'
CC='gcc'
CXX='g++'
CGO_ENABLED='1'
GOMOD='/var/lib/buildkite-agent/platform/api/go.mod'
GOWORK=''
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-build3665776840=/tmp/go-build -gno-record-gcc-switches'

What did you do?

We are using the gqlgen library to build a GraphQL service for our application. It generates a file that is 340K lines long (although I've tried refactoring the generated code to break it up into smaller files but this somewhat expectedly did not have any impact on the memory utilization). Compiling this file results in ~30GB memory being utilized which often results in our CI build failing and making it difficult for developers to build the code on their local machines.

What did you see happen?

The command used to compile the service is as follows:

/usr/local/go/pkg/tool/linux_amd64/compile -memprofile memprofile.bin -memprofilerate 1024 -o $WORK/b426/_pkg_.a -trimpath "/var/lib/buildkite-agent/platform/api=>github.com/XXXXX/platform/api;$WORK/b426=>" -p github.com/XXXXX/platform/api -lang=go1.21 -complete -buildid XcMOWUUMAvFgLyKV84rF/XcMOWUUMAvFgLyKV84rF -goversion go1.21.7 -c=4 -nolocalimports -importcfg $WORK/b426/im^Crtcfg -embedcfg $WORK/b426/embedcfg -pack ./customview.resolvers.go ./ent.resolvers.go ./generate.go ./generated_gen.go ./job.resolvers.go ./job_line_item_reason.resolvers.go ./resolver.go ./servepricing.resolvers.go

I profiled the compilation via go tool pprof -top -alloc_space /usr/local/go/pkg/tool/linux_amd64/compile memprofile.bin and it outputted the following:

File: compile
Type: alloc_space
Showing nodes accounting for 55542484.43kB, 78.44% of 70805708.11kB total
Dropped 1356 nodes (cum <= 354028.54kB)
      flat  flat%   sum%        cum   cum%
16141573.52kB 22.80% 22.80% 16141573.52kB 22.80%  cmd/compile/internal/escape.(*batch).walkAll
4503806.53kB  6.36% 29.16% 5212829.74kB  7.36%  cmd/compile/internal/ssa.(*regAllocState).regalloc
2384815.13kB  3.37% 32.53% 2386168.32kB  3.37%  cmd/compile/internal/abt.(*node32).aInsert
2217639.25kB  3.13% 35.66% 2217639.25kB  3.13%  cmd/compile/internal/ssa.(*Func).newValue
1794990.19kB  2.54% 38.19% 1794990.19kB  2.54%  cmd/compile/internal/ssa.(*Func).NewBlock
1518815.58kB  2.15% 40.34% 1518815.58kB  2.15%  cmd/compile/internal/ssa.(*Block).NewValue0A
1516633.66kB  2.14% 42.48% 1989730.73kB  2.81%  cmd/compile/internal/ssa.(*regAllocState).computeLive
1462693.81kB  2.07% 44.55% 4097925.83kB  5.79%  cmd/compile/internal/walk.walkCompareString
1425591.11kB  2.01% 46.56% 1425591.11kB  2.01%  cmd/compile/internal/ssa.(*Block).NewValue1
1389533.74kB  1.96% 48.52% 4942592.34kB  6.98%  cmd/compile/internal/ssagen.(*state).boundsCheck
1181027.31kB  1.67% 50.19% 1616530.76kB  2.28%  cmd/compile/internal/liveness.Compute
1081046.50kB  1.53% 51.72% 3193493.55kB  4.51%  cmd/compile/internal/ssa.(*regAllocState).init
1013283.68kB  1.43% 53.15% 1053286.06kB  1.49%  cmd/compile/internal/liveness.ArgLiveness
951432.37kB  1.34% 54.49% 951473.63kB  1.34%  cmd/compile/internal/typecheck.convlit1
888102.45kB  1.25% 55.75% 2673922.17kB  3.78%  cmd/compile/internal/ssa.expandCalls
848635.24kB  1.20% 56.94% 1062179.98kB  1.50%  cmd/compile/internal/ssa.(*Func).Sdom
845943.64kB  1.19% 58.14% 845943.64kB  1.19%  cmd/compile/internal/ssa.newSparseTree
805158.22kB  1.14% 59.28% 925076.15kB  1.31%  cmd/compile/internal/ssa.numberLines
781584.63kB  1.10% 60.38% 12876109.76kB 18.19%  cmd/compile/internal/ssagen.(*state).stmt
769761.46kB  1.09% 61.47% 769761.46kB  1.09%  cmd/compile/internal/ssa.(*Block).NewValue2
720770.28kB  1.02% 62.48% 720770.28kB  1.02%  cmd/compile/internal/ssa.makeLCArange
714312.88kB  1.01% 63.49% 714312.88kB  1.01%  cmd/compile/internal/ir.NewConvExpr
695698.86kB  0.98% 64.48% 825427.23kB  1.17%  cmd/compile/internal/ssagen.(*phiState).insertPhis
686755.40kB  0.97% 65.45% 686755.40kB  0.97%  cmd/compile/internal/objw.(*Progs).Prog
612670.09kB  0.87% 66.31% 612670.09kB  0.87%  cmd/compile/internal/ssagen.(*state).startBlock
583662.40kB  0.82% 67.14% 583662.40kB  0.82%  cmd/compile/internal/types.NewStruct
561787.38kB  0.79% 67.93% 6189173.04kB  8.74%  cmd/compile/internal/walk.walkSwitchExpr
521300.96kB  0.74% 68.67% 532643.50kB  0.75%  cmd/compile/internal/ssa.(*Func).dominatorsLTOrig
506214.43kB  0.71% 69.38% 506214.43kB  0.71%  cmd/compile/internal/types.newType
479806.66kB  0.68% 70.06% 479806.66kB  0.68%  cmd/compile/internal/ir.NewInt
  453072kB  0.64% 70.70% 1238881.30kB  1.75%  cmd/compile/internal/typecheck.NewMethodType
433473.93kB  0.61% 71.31% 614342.10kB  0.87%  cmd/compile/internal/walk.ascompatee
370878.97kB  0.52% 71.83% 403798.80kB  0.57%  cmd/compile/internal/abi.(*ABIConfig).ABIAnalyzeFuncType
367359.33kB  0.52% 72.35% 367359.33kB  0.52%  cmd/compile/internal/ssa.(*Block).NewValue3I
333547.82kB  0.47% 72.82% 3589219.63kB  5.07%  cmd/compile/internal/ssa.BuildFuncDebug
293115.96kB  0.41% 73.24% 513287.71kB  0.72%  cmd/compile/internal/ssagen.(*state).assignWhichMayOverlap
278410.09kB  0.39% 73.63% 1216846.82kB  1.72%  cmd/compile/internal/ssagen.(*state).variable
274543.59kB  0.39% 74.02% 407320.87kB  0.58%  cmd/compile/internal/walk.stringSearch
253948.51kB  0.36% 74.38% 7458664.92kB 10.53%  cmd/compile/internal/ssagen.genssa
222813.52kB  0.31% 74.69% 779903.19kB  1.10%  cmd/compile/internal/ssa.loopnestfor
220717.85kB  0.31% 75.00% 1288394.58kB  1.82%  cmd/compile/internal/ssa.cse
191650.80kB  0.27% 75.27% 384859.33kB  0.54%  cmd/compile/internal/escape.(*escape).exprSkipInit
185886.26kB  0.26% 75.54% 528524.96kB  0.75%  cmd/compile/internal/ssa.(*factsTable).update
178263.22kB  0.25% 75.79% 1604049.51kB  2.27%  cmd/compile/internal/ssagen.(*state).call
160830.65kB  0.23% 76.02% 490870.68kB  0.69%  cmd/compile/internal/ssa.combineLoads
121603.50kB  0.17% 76.19% 2909114.48kB  4.11%  cmd/compile/internal/noder.(*reader).multiExpr
118851.90kB  0.17% 76.36% 591937.45kB  0.84%  cmd/compile/internal/ssa.(*expandState).storeArgOrLoad
118069.29kB  0.17% 76.52% 2932409.88kB  4.14%  cmd/compile/internal/noder.(*reader).expr
114343.90kB  0.16% 76.68% 29413325.52kB 41.54%  cmd/compile/internal/ssagen.buildssa
106260.86kB  0.15% 76.83% 635801.05kB   0.9%  cmd/compile/internal/ssa.prove
102546.06kB  0.14% 76.98% 547758.99kB  0.77%  cmd/compile/internal/ssa.(*expandState).rewriteArgs
92123.30kB  0.13% 77.11% 396868.16kB  0.56%  cmd/compile/internal/escape.(*escape).stmt
83268.71kB  0.12% 77.23% 556489.45kB  0.79%  cmd/compile/internal/walk.(*orderState).stmt
80953.35kB  0.11% 77.34% 2469387.48kB  3.49%  cmd/compile/internal/noder.(*reader).switchStmt
80702.65kB  0.11% 77.45% 502701.51kB  0.71%  cmd/compile/internal/ssagen.(*state).mem
72519.15kB   0.1% 77.56% 1255826.98kB  1.77%  cmd/compile/internal/noder.(*reader).methodExpr
66668.14kB 0.094% 77.65% 380548.55kB  0.54%  cmd/compile/internal/escape.(*escape).assignList
65762.42kB 0.093% 77.74% 3003005.03kB  4.24%  cmd/compile/internal/noder.(*reader).stmt1
62985.34kB 0.089% 77.83% 2122460.89kB  3.00%  cmd/compile/internal/noder.unifiedInlineCall
46698.38kB 0.066% 77.90% 426335.37kB   0.6%  cmd/compile/internal/walk.walkAssignList
37521.84kB 0.053% 77.95% 753083.42kB  1.06%  cmd/compile/internal/amd64.ssaGenValue
37373.98kB 0.053% 78.00% 443367.27kB  0.63%  cmd/compile/internal/walk.orderBlock
   29444kB 0.042% 78.05% 505228.57kB  0.71%  cmd/compile/internal/walk.(*exprSwitch).flush
26891.50kB 0.038% 78.08% 2631179.97kB  3.72%  cmd/compile/internal/noder.(*reader).compLit
25943.54kB 0.037% 78.12% 402322.88kB  0.57%  cmd/compile/internal/compare.EqString
24872.64kB 0.035% 78.16% 435842.08kB  0.62%  cmd/compile/internal/walk.(*orderState).expr1
24103.75kB 0.034% 78.19% 443804.52kB  0.63%  cmd/compile/internal/ssa.stackalloc
22809.03kB 0.032% 78.22% 432470.41kB  0.61%  cmd/internal/dwarf.PutDefaultFunc
21886.09kB 0.031% 78.25% 8428210.96kB 11.90%  cmd/compile/internal/ssa.regalloc
20468.07kB 0.029% 78.28% 6589700.44kB  9.31%  cmd/compile/internal/walk.walkStmt
16332.63kB 0.023% 78.31% 3006400.15kB  4.25%  cmd/compile/internal/noder.(*reader).stmts
14416.63kB  0.02% 78.33% 2557821.34kB  3.61%  cmd/compile/internal/noder.(*reader).addBody
13411.47kB 0.019% 78.34% 1916300.63kB  2.71%  cmd/compile/internal/inline.mkinlcall
 9283.66kB 0.013% 78.36% 16582668.32kB 23.42%  cmd/compile/internal/ir.(*bottomUpVisitor).visit
 9218.80kB 0.013% 78.37% 9681871.46kB 13.67%  cmd/compile/internal/ssagen.(*state).exprCheckPtr
 9074.44kB 0.013% 78.38% 504336.43kB  0.71%  cmd/compile/internal/walk.walkAssignFunc
 8925.60kB 0.013% 78.40% 8918687.25kB 12.60%  cmd/compile/internal/ssagen.(*state).condBranch
 8808.58kB 0.012% 78.41% 513146.93kB  0.72%  cmd/compile/internal/walk.(*exprSwitch).Emit
 5936.55kB 0.0084% 78.42% 561978.75kB  0.79%  cmd/compile/internal/walk.order
 3321.67kB 0.0047% 78.42% 18040663.99kB 25.48%  cmd/compile/internal/ssa.Compile
 2595.65kB 0.0037% 78.43% 398294.49kB  0.56%  cmd/compile/internal/escape.(*batch).walkFunc
 2226.81kB 0.0031% 78.43% 493097.49kB   0.7%  cmd/compile/internal/ssa.memcombineLoads
 2175.10kB 0.0031% 78.43% 16512095.96kB 23.32%  cmd/compile/internal/escape.Batch
 1962.41kB 0.0028% 78.43% 385482.76kB  0.54%  cmd/compile/internal/walk.walkCall1
 1786.27kB 0.0025% 78.44% 2246191.14kB  3.17%  cmd/compile/internal/noder.unifiedInlineCall.func2
 1287.16kB 0.0018% 78.44% 6546772.97kB  9.25%  cmd/compile/internal/gc.enqueueFunc
 1143.38kB 0.0016% 78.44% 2387311.70kB  3.37%  cmd/compile/internal/abt.(*T).Insert
  824.41kB 0.0012% 78.44% 37455666.90kB 52.90%  cmd/compile/internal/ssagen.Compile
  439.23kB 0.00062% 78.44%   909890kB  1.29%  cmd/compile/internal/ssa.tighten
  422.65kB 0.0006% 78.44% 1493306.90kB  2.11%  cmd/internal/obj.Flushplist
  279.70kB 0.0004% 78.44% 2639813.38kB  3.73%  cmd/compile/internal/noder.(*reader).funcLit
  192.10kB 0.00027% 78.44% 427633.34kB   0.6%  cmd/compile/internal/ssagen.(*state).addr
  103.84kB 0.00015% 78.44% 5198790.40kB  7.34%  cmd/compile/internal/walk.walkExpr
   35.27kB 5e-05% 78.44% 420856.18kB  0.59%  cmd/compile/internal/typecheck.tcIndex
   18.86kB 2.7e-05% 78.44% 36397847.57kB 51.41%  cmd/compile/internal/gc.compileFunctions.func3.1
   15.49kB 2.2e-05% 78.44% 1600634.22kB  2.26%  cmd/compile/internal/typecheck.typecheck1
    6.05kB 8.5e-06% 78.44% 5236918.99kB  7.40%  cmd/compile/internal/walk.walkExpr1
    5.27kB 7.4e-06% 78.44% 503446.43kB  0.71%  cmd/compile/internal/noder.writePkgStub
    1.25kB 1.8e-06% 78.44% 386693.55kB  0.55%  cmd/compile/internal/types2.(*Config).Check
    1.15kB 1.6e-06% 78.44% 879910.43kB  1.24%  cmd/compile/internal/noder.LoadPackage
    1.13kB 1.6e-06% 78.44% 1600634.22kB  2.26%  cmd/compile/internal/typecheck.typecheck
         0     0% 78.44% 356342.80kB   0.5%  cmd/compile/internal/escape.(*escape).call
         0     0% 78.44% 356897.96kB   0.5%  cmd/compile/internal/escape.(*escape).callCommon
         0     0% 78.44% 381948.15kB  0.54%  cmd/compile/internal/escape.(*escape).expr
         0     0% 78.44% 8142162.48kB 11.50%  cmd/compile/internal/gc.Main
         0     0% 78.44% 36877340.46kB 52.08%  cmd/compile/internal/gc.compileFunctions.func5.1
         0     0% 78.44% 401636.21kB  0.57%  cmd/compile/internal/gc.dumpobj
         0     0% 78.44% 404224.57kB  0.57%  cmd/compile/internal/gc.dumpobj1
         0     0% 78.44% 6640292.36kB  9.38%  cmd/compile/internal/gc.prepareFunc
         0     0% 78.44% 1833928.77kB  2.59%  cmd/compile/internal/inline.InlineCalls.func1
         0     0% 78.44% 1907866.15kB  2.69%  cmd/compile/internal/inline.inlnode
         0     0% 78.44% 16385638.83kB 23.14%  cmd/compile/internal/ir.(*AssignListStmt).doChildren
         0     0% 78.44% 1065488.47kB  1.50%  cmd/compile/internal/ir.(*AssignListStmt).editChildren
         0     0% 78.44% 16525971.13kB 23.34%  cmd/compile/internal/ir.(*CallExpr).doChildren
         0     0% 78.44% 16433279.94kB 23.21%  cmd/compile/internal/ir.(*CaseClause).doChildren
         0     0% 78.44% 16411864.40kB 23.18%  cmd/compile/internal/ir.(*ConvExpr).doChildren
         0     0% 78.44% 376735.89kB  0.53%  cmd/compile/internal/ir.(*ConvExpr).editChildren
         0     0% 78.44% 16437207.57kB 23.21%  cmd/compile/internal/ir.(*Func).doChildren
         0     0% 78.44% 16406796.94kB 23.17%  cmd/compile/internal/ir.(*ReturnStmt).doChildren
         0     0% 78.44% 16420862.47kB 23.19%  cmd/compile/internal/ir.(*SwitchStmt).doChildren
         0     0% 78.44% 16561533.84kB 23.39%  cmd/compile/internal/ir.(*bottomUpVisitor).visit.func1
         0     0% 78.44% 16555762.49kB 23.38%  cmd/compile/internal/ir.(*bottomUpVisitor).visit.func2
         0     0% 78.44% 16560817.73kB 23.39%  cmd/compile/internal/ir.Visit.func1
         0     0% 78.44% 3050411.19kB  4.31%  cmd/compile/internal/ir.WithFunc
         0     0% 78.44% 1383178.19kB  1.95%  cmd/compile/internal/ir.editNodes
         0     0% 78.44% 2785115.40kB  3.93%  cmd/compile/internal/noder.(*reader).funcBody
         0     0% 78.44% 2785057.58kB  3.93%  cmd/compile/internal/noder.(*reader).funcBody.func1
         0     0% 78.44% 380201.86kB  0.54%  cmd/compile/internal/noder.checkFiles
         0     0% 78.44% 2825425.89kB  3.99%  cmd/compile/internal/noder.pkgReaderIndex.funcBody
         0     0% 78.44% 408859.43kB  0.58%  cmd/compile/internal/noder.readBodies
         0     0% 78.44% 919908.61kB  1.30%  cmd/compile/internal/noder.unified
         0     0% 78.44% 498098.50kB   0.7%  cmd/compile/internal/ssa.addRestrictions
         0     0% 78.44% 532643.50kB  0.75%  cmd/compile/internal/ssa.dominators
         0     0% 78.44% 672149.39kB  0.95%  cmd/compile/internal/ssa.likelyadjust
         0     0% 78.44% 531895.69kB  0.75%  cmd/compile/internal/ssa.memcombine
         0     0% 78.44% 503791.97kB  0.71%  cmd/compile/internal/ssagen.(*State).Prog
         0     0% 78.44% 385570.67kB  0.54%  cmd/compile/internal/ssagen.(*state).conv
         0     0% 78.44% 790713.19kB  1.12%  cmd/compile/internal/ssagen.(*state).load
         0     0% 78.44% 1265777.36kB  1.79%  cmd/compile/internal/ssagen.(*state).newValue1
         0     0% 78.44% 618937.90kB  0.87%  cmd/compile/internal/ssagen.(*state).newValue1I
         0     0% 78.44% 1485575.07kB  2.10%  cmd/compile/internal/ssagen.(*state).newValue2
         0     0% 78.44% 533129.47kB  0.75%  cmd/compile/internal/ssagen.(*state).putArg
         0     0% 78.44% 790788.07kB  1.12%  cmd/compile/internal/ssagen.(*state).rawLoad
         0     0% 78.44% 1068506.69kB  1.51%  cmd/compile/internal/typecheck.Conv
         0     0% 78.44% 522273.56kB  0.74%  cmd/compile/internal/typecheck.NewMethodType.NewSignature.func1
         0     0% 78.44% 419635.75kB  0.59%  cmd/compile/internal/typecheck.indexlit
         0     0% 78.44% 384389.61kB  0.54%  cmd/compile/internal/typecheck.tcConv
         0     0% 78.44% 591657.93kB  0.84%  cmd/compile/internal/typecheck.tcDot
         0     0% 78.44% 588728.78kB  0.83%  cmd/compile/internal/typecheck.typecheckMethodExpr
         0     0% 78.44% 388110.98kB  0.55%  cmd/compile/internal/types2.(*Checker).checkFiles
         0     0% 78.44% 435649.59kB  0.62%  cmd/compile/internal/walk.(*orderState).expr
         0     0% 78.44% 547927.76kB  0.77%  cmd/compile/internal/walk.(*orderState).stmtList
         0     0% 78.44% 6633562.18kB  9.37%  cmd/compile/internal/walk.Walk
         0     0% 78.44% 385586.19kB  0.54%  cmd/compile/internal/walk.walkCall
         0     0% 78.44% 4065998.20kB  5.74%  cmd/compile/internal/walk.walkCompare
         0     0% 78.44% 6043091.20kB  8.53%  cmd/compile/internal/walk.walkSwitch
         0     0% 78.44% 8064166.70kB 11.39%  main.main
         0     0% 78.44% 43857713.36kB 61.94%  runtime.goexit
         0     0% 78.44% 7952558.41kB 11.23%  runtime.main

What did you expect to see?

30GB seems excessive for the go compiler to require to build this source file. Please provide some guidance on how we can track down what is causing the high memory usage.

proof-nicholas avatar Aug 24 '24 13:08 proof-nicholas

CC @randall77 @golang/compiler

ianlancetaylor avatar Aug 24 '24 14:08 ianlancetaylor

Thanks for reporting. Are you able to also try with go1.23.0 and/or go1.22.6 and see if there's any noticeable difference?

dmitshur avatar Aug 24 '24 18:08 dmitshur

I tried 1.23.0 and it did not have a noticeable impact.

proof-nicholas avatar Aug 24 '24 18:08 proof-nicholas

Please let me know if there's additional data I can collect or anything I can provide to help diagnose root cause. This has become a priority issue for my team. Thanks!

proof-nicholas avatar Aug 26 '24 20:08 proof-nicholas

You're tracking alloc_space here, which isn't particularly relevant for OOMs, as this tracks the total allocation, most of which might have been immediately freed + garbage collected. Much more important is inuse_space which tracks currently live data (allocated - freed). It would be great to grab an inuse_space profile just before the OOM if that is possible.

Can you share your source code, or extract a reproducer? That would make it a whole lot easier to debug on our end.

How much memory is your build system limiting the compile process to? When you say your "CI build failed", what does that mean, exactly? What process dies with what error?

randall77 avatar Aug 26 '24 22:08 randall77

Our build system isn't limiting the memory allocated to the compile process. We are building on EC2 instances without swap space configured that have 32 GB memory. What is happening is that the kernel OOM killer is terminating the process when it is consuming too much memory. It takes on average 25 minutes for the compilation to reach that point before it is killed.

I will work on extracting a reproducer for this and post something by the end of the week. Thanks!

proof-nicholas avatar Aug 26 '24 23:08 proof-nicholas

Timed out in state WaitingForInfo. Closing.

(I am just a bot, though. Please speak up if this is a mistake or you have the requested information.)

gopherbot avatar Sep 28 '24 22:09 gopherbot