go/types: slow type checking with thousands of methods on a type #66699
Labels
NeedsInvestigation
Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Performance
Milestone
Comments
|
CC @adonovan @griesemer @mdempsky @timothy-king I'm not sure if this is worth doing, unless we can prove that it has benefits in the common case. However, it may be worth some investigation. @jacobmischka can you confirm that the codegen assigns a bunch of values of the same type? |
|
I suspect (without data) that most assignableTo operations are fast, and that the worst case only occurs when assigning a concrete type to an interface type of many methods. (It would help to know how many there are in your code). So it wouldn't make sense to memoize the entire operation, but only the slow path for large interfaces. We would also need a way to asynchronously clear the cache, as the elements could otherwise pin very large data structures indefinitely. It would be nice to get a repro before we talk more about caching. The ideal solution is always to make the predicate fast enough that no cache is necessary. |
|
In the go/types benchmarks, assignableTo is ~1-2% of type checking time (ignoring imports) across a stratified collection of standard library packages. Not sure how much of that could be cached, but in any case this suggests that this optimization will probably not be very helpful for most packages. I'll try to investigate more thoroughly at some point. |
|
This is the library we're using that I suspect is the issue: https://gqlgen.com/ It's a graphql server library which relies on codegen. I am skimming the generated files and I don't believe there are a lot of assignments of the same type, rather it seems like there's one very large struct type with a lot of instance methods. I don't see much uses of interfaces but I definitely could be missing it. We're going to try looking through suggestions in discussions for that package in particular and see if we can find a good work around. Splitting the one large file into multiple files in a sub-package didn't seem to help, unfortunately. Will try an entirely separate package if possible to see if that helps. |
Thanks, that's interesting. Approximately how many methods are there? Splitting into separate files may help for parsing, but won't help for type checking, which considers all package files. Moving to a different package will help, although if you then import that type with thousands of methods, you may pay a significant cost type checking code that uses it. |
About 4500.
Yeah, I've realized/confirmed now that it's definitely packages that import the generated package that are slow and everything else is quite fast. |
findleyr
changed the title
|
Thanks. It sounds like a cache wouldn't really help much in this case, or in general, so I've retitled this issue to more generally describe the symptoms you observe. There still may be room for improvement in our lookupMethod algorithms. |
While our tools could certainly do better, creating a type with this many methods (and then generating very large files file of assignability conversions) is likely to push a lot of algorithms into poor performance. I wonder how many of those methods are necessarily methods, and how many might be more neatly expressed as standalone functions with more focussed lists of parameters. |
|
This sounds to me like a possibly (implicit) quadratic algorithm because we look up methods sequentially. Keeping them in a map (or perhaps adding them to a map as a cache as needed) might help here. |
|
If it's helpful, as a note, some coworkers use goland and they don't experience the same issue. |
dmitshur
added
NeedsInvestigation
|
Hi, I'm one of @jacobmischka's coworkers experiencing this issue. Here's an open, unsolved issue in gqlgen that describes the same issue that we're having, with gopls struggling with ~4000 instance methods (same number that we have at our current codebase's size) on a single type: 99designs/gqlgen#2681. We'll see if there are any fixes that can be made in gqlgen but it seems this issue is being felt by others, even back in mid-2023. Thank you for helping look into this! |
|
Thanks @jacobmischka and @ericmeter. It sounds like there is room for improvement in the type checker. With respect to goland: they have their own type checker and I'm guessing its interface implementation algorithm is better optimized for very large interfaces. There are several things we could do to optimize predicates. For example, gopls itself has a fast implements algorithm for finding implementers, but that's only used for indexing method sets after type checking. We could use some of those techniques in the type checker itself, during the type checking pass. The most straightforward thing to try first would be a map lookup, as @griesemer suggests. It's hard to measure the impact of this change, as it doesn't make much difference in the common case where a type has <=dozens of methods. I suspect that a decent fraction of the work here is to set up an environment that reproduces the extreme slowness you're encountering. If anyone here has a pointer to an open source repository that reproduces the problem, that would help us get started. |
|
Thanks! I'll try to find an open source project with a nontrivial amount of these. If not, we can probably put one together but I'm afraid that will take a little longer (we're quite busy the next two weeks unfortunately). |
|
@jacobmischka what is your Can you share |
I just upgraded to 1.22.2 after running that though, so I can see if that helps at all tomorrow. Edit: That didn't help. |
|
@jacobmischka thanks. No, upgrading won't help, but your version puts the profile above in context. |
|
We modified the codegen to use plain functions instead of instance methods and the performance unfortunately didn't improve significantly. We plan to investigate further tomorrow, will report back with some more profiles. |
|
Here's an updated trace. We reduced the number of instance methods on the main generated struct to about 500 and it's still just about as slow. I stripped the paths again, but let me know if you'd like me to email an unstripped version to any of you, I just want to avoid sharing it publicly. Also please let me know if there is any other profiling we can do. Trace Main Info Memory Profiling Metrics RPC Trace Analysis Trace Information $/cancelRequest last: 33.125µs, longest: 52.25µs $/progress last: 44.417µs, longest: 44.417µs Server.diagnose last: 3.055607042s, longest: 3.753160458s Server.diagnoseChangedFiles last: 1.930986708s, longest: 2.154471917s Server.diagnoseSnapshot last: 5.988188625s, longest: 5.988188625s Server.publishDiagnostics last: 61.875µs, longest: 179.667µs cache.ModTidy last: 215.9465ms, longest: 215.9465ms cache.ParseGoSrc last: 222.542µs, longest: 39.335916ms cache.ParseMod last: 352.875µs, longest: 352.875µs cache.forEachPackage last: 2.896547166s, longest: 2.896547166s cache.readFile last: 795.25µs, longest: 12.633833ms cache.resolveImportGraph last: 8.762292ms, longest: 105.89325ms cache.snapshot.ModTidy last: 51.625µs, longest: 216.008542ms cache.snapshot.PackageDiagnostics last: 2.896602542s, longest: 2.896602542s cache.snapshot.clone last: 329.375µs, longest: 4.703459ms cache.snapshot.load last: 1.581146667s, longest: 1.581146667s cache.typeCheckBatch.checkPackage last: 2.872711375s, longest: 2.872711375s cache.typeCheckBatch.checkPackageForImport last: 494.17725ms, longest: 494.939458ms cache.typeCheckBatch.importPackage last: 7.02175ms, longest: 387.068042ms completion.Completion last: 1.954111375s, longest: 2.053395959s gocommand.Runner.Run last: 210.65475ms, longest: 210.65475ms gocommand.Runner.RunRaw last: 210.624917ms, longest: 1.279285541s golang.SignatureHelp last: 15.584µs, longest: 2.160838583s initialize last: 1.409792ms, longest: 1.409792ms initialized last: 1.598106417s, longest: 1.598106417s lsp.Server.completion last: 1.954131625s, longest: 2.053419125s lsp.Server.didChange last: 392.166µs, longest: 2.476709ms lsp.Server.didOpen last: 5.74775ms, longest: 5.74775ms lsp.Server.initialize last: 534.625µs, longest: 534.625µs lsp.Server.initialized last: 1.598066667s, longest: 1.598066667s lsp.Server.semanticTokens last: 11.958µs, longest: 30.541µs lsp.Server.signatureHelp last: 34.5µs, longest: 2.160863709s mod.Diagnostics last: 301.75µs, longest: 216.131ms mod.UpgradeDiagnostics last: 55.958µs, longest: 55.958µs mod.VulnerabilityDiagnostics last: 43.208µs, longest: 44.208µs queued last: 2.93266125s, longest: 6.652674458s snapshot.Analyze last: 3.044961459s, longest: 3.044961459s textDocument/completion last: 2.073806333s, longest: 3.969149875s textDocument/didChange last: 1.476623125s, longest: 4.897534583s textDocument/didOpen last: 1.600358875s, longest: 1.600358875s textDocument/publishDiagnostics last: 69.292µs, longest: 69.292µs textDocument/semanticTokens/full last: 1.331482125s, longest: 6.652761916s textDocument/signatureHelp last: 3.223286583s, longest: 6.757727542s window/logMessage last: 857.834µs, longest: 904.084µs window/workDoneProgress/create last: 3.698292ms, longest: 3.698292ms work.Diagnostics last: 24.75µs, longest: 37.375µs workspace/configuration last: 85.709µs, longest: 85.709µs Recent spans (oldest first) |
|
We've actually binary searched by deleting code and found that the issue was not this library with its many methods, it's a separate codegen library https://github.com/sqlc-dev/sqlc which generates an interface with ~1000 methods. Deleting the interface but keeping the implementation structs makes everything fast again. |
|
@jacobmischka Presumably there was a use for the interface? While such a large interface seems esoteric it would still be good (for us) to know where the issue with compilation is. Is it just the presence of the interface or some particular use of it? Do you know? |
|
Here's the PR in the library that implements the feature: sqlc-dev/sqlc#240 In brief, the library exposes both a struct that represents a database connection, and a separate struct that represents a database transaction. The interface represents either, so if the consumer doesn't care whether it's in a transaction or not it can use that. Edit: Oh sorry, I didn't answer your question. Just deleting the methods from the interface makes gopls instantly fast (despite obviously most of our code no longer working and having diagnostic errors). I think that suggests it's just the presence of the interface? |
|
The PR you mention shows a small-ish interface. Presumably there's a much larger one, or this one grew eventually to the huge size, is that correct? Obviously, having the interface is causing the slow-down, but your code is also not working anymore, which is of course not what you want. For us it would be good to have a concrete test case (it may suffice to generate an artificial interface with 1000 methods and and corresponding structs that satisfy the interface) - this would allow us to profile this case and find out if there's anything that can be done about it. Do you need a single huge interface? Maybe you can make your code work with a set of smaller interfaces that have exactly (more or less) the methods that you need. |
|
Sorry, the PR I linked is for the library that generates it, just for context. Its usage in our code base has generated an interface with 1250 functions now. We're currently looking into refactoring to remove the interface. Will also look a minimal reproduction. |
|
Unfortunately, a basic reproduction with almost 5000 functions in the interface doesn't immediately reproduce the issue :/ https://gist.github.com/jacobmischka/6d41f0c3361db29eaa3115e469132315 |
|
Okay, we've found the root cause (embedding the struct which implements that large interface into another struct, which is itself a field in the other non-interface struct with 4500 methods on it) and I'll stop prematurely updating. Will write back with final learnings once we've finished refactoring. |
|
@jacobmischka |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
In a discussion of gopls performance issues on #66647, a user is reporting difficulty working in a package that has a very large (140K lines) amount of code gen. Tracing showed that type checking that package was taking 2s.
Looking at their profile, it seems that almost almost all the time is spent in the
assignableTopredicate. I'm guessing that the generated code assigns a lot of values of the same type. I wonder if we should consider caching predicates during the type checking pass. In this case it appears that may reduce type checking by an order of magnitude. Would this be an overfit solution?Trace profile checkPackage
File: gopls Type: cpu Time: Apr 5, 2024 at 10:13am (CDT) Duration: 10.11s, Total samples = 11.82s (116.95%) Entering interactive mode (type "help" for commands, "o" for options) (pprof) top 50 -cum checkPackage Active filters: focus=checkPackage Showing nodes accounting for 4.70s, 39.76% of 11.82s total Dropped 87 nodes (cum <= 0.06s) Showing top 50 nodes out of 73 flat flat% sum% cum cum% 0 0% 0% 5.35s 45.26% go/types.(*Checker).Files (inline) 0 0% 0% 5.35s 45.26% go/types.(*Checker).checkFiles 0 0% 0% 5.35s 45.26% go/types.(*Checker).funcBody 0 0% 0% 5.35s 45.26% go/types.(*Checker).funcDecl.func1 0 0% 0% 5.35s 45.26% go/types.(*Checker).processDelayed 0.01s 0.085% 0.085% 5.35s 45.26% go/types.(*Checker).stmt 0 0% 0.085% 5.35s 45.26% go/types.(*Checker).stmtList 0 0% 0.085% 5.35s 45.26% golang.org/x/sync/errgroup.(*Group).Go.func1 0 0% 0.085% 5.35s 45.26% golang.org/x/tools/gopls/internal/cache.(*Snapshot).forEachPackageInternal.func2 0 0% 0.085% 5.35s 45.26% golang.org/x/tools/gopls/internal/cache.(*typeCheckBatch).checkPackage 0 0% 0.085% 5.35s 45.26% golang.org/x/tools/gopls/internal/cache.(*typeCheckBatch).handleSyntaxPackage 0 0% 0.085% 5.28s 44.67% go/types.(*Checker).rawExpr 0 0% 0.085% 5.27s 44.59% go/types.(*Checker).exprInternal 0 0% 0.085% 5.22s 44.16% go/types.(*Checker).callExpr 0 0% 0.085% 5.02s 42.47% go/types.(*Checker).arguments 0 0% 0.085% 4.98s 42.13% go/types.(*Checker).assignment 0 0% 0.085% 4.96s 41.96% go/types.(*Checker).implements 0.02s 0.17% 0.25% 4.96s 41.96% go/types.(*Checker).missingMethod 0 0% 0.25% 4.96s 41.96% go/types.(*operand).assignableTo 0.03s 0.25% 0.51% 4.85s 41.03% go/types.lookupFieldOrMethodImpl 0 0% 0.51% 3.62s 30.63% go/types.(*Checker).multiExpr 0 0% 0.51% 3.44s 29.10% go/types.(*Checker).initVars 0 0% 0.51% 3.35s 28.34% go/types.(*Checker).shortVarDecl 0.04s 0.34% 0.85% 2.54s 21.49% runtime.growslice 0.50s 4.23% 5.08% 2.36s 19.97% runtime.mallocgc 0.03s 0.25% 5.33% 1.93s 16.33% go/types.(*Named).lookupMethod 0.99s 8.38% 13.71% 1.93s 16.33% go/types.lookupMethod 1.83s 15.48% 29.19% 1.83s 15.48% runtime.memclrNoHeapPointers 0 0% 29.19% 1.18s 9.98% go/types.(*Checker).expr 0 0% 29.19% 0.97s 8.21% go/types.(*Checker).unary 0.88s 7.45% 36.63% 0.94s 7.95% go/types.(*object).sameId 0 0% 36.63% 0.91s 7.70% runtime.(*mcache).nextFree 0 0% 36.63% 0.91s 7.70% runtime.(*mcache).refill 0 0% 36.63% 0.91s 7.70% runtime.(*mcentral).cacheSpan 0 0% 36.63% 0.91s 7.70% runtime.(*mcentral).grow 0 0% 36.63% 0.89s 7.53% runtime.(*mspan).initHeapBits 0 0% 36.63% 0.77s 6.51% go/types.(*Checker).simpleStmt (inline) 0 0% 36.63% 0.76s 6.43% go/types.concat (inline) 0 0% 36.63% 0.29s 2.45% go/types.(*Checker).assignVars 0.25s 2.12% 38.75% 0.25s 2.12% runtime.memmove 0 0% 38.75% 0.20s 1.69% go/types.(*Checker).rangeStmt 0 0% 38.75% 0.17s 1.44% go/types.consolidateMultiples 0 0% 38.75% 0.16s 1.35% go/types.(*Checker).genericExprList 0.05s 0.42% 39.17% 0.14s 1.18% go/types.(*comparer).identical 0 0% 39.17% 0.14s 1.18% go/types.Identical (partial-inline) 0 0% 39.17% 0.14s 1.18% go/types.lookupType 0.07s 0.59% 39.76% 0.14s 1.18% runtime.mapassign 0 0% 39.76% 0.11s 0.93% go/types.(*Checker).exprOrType 0 0% 39.76% 0.11s 0.93% runtime.newobject (partial-inline) 0 0% 39.76% 0.09s 0.76% go/types.(*Checker).selectorOriginally posted by @jacobmischka in #66647 (comment)
The text was updated successfully, but these errors were encountered: