x/tools/gopls: Is there a way to reduce the memory usage? #61352

Kidsunbo · 2023-07-14T05:35:29Z

gopls version

Build info
----------
golang.org/x/tools/gopls v0.12.4
    golang.org/x/tools/gopls@v0.12.4 h1:nce5etAamR46d9oNGxop1aRK5rDQ0NqcY/SHIcyfEKY=
    github.com/BurntSushi/toml@v1.2.1 h1:9F2/+DoOYIOksmaJFPw1tGFy1eDnIJXg+UHjuD8lTak=
    github.com/google/go-cmp@v0.5.9 h1:O2Tfq5qg4qc4AmwVlvv0oLiVAGB7enBSJ2x2DqQFi38=
    github.com/sergi/go-diff@v1.1.0 h1:we8PVUC3FE2uYfodKH/nBHMSetSfHDR6scGdBi+erh0=
    golang.org/x/exp@v0.0.0-20220722155223-a9213eeb770e h1:+WEEuIdZHnUeJJmEUjyYC2gfUMj69yZXw17EnHg/otA=
    golang.org/x/exp/typeparams@v0.0.0-20221212164502-fae10dda9338 h1:2O2DON6y3XMJiQRAS1UWU+54aec2uopH3x7MAiqGW6Y=
    golang.org/x/mod@v0.11.0 h1:bUO06HqtnRcc/7l71XBe4WcqTZ+3AH1J59zWDDwLKgU=
    golang.org/x/sync@v0.3.0 h1:ftCYgMx6zT/asHUrPw8BLLscYtGznsLAnjq5RH9P66E=
    golang.org/x/sys@v0.9.0 h1:KS/R3tvhPqvJvwcKfnBHJwwthS11LRhmM5D59eEXa0s=
    golang.org/x/text@v0.10.0 h1:UpjohKhiEgNc0CSauXmwYftY1+LlaC75SJwh0SgCX58=
    golang.org/x/tools@v0.10.1-0.20230622221742-0622ad2359a7 h1:5PWemM67wMSPpO0Y3lOPlyvgO3z56YkZRxPFcdd300g=
    golang.org/x/vuln@v0.0.0-20230110180137-6ad3e3d07815 h1:A9kONVi4+AnuOr1dopsibH6hLi1Huy54cbeJxnq4vmU=
    honnef.co/go/tools@v0.4.2 h1:6qXr+R5w+ktL5UkwEbPp+fEvfyoMPche6GkOpGHZcLc=
    mvdan.cc/gofumpt@v0.4.0 h1:JVf4NN1mIpHogBj7ABpgOyZc65/UUOkKQFkoURsz4MM=
    mvdan.cc/xurls/v2@v2.4.0 h1:tzxjVAj+wSBmDcF6zBB7/myTy3gX9xvi8Tyr28AuQgc=
go: go1.20.6

go env

What did you do?

I have one close-source backend project, gopls takes 20 minutes to index and the memory usage is intolerably high. For comparison, GoLand only uses no more than 5 GB and only 30 sec to finish the indexing.

The computer I use is MacBook Pro (16-inch, 2019) with 32 GB memory.

I don't know what causes this but for information, the project has some big Golang source code files with more than 400,000 LOC, which are generated by thrift. I've also tried to index the source code of k8s, it works fine and can finish indexing in seconds and the memory usage is less than 4GB.

What did you expect to see?

The memory usage could be much less and the speed could be faster.

What did you see instead?

The whole process takes so long and uses a lot of memory.

Editor and settings

All the settings are default with the default Golang extension in VSCode.

Logs

The text was updated successfully, but these errors were encountered:

findleyr · 2023-07-14T12:41:44Z

Hi, do you by any chance have "staticcheck" enabled? Can you share your gopls settings?

Kidsunbo · 2023-07-14T16:58:02Z

Hi, do you by any chance have "staticcheck" enabled? Can you share your gopls settings?

Yeah, the gopls setting is all the default. I didn't change anything after install it. I notice that staticcheck is enabled.
There are three stages when indexing:

gopls takes all available CPU and memory when I open some files in VSCode. I notice that if the package containing the opened file imports less package, the memory is consumed less and the indexing finishes earlier. But it seems that it only indexes that package and the imported packages.
Multiple compile processes start compiling. It takes some time and use a lot of CPU. But the memory is fine.
Staticcheck is running. Same with stage2, memory is fine.

The memory problem only happens in stage1.

findleyr · 2023-07-14T17:09:34Z

@Kidsunbo sorry I meant the staticcheck analyzers integrated with gopls, via the "staticcheck" setting: https://github.com/golang/tools/blob/master/gopls/doc/settings.md#staticcheck-bool

If you are using the defaults, I assume this is not enabled, unless your editor changes the defaults.

~~Which editor are you using?~~ Nevermind, I see that you are using VS Code!

Can you share the output of gopls stats -anon? Would you also be willing to grab a profile?

Kidsunbo · 2023-07-15T03:04:21Z

Sure, here is the output of gopls stats -anon.

Initializing workspace...     done (34.534946727s)
Gathering bug reports...      done (122.796093ms)
Querying memstats...          done (1.047511462s)
Querying workspace stats...   done (16.829792ms)
Collecting directory info...  done (14.952613ms)
{
  "DirStats": {
    "Files": 967,
    "TestdataFiles": 0,
    "GoFiles": 922,
    "ModFiles": 1,
    "Dirs": 232
  },
  "GOARCH": "amd64",
  "GOOS": "darwin",
  "GoVersion": "go1.20.6",
  "GoplsVersion": "v0.12.4",
  "InitialWorkspaceLoadDuration": "34.534946727s",
  "MemStats": {
    "HeapAlloc": 941055336,
    "HeapInUse": 1035337728,
    "TotalAlloc": 30576936664
  },
  "WorkspaceStats": {
    "Files": {
      "Total": 10552,
      "Largest": 8091936,
      "Errs": 0
    },
    "Views": [
      {
        "GoCommandVersion": "go1.20.6",
        "AllPackages": {
          "Packages": 2318,
          "LargestPackage": 187,
          "CompiledGoFiles": 10865,
          "Modules": 460
        },
        "WorkspacePackages": {
          "Packages": 204,
          "LargestPackage": 104,
          "CompiledGoFiles": 1238,
          "Modules": 1
        },
        "Diagnostics": 5
      }
    ]
  }
}

