I am trying to understand how Java handles memory allocation for lambdas and whether it's possible to use them in a GC-free style for latency-critical applications. My goal is to determine if lambdas can be used without generating garbage, as avoiding GC is crucial for my use case.
Below are two examples to illustrate my questions. In both lambda captures effectively final variable.
Environment: Amazon Corretto 17.0.12 JDK, G1GC.
Example 1: Inline Lambda
package com.example;
import java.util.List;
import java.util.function.Predicate;
public class LambdaTest {
private static final Something something = new Something();
public static void main(String[] args) {
String a = "hello there";
while (true) {
something.method(x -> x.equals(a));
}
}
}
class Something {
private final List<String> list = List.of("1", "2");
void method(Predicate<String> predicate) {
for (int i = 0; i < list.size(); i++) {
predicate.test(list.get(i));
}
}
}
When running this code for about 15 seconds, ~22 MB of memory is allocated (as observed using Java Flight Recorder). This is surprising for what seems like a simple lambda call.
The GC logs also show a lot of "Cleanup" events and G1 collections. Why does this happen?
GC log:
[2024-11-21T11:17:19.564+0400][0.009s][info][gc] Using G1
[2024-11-21T11:17:19.566+0400][0.011s][info][gc,init] Version: 17.0.12+7-LTS (release)
[2024-11-21T11:17:19.566+0400][0.011s][info][gc,init] CPUs: 12 total, 12 available
[2024-11-21T11:17:19.566+0400][0.011s][info][gc,init] Memory: 32448M
[2024-11-21T11:17:19.566+0400][0.011s][info][gc,init] Large Page Support: Disabled
[2024-11-21T11:17:19.567+0400][0.011s][info][gc,init] NUMA Support: Disabled
[2024-11-21T11:17:19.567+0400][0.011s][info][gc,init] Compressed Oops: Enabled (Zero based)
[2024-11-21T11:17:19.567+0400][0.011s][info][gc,init] Heap Region Size: 4M
[2024-11-21T11:17:19.567+0400][0.011s][info][gc,init] Heap Min Capacity: 8M
[2024-11-21T11:17:19.567+0400][0.011s][info][gc,init] Heap Initial Capacity: 508M
[2024-11-21T11:17:19.568+0400][0.013s][info][gc,init] Heap Max Capacity: 8116M
[2024-11-21T11:17:19.568+0400][0.013s][info][gc,init] Pre-touch: Disabled
[2024-11-21T11:17:19.568+0400][0.013s][info][gc,init] Parallel Workers: 10
[2024-11-21T11:17:19.568+0400][0.013s][info][gc,init] Concurrent Workers: 3
[2024-11-21T11:17:19.568+0400][0.013s][info][gc,init] Concurrent Refinement Workers: 10
[2024-11-21T11:17:19.568+0400][0.013s][info][gc,init] Periodic GC: Disabled
[2024-11-21T11:17:19.574+0400][0.019s][info][gc,metaspace] CDS archive(s) mapped at: [0x000001f851000000-0x000001f851bb0000-0x000001f851bb0000), size 12255232, SharedBaseAddress: 0x000001f851000000, ArchiveRelocationMode: 1.
[2024-11-21T11:17:19.574+0400][0.019s][info][gc,metaspace] Compressed class space mapped at: 0x000001f852000000-0x000001f892000000, reserved size: 1073741824
[2024-11-21T11:17:19.574+0400][0.019s][info][gc,metaspace] Narrow klass base: 0x000001f851000000, Narrow klass shift: 0, Narrow klass range: 0x100000000
[2024-11-21T11:17:19.766+0400][0.211s][info][safepoint ] Safepoint "ICBufferFull", Time since last: 189551200 ns, Reaching safepoint: 17600 ns, Cleanup: 60000 ns, At safepoint: 7500 ns, Total: 85100 ns
[2024-11-21T11:17:19.787+0400][0.232s][info][safepoint ] Safepoint "RedefineClasses", Time since last: 16989500 ns, Reaching safepoint: 3100 ns, Cleanup: 45500 ns, At safepoint: 3409200 ns, Total: 3457800 ns
[2024-11-21T11:17:19.814+0400][0.259s][info][safepoint ] Safepoint "JFRCheckpoint", Time since last: 27203200 ns, Reaching safepoint: 2100 ns, Cleanup: 8500 ns, At safepoint: 1600 ns, Total: 12200 ns
[2024-11-21T11:17:20.614+0400][1.058s][info][gc,start ] GC(0) Pause Young (Normal) (G1 Evacuation Pause)
[2024-11-21T11:17:20.614+0400][1.059s][info][gc,task ] GC(0) Using 10 workers of 10 for evacuation
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,phases ] GC(0) Pre Evacuate Collection Set: 0.1ms
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,phases ] GC(0) Merge Heap Roots: 0.1ms
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,phases ] GC(0) Evacuate Collection Set: 1.5ms
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,phases ] GC(0) Post Evacuate Collection Set: 0.2ms
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,phases ] GC(0) Other: 0.4ms
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,heap ] GC(0) Eden regions: 6->0(7)
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,heap ] GC(0) Survivor regions: 0->1(1)
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,heap ] GC(0) Old regions: 0->0
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,heap ] GC(0) Archive regions: 0->0
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,heap ] GC(0) Humongous regions: 0->0
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,metaspace] GC(0) Metaspace: 3984K(4096K)->3984K(4096K) NonClass: 3594K(3648K)->3594K(3648K) Class: 389K(448K)->389K(448K)
[2024-11-21T11:17:20.616+0400][1.061s][info][gc ] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 24M->3M(508M) 2.466ms
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,cpu ] GC(0) User=0.00s Sys=0.00s Real=0.00s
[2024-11-21T11:17:20.616+0400][1.061s][info][safepoint ] Safepoint "G1CollectForAllocation", Time since last: 799453500 ns, Reaching safepoint: 23700 ns, Cleanup: 10700 ns, At safepoint: 2637900 ns, Total: 2672300 ns
[2024-11-21T11:17:21.803+0400][2.248s][info][safepoint ] Safepoint "Cleanup", Time since last: 1186781600 ns, Reaching safepoint: 25100 ns, Cleanup: 41800 ns, At safepoint: 5600 ns, Total: 72500 ns
[2024-11-21T11:17:22.804+0400][3.248s][info][safepoint ] Safepoint "Cleanup", Time since last: 1000461600 ns, Reaching safepoint: 43400 ns, Cleanup: 6300 ns, At safepoint: 5000 ns, Total: 54700 ns
[2024-11-21T11:17:23.805+0400][4.249s][info][safepoint ] Safepoint "Cleanup", Time since last: 1000781300 ns, Reaching safepoint: 59000 ns, Cleanup: 11500 ns, At safepoint: 11600 ns, Total: 82100 ns
[2024-11-21T11:17:24.805+0400][5.249s][info][safepoint ] Safepoint "Cleanup", Time since last: 1000039000 ns, Reaching safepoint: 28800 ns, Cleanup: 7100 ns, At safepoint: 4200 ns, Total: 40100 ns
[2024-11-21T11:17:26.806+0400][7.250s][info][safepoint ] Safepoint "Cleanup", Time since last: 2000881000 ns, Reaching safepoint: 24300 ns, Cleanup: 8800 ns, At safepoint: 6300 ns, Total: 39400 ns
[2024-11-21T11:17:28.807+0400][9.251s][info][safepoint ] Safepoint "Cleanup", Time since last: 2000920600 ns, Reaching safepoint: 28000 ns, Cleanup: 7500 ns, At safepoint: 4100 ns, Total: 39600 ns
[2024-11-21T11:17:34.810+0400][15.254s][info][safepoint ] Safepoint "Cleanup", Time since last: 6002864400 ns, Reaching safepoint: 37000 ns, Cleanup: 9400 ns, At safepoint: 8600 ns, Total: 55000 ns
[2024-11-21T11:17:35.086+0400][15.531s][info][safepoint ] Safepoint "JFRCheckpoint", Time since last: 276571100 ns, Reaching safepoint: 36100 ns, Cleanup: 6400 ns, At safepoint: 58900 ns, Total: 101400 ns
[2024-11-21T11:17:35.105+0400][15.549s][info][gc,heap,exit] Heap
[2024-11-21T11:17:35.105+0400][15.549s][info][gc,heap,exit] garbage-first heap total 520192K, used 9809K [0x0000000604c00000, 0x0000000800000000)
[2024-11-21T11:17:35.105+0400][15.549s][info][gc,heap,exit] region size 4096K, 3 young (12288K), 1 survivors (4096K)
[2024-11-21T11:17:35.105+0400][15.549s][info][gc,heap,exit] Metaspace used 8222K, committed 8512K, reserved 1114112K
[2024-11-21T11:17:35.105+0400][15.549s][info][gc,heap,exit] class space used 900K, committed 1024K, reserved 1048576K
Example 2: Predefined Lambda
public static void main(String[] args) {
String a = "hello there";
Predicate<String> stringPredicate = x -> x.equals(a);
while (true) {
something.method(stringPredicate);
}
}
In this example, the lambda is assigned to a variable beforehand and reused in the loop. Interestingly, much less memory is allocated (according to IDEA profiler hints), but almost the same number of Safepoint "Cleanup" events.
GC log:
[2024-11-21T11:29:08.186+0400][0.011s][info][gc] Using G1
[2024-11-21T11:29:08.187+0400][0.013s][info][gc,init] Version: 17.0.12+7-LTS (release)
[2024-11-21T11:29:08.187+0400][0.013s][info][gc,init] CPUs: 12 total, 12 available
[2024-11-21T11:29:08.187+0400][0.013s][info][gc,init] Memory: 32448M
[2024-11-21T11:29:08.187+0400][0.013s][info][gc,init] Large Page Support: Disabled
[2024-11-21T11:29:08.187+0400][0.013s][info][gc,init] NUMA Support: Disabled
[2024-11-21T11:29:08.187+0400][0.013s][info][gc,init] Compressed Oops: Enabled (Zero based)
[2024-11-21T11:29:08.187+0400][0.013s][info][gc,init] Heap Region Size: 4M
[2024-11-21T11:29:08.187+0400][0.013s][info][gc,init] Heap Min Capacity: 8M
[2024-11-21T11:29:08.187+0400][0.013s][info][gc,init] Heap Initial Capacity: 508M
[2024-11-21T11:29:08.188+0400][0.013s][info][gc,init] Heap Max Capacity: 8116M
[2024-11-21T11:29:08.188+0400][0.013s][info][gc,init] Pre-touch: Disabled
[2024-11-21T11:29:08.188+0400][0.013s][info][gc,init] Parallel Workers: 10
[2024-11-21T11:29:08.188+0400][0.013s][info][gc,init] Concurrent Workers: 3
[2024-11-21T11:29:08.188+0400][0.013s][info][gc,init] Concurrent Refinement Workers: 10
[2024-11-21T11:29:08.188+0400][0.013s][info][gc,init] Periodic GC: Disabled
[2024-11-21T11:29:08.194+0400][0.019s][info][gc,metaspace] CDS archive(s) mapped at: [0x0000024c45000000-0x0000024c45bb0000-0x0000024c45bb0000), size 12255232, SharedBaseAddress: 0x0000024c45000000, ArchiveRelocationMode: 1.
[2024-11-21T11:29:08.194+0400][0.019s][info][gc,metaspace] Compressed class space mapped at: 0x0000024c46000000-0x0000024c86000000, reserved size: 1073741824
[2024-11-21T11:29:08.194+0400][0.019s][info][gc,metaspace] Narrow klass base: 0x0000024c45000000, Narrow klass shift: 0, Narrow klass range: 0x100000000
[2024-11-21T11:29:08.391+0400][0.216s][info][safepoint ] Safepoint "ICBufferFull", Time since last: 193888700 ns, Reaching safepoint: 7400 ns, Cleanup: 69600 ns, At safepoint: 8300 ns, Total: 85300 ns
[2024-11-21T11:29:08.410+0400][0.235s][info][safepoint ] Safepoint "RedefineClasses", Time since last: 16389000 ns, Reaching safepoint: 2900 ns, Cleanup: 45800 ns, At safepoint: 2560100 ns, Total: 2608800 ns
[2024-11-21T11:29:08.438+0400][0.263s][info][safepoint ] Safepoint "JFRCheckpoint", Time since last: 28071700 ns, Reaching safepoint: 2800 ns, Cleanup: 11700 ns, At safepoint: 2500 ns, Total: 17000 ns
[2024-11-21T11:29:09.396+0400][1.221s][info][gc,start ] GC(0) Pause Young (Normal) (G1 Evacuation Pause)
[2024-11-21T11:29:09.396+0400][1.222s][info][gc,task ] GC(0) Using 10 workers of 10 for evacuation
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,phases ] GC(0) Pre Evacuate Collection Set: 0.1ms
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,phases ] GC(0) Merge Heap Roots: 0.1ms
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,phases ] GC(0) Evacuate Collection Set: 2.0ms
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,phases ] GC(0) Post Evacuate Collection Set: 0.4ms
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,phases ] GC(0) Other: 0.5ms
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,heap ] GC(0) Eden regions: 6->0(7)
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,heap ] GC(0) Survivor regions: 0->1(1)
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,heap ] GC(0) Old regions: 0->0
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,heap ] GC(0) Archive regions: 0->0
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,heap ] GC(0) Humongous regions: 0->0
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,metaspace] GC(0) Metaspace: 7360K(7552K)->7360K(7552K) NonClass: 6565K(6656K)->6565K(6656K) Class: 794K(896K)->794K(896K)
[2024-11-21T11:29:09.400+0400][1.225s][info][gc ] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 24M->3M(508M) 3.217ms
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,cpu ] GC(0) User=0.00s Sys=0.00s Real=0.00s
[2024-11-21T11:29:09.400+0400][1.225s][info][safepoint ] Safepoint "G1CollectForAllocation", Time since last: 958423000 ns, Reaching safepoint: 23600 ns, Cleanup: 37100 ns, At safepoint: 3297100 ns, Total: 3357800 ns
[2024-11-21T11:29:10.419+0400][2.244s][info][safepoint ] Safepoint "Cleanup", Time since last: 1019081500 ns, Reaching safepoint: 15700 ns, Cleanup: 21900 ns, At safepoint: 5300 ns, Total: 42900 ns
[2024-11-21T11:29:11.420+0400][3.244s][info][safepoint ] Safepoint "Cleanup", Time since last: 1000396700 ns, Reaching safepoint: 13700 ns, Cleanup: 8300 ns, At safepoint: 4800 ns, Total: 26800 ns
[2024-11-21T11:29:12.420+0400][4.245s][info][safepoint ] Safepoint "Cleanup", Time since last: 1000880300 ns, Reaching safepoint: 25700 ns, Cleanup: 10100 ns, At safepoint: 66000 ns, Total: 101800 ns
[2024-11-21T11:29:13.421+0400][5.245s][info][safepoint ] Safepoint "Cleanup", Time since last: 1000087200 ns, Reaching safepoint: 18300 ns, Cleanup: 13100 ns, At safepoint: 5200 ns, Total: 36600 ns
[2024-11-21T11:29:14.421+0400][6.246s][info][safepoint ] Safepoint "Cleanup", Time since last: 1000750200 ns, Reaching safepoint: 16000 ns, Cleanup: 8300 ns, At safepoint: 28600 ns, Total: 52900 ns
[2024-11-21T11:29:15.422+0400][7.247s][info][safepoint ] Safepoint "Cleanup", Time since last: 1000323100 ns, Reaching safepoint: 13500 ns, Cleanup: 9500 ns, At safepoint: 566000 ns, Total: 589000 ns
[2024-11-21T11:29:17.423+0400][9.248s][info][safepoint ] Safepoint "Cleanup", Time since last: 2000973400 ns, Reaching safepoint: 17600 ns, Cleanup: 6200 ns, At safepoint: 4500 ns, Total: 28300 ns
[2024-11-21T11:29:23.427+0400][15.251s][info][safepoint ] Safepoint "Cleanup", Time since last: 6003316900 ns, Reaching safepoint: 16300 ns, Cleanup: 13000 ns, At safepoint: 11100 ns, Total: 40400 ns
[2024-11-21T11:29:23.858+0400][15.683s][info][safepoint ] Safepoint "JFRCheckpoint", Time since last: 431903500 ns, Reaching safepoint: 12800 ns, Cleanup: 10400 ns, At safepoint: 44800 ns, Total: 68000 ns
[2024-11-21T11:29:23.876+0400][15.701s][info][gc,heap,exit] Heap
[2024-11-21T11:29:23.876+0400][15.701s][info][gc,heap,exit] garbage-first heap total 520192K, used 7237K [0x0000000604c00000, 0x0000000800000000)
[2024-11-21T11:29:23.876+0400][15.701s][info][gc,heap,exit] region size 4096K, 2 young (8192K), 1 survivors (4096K)
[2024-11-21T11:29:23.876+0400][15.701s][info][gc,heap,exit] Metaspace used 8206K, committed 8448K, reserved 1114112K
[2024-11-21T11:29:23.876+0400][15.701s][info][gc,heap,exit] class space used 900K, committed 1024K, reserved 1048576K
Questions
Why does Example 1 result in significantly more memory allocation compared to Example 2?
- Is a new lambda object created each time the inline lambda is called?
- How is memory allocated for lambdas in the JVM?
In both examples, the GC logs show many "Cleanup" events.
- What exactly is being cleaned up during these events?
- Is it related to lambdas, thread-local storage, or something else?
Is there a way to use lambdas in a GC-free style, such that no garbage is generated when they are called repeatedly?
- If not, would sticking to anonymous classes or functional interfaces help?
How can I profile and debug this further to understand the internal memory behavior of lambdas?
I am trying to understand how Java handles memory allocation for lambdas and whether it's possible to use them in a GC-free style for latency-critical applications. My goal is to determine if lambdas can be used without generating garbage, as avoiding GC is crucial for my use case.
Below are two examples to illustrate my questions. In both lambda captures effectively final variable.
Environment: Amazon Corretto 17.0.12 JDK, G1GC.
Example 1: Inline Lambda
package com.example;
import java.util.List;
import java.util.function.Predicate;
public class LambdaTest {
private static final Something something = new Something();
public static void main(String[] args) {
String a = "hello there";
while (true) {
something.method(x -> x.equals(a));
}
}
}
class Something {
private final List<String> list = List.of("1", "2");
void method(Predicate<String> predicate) {
for (int i = 0; i < list.size(); i++) {
predicate.test(list.get(i));
}
}
}
When running this code for about 15 seconds, ~22 MB of memory is allocated (as observed using Java Flight Recorder). This is surprising for what seems like a simple lambda call.
The GC logs also show a lot of "Cleanup" events and G1 collections. Why does this happen?
GC log:
[2024-11-21T11:17:19.564+0400][0.009s][info][gc] Using G1
[2024-11-21T11:17:19.566+0400][0.011s][info][gc,init] Version: 17.0.12+7-LTS (release)
[2024-11-21T11:17:19.566+0400][0.011s][info][gc,init] CPUs: 12 total, 12 available
[2024-11-21T11:17:19.566+0400][0.011s][info][gc,init] Memory: 32448M
[2024-11-21T11:17:19.566+0400][0.011s][info][gc,init] Large Page Support: Disabled
[2024-11-21T11:17:19.567+0400][0.011s][info][gc,init] NUMA Support: Disabled
[2024-11-21T11:17:19.567+0400][0.011s][info][gc,init] Compressed Oops: Enabled (Zero based)
[2024-11-21T11:17:19.567+0400][0.011s][info][gc,init] Heap Region Size: 4M
[2024-11-21T11:17:19.567+0400][0.011s][info][gc,init] Heap Min Capacity: 8M
[2024-11-21T11:17:19.567+0400][0.011s][info][gc,init] Heap Initial Capacity: 508M
[2024-11-21T11:17:19.568+0400][0.013s][info][gc,init] Heap Max Capacity: 8116M
[2024-11-21T11:17:19.568+0400][0.013s][info][gc,init] Pre-touch: Disabled
[2024-11-21T11:17:19.568+0400][0.013s][info][gc,init] Parallel Workers: 10
[2024-11-21T11:17:19.568+0400][0.013s][info][gc,init] Concurrent Workers: 3
[2024-11-21T11:17:19.568+0400][0.013s][info][gc,init] Concurrent Refinement Workers: 10
[2024-11-21T11:17:19.568+0400][0.013s][info][gc,init] Periodic GC: Disabled
[2024-11-21T11:17:19.574+0400][0.019s][info][gc,metaspace] CDS archive(s) mapped at: [0x000001f851000000-0x000001f851bb0000-0x000001f851bb0000), size 12255232, SharedBaseAddress: 0x000001f851000000, ArchiveRelocationMode: 1.
[2024-11-21T11:17:19.574+0400][0.019s][info][gc,metaspace] Compressed class space mapped at: 0x000001f852000000-0x000001f892000000, reserved size: 1073741824
[2024-11-21T11:17:19.574+0400][0.019s][info][gc,metaspace] Narrow klass base: 0x000001f851000000, Narrow klass shift: 0, Narrow klass range: 0x100000000
[2024-11-21T11:17:19.766+0400][0.211s][info][safepoint ] Safepoint "ICBufferFull", Time since last: 189551200 ns, Reaching safepoint: 17600 ns, Cleanup: 60000 ns, At safepoint: 7500 ns, Total: 85100 ns
[2024-11-21T11:17:19.787+0400][0.232s][info][safepoint ] Safepoint "RedefineClasses", Time since last: 16989500 ns, Reaching safepoint: 3100 ns, Cleanup: 45500 ns, At safepoint: 3409200 ns, Total: 3457800 ns
[2024-11-21T11:17:19.814+0400][0.259s][info][safepoint ] Safepoint "JFRCheckpoint", Time since last: 27203200 ns, Reaching safepoint: 2100 ns, Cleanup: 8500 ns, At safepoint: 1600 ns, Total: 12200 ns
[2024-11-21T11:17:20.614+0400][1.058s][info][gc,start ] GC(0) Pause Young (Normal) (G1 Evacuation Pause)
[2024-11-21T11:17:20.614+0400][1.059s][info][gc,task ] GC(0) Using 10 workers of 10 for evacuation
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,phases ] GC(0) Pre Evacuate Collection Set: 0.1ms
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,phases ] GC(0) Merge Heap Roots: 0.1ms
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,phases ] GC(0) Evacuate Collection Set: 1.5ms
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,phases ] GC(0) Post Evacuate Collection Set: 0.2ms
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,phases ] GC(0) Other: 0.4ms
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,heap ] GC(0) Eden regions: 6->0(7)
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,heap ] GC(0) Survivor regions: 0->1(1)
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,heap ] GC(0) Old regions: 0->0
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,heap ] GC(0) Archive regions: 0->0
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,heap ] GC(0) Humongous regions: 0->0
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,metaspace] GC(0) Metaspace: 3984K(4096K)->3984K(4096K) NonClass: 3594K(3648K)->3594K(3648K) Class: 389K(448K)->389K(448K)
[2024-11-21T11:17:20.616+0400][1.061s][info][gc ] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 24M->3M(508M) 2.466ms
[2024-11-21T11:17:20.616+0400][1.061s][info][gc,cpu ] GC(0) User=0.00s Sys=0.00s Real=0.00s
[2024-11-21T11:17:20.616+0400][1.061s][info][safepoint ] Safepoint "G1CollectForAllocation", Time since last: 799453500 ns, Reaching safepoint: 23700 ns, Cleanup: 10700 ns, At safepoint: 2637900 ns, Total: 2672300 ns
[2024-11-21T11:17:21.803+0400][2.248s][info][safepoint ] Safepoint "Cleanup", Time since last: 1186781600 ns, Reaching safepoint: 25100 ns, Cleanup: 41800 ns, At safepoint: 5600 ns, Total: 72500 ns
[2024-11-21T11:17:22.804+0400][3.248s][info][safepoint ] Safepoint "Cleanup", Time since last: 1000461600 ns, Reaching safepoint: 43400 ns, Cleanup: 6300 ns, At safepoint: 5000 ns, Total: 54700 ns
[2024-11-21T11:17:23.805+0400][4.249s][info][safepoint ] Safepoint "Cleanup", Time since last: 1000781300 ns, Reaching safepoint: 59000 ns, Cleanup: 11500 ns, At safepoint: 11600 ns, Total: 82100 ns
[2024-11-21T11:17:24.805+0400][5.249s][info][safepoint ] Safepoint "Cleanup", Time since last: 1000039000 ns, Reaching safepoint: 28800 ns, Cleanup: 7100 ns, At safepoint: 4200 ns, Total: 40100 ns
[2024-11-21T11:17:26.806+0400][7.250s][info][safepoint ] Safepoint "Cleanup", Time since last: 2000881000 ns, Reaching safepoint: 24300 ns, Cleanup: 8800 ns, At safepoint: 6300 ns, Total: 39400 ns
[2024-11-21T11:17:28.807+0400][9.251s][info][safepoint ] Safepoint "Cleanup", Time since last: 2000920600 ns, Reaching safepoint: 28000 ns, Cleanup: 7500 ns, At safepoint: 4100 ns, Total: 39600 ns
[2024-11-21T11:17:34.810+0400][15.254s][info][safepoint ] Safepoint "Cleanup", Time since last: 6002864400 ns, Reaching safepoint: 37000 ns, Cleanup: 9400 ns, At safepoint: 8600 ns, Total: 55000 ns
[2024-11-21T11:17:35.086+0400][15.531s][info][safepoint ] Safepoint "JFRCheckpoint", Time since last: 276571100 ns, Reaching safepoint: 36100 ns, Cleanup: 6400 ns, At safepoint: 58900 ns, Total: 101400 ns
[2024-11-21T11:17:35.105+0400][15.549s][info][gc,heap,exit] Heap
[2024-11-21T11:17:35.105+0400][15.549s][info][gc,heap,exit] garbage-first heap total 520192K, used 9809K [0x0000000604c00000, 0x0000000800000000)
[2024-11-21T11:17:35.105+0400][15.549s][info][gc,heap,exit] region size 4096K, 3 young (12288K), 1 survivors (4096K)
[2024-11-21T11:17:35.105+0400][15.549s][info][gc,heap,exit] Metaspace used 8222K, committed 8512K, reserved 1114112K
[2024-11-21T11:17:35.105+0400][15.549s][info][gc,heap,exit] class space used 900K, committed 1024K, reserved 1048576K
Example 2: Predefined Lambda
public static void main(String[] args) {
String a = "hello there";
Predicate<String> stringPredicate = x -> x.equals(a);
while (true) {
something.method(stringPredicate);
}
}
In this example, the lambda is assigned to a variable beforehand and reused in the loop. Interestingly, much less memory is allocated (according to IDEA profiler hints), but almost the same number of Safepoint "Cleanup" events.
GC log:
[2024-11-21T11:29:08.186+0400][0.011s][info][gc] Using G1
[2024-11-21T11:29:08.187+0400][0.013s][info][gc,init] Version: 17.0.12+7-LTS (release)
[2024-11-21T11:29:08.187+0400][0.013s][info][gc,init] CPUs: 12 total, 12 available
[2024-11-21T11:29:08.187+0400][0.013s][info][gc,init] Memory: 32448M
[2024-11-21T11:29:08.187+0400][0.013s][info][gc,init] Large Page Support: Disabled
[2024-11-21T11:29:08.187+0400][0.013s][info][gc,init] NUMA Support: Disabled
[2024-11-21T11:29:08.187+0400][0.013s][info][gc,init] Compressed Oops: Enabled (Zero based)
[2024-11-21T11:29:08.187+0400][0.013s][info][gc,init] Heap Region Size: 4M
[2024-11-21T11:29:08.187+0400][0.013s][info][gc,init] Heap Min Capacity: 8M
[2024-11-21T11:29:08.187+0400][0.013s][info][gc,init] Heap Initial Capacity: 508M
[2024-11-21T11:29:08.188+0400][0.013s][info][gc,init] Heap Max Capacity: 8116M
[2024-11-21T11:29:08.188+0400][0.013s][info][gc,init] Pre-touch: Disabled
[2024-11-21T11:29:08.188+0400][0.013s][info][gc,init] Parallel Workers: 10
[2024-11-21T11:29:08.188+0400][0.013s][info][gc,init] Concurrent Workers: 3
[2024-11-21T11:29:08.188+0400][0.013s][info][gc,init] Concurrent Refinement Workers: 10
[2024-11-21T11:29:08.188+0400][0.013s][info][gc,init] Periodic GC: Disabled
[2024-11-21T11:29:08.194+0400][0.019s][info][gc,metaspace] CDS archive(s) mapped at: [0x0000024c45000000-0x0000024c45bb0000-0x0000024c45bb0000), size 12255232, SharedBaseAddress: 0x0000024c45000000, ArchiveRelocationMode: 1.
[2024-11-21T11:29:08.194+0400][0.019s][info][gc,metaspace] Compressed class space mapped at: 0x0000024c46000000-0x0000024c86000000, reserved size: 1073741824
[2024-11-21T11:29:08.194+0400][0.019s][info][gc,metaspace] Narrow klass base: 0x0000024c45000000, Narrow klass shift: 0, Narrow klass range: 0x100000000
[2024-11-21T11:29:08.391+0400][0.216s][info][safepoint ] Safepoint "ICBufferFull", Time since last: 193888700 ns, Reaching safepoint: 7400 ns, Cleanup: 69600 ns, At safepoint: 8300 ns, Total: 85300 ns
[2024-11-21T11:29:08.410+0400][0.235s][info][safepoint ] Safepoint "RedefineClasses", Time since last: 16389000 ns, Reaching safepoint: 2900 ns, Cleanup: 45800 ns, At safepoint: 2560100 ns, Total: 2608800 ns
[2024-11-21T11:29:08.438+0400][0.263s][info][safepoint ] Safepoint "JFRCheckpoint", Time since last: 28071700 ns, Reaching safepoint: 2800 ns, Cleanup: 11700 ns, At safepoint: 2500 ns, Total: 17000 ns
[2024-11-21T11:29:09.396+0400][1.221s][info][gc,start ] GC(0) Pause Young (Normal) (G1 Evacuation Pause)
[2024-11-21T11:29:09.396+0400][1.222s][info][gc,task ] GC(0) Using 10 workers of 10 for evacuation
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,phases ] GC(0) Pre Evacuate Collection Set: 0.1ms
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,phases ] GC(0) Merge Heap Roots: 0.1ms
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,phases ] GC(0) Evacuate Collection Set: 2.0ms
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,phases ] GC(0) Post Evacuate Collection Set: 0.4ms
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,phases ] GC(0) Other: 0.5ms
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,heap ] GC(0) Eden regions: 6->0(7)
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,heap ] GC(0) Survivor regions: 0->1(1)
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,heap ] GC(0) Old regions: 0->0
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,heap ] GC(0) Archive regions: 0->0
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,heap ] GC(0) Humongous regions: 0->0
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,metaspace] GC(0) Metaspace: 7360K(7552K)->7360K(7552K) NonClass: 6565K(6656K)->6565K(6656K) Class: 794K(896K)->794K(896K)
[2024-11-21T11:29:09.400+0400][1.225s][info][gc ] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 24M->3M(508M) 3.217ms
[2024-11-21T11:29:09.400+0400][1.225s][info][gc,cpu ] GC(0) User=0.00s Sys=0.00s Real=0.00s
[2024-11-21T11:29:09.400+0400][1.225s][info][safepoint ] Safepoint "G1CollectForAllocation", Time since last: 958423000 ns, Reaching safepoint: 23600 ns, Cleanup: 37100 ns, At safepoint: 3297100 ns, Total: 3357800 ns
[2024-11-21T11:29:10.419+0400][2.244s][info][safepoint ] Safepoint "Cleanup", Time since last: 1019081500 ns, Reaching safepoint: 15700 ns, Cleanup: 21900 ns, At safepoint: 5300 ns, Total: 42900 ns
[2024-11-21T11:29:11.420+0400][3.244s][info][safepoint ] Safepoint "Cleanup", Time since last: 1000396700 ns, Reaching safepoint: 13700 ns, Cleanup: 8300 ns, At safepoint: 4800 ns, Total: 26800 ns
[2024-11-21T11:29:12.420+0400][4.245s][info][safepoint ] Safepoint "Cleanup", Time since last: 1000880300 ns, Reaching safepoint: 25700 ns, Cleanup: 10100 ns, At safepoint: 66000 ns, Total: 101800 ns
[2024-11-21T11:29:13.421+0400][5.245s][info][safepoint ] Safepoint "Cleanup", Time since last: 1000087200 ns, Reaching safepoint: 18300 ns, Cleanup: 13100 ns, At safepoint: 5200 ns, Total: 36600 ns
[2024-11-21T11:29:14.421+0400][6.246s][info][safepoint ] Safepoint "Cleanup", Time since last: 1000750200 ns, Reaching safepoint: 16000 ns, Cleanup: 8300 ns, At safepoint: 28600 ns, Total: 52900 ns
[2024-11-21T11:29:15.422+0400][7.247s][info][safepoint ] Safepoint "Cleanup", Time since last: 1000323100 ns, Reaching safepoint: 13500 ns, Cleanup: 9500 ns, At safepoint: 566000 ns, Total: 589000 ns
[2024-11-21T11:29:17.423+0400][9.248s][info][safepoint ] Safepoint "Cleanup", Time since last: 2000973400 ns, Reaching safepoint: 17600 ns, Cleanup: 6200 ns, At safepoint: 4500 ns, Total: 28300 ns
[2024-11-21T11:29:23.427+0400][15.251s][info][safepoint ] Safepoint "Cleanup", Time since last: 6003316900 ns, Reaching safepoint: 16300 ns, Cleanup: 13000 ns, At safepoint: 11100 ns, Total: 40400 ns
[2024-11-21T11:29:23.858+0400][15.683s][info][safepoint ] Safepoint "JFRCheckpoint", Time since last: 431903500 ns, Reaching safepoint: 12800 ns, Cleanup: 10400 ns, At safepoint: 44800 ns, Total: 68000 ns
[2024-11-21T11:29:23.876+0400][15.701s][info][gc,heap,exit] Heap
[2024-11-21T11:29:23.876+0400][15.701s][info][gc,heap,exit] garbage-first heap total 520192K, used 7237K [0x0000000604c00000, 0x0000000800000000)
[2024-11-21T11:29:23.876+0400][15.701s][info][gc,heap,exit] region size 4096K, 2 young (8192K), 1 survivors (4096K)
[2024-11-21T11:29:23.876+0400][15.701s][info][gc,heap,exit] Metaspace used 8206K, committed 8448K, reserved 1114112K
[2024-11-21T11:29:23.876+0400][15.701s][info][gc,heap,exit] class space used 900K, committed 1024K, reserved 1048576K
Questions
Why does Example 1 result in significantly more memory allocation compared to Example 2?
- Is a new lambda object created each time the inline lambda is called?
- How is memory allocated for lambdas in the JVM?
In both examples, the GC logs show many "Cleanup" events.
- What exactly is being cleaned up during these events?
- Is it related to lambdas, thread-local storage, or something else?
Is there a way to use lambdas in a GC-free style, such that no garbage is generated when they are called repeatedly?
- If not, would sticking to anonymous classes or functional interfaces help?
How can I profile and debug this further to understand the internal memory behavior of lambdas?
1 Answer
Reset to default 2I haven't looked at the JLS in a long time, and am not sure if it says anything about lambda optimization, but after reading the code of folks much smarter than myself (e.g. Martin Thompson) is seems that the following holds: every time the code executes a lambda expression, you should assume that a new object is created, UNLESS that lambda is completely stateless (non-capturing), i.e. the lambda's result is only a function of its input.
I came here to just post the above as a comment, but after looking over the details of your question, I decided to make this into an answer, mainly because I wanted to point out some issues with your experiment design, especially to help others that are new to this.
First, generally speaking (as I haven't used the IntelliJ profiler) attaching a profiler to your application changes it. This is fine for most use cases, but if you are trying to show that your code isn't garbage collecting, unless the code added by the profiler is garbage free, you can confuse the results: just because you're seeing allocations or collections, it doesn't mean that it is coming from your own code. Similarly, java itself does a lot of work when starting your program which might result in some collections at the start. Finally, it takes a few iterations of your code before everything is all JITed to its final form. Therefore, I think the best approach is a to create a small "kernel" of code for testing, and run it many, many, times in a loop, and just observe the collections (by logging the GCs or by running it via JMH with prof gc).
Second, the java compiler is smart and will perform optimizations. When I ran both of your programs above, I did not see evidence that either of them was allocating/collecting. I'm pretty sure that it could determine that the call to Something.method was just dead code, and eliminate it. As those calls were eliminated, there was no need to execute the lambda expression. (This required doing inlining first, b/c it needed to know that the lambda was side effect free, too).
Finally, even once I made Something.method sufficiently complex that it could not be safely eliminated, I still didn't see any sign of allocation/collecting. What was happening was that the lambda was simple enough, that it was completely inlined, eliminating the need to actually allocate an object (see note below). This required making the lambda more complex.
My final version of your code is below
import java.util.List;
import java.util.function.Predicate;
public class LambdaTest {
static Something something = new Something();
public static void main(String[] args) {
String a = "a";
String b = "b";
String c = "c";
Predicate<String> preBuiltSimple = x -> x.equals(a);
Predicate<String> preBuiltComplex = x -> x.equals(a) || x.equals(b) || x.equals(c);
for(int i = 0; i < Integer.MAX_VALUE; i++) {
switch (args[0])
{
case "prebuiltSimple" ->
something.anyTrue(preBuiltSimple);
case "prebuiltComplex" ->
something.anyTrue(preBuiltComplex);
case "simple" ->
something.anyTrue(x -> x.equals(a));
case "complex" ->
something.anyTrue(x -> x.equals(a) || x.equals(b) || x.equals(c));
case "nonCapturing" ->
something.anyTrue(x -> x.equals("foo"));
default -> throw new IllegalArgumentException();
};
}
}
}
class Something {
List<String> list = List.of("1", "2");
public boolean anyTrue(Predicate<String> predicate) {
boolean anyTrue = predicate.test(list.get(0));
for (int i = 1; i < list.size(); i++) {
anyTrue |= predicate.test(list.get(i));
}
return anyTrue;
}
}
I ran it like
java -XX:+UseG1GC -Xmx500m -Xms500m -Xlog:gc* LambdaTest prebuiltSimple
The first three modes each ran without logging a single collection, while the 4th mode, 'complex', triggered 164 collections. The last mode, 'noncapturing' did not cause any collections.
It is very important to note that just because, in this example, the simple lambda results in no allocations does not mean that you can draw some generalization about "simple lambdas" - it just means that for this test program, it was able to perform some optimizations.
My environment, for reference.
$ uname -a
Linux myhost 3.10.0-1160.105.1.el7.x86_64 #1 SMP Thu Dec 7 15:39:45 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux
$ java --version
openjdk 17.0.1 2021-10-19 LTS
OpenJDK Runtime Environment Corretto-17.0.1.12.1 (build 17.0.1+12-LTS)
OpenJDK 64-Bit Server VM Corretto-17.0.1.12.1 (build 17.0.1+12-LTS, mixed mode, sharing)
Note:
If you run these tests with -XX:-Inline, which disables inlining, you'll see that the 'simple' now results in allocations/collections, but the 'noncapturing' one still does not.
If you do this, you might want to cut the number of iterations (MAX_VALUE / 10) as the tests run significantly longer without inlining.
x -> x.equals(a)needs to create a new instance. In the first example this happens every time thewhile (true)loop executes (because that variableacould have been changed). In the second example you create only one instance before the loop executes. The need to create a new instance arises because of the need to capturea- if you could use aBiPredicateand supply bothaandxat runtime the JVM could allocate a single instance and reuse that. – Thomas Kläger Commented Nov 21, 2024 at 8:19x -> x.equals("hello there")instead – Holger Commented Nov 22, 2024 at 11:45