Hi Luis, I find 4.0.8 a bit outdated. Please give Groovy 4.0.26 a try.
BTW, could you submit a JIRA ticket and attach a script to reproduce the issue? Cheers, Daniel Sun On 2025/04/25 05:13:15 Luis Ashurei wrote: > Hello, > > I have a java application running heavily groovy scripts. After > running for weeks, the system encountered Full GC in every day, every > time it cost about one second which is not acceptable. > > Any suggestions are appreciated. > > (I also start a stackoverflow topic here: > https://stackoverflow.com/questions/79591808/gc-pause-by-metadata-gc-threshold-for-weeks-then-turned-to-full-gc > ) > > ------- > Environment: > Server: 8 CPU, 16 GB memory, docker > OS: Centos6 > JDK: Oracle jdk18-191 > JVM args: > -server -Xms8192m -Xmx8192m -XX:MaxDirectMemorySize=4g > -XX:MaxMetaspaceSize=768m -XX:+UseG1GC -XX:ParallelGCThreads=8 > -XX:ConcGCThreads=2 -XX:MaxGCPauseMillis=50 > Groovy ver: 4.0.8 > > ------- > What I have investigated: > > 1. > Before the first time Full GC, every time Metadata minor GC, space > will increase a little bit. > e.g.: > 1st: > meta size before gc: 502.14 > meta size after gc: 359.07 > 2nd > meta size before gc: 535.11 > meta size after gc: 361.08 > 3rd > meta size before gc: 559.96 > meta size after gc: 358.70 > ... > > After the meta size increased to about 630MB threshold, GC changed to > Full GC every time. First Full GC happens one months later, and then > about every 24 hours frequently. > No resource leak happened since every time full gc meta size went back > to 300MB+. > > 2. > After opened jvm TraceClassLoading and TraceClassUnloading, I found > hundreds of follows logs prints time to time > > [Loaded java.lang.invoke.LambdaForm$MH/1818461913 from > java.lang.invoke.LambdaForm] > [Loaded java.lang.invoke.LambdaForm$MH/1950338341 from > java.lang.invoke.LambdaForm] > [Loaded java.lang.invoke.LambdaForm$MH/411925311 from > java.lang.invoke.LambdaForm] > ... > //Metadata GC Threshold > ... > [Unloading class java.lang.invoke.LambdaForm$MH/1871712942 0x00000007c7ac3828] > [Unloading class java.lang.invoke.LambdaForm$MH/55669925 0x00000007c7ac3428] > [Unloading class java.lang.invoke.LambdaForm$MH/1781124732 0x00000007c7ac3028] > > I tried to dump the class via arthas, but it failed with process crashed. > > 3. > I tried MaxGCPauseMillis from 50ms to 100ms, meta size threshold > increasing still happens, problem not solved. > > ------------- > Metadata GC Threshold log sample: > > 2025-04-25T08:44:54.824+0800: 1549660.716: [GC pause (Metadata GC > Threshold) (young) (initial-mark), 0.0793971 secs] > [Parallel Time: 73.7 ms, GC Workers: 8] > [GC Worker Start (ms): Min: 1549660734.7, Avg: 1549660734.7, Max: > 1549660734.8, Diff: 0.1] > [Ext Root Scanning (ms): Min: 47.2, Avg: 47.7, Max: 48.5, Diff: 1.3, Sum: > 381.3] > [Update RS (ms): Min: 3.4, Avg: 3.5, Max: 3.6, Diff: 0.1, Sum: 28.1] > [Processed Buffers: Min: 135, Avg: 155.5, Max: 183, Diff: 48, Sum: 1244] > [Scan RS (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.0, Sum: 0.4] > [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.2, Diff: 0.2, Sum: 0.3] > [Object Copy (ms): Min: 4.3, Avg: 5.1, Max: 5.5, Diff: 1.2, Sum: 41.0] > [Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.4] > [Termination Attempts: Min: 1, Avg: 87.0, Max: 121, Diff: 120, Sum: 696] > [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.7] > [GC Worker Total (ms): Min: 56.5, Avg: 56.5, Max: 56.6, Diff: 0.2, Sum: 452.2] > [GC Worker End (ms): Min: 1549660791.2, Avg: 1549660791.2, Max: > 1549660791.3, Diff: 0.1] > [Code Root Fixup: 0.0 ms] > [Code Root Purge: 0.0 ms] > [Clear CT: 0.2 ms] > [Other: 5.4 ms] > [Choose CSet: 0.0 ms] > [Ref Proc: 3.1 ms] > [Ref Enq: 0.0 ms] > [Redirty Cards: 0.1 ms] > [Humongous Register: 0.0 ms] > [Humongous Reclaim: 0.0 ms] > [Free CSet: 0.3 ms] > [Eden: 2272.0M(4896.0M)->0.0B(4896.0M) Survivors: 16.0M->16.0M Heap: > 3627.3M(8192.0M)->1358.9M(8192.0M)] > [Times: user=0.48 sys=0.00, real=0.08 secs] > 2025-04-25T08:44:54.904+0800: 1549660.796: [GC > concurrent-root-region-scan-start] > 2025-04-25T08:44:54.917+0800: 1549660.809: [GC > concurrent-root-region-scan-end, 0.0130581 secs] > 2025-04-25T08:44:54.917+0800: 1549660.809: [GC concurrent-mark-start] > 2025-04-25T08:44:55.259+0800: 1549661.151: [GC concurrent-mark-end, > 0.3418808 secs] > 2025-04-25T08:44:55.268+0800: 1549661.160: [GC remark > 2025-04-25T08:44:55.268+0800: 1549661.160: [Finalize Marking, > 0.0009449 secs] 2025-04-25T08:44:55.269+0800: 1549661.161: [GC > ref-proc, 0.0094765 secs] 2025-04-25T08:44:55.279+0800: 1549661.170: > [Unloading, 0.4803602 secs], 0.4925154 secs] > [Times: user=0.74 sys=0.48, real=0.50 secs] > > (Have no Full GC log yet.) >
