micronaut-projects / micronaut-core

Micronaut Application Framework
http://micronaut.io
Apache License 2.0
6.03k stars 1.05k forks source link

KSP: Performance regression after migration to KSP #9750

Open tobias-bahls opened 1 year ago

tobias-bahls commented 1 year ago

Expected Behavior

After migrating from kapt to KSP, we notice a large performance regression:

Both kaptGenerateStubs and kaptKotlin combined take ~1.5 min on my machine. kspKotlin takes over 30 mins, at which point I aborted the task.

Actual Behaviour

I expected the kspKotlin step taking significantly less time than kaptGenerateStubs and kaptKotlin combined.

Steps To Reproduce

Unfortunately I don't know what exactly in our codebase triggers this issue. If there are anything more that I can provide apart from the attached VisualVM sampling profile, I'm happy to help.

Screenshot 2023-08-21 at 11 10 52

micronaut-ksp-perf-issue.nps.zip

Environment Information

Example Application

No response

Version

4.0.4

dstepanov commented 1 year ago

How big is your project? I don't think we can do anything about it, you better report it here https://github.com/google/ksp

tobias-bahls commented 1 year ago

Thanks for looking into this. We have roughly 3k classes and interfaces in our project

Spikhalskiy commented 1 year ago

We have the same experience with a small project. kapt - about 1 minute time for all kapt steps. ksp - 30 minutes+. Never finished, currently facing failures that were reported separately, but they happen after 30 minutes. We have around 1k classes. We are open to collecting any telemetry during the build needed to investigate the reason. Currently, unfortunately, I don't see any options to turn on any kind of verbosity on ksp side that may be helpful: https://github.com/google/ksp/issues/1415

dstepanov commented 1 year ago

I have merged an improvement, you can try 4.0 SNAPSHOT or wait for next 4.0.X release

dstepanov commented 1 year ago

Can you please try the 4.1 platform?

Spikhalskiy commented 1 year ago

Our project doesn't really build with KSP yet. Our next blocker is #9764 Before your change, the relevant to #9764 failure was happening after 30+ minutes. Now after 6 minutes. KAPS takes about 1-1.5 minutes. There is clearly a big improvement, but KSP is still much slowers that KAPT. Now when the performance got tolerable, I will try to hack the project so it builds and will try to provide a useful telemetry.

dstepanov commented 1 year ago

I think I can come up with more improvements.

Not sure what to do about the open issue… we might need to provide our own set of open annotations.

Spikhalskiy commented 1 year ago

@dstepanov unfortunately, without some workaround for that issue it's not feasible for us to get a full build on ksp. We have to explicitly open all our Singletons that perform any validation on the parameters. I offered a solution there by letting users modify shouldBeOpen variable in gradle build config. We already have to supply Singleton to allOpen, it wouldn't be a problem to supply it to micronaut plugin too. I understand that it's not an ideal solution and we shouldn't just open all Singletons indiscriminately, but at least it's a way to make things work.

Spikhalskiy commented 1 year ago

For our project, ValidationVisitor#visitMethod looks like the largest offender during the kspKotlin task currently. Screenshot 2023-09-04 at 4 36 49 PM

dstepanov commented 1 year ago

Can you somehow share the profiling info?

Spikhalskiy commented 1 year ago

@dstepanov Here is the exported VisualVM CPU sampling snapshot. Let me know if you need async-profiler results or anything else. ksp-validation-visitor.zip

sgammon commented 1 year ago

We've avoided some of these regressions for now by switching back temporarily to kapt.

We are all in on KSP but we've hidden our use of ksp behind a flag for now so we can test without disrupting build times.

Kapt is still supported on Micronaut 4. We hadn't realized that initially so I wanted to share here in case that's useful for any other V4 adopters.

sgammon commented 1 year ago

One other note: in our experience, clean build times are longer but cached build times with KSP are much faster than the equivalent with kapt.

Over time it seems like KSP will win on both a performance and functionality basis. So that's why we went with a flag.

Spikhalskiy commented 9 months ago

9832 made a big difference cutting down the build time until the allopen + ksp failure that our project experiences in half

Spikhalskiy commented 7 months ago

On a project kaptKotlin takes 14 seconds with the current 4.3.0-SNAPSHOT.

kspKotlin takes 40 minutes to run into "Method defines AOP advice but is declared final. Change the method to be non-final in order for AOP advice to be applied." on 4.3.0-SNAPSHOT. On micronaut 4.2.3 it takes about 5m30sec on the same project. So it looks like there is a significant kspKotlin performance degradation between 4.2.3 and 4.3.0-SNAPSHOT.

Partial CPU samplings of the kspKotlin steps:

Kotlin 1.9.20 and ksp 1.9.20-1.0.14: ksp-partialDump.nps.zip Screenshot 2024-01-15 at 2 05 19 PM

Kotlin 1.9.22 and ksp 1.9.22-1.0.16: ksp-1.9.22-1.0.16.nps.zip

graemerocher commented 7 months ago

probably the PR that resolves annotations on generic arguments via inheritance causes this //cc @dstepanov

Spikhalskiy commented 7 months ago

I'm also a little puzzled to see visitInnerClasses is taking up almost the same amount of time as the top-level visitClass. Our project doesn't have a lot of inner classes at all, except companion objects.

dstepanov commented 7 months ago

I suspect that caching might not work for KSP, might be a good idea to recompile the project with some added printl and check

dstepanov commented 7 months ago

@Spikhalskiy Please try with the latest snapshot

Spikhalskiy commented 7 months ago

@dstepanov It's much better than before. kspKotlin takes about 1m30 seconds now before failing. Still significantly longer than kapt, but much better than 4.1.x 4.2.x performances. Thank you!

dstepanov commented 7 months ago

@Spikhalskiy Still, it takes a lot of time. Maybe you need to add more memory for Gradle?

Our test-suite-kotlin-ksp project is quite extensive, and the KSP processing is less than the compilation:

:test-suite-kotlin-ksp:kspTestKotlin 11.839s    com.google.devtools.ksp.gradle.KspTaskJvm   
:test-suite-kotlin-ksp:compileTestKotlin 17.220s    org.jetbrains.kotlin.gradle.tasks.KotlinCompile
Spikhalskiy commented 7 months ago

@dstepanov Our timings are:

kaptKotlin (without generating stubs, it's a separate task): 15s compileKotlin: 60s kspKotlin: 1m20s

We already give kotlin daemon 4Gb, I tried to increase it to 8Gb and didn't see much of a change in timings. I inspected the kotlin daemon with Visual VM and didn't see significant GC pressure.

dstepanov commented 7 months ago

When the KSP is enabled there is no KAPT task right?

dstepanov commented 7 months ago

You should have just those two tasks like the message above

Spikhalskiy commented 7 months ago

Yeah, it's mutually exclusive. I just put them together for comparison. It's either-or.

When the KSP is enabled there is no KAPT task right?

correct

dstepanov commented 7 months ago

Is that still the override method check that takes much time?

Spikhalskiy commented 7 months ago

Kinda. processClassHierarchy() is the worst offender to be exact.

Screenshot from 2024-01-18 13-42-51

snapshot-1705603226311.nps.zip

dstepanov commented 7 months ago

Hard to tell, but findOverridenMethods should be called once per class

erkieh commented 3 days ago

Similar thing happened in one of my bigger projects where kapt worked but ksp failed with a "GC overhead limit exceeded" exception or it took just too much time complete.

I got ksp to work by adding compileOnly("io.micronaut:micronaut-inject-kotlin") to my gradle build file.