Maybe it's due to I restarted my Mac. This time the process seems to be OK. It finished in just a few minutes. But is the TotalAlloc still a little high or expected?

As for the profile, I didn't find it in /tmp. In addition, all the projects that trigger the problem are close-source projects in my company. I think I am not allowed to share the profile which might contain debug info or something. Sorry for that.

findleyr · 2023-07-16T01:46:11Z

Thanks @Kidsunbo.

It looks like you have a medium-large workspace, but perhaps with some large packages. We have two existing bugs related to opening a package that depends on a particularly large package (#61178 and #61207).

Based on the symptoms you describe, it sounds like static analysis is taking a long time. It may not take a long time now, because it successfully analyzed all your dependencies (and now those results are cached).

As for the profile, I didn't find it in /tmp. In addition, all the projects that trigger the problem are close-source projects in my company. I think I am not allowed to share the profile which might contain debug info or something.

Profiles in general do not contain private information (they contain timing information for functions in the gopls executable). However, all we really need is the top functions, which you can inspect before sharing. If you could do this, it would be very useful:

Start gopls with -debug=localhost:6060
From a terminal, run go tool pprof -seconds 10 -top -cum http://localhost:6060/debug/pprof/profile

That will output the top functions consuming CPU in gopls, during the 10 seconds that it samples. Try to catch gopls in the act of burning through CPU/memory. If you can share the results, it will tell us the root cause.

Kidsunbo · 2023-07-16T02:53:12Z

Thanks @Kidsunbo.

It looks like you have a medium-large workspace, but perhaps with some large packages. We have two existing bugs related to opening a package that depends on a particularly large package (#61178 and #61207).

Based on the symptoms you describe, it sounds like static analysis is taking a long time. It may not take a long time now, because it successfully analyzed all your dependencies (and now those results are cached).

As for the profile, I didn't find it in /tmp. In addition, all the projects that trigger the problem are close-source projects in my company. I think I am not allowed to share the profile which might contain debug info or something.

Profiles in general do not contain private information (they contain timing information for functions in the gopls executable). However, all we really need is the top functions, which you can inspect before sharing. If you could do this, it would be very useful:

Start gopls with -debug=localhost:6060

From a terminal, run go tool pprof -seconds 10 -top -cum http://localhost:6060/debug/pprof/profile

That will output the top functions consuming CPU in gopls, during the 10 seconds that it samples. Try to catch gopls in the act of burning through CPU/memory. If you can share the results, it will tell us the root cause.

Sure, here is the output:

Fetching profile over HTTP from http://localhost:6060/debug/pprof/profile?seconds=10
Please wait... (10s)
Saved profile in /Users/sunbo/pprof/pprof.samples.cpu.002.pb.gz
Type: cpu
Time: Jul 16, 2023 at 10:47am (CST)
Duration: 10.11s, Total samples = 38.46s (380.59%)
Showing nodes accounting for 33.78s, 87.83% of 38.46s total
Dropped 517 nodes (cum <= 0.19s)
      flat  flat%   sum%        cum   cum%
         0     0%     0%     28.95s 75.27%  golang.org/x/sync/errgroup.(*Group).Go.func1
         0     0%     0%     23.73s 61.70%  go/types.(*Checker).Files (inline)
         0     0%     0%     23.73s 61.70%  go/types.(*Checker).checkFiles
         0     0%     0%     22.76s 59.18%  golang.org/x/tools/gopls/internal/lsp/cache.(*analysisNode).run
         0     0%     0%     22.76s 59.18%  golang.org/x/tools/gopls/internal/lsp/cache.(*analysisNode).runCached
         0     0%     0%     22.76s 59.18%  golang.org/x/tools/gopls/internal/lsp/cache.(*snapshot).Analyze.func3.1
         0     0%     0%     22.74s 59.13%  golang.org/x/tools/gopls/internal/lsp/cache.(*analysisNode).typeCheck
     0.01s 0.026% 0.026%     18.81s 48.91%  runtime.systemstack
     0.32s  0.83%  0.86%     17.02s 44.25%  runtime.mallocgc
    13.60s 35.36% 36.22%     15.26s 39.68%  runtime.scanobject
     0.03s 0.078% 36.30%     14.14s 36.77%  runtime.deductAssistCredit
     0.01s 0.026% 36.32%     14.11s 36.69%  runtime.gcAssistAlloc
         0     0% 36.32%     14.10s 36.66%  runtime.gcAssistAlloc.func1
     0.25s  0.65% 36.97%     14.10s 36.66%  runtime.gcAssistAlloc1
     0.03s 0.078% 37.05%     13.85s 36.01%  runtime.gcDrainN
     0.15s  0.39% 37.44%     11.99s 31.18%  go/types.(*Checker).processDelayed
     0.02s 0.052% 37.49%     11.77s 30.60%  runtime.newobject (partial-inline)
     0.07s  0.18% 37.68%     11.63s 30.24%  go/types.(*Checker).funcDecl.func1
     0.05s  0.13% 37.81%     11.56s 30.06%  go/types.(*Checker).funcBody
         0     0% 37.81%        11s 28.60%  go/types.(*Checker).stmtList
     0.20s  0.52% 38.33%     10.92s 28.39%  go/types.(*Checker).stmt
     0.01s 0.026% 38.35%     10.28s 26.73%  go/types.(*Checker).rawExpr
     0.07s  0.18% 38.53%      9.31s 24.21%  go/types.(*Checker).exprInternal
     0.08s  0.21% 38.74%      8.57s 22.28%  go/types.(*Checker).packageObjects
     0.07s  0.18% 38.92%      8.32s 21.63%  go/types.(*Checker).objDecl
         0     0% 38.92%      7.45s 19.37%  go/types.(*Checker).expr
         0     0% 38.92%      6.14s 15.96%  golang.org/x/tools/gopls/internal/lsp/cache.ParseGoSrc
         0     0% 38.92%      6.12s 15.91%  go/parser.ParseFile
         0     0% 38.92%      6.10s 15.86%  go/parser.(*parser).parseFile
     2.03s  5.28% 44.20%      5.82s 15.13%  runtime.mapassign
     0.22s  0.57% 44.77%      5.35s 13.91%  go/types.(*Checker).recordTypeAndValue
     0.02s 0.052% 44.83%      5.05s 13.13%  go/types.(*Checker).exprList
     0.02s 0.052% 44.88%      5.03s 13.08%  go/types.(*Checker).callExpr
         0     0% 44.88%      4.82s 12.53%  go/parser.(*parser).parseDecl
         0     0% 44.88%      4.71s 12.25%  go/parser.(*parser).parseFuncDecl
     0.09s  0.23% 45.11%      4.29s 11.15%  go/types.(*Checker).funcDecl
     0.08s  0.21% 45.32%      4.23s 11.00%  go/types.(*Checker).funcType
         0     0% 45.32%      3.97s 10.32%  golang.org/x/tools/gopls/internal/lsp/cache.(*analysisNode).run.func1
         0     0% 45.32%      3.97s 10.32%  golang.org/x/tools/gopls/internal/lsp/cache.parseGoImpl
         0     0% 45.32%      3.73s  9.70%  go/parser.(*parser).parseBody
         0     0% 45.32%      3.70s  9.62%  go/types.(*Checker).multiExpr
     0.02s 0.052% 45.37%      3.62s  9.41%  go/parser.(*parser).parseStmtList
     0.41s  1.07% 46.44%      3.59s  9.33%  go/ast.Walk
         0     0% 46.44%      3.48s  9.05%  go/parser.(*parser).parseStmt
         0     0% 46.44%      3.21s  8.35%  sync.(*Once).Do (inline)
         0     0% 46.44%      3.21s  8.35%  sync.(*Once).doSlow
     0.02s 0.052% 46.49%      3.06s  7.96%  runtime.growslice
     0.01s 0.026% 46.52%      2.97s  7.72%  go/types.(*Checker).record
         0     0% 46.52%      2.81s  7.31%  go/types.(*Checker).initVars
     0.10s  0.26% 46.78%      2.80s  7.28%  go/types.(*Checker).collectParams
         0     0% 46.78%      2.67s  6.94%  go/types.(*Checker).binary
         0     0% 46.78%      2.64s  6.86%  go/types.(*Checker).varDecl
     0.15s  0.39% 47.17%      2.52s  6.55%  go/types.(*Checker).selector
         0     0% 47.17%      2.51s  6.53%  go/types.(*Checker).assignVars
     0.05s  0.13% 47.30%      2.48s  6.45%  go/types.(*Checker).collectObjects
         0     0% 47.30%      2.45s  6.37%  go/ast.Inspect (inline)
         0     0% 47.30%      2.45s  6.37%  go/ast.walkDeclList
         0     0% 47.30%      2.42s  6.29%  go/types.(*Checker).exprOrType
     0.01s 0.026% 47.32%      2.37s  6.16%  go/parser.(*parser).parseSimpleStmt
         0     0% 47.32%      2.31s  6.01%  go/types.(*Checker).indexedElts
         0     0% 47.32%      2.29s  5.95%  go/types.(*Checker).updateExprType (inline)
         0     0% 47.32%      2.29s  5.95%  go/types.(*Checker).updateExprType0
     0.06s  0.16% 47.48%      2.24s  5.82%  go/types.(*Checker).walkDecl
         0     0% 47.48%      2.23s  5.80%  golang.org/x/tools/gopls/internal/lsp/cache.(*typeCheckBatch).checkPackage.func1
         0     0% 47.48%      2.22s  5.77%  golang.org/x/tools/gopls/internal/lsp/cache.(*snapshot).forEachPackageInternal.func2
         0     0% 47.48%      2.22s  5.77%  golang.org/x/tools/gopls/internal/lsp/cache.(*typeCheckBatch).checkPackage
         0     0% 47.48%      2.22s  5.77%  golang.org/x/tools/gopls/internal/lsp/cache.(*typeCheckBatch).handleSyntaxPackage
         0     0% 47.48%      2.21s  5.75%  golang.org/x/tools/gopls/internal/lsp/cache.typeCheckImpl
         0     0% 47.48%      2.21s  5.75%  golang.org/x/tools/internal/memoize.(*Promise).run.func2
         0     0% 47.48%      2.20s  5.72%  golang.org/x/tools/gopls/internal/lsp/cache.(*parseCache).startParse.func1
         0     0% 47.48%      2.20s  5.72%  golang.org/x/tools/gopls/internal/lsp/cache.doTypeCheck
         0     0% 47.48%      2.20s  5.72%  golang.org/x/tools/internal/memoize.(*Promise).run.func2.1
         0     0% 47.48%      2.20s  5.72%  runtime/trace.WithRegion
     0.01s 0.026% 47.50%      2.17s  5.64%  go/types.(*Checker).assignment
         0     0% 47.50%      2.15s  5.59%  go/types.(*Checker).definedType
         0     0% 47.50%      2.13s  5.54%  go/parser.(*parser).parseExprList
         0     0% 47.50%      2.13s  5.54%  go/parser.(*parser).parseList (partial-inline)
     2.11s  5.49% 52.99%      2.11s  5.49%  runtime.memclrNoHeapPointers
     0.01s 0.026% 53.02%      2.08s  5.41%  go/types.(*Checker).varType
     0.03s 0.078% 53.09%      2.02s  5.25%  go/parser.(*parser).parseIfStmt
         0     0% 53.09%      2.02s  5.25%  go/types.(*Checker).simpleStmt
         0     0% 53.09%      2.01s  5.23%  golang.org/x/tools/gopls/internal/lsp/cache.(*syntaxPackage).xrefs
         0     0% 53.09%      2.01s  5.23%  golang.org/x/tools/gopls/internal/lsp/cache.(*syntaxPackage).xrefs.func1
         0     0% 53.09%      2.01s  5.23%  golang.org/x/tools/gopls/internal/lsp/source/xrefs.Index
         0     0% 53.09%      1.99s  5.17%  go/types.(*Checker).walkDecls (inline)
     0.08s  0.21% 53.30%      1.95s  5.07%  go/ast.walkStmtList
     0.55s  1.43% 54.73%      1.95s  5.07%  go/types.(*Checker).collectObjects.func1
     0.60s  1.56% 56.29%      1.95s  5.07%  runtime.mapassign_fast64ptr
     0.02s 0.052% 56.34%      1.91s  4.97%  go/ast.inspector.Visit
     0.02s 0.052% 56.40%      1.87s  4.86%  go/parser.(*parser).parseBinaryExpr
         0     0% 56.40%      1.87s  4.86%  go/parser.(*parser).parseExpr
         0     0% 56.40%      1.87s  4.86%  runtime.(*mheap).alloc.func1
         0     0% 56.40%      1.87s  4.86%  runtime.(*mheap).allocSpan
     0.14s  0.36% 56.76%      1.78s  4.63%  go/types.(*Checker).ident
         0     0% 56.76%      1.74s  4.52%  go/parser.(*parser).parseUnaryExpr
     0.02s 0.052% 56.81%      1.73s  4.50%  go/parser.(*parser).parsePrimaryExpr
     1.71s  4.45% 61.26%      1.71s  4.45%  runtime.madvise
         0     0% 61.26%      1.71s  4.45%  runtime.sysUsed (inline)
         0     0% 61.26%      1.71s  4.45%  runtime.sysUsedOS (inline)
     0.02s 0.052% 61.31%      1.65s  4.29%  go/types.(*Checker).typInternal
         0     0% 61.31%      1.54s  4.00%  go/parser.(*parser).parseBlockStmt
         0     0% 61.31%      1.53s  3.98%  runtime.gcBgMarkWorker.func2
     0.01s 0.026% 61.34%      1.53s  3.98%  runtime.gcDrain
         0     0% 61.34%      1.52s  3.95%  runtime.gcBgMarkWorker
     0.04s   0.1% 61.44%      1.52s  3.95%  runtime.typedmemmove
     0.16s  0.42% 61.86%      1.50s  3.90%  golang.org/x/tools/gopls/internal/lsp/source/xrefs.Index.func3
         0     0% 61.86%      1.47s  3.82%  go/types.(*Checker).openScope
     0.86s  2.24% 64.09%      1.46s  3.80%  runtime.findObject
     0.68s  1.77% 65.86%      1.45s  3.77%  runtime.evacuate
         0     0% 65.86%      1.45s  3.77%  runtime.growWork
     0.06s  0.16% 66.02%      1.43s  3.72%  go/ast.walkExprList
     0.11s  0.29% 66.30%      1.37s  3.56%  runtime.mapassign_faststr
     0.06s  0.16% 66.46%      1.37s  3.56%  runtime.wbBufFlush
         0     0% 66.46%      1.33s  3.46%  go/parser.(*parser).next
     0.56s  1.46% 67.91%      1.30s  3.38%  runtime.gcWriteBarrier
         0     0% 67.91%      1.30s  3.38%  runtime.wbBufFlush.func1
     0.35s  0.91% 68.82%      1.30s  3.38%  runtime.wbBufFlush1
         0     0% 68.82%      1.23s  3.20%  go/parser.(*parser).next0
     1.23s  3.20% 72.02%      1.23s  3.20%  runtime.memmove
     0.03s 0.078% 72.10%      1.22s  3.17%  go/parser.resolveFile
         0     0% 72.10%      1.20s  3.12%  golang.org/x/tools/internal/gcimporter.IExportShallow
         0     0% 72.10%      1.20s  3.12%  golang.org/x/tools/internal/gcimporter.iexportCommon
     0.05s  0.13% 72.23%      1.18s  3.07%  go/scanner.(*Scanner).Scan
         0     0% 72.23%      1.18s  3.07%  golang.org/x/tools/gopls/internal/lsp/cache.execActions.func1
         0     0% 72.23%      1.18s  3.07%  golang.org/x/tools/gopls/internal/lsp/cache.execActions.func1.1
     0.02s 0.052% 72.28%      1.17s  3.04%  runtime.(*hmap).newoverflow
         0     0% 72.28%      1.15s  2.99%  golang.org/x/tools/gopls/internal/lsp/cache.(*action).exec
     0.08s  0.21% 72.49%      1.14s  2.96%  go/parser.(*resolver).Visit
     0.03s 0.078% 72.57%      1.12s  2.91%  go/parser.(*parser).parseIdent
         0     0% 72.57%      1.12s  2.91%  go/types.(*Checker).shortVarDecl
         0     0% 72.57%      1.10s  2.86%  golang.org/x/tools/gopls/internal/lsp/cache.(*action).exec.func6
         0     0% 72.57%      1.06s  2.76%  go/types.(*Scope).Insert
         0     0% 72.57%      1.05s  2.73%  go/types.(*Checker).recordUse
     0.05s  0.13% 72.70%      1.01s  2.63%  go/types.(*Checker).arguments
     0.03s 0.078% 72.78%      1.01s  2.63%  go/types.(*Checker).unary
         0     0% 72.78%      1.01s  2.63%  go/types.(*Scope).insert (inline)
     0.23s   0.6% 73.37%      0.93s  2.42%  runtime.bulkBarrierPreWrite
         0     0% 73.37%      0.91s  2.37%  go/types.(*Checker).exprWithHint
         0     0% 73.37%      0.91s  2.37%  runtime.hashGrow
         0     0% 73.37%      0.90s  2.34%  golang.org/x/tools/internal/gcimporter.(*iexporter).doDecl
         0     0% 73.37%      0.90s  2.34%  runtime.makeBucketArray
     0.02s 0.052% 73.43%      0.89s  2.31%  go/parser.(*parser).parseCallOrConversion
         0     0% 73.43%      0.89s  2.31%  go/parser.(*parser).parseForStmt
     0.02s 0.052% 73.48%      0.89s  2.31%  go/types.NewScope (inline)
         0     0% 73.48%      0.88s  2.29%  go/types.(*Checker).declare
         0     0% 73.48%      0.87s  2.26%  runtime.newarray
         0     0% 73.48%      0.84s  2.18%  go/parser.(*parser).parseIfHeader
     0.02s 0.052% 73.53%      0.84s  2.18%  runtime.slicebytetostring
     0.01s 0.026% 73.56%      0.81s  2.11%  golang.org/x/tools/go/types/objectpath.(*Encoder).For
     0.17s  0.44% 74.00%      0.78s  2.03%  go/scanner.(*Scanner).scanIdentifier
         0     0% 74.00%      0.75s  1.95%  go/types.(*Checker).typeDecl
         0     0% 74.00%      0.74s  1.92%  go/parser.(*parser).parseParameters
     0.33s  0.86% 74.86%      0.74s  1.92%  runtime.evacuate_fast64
         0     0% 74.86%      0.74s  1.92%  runtime.growWork_fast64
         0     0% 74.86%      0.73s  1.90%  go/types.(*Checker).assignVar
     0.01s 0.026% 74.88%      0.73s  1.90%  go/types.(*Checker).recordDef (inline)
         0     0% 74.88%      0.73s  1.90%  runtime.makeslice
     0.04s   0.1% 74.99%      0.70s  1.82%  go/types.lookupFieldOrMethod
         0     0% 74.99%      0.69s  1.79%  go/parser.(*resolver).walkBody
     0.01s 0.026% 75.01%      0.69s  1.79%  go/types.LookupFieldOrMethod
     0.69s  1.79% 76.81%      0.69s  1.79%  runtime.heapBitsForAddr
     0.04s   0.1% 76.91%      0.64s  1.66%  go/parser.(*resolver).walkStmts (inline)
         0     0% 76.91%      0.63s  1.64%  golang.org/x/tools/go/analysis/passes/inspect.run
         0     0% 76.91%      0.63s  1.64%  golang.org/x/tools/go/ast/inspector.New (inline)
         0     0% 76.91%      0.63s  1.64%  golang.org/x/tools/go/ast/inspector.traverse
         0     0% 76.91%      0.62s  1.61%  go/types.(*Checker).validVarType
     0.01s 0.026% 76.94%      0.62s  1.61%  go/types.(*objset).insert
     0.01s 0.026% 76.96%      0.60s  1.56%  go/parser.(*parser).parseOperand
         0     0% 76.96%      0.60s  1.56%  go/parser.(*parser).parseReturnStmt
         0     0% 76.96%      0.59s  1.53%  go/parser.(*parser).expect
         0     0% 76.96%      0.59s  1.53%  go/parser.(*parser).parseParameterList
     0.03s 0.078% 77.04%      0.59s  1.53%  go/types.(*Checker).collectMethods
         0     0% 77.04%      0.58s  1.51%  bytes.(*Buffer).grow
         0     0% 77.04%      0.58s  1.51%  go/parser.(*parser).parseSwitchStmt
         0     0% 77.04%      0.58s  1.51%  go/types.(*Checker).recordSelection
         0     0% 77.04%      0.57s  1.48%  go/parser.(*parser).parseCaseClause
     0.08s  0.21% 77.25%      0.57s  1.48%  golang.org/x/tools/internal/gcimporter.(*exportWriter).param
     0.11s  0.29% 77.54%      0.53s  1.38%  go/types.(*Checker).structType
         0     0% 77.54%      0.48s  1.25%  go/types.(*Checker).sprintf
         0     0% 77.54%      0.48s  1.25%  golang.org/x/tools/internal/gcimporter.(*exportWriter).typ
         0     0% 77.54%      0.47s  1.22%  golang.org/x/tools/internal/gcimporter.(*iexporter).typOff
     0.18s  0.47% 78.00%      0.47s  1.22%  runtime.mapaccess1_faststr
         0     0% 78.00%      0.46s  1.20%  go/parser.(*parser).parseRhs (inline)
     0.02s 0.052% 78.06%      0.46s  1.20%  go/types.(*Scope).Lookup (inline)
         0     0% 78.06%      0.46s  1.20%  go/types.(*object).Id (partial-inline)
         0     0% 78.06%      0.46s  1.20%  go/types.Id
         0     0% 78.06%      0.46s  1.20%  go/types.sprintf
         0     0% 78.06%      0.44s  1.14%  go/types.(*Checker).labels
     0.01s 0.026% 78.08%      0.43s  1.12%  go/types.(*Checker).blockBranches
         0     0% 78.08%      0.43s  1.12%  runtime.(*mSpanStateBox).get (inline)
     0.43s  1.12% 79.20%      0.43s  1.12%  runtime/internal/atomic.(*Uint8).Load (inline)
         0     0% 79.20%      0.42s  1.09%  go/types.(*Checker).blockBranches.func4
         0     0% 79.20%      0.42s  1.09%  go/types.(*Scope).squash
         0     0% 79.20%      0.42s  1.09%  go/types.(*operand).setConst
         0     0% 79.20%      0.42s  1.09%  runtime.makemap_small
         0     0% 79.20%      0.41s  1.07%  go/constant.MakeFromLiteral
     0.02s 0.052% 79.25%      0.41s  1.07%  runtime.gcWriteBarrierDX
         0     0% 79.25%      0.40s  1.04%  go/types.(*Checker).initOrder
     0.01s 0.026% 79.28%      0.39s  1.01%  go/types.dependencyGraph
     0.17s  0.44% 79.72%      0.39s  1.01%  golang.org/x/tools/go/ast/inspector.traverse.func1
         0     0% 79.72%      0.37s  0.96%  runtime.memclrHasPointers
         0     0% 79.72%      0.35s  0.91%  go/parser.(*parser).parseParamDecl
         0     0% 79.72%      0.35s  0.91%  go/parser.(*parser).parseSelector
     0.01s 0.026% 79.75%      0.35s  0.91%  golang.org/x/tools/go/ast/inspector.(*Inspector).Preorder
     0.34s  0.88% 80.63%      0.34s  0.88%  aeshashbody
     0.01s 0.026% 80.66%      0.34s  0.88%  go/parser.(*parser).tryIdentOrType
     0.27s   0.7% 81.36%      0.33s  0.86%  go/types.(*Checker).resolveBaseTypeName
     0.33s  0.86% 82.22%      0.33s  0.86%  runtime.evacuated (inline)
         0     0% 82.22%      0.33s  0.86%  sort.Slice
         0     0% 82.22%      0.33s  0.86%  sort.pdqsort_func
         0     0% 82.22%      0.32s  0.83%  bytes.(*Buffer).Write
     0.01s 0.026% 82.24%      0.32s  0.83%  go/types.NewParam (inline)
         0     0% 82.24%      0.31s  0.81%  go/parser.(*parser).expectSemi
         0     0% 82.24%      0.31s  0.81%  go/parser.(*parser).parseType
         0     0% 82.24%      0.30s  0.78%  go/types.(*Checker).recordScope
         0     0% 82.24%      0.30s  0.78%  go/types.ExprString
         0     0% 82.24%      0.30s  0.78%  golang.org/x/tools/go/analysis/passes/printf.run
     0.29s  0.75% 83.00%      0.29s  0.75%  go/ast.(*FieldList).NumFields (inline)
     0.01s 0.026% 83.02%      0.29s  0.75%  go/types.(*Checker).recordUntyped
         0     0% 83.02%      0.29s  0.75%  go/types.(*Checker).rememberUntyped (inline)
         0     0% 83.02%      0.29s  0.75%  golang.org/x/tools/go/analysis/passes/printf.checkCall
         0     0% 83.02%      0.29s  0.75%  net/http.(*ServeMux).ServeHTTP
         0     0% 83.02%      0.29s  0.75%  net/http.(*conn).serve
         0     0% 83.02%      0.29s  0.75%  net/http.HandlerFunc.ServeHTTP
         0     0% 83.02%      0.29s  0.75%  net/http.serverHandler.ServeHTTP
         0     0% 83.02%      0.28s  0.73%  golang.org/x/tools/go/analysis/passes/printf.checkCall.func1
         0     0% 83.02%      0.28s  0.73%  runtime.concatstrings
     0.10s  0.26% 83.28%      0.27s   0.7%  go/scanner.(*Scanner).next
         0     0% 83.28%      0.27s   0.7%  go/token.IsExported
         0     0% 83.28%      0.27s   0.7%  go/types.(*Checker).comparison
         0     0% 83.28%      0.27s   0.7%  go/types.(*Checker).initVar
         0     0% 83.28%      0.27s   0.7%  go/types.(*Checker).typ (inline)
     0.14s  0.36% 83.65%      0.27s   0.7%  go/types.lookupMethod
         0     0% 83.65%      0.27s   0.7%  golang.org/x/tools/internal/gcimporter.(*exportWriter).paramList
         0     0% 83.65%      0.27s   0.7%  golang.org/x/tools/internal/gcimporter.(*exportWriter).signature
         0     0% 83.65%      0.27s   0.7%  golang.org/x/tools/internal/gcimporter.(*iexporter).newWriter (inline)
         0     0% 83.65%      0.26s  0.68%  go/types.(*Named).lookupMethod
         0     0% 83.65%      0.26s  0.68%  go/types.(*Scope).LookupParent
         0     0% 83.65%      0.26s  0.68%  net/http/pprof.Index
         0     0% 83.65%      0.26s  0.68%  net/http/pprof.collectProfile
         0     0% 83.65%      0.26s  0.68%  net/http/pprof.handler.ServeHTTP
         0     0% 83.65%      0.26s  0.68%  net/http/pprof.handler.serveDeltaProfile
     0.17s  0.44% 84.09%      0.26s  0.68%  runtime.greyobject
         0     0% 84.09%      0.26s  0.68%  sort.Sort
         0     0% 84.09%      0.26s  0.68%  sort.pdqsort
     0.26s  0.68% 84.76%      0.26s  0.68%  unicode/utf8.DecodeRuneInString
         0     0% 84.76%      0.25s  0.65%  bytes.growSlice
     0.24s  0.62% 85.39%      0.25s  0.65%  go/ast.(*FuncType).Pos (partial-inline)
         0     0% 85.39%      0.25s  0.65%  go/ast.NewScope (inline)
         0     0% 85.39%      0.25s  0.65%  go/types.(*Checker).declStmt
     0.15s  0.39% 85.78%      0.25s  0.65%  runtime.bulkBarrierPreWriteSrcOnly
         0     0% 85.78%      0.25s  0.65%  runtime.concatstring3
         0     0% 85.78%      0.25s  0.65%  runtime.rawstring (inline)
         0     0% 85.78%      0.25s  0.65%  runtime.rawstringtmp
         0     0% 85.78%      0.25s  0.65%  runtime/pprof.(*Profile).WriteTo
         0     0% 85.78%      0.25s  0.65%  runtime/pprof.writeHeap
         0     0% 85.78%      0.25s  0.65%  runtime/pprof.writeHeapInternal
         0     0% 85.78%      0.25s  0.65%  runtime/pprof.writeHeapProto
     0.01s 0.026% 85.80%      0.24s  0.62%  runtime.gcWriteBarrierCX
     0.24s  0.62% 86.43%      0.24s  0.62%  runtime.memhash64
     0.02s 0.052% 86.48%      0.23s   0.6%  go/types.(*Checker).declStmt.func1
         0     0% 86.48%      0.23s   0.6%  golang.org/x/tools/gopls/internal/lsp/filecache.gc
     0.01s 0.026% 86.51%      0.22s  0.57%  bytes.(*Buffer).WriteString
         0     0% 86.51%      0.22s  0.57%  go/parser.(*resolver).declare
         0     0% 86.51%      0.22s  0.57%  go/parser.(*resolver).openScope (inline)
     0.02s 0.052% 86.56%      0.22s  0.57%  go/types.(*Checker).sliceExpr
     0.01s 0.026% 86.58%      0.22s  0.57%  go/types.NewFunc (inline)
     0.04s   0.1% 86.69%      0.22s  0.57%  runtime.heapBitsSetType
         0     0% 86.69%      0.21s  0.55%  go/parser.(*resolver).resolve
         0     0% 86.69%      0.21s  0.55%  go/types.(*Checker).later (inline)
         0     0% 86.69%      0.21s  0.55%  go/types.concat (inline)
     0.01s 0.026% 86.71%      0.21s  0.55%  golang.org/x/tools/internal/gcimporter.(*exportWriter).doTyp
         0     0% 86.71%      0.21s  0.55%  golang.org/x/tools/internal/gcimporter.(*intWriter).uint64
     0.21s  0.55% 87.26%      0.21s  0.55%  memeqbody
         0     0% 87.26%      0.21s  0.55%  path/filepath.Walk
         0     0% 87.26%      0.21s  0.55%  path/filepath.walk
     0.21s  0.55% 87.81%      0.21s  0.55%  runtime.(*bmap).overflow (inline)
     0.01s 0.026% 87.83%      0.20s  0.52%  go/types.(*Checker).interfaceType

Kidsunbo · 2023-07-16T02:56:38Z

Thanks @Kidsunbo.

It looks like you have a medium-large workspace, but perhaps with some large packages. We have two existing bugs related to opening a package that depends on a particularly large package (#61178 and #61207).

Based on the symptoms you describe, it sounds like static analysis is taking a long time. It may not take a long time now, because it successfully analyzed all your dependencies (and now those results are cached).

As for the profile, I didn't find it in /tmp. In addition, all the projects that trigger the problem are close-source projects in my company. I think I am not allowed to share the profile which might contain debug info or something.

Profiles in general do not contain private information (they contain timing information for functions in the gopls executable). However, all we really need is the top functions, which you can inspect before sharing. If you could do this, it would be very useful:

Start gopls with -debug=localhost:6060

From a terminal, run go tool pprof -seconds 10 -top -cum http://localhost:6060/debug/pprof/profile

That will output the top functions consuming CPU in gopls, during the 10 seconds that it samples. Try to catch gopls in the act of burning through CPU/memory. If you can share the results, it will tell us the root cause.

I run the command three times, and here is the generated pb file.
pprof.samples.cpu.001.pb.gz
pprof.samples.cpu.002.pb.gz
pprof.samples.cpu.003.pb.gz

Kidsunbo · 2023-07-16T03:28:47Z

Thanks @Kidsunbo.

It looks like you have a medium-large workspace, but perhaps with some large packages. We have two existing bugs related to opening a package that depends on a particularly large package (#61178 and #61207).

Based on the symptoms you describe, it sounds like static analysis is taking a long time. It may not take a long time now, because it successfully analyzed all your dependencies (and now those results are cached).

As for the profile, I didn't find it in /tmp. In addition, all the projects that trigger the problem are close-source projects in my company. I think I am not allowed to share the profile which might contain debug info or something.

Profiles in general do not contain private information (they contain timing information for functions in the gopls executable). However, all we really need is the top functions, which you can inspect before sharing. If you could do this, it would be very useful:

Start gopls with -debug=localhost:6060

From a terminal, run go tool pprof -seconds 10 -top -cum http://localhost:6060/debug/pprof/profile

That will output the top functions consuming CPU in gopls, during the 10 seconds that it samples. Try to catch gopls in the act of burning through CPU/memory. If you can share the results, it will tell us the root cause.

I also pprof the heap which should be more related to the problem:

(pprof) top -cum
Showing nodes accounting for 42.71MB, 0.19% of 23085.89MB total
Dropped 541 nodes (cum <= 115.43MB)
Showing top 10 nodes out of 210
      flat  flat%   sum%        cum   cum%
         0     0%     0% 17907.32MB 77.57%  golang.org/x/sync/errgroup.(*Group).Go.func1
         0     0%     0% 12379.86MB 53.63%  go/types.(*Checker).checkFiles
         0     0%     0% 12343.49MB 53.47%  go/types.(*Checker).Files (inline)
       1MB 0.0043% 0.0043%  9151.34MB 39.64%  golang.org/x/tools/gopls/internal/lsp/cache.(*analysisNode).typeCheck
    2.50MB 0.011% 0.015%  9126.84MB 39.53%  golang.org/x/tools/gopls/internal/lsp/cache.(*analysisNode).run
         0     0% 0.015%  9061.40MB 39.25%  golang.org/x/tools/gopls/internal/lsp/cache.(*analysisNode).runCached
         0     0% 0.015%  9022.05MB 39.08%  golang.org/x/tools/gopls/internal/lsp/cache.(*snapshot).Analyze.func3.1
       1MB 0.0043% 0.019%  7171.92MB 31.07%  go/parser.ParseFile
   38.21MB  0.17%  0.19%  7020.44MB 30.41%  go/parser.(*parser).parseFile
         0     0%  0.19%     6981MB 30.24%  golang.org/x/tools/gopls/internal/lsp/cache.ParseGoSrc

heap.zip

adonovan · 2023-07-25T12:10:13Z

See: https://go.dev/cl/511715

findleyr · 2023-07-26T21:22:27Z

I believe we have made progress on the runaway resource usage caused by analysis. In particular, we have reduced parallelism so that analysis should never hit the same high water mark.

@Kidsunbo could you please try out the prerelease to see if it improves the situation for you?

go install golang.org/x/tools/gopls@v0.13.0-pre.2

We have ideas for how to improve the cost of analysis facts, but that is a separate issue.

Also: @xiaokentrl I see you 👎ed a few comments: are you also experiencing problems with memory usage? If so, could you share what you are experiencing?

Kidsunbo · 2023-07-27T07:49:58Z

I believe we have made progress on the runaway resource usage caused by analysis. In particular, we have reduced parallelism so that analysis should never hit the same high water mark.

@Kidsunbo could you please try out the prerelease to see if it improves the situation for you?
go install golang.org/x/tools/gopls@v0.13.0-pre.2
We have ideas for how to improve the cost of analysis facts, but that is a separate issue.

Also: @xiaokentrl I see you 👎ed a few comments: are you also experiencing problems with memory usage? If so, could you share what you are experiencing?

Yeah, much better, you guys did a good job. And now there is the progress to learn about how many packages have been indexed, which is good.
But maybe this should be fixed? VSCode seems not to display properly.

I think now this issue can be closed. It does not exhaust my resource. Thank you so much.

gopherbot · 2023-07-27T16:03:29Z

Change https://go.dev/cl/513735 mentions this issue: gopls/internal/lsp/cache: keep analysis progress reports on one line

gopherbot added Tools This label describes issues relating to any tools in the x/tools repository. gopls Issues related to the Go language server, gopls. labels Jul 14, 2023

gopherbot added this to the Unreleased milestone Jul 14, 2023

findleyr modified the milestones: Unreleased, gopls/v0.12.5 Jul 14, 2023

findleyr added the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Jul 14, 2023

seankhliao added WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. and removed WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. labels Jul 14, 2023

jamalc assigned jamalc and adonovan and unassigned jamalc Jul 20, 2023

gopherbot closed this as completed in golang/tools@38606b3 Jul 27, 2023

golang locked and limited conversation to collaborators Jul 26, 2024

gopherbot added the FrozenDueToAge label Jul 26, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

x/tools/gopls: Is there a way to reduce the memory usage? #61352

x/tools/gopls: Is there a way to reduce the memory usage? #61352

Kidsunbo commented Jul 14, 2023 •

edited

Loading

findleyr commented Jul 14, 2023 •

edited

Loading

Kidsunbo commented Jul 14, 2023

findleyr commented Jul 14, 2023 •

edited

Loading

Kidsunbo commented Jul 15, 2023 •

edited

Loading

findleyr commented Jul 16, 2023

Kidsunbo commented Jul 16, 2023

Kidsunbo commented Jul 16, 2023

Kidsunbo commented Jul 16, 2023 •

edited

Loading

adonovan commented Jul 25, 2023

findleyr commented Jul 26, 2023

Kidsunbo commented Jul 27, 2023 •

edited

Loading

gopherbot commented Jul 27, 2023

x/tools/gopls: Is there a way to reduce the memory usage? #61352

x/tools/gopls: Is there a way to reduce the memory usage? #61352

Comments

Kidsunbo commented Jul 14, 2023 • edited Loading

gopls version

go env

What did you do?

What did you expect to see?

What did you see instead?

Editor and settings

Logs

findleyr commented Jul 14, 2023 • edited Loading

Kidsunbo commented Jul 14, 2023

findleyr commented Jul 14, 2023 • edited Loading

Kidsunbo commented Jul 15, 2023 • edited Loading

findleyr commented Jul 16, 2023

Kidsunbo commented Jul 16, 2023

Kidsunbo commented Jul 16, 2023

Kidsunbo commented Jul 16, 2023 • edited Loading

adonovan commented Jul 25, 2023

findleyr commented Jul 26, 2023

Kidsunbo commented Jul 27, 2023 • edited Loading

gopherbot commented Jul 27, 2023

Kidsunbo commented Jul 14, 2023 •

edited

Loading

findleyr commented Jul 14, 2023 •

edited

Loading

findleyr commented Jul 14, 2023 •

edited

Loading

Kidsunbo commented Jul 15, 2023 •

edited

Loading

Kidsunbo commented Jul 16, 2023 •

edited

Loading

Kidsunbo commented Jul 27, 2023 •

edited

Loading