Garbage Collection in Java has a lot of advantages over manual deallocation of objects. But sometimes its automatic character makes that some of programmers neglect the aspect of objects lifecycle management.
This post presents basic information about Garbage Collection (GC) in Java. The first part shows the initial step in this process - marking. The second part presents safepoints as one of requirements for marking. The last part contains some Java code that should help to understand explained terms through a real example.
Marking step
The first step of Java's GC is marking. This operation detects all alive objects and marks them as "untouchable". By doing so the GC tells that these objects are still in use by the application and they shouldn't be reclaimed during garbage collection.
Objects are considered alive as long as they are referenced. So, to put an object from alive to not alive state, we can simply set its reference to null or make its reference points to another object, for example:
Worker theBestWorker = new Worker(); // set to null theBestWorker = null; // replace theBestWorker = new Worker();
To discover object state, the GC traverses a graph composed of objects referencing other objects. It starts the traversal from points called Garbage Collection roots (GC roots) that can be: active threads, static fields or local variables of currently executed methods. Every visited object during graph traversal is considered as alive because it can be reached from GC root. All other objects are marked as unreachable. Thanks to that the space that they take can be reclaimed during GC process. Below schema shows this operation of marking one object unreachable:
public class Worker {
private Company currentCompany;
}
// All reachable (alive)
Worker worker = new Worker();
worker.setCompany(new Company());
// Company becomes unreachable, so it's not alive naymore
worker.setCompany(null);
Safepoint
Unfortunately, marking is a process having some impact on JVM performances under the form of safepoints. GC can traverse graph objects only when JVM is stopped. Thanks to that it ensures that analyzed objects are in consistent and known state. The duration of this pause depends on the number of alive objects. GC doesn't traverse unreachable objects so it's really the size of graph built of alive objects that matters.
To know if the interruption is needed, each method is enriched with a kind of barrier points. Every time when executed method reaches one of these points, it checks if it should interrupt the execution to make safepoint operation. If it's the case, it stops and restarts when safepoint isn't need anymore. By the way, GC is not the only reason for safepoint. The other valid reasons are: code deoptimization, code cache flushing, class redefiniton and thread manipulation (dump, suspension, stopping).
These "barrier points" are put in method body by the JIT. The synchronization between GC and running threads are made through calls to polling page. During normal execution, this page is available for reads, so the calls pass. However, when GC wants to detect alive objects, it acquires safepoint lock on the page and makes it unavailable. Now, when running threads try to read polling page, they fail to do so and block themselves. Once GC ends its work, it makes the page readable again and running threads unblock.
GC marking example
Below code is used to show GC safepoints:
public class MarkingTest {
// Execute this code with options:
// -XX:+PrintGCApplicationStoppedTime - prints the time the application was stopped
// -XX:+PrintSafepointStatistics - prints stats about safepoints
// -Xmx300m - maximum heap size (in mb)
// -XX:+PrintGCDetails - prints GC details
// -XX:+PrintGCTimeStamps - prints GC time
public static void main(String[] args) throws InterruptedException {
long startTime = System.currentTimeMillis();
int upperBound = 5_800_000;
List<Worker> workers = new ArrayList<>();
for (int i = 0; i < upperBound; i++) {
Worker worker = new Worker();
worker.setCurrentCompany(new Company());
workers.add(worker);
}
// Now dereference the half of companies
for (int i = 0; i < upperBound / 2; i++) {
workers.get(i).setCurrentCompany(null);
}
long endTime = System.currentTimeMillis();
System.out.println("Executed on " + (endTime - startTime) + " ms");
}
public static class Worker {
private Company currentCompany;
public Company getCurrentCompany() {
return currentCompany;
}
public void setCurrentCompany(Company currentCompany) {
this.currentCompany = currentCompany;
}
}
public static class Company {
}
}
The output I had the most often was:
0,102: [GC (Allocation Failure) [details omitted for brevity]
0,152: Total time for which application threads were stopped: 0,0500968 seconds, Stopping threads took: 0,0000223 seconds
0,161: [GC (Allocation Failure) [details omitted for brevity]
0,207: Total time for which application threads were stopped: 0,0454664 seconds, Stopping threads took: 0,0000176 seconds
0,227: [GC (Allocation Failure) [details omitted for brevity]
0,332: [Full GC (Ergonomics) [details omitted for brevity]
1,394: Total time for which application threads were stopped: 1,1671738 seconds, Stopping threads took: 0,0000172 seconds
1,411: [GC (Allocation Failure) [details omitted for brevity]
1,484: [Full GC (Ergonomics) [details omitted for brevity]
2,452: Total time for which application threads were stopped: 1,0407754 seconds, Stopping threads took: 0,0000215 seconds
Executed on 2236 ms
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count
0,101: ParallelGCFailedAllocation [ 10 0 0 ] [ 0 0 0 0 50 ] 0
0,161: ParallelGCFailedAllocation [ 10 0 0 ] [ 0 0 0 0 45 ] 0
0,227: ParallelGCFailedAllocation [ 10 0 0 ] [ 0 0 0 0 1167 ] 0
1,411: ParallelGCFailedAllocation [ 10 0 0 ] [ 0 0 0 0 1040 ] 0
2,488: no vm operation [ 9 0 1 ] [ 0 0 0 0 312 ] 0
Polling page always armed
ParallelGCFailedAllocation 4
0 VM operations coalesced during safepoint
Maximum sync time 0 ms
Maximum vm operation time (except for Exit VM operation) 1167 ms
The resume shows executed VM operations. The operation made the most frequently is ParallelGCFailedAllocation. As its name indicates, it makes a parallel GC because of failed allocation. In additional, their time matches with the time of printed GC from the beginning of the output.
Another interesting VM operation is...no vm operation. It doesn't really mean that VM did nothing. This entry represents a so-called guaranteed safepoint, i.e. a safepoint operation guaranteed to be executed every X seconds (1 second by default). Guaranteed safepoint process all queued-up operations that are not urgent
As you can see, the time spent on safepoint pauses was about 1 second (1167 ms). In this extreme case (very small heap - 300mb) it was almost a half of execution time. Even if this example shouldn't be take into account seriously, it shows how unproperly managed and configured application can slow down because of too frequent pauses during GC marking step.
