Memory leaked every time formatKotlin task is run

[marshallpierce]

It seems like each invocation of formatKotlin leaks tens of MiB of heap on a small codebase (2500loc). This is using Gradle 7.0 with kotlinter 3.4.4 and kotlin 1.5.0.

Here's the sequence of output from the class histogram (obtained via jcmd 15861 GC.run && jcmd 15861 GC.class_histogram | grep kotlin | head) after running the formatKotlin task several times, capturing the histogram after each run:

% jcmd 15861 GC.run && jcmd 15861 GC.class_histogram | grep kotlin | head
15861:
Command executed successfully
   3:        502184       16069888  org.jetbrains.kotlin.name.FqNameUnsafe
   4:        502184       12052416  org.jetbrains.kotlin.name.FqName
   5:        502183       12052392  org.jetbrains.kotlin.resolve.jvm.modules.JavaModuleInfo$Exports
   9:        236643        5679432  org.jetbrains.kotlin.resolve.jvm.modules.JavaModuleInfo$Requires
  10:        228052        5473248  org.jetbrains.kotlin.cli.jvm.modules.CoreJrtVirtualFile
  13:         93720        2249280  org.jetbrains.kotlin.resolve.jvm.modules.JavaModule$Explicit
  14:         93720        2249280  org.jetbrains.kotlin.resolve.jvm.modules.JavaModule$Root
  15:         93720        2249280  org.jetbrains.kotlin.resolve.jvm.modules.JavaModuleInfo
  22:         17219         964264  org.jetbrains.kotlin.com.intellij.openapi.extensions.impl.InterfaceExtensionPoint
  23:         39831         955944  org.jetbrains.kotlin.cli.jvm.index.JavaRoot
% jcmd 15861 GC.run && jcmd 15861 GC.class_histogram | grep kotlin | head
15861:
Command executed successfully
   3:        547837       17530784  org.jetbrains.kotlin.name.FqNameUnsafe
   4:        547837       13148088  org.jetbrains.kotlin.name.FqName
   5:        547836       13148064  org.jetbrains.kotlin.resolve.jvm.modules.JavaModuleInfo$Exports
   9:        258156        6195744  org.jetbrains.kotlin.resolve.jvm.modules.JavaModuleInfo$Requires
  10:        248784        5970816  org.jetbrains.kotlin.cli.jvm.modules.CoreJrtVirtualFile
  13:        102240        2453760  org.jetbrains.kotlin.resolve.jvm.modules.JavaModule$Explicit
  14:        102240        2453760  org.jetbrains.kotlin.resolve.jvm.modules.JavaModule$Root
  15:        102240        2453760  org.jetbrains.kotlin.resolve.jvm.modules.JavaModuleInfo
  22:         18781        1051736  org.jetbrains.kotlin.com.intellij.openapi.extensions.impl.InterfaceExtensionPoint
  23:         43452        1042848  org.jetbrains.kotlin.cli.jvm.index.JavaRoot
% jcmd 15861 GC.run && jcmd 15861 GC.class_histogram | grep kotlin | head
15861:
Command executed successfully
   3:        593490       18991680  org.jetbrains.kotlin.name.FqNameUnsafe
   4:        593490       14243760  org.jetbrains.kotlin.name.FqName
   5:        593489       14243736  org.jetbrains.kotlin.resolve.jvm.modules.JavaModuleInfo$Exports
   9:        279669        6712056  org.jetbrains.kotlin.resolve.jvm.modules.JavaModuleInfo$Requires
  10:        269516        6468384  org.jetbrains.kotlin.cli.jvm.modules.CoreJrtVirtualFile
  13:        110760        2658240  org.jetbrains.kotlin.resolve.jvm.modules.JavaModule$Explicit
  14:        110760        2658240  org.jetbrains.kotlin.resolve.jvm.modules.JavaModule$Root
  15:        110760        2658240  org.jetbrains.kotlin.resolve.jvm.modules.JavaModuleInfo
  22:         20343        1139208  org.jetbrains.kotlin.com.intellij.openapi.extensions.impl.InterfaceExtensionPoint
  23:         47073        1129752  org.jetbrains.kotlin.cli.jvm.index.JavaRoot
% jcmd 15861 GC.run && jcmd 15861 GC.class_histogram | grep kotlin | head
15861:
Command executed successfully
   3:        639143       20452576  org.jetbrains.kotlin.name.FqNameUnsafe
   4:        639143       15339432  org.jetbrains.kotlin.name.FqName
   5:        639142       15339408  org.jetbrains.kotlin.resolve.jvm.modules.JavaModuleInfo$Exports
   9:        301182        7228368  org.jetbrains.kotlin.resolve.jvm.modules.JavaModuleInfo$Requires
  10:        290248        6965952  org.jetbrains.kotlin.cli.jvm.modules.CoreJrtVirtualFile
  13:        119280        2862720  org.jetbrains.kotlin.resolve.jvm.modules.JavaModule$Explicit
  14:        119280        2862720  org.jetbrains.kotlin.resolve.jvm.modules.JavaModule$Root
  15:        119280        2862720  org.jetbrains.kotlin.resolve.jvm.modules.JavaModuleInfo
  21:         21905        1226680  org.jetbrains.kotlin.com.intellij.openapi.extensions.impl.InterfaceExtensionPoint
  22:         50694        1216656  org.jetbrains.kotlin.cli.jvm.index.JavaRoot

Here's the same type of data, this time on a fresh daemon (./gradlew --stop && ./gradlew classes to create a warmed up daemon), then showing the first two invocations of formatKotlin.

% jcmd 16318 GC.run && jcmd 16318 GC.class_histogram | grep kotlin | head
16318:
Command executed successfully
  17:          5254         210160  kotlin.reflect.jvm.internal.impl.protobuf.SmallSortedMap$1
  21:          1817         159896  kotlin.reflect.jvm.internal.impl.metadata.ProtoBuf$Type
  26:          5254         126096  kotlin.reflect.jvm.internal.impl.protobuf.FieldSet
  33:          1072          94336  kotlin.reflect.jvm.internal.impl.metadata.ProtoBuf$Function
  42:          1203          76992  kotlin.reflect.jvm.internal.impl.metadata.ProtoBuf$ValueParameter
  47:          2570          61680  kotlin.reflect.jvm.internal.impl.name.Name
  49:          2478          59472  kotlin.reflect.jvm.internal.ReflectProperties$LazySoftVal
  58:           515          45320  kotlin.reflect.jvm.internal.impl.metadata.ProtoBuf$Property
  62:          1226          39232  kotlin.reflect.jvm.internal.impl.name.FqNameUnsafe
  70:           847          33880  kotlin.reflect.jvm.internal.impl.metadata.jvm.JvmProtoBuf$JvmMethodSignature
% jcmd 16318 GC.run && jcmd 16318 GC.class_histogram | grep kotlin | head
16318:
Command executed successfully
   8:         45654        1460928  org.jetbrains.kotlin.name.FqNameUnsafe
  10:         45654        1095696  org.jetbrains.kotlin.name.FqName
  11:         45653        1095672  org.jetbrains.kotlin.resolve.jvm.modules.JavaModuleInfo$Exports
  19:         21513         516312  org.jetbrains.kotlin.resolve.jvm.modules.JavaModuleInfo$Requires
  20:         20732         497568  org.jetbrains.kotlin.cli.jvm.modules.CoreJrtVirtualFile
  26:          5535         221400  kotlin.reflect.jvm.internal.impl.protobuf.SmallSortedMap$1
  27:          8520         204480  org.jetbrains.kotlin.resolve.jvm.modules.JavaModule$Explicit
  28:          8520         204480  org.jetbrains.kotlin.resolve.jvm.modules.JavaModule$Root
  29:          8520         204480  org.jetbrains.kotlin.resolve.jvm.modules.JavaModuleInfo
  32:          1976         173888  kotlin.reflect.jvm.internal.impl.metadata.ProtoBuf$Type
% jcmd 16318 GC.run && jcmd 16318 GC.class_histogram | grep kotlin | head
16318:
Command executed successfully
   4:         91307        2921824  org.jetbrains.kotlin.name.FqNameUnsafe
   6:         91307        2191368  org.jetbrains.kotlin.name.FqName
   7:         91306        2191344  org.jetbrains.kotlin.resolve.jvm.modules.JavaModuleInfo$Exports
  14:         43026        1032624  org.jetbrains.kotlin.resolve.jvm.modules.JavaModuleInfo$Requires
  15:         41464         995136  org.jetbrains.kotlin.cli.jvm.modules.CoreJrtVirtualFile
  24:         17040         408960  org.jetbrains.kotlin.resolve.jvm.modules.JavaModule$Explicit
  25:         17040         408960  org.jetbrains.kotlin.resolve.jvm.modules.JavaModule$Root
  26:         17040         408960  org.jetbrains.kotlin.resolve.jvm.modules.JavaModuleInfo
  30:          5535         221400  kotlin.reflect.jvm.internal.impl.protobuf.SmallSortedMap$1
  32:          3161         177016  org.jetbrains.kotlin.com.intellij.openapi.extensions.impl.InterfaceExtensionPoint

I've attached a heap graph created with my heap analysis tools in case that's instructive. It's clear that there are a whole lot of PicoContainers being made, among other kotlin internal classes, so perhaps there is some reference being cached when it shouldn't be either in the plugin or in ktlint itself?

gradle daemon heap graph.svg.gz

[mateuszkwiecinski]

Hey @marshallpierce 👋 I'd shoot you're facing the kotlin gradle plugin memory leak: https://youtrack.jetbrains.com/issue/KT-46368 which will be fixed in kotlin 1.5.10

Have you tried to apply a workaround, for example Zac Sweers plugin: https://github.com/ZacSweers/kgp-150-leak-patcher?

[marshallpierce]

I see the same leak behavior with kotlin 1.4.32 selected. The same goes for the workaround plugin + 1.5.0.

[marshallpierce]

I made a teeny tiny repro project: https://github.com/marshallpierce/kotlinter-leak-repro

With less code it leaks more slowly but it's still leaking (easily visible with GC.class_histogram).

[jeremymailen]

Thanks for the research and the repro repo. I have also recently noticed some jvm heap space errors from gradle in a local setup with similar versions.

Have we looked to see how far back this issue goes? I've looked over the changes starting with 3.4.0 and don't see any recent changes in the plugin logic that seem impactful -- the main changes have been to dependencies: new ktlint, kotlin, gradle. Has anyone tried 3.3.0?

[jeremymailen]

At the risk of sounding naive, are we sure this isn't normal lazy garbage collection behavior on the gradle daemon?

A ran a series of formatKotlin commands and they sawtooth upwards for 4 runs or so and then eventually GC kicks in and things go back to baseline. These are the small saw teeth on the left side of the graph. Then I ran test on a fairly large project and you can see a similar effect: the heap is large afterwards. I hit the manual GC button in VisualVM and back the baseline again. So the behavior of lintKotlin and formatKotlin don't look different than other gradle commands.

Are you seeing the baseline climb after GC? This is using gradle 7.

I ran the same tests with kotlinter 3.3.0 and kotlin 1.4.32 and behavior seemed the same.

[marshallpierce]

Nothing naive about being thorough! :) Unfortunately, in my measurements above, I'm running a GC (the jcmd ... GC.run part) before each measurement, and you can see the occupancy numbers rising. jcmd .. GC.heap_info shows a similar story, and when observing in visualvm, you can see GC time spike up and then eventually max out for a while before the JVM gives up.

I'd try repeat 100 ./gradlew formatKotlin or equivalent -- just a handful of runs isn't enough. FWIW I'm also seeing this behavior in a larger (real) project on x64 linux. The above output was captured on x64 macOS, all using the Zulu 16.0.1 JVM (sdk i java 16.0.1-zulu if you want to match it).

[jeremymailen]

Ok, digging into a bigger codebase with thousands of lines of code, I do see the problem.

• Only effectsformatKotlin not lintKotlin
• Appears to scale with the amount of code being operated on
• Is a regression between 3.3.0 and 3.4.4
• Happens in gradle 6.8.3 and 7.0.2, so not sensitive to that

I can comb through the changes between the versions again. My best guess it's a side effect of upgrading ktlint 0.40.0 -> 0.41.0. Although certainly maybe we're using it wrong in some way?

[jeremymailen]

I haven't forgotten about this issue, but I haven't had the chance to delve into the guts of ktlint where the leak most likely is. hiding. I have a feeling, not scientific whatsoever, that ktlint is going to spin a new release soon upgrading to kotlin 1.5 and this leak will be fixed. I could be wrong though.

[jeremymailen]

This memory leak can happen on lintKotlin as well, most easily seen when gradle --rerun-tasks lintKotlin. Does not appear as frequently because incremental builds keep the number of files examined small.

I wonder if the root cause is the same as JLLeitschuh/ktlint-gradle#507?

People have pointed to the usage of gradle workers as being the potential culprit. Perhaps this could be, but I believe workers are being used according to gradle's instructions here and there's nothing to explicitly close or return. It could be newer versions of gradle have introduced a bug with workers leaking memory, but I'm doubtful.

I still suspect there's a memory leak at the ktlint level, perhaps even in the embedded kotlin compiler that we use to parse files.

[jeremymailen]

Update on this. The leak is still present in kotlinter 3.5.0 and ktlint 0.42.1.
I believe, but don't have the cause pinpointed yet, that the leak was introduced in ktlint 0.41.0.
I'll go file a bug there to investigate.

[jeremymailen]

With 3.7.0 (ktlint 0.43.0) this issue appears to be fixed. I was able to run formatKotlin in a loop 100 times on a sizable project without trouble and using GC button in VisualVM restored the gradle daemon memory back to the pre-run baseline. I assume updates to kotlin or ktlint have closed the hole.

Closing, but please let me know if anyone sees the issue crop up again.