How to make a long time Full GC in Java manually

by

“Allocate the objects into Old Gen” and “long GC pauses” are hard to combine, as the worst thing you could do to the garbage collector, is to create lots of small, linked, live objects forming a graph that the garbage collector must traverse.

But small objects are not allocated into the Old Gen. Only large objects, e.g. arrays, are allocated directly into the Old Gen, but these do not stress the GC that much. Especially primitive type arrays, which you stated to have been used in your first attempt, are no challenge, as they can not contain object references in general.

So, to stress the GC, you have to create lots of small linked objects, enough to get them eventually promoted to the Old Gen, followed by modifying the old objects to enforce Full GC, resp. updates of the remembered sets of the affected cards.

If that’s sounds like familiar pattern, you’re right. We’re talking about LinkedList here.

LinkedList<Object> list = new LinkedList<>();
for(ListIterator<Object> it = list.listIterator();;) {
    for(;;) {
        it.add(new Object());
        if(!it.hasNext()) break;
        it.next();
    }
    while(it.hasPrevious()) {
        it.previous();
        it.add(new Object());
        it.previous();
    }
}

This iterates over the list back and forth, inserting new objects between the old ones, which implies modifying the next pointer of the preceding and the prev pointer of the succeeding list node. We have to do this via ListIterator, as trying to use add(int index, E element) would become too slow for a growing linked list, not creating enough objects to stress the GC.

Running on Java 9.0.4 with -Xmx7G -Xlog:gc gave me

[0.023s][info][gc] Using G1
[0.230s][info][gc] GC(0) Pause Young (G1 Evacuation Pause) 24M->22M(256M) 60.748ms
[0.263s][info][gc] GC(1) Pause Young (G1 Evacuation Pause) 34M->36M(256M) 21.686ms
[0.299s][info][gc] GC(2) Pause Young (G1 Evacuation Pause) 46M->47M(256M) 18.848ms
[0.336s][info][gc] GC(3) Pause Young (G1 Evacuation Pause) 57M->58M(256M) 20.904ms
[0.391s][info][gc] GC(4) Pause Young (G1 Evacuation Pause) 68M->68M(768M) 31.420ms
[0.521s][info][gc] GC(5) Pause Young (G1 Evacuation Pause) 104M->105M(768M) 56.681ms
[0.620s][info][gc] GC(6) Pause Young (G1 Evacuation Pause) 138M->140M(768M) 46.616ms
[0.737s][info][gc] GC(7) Pause Young (G1 Evacuation Pause) 173M->174M(768M) 58.947ms
[0.906s][info][gc] GC(8) Pause Young (G1 Evacuation Pause) 207M->209M(2304M) 100.361ms
[1.272s][info][gc] GC(9) Pause Young (G1 Evacuation Pause) 319M->321M(2304M) 142.440ms
[1.656s][info][gc] GC(10) Pause Young (G1 Evacuation Pause) 421M->423M(2304M) 162.770ms
[1.992s][info][gc] GC(11) Pause Young (G1 Evacuation Pause) 523M->525M(2304M) 145.804ms
[2.404s][info][gc] GC(12) Pause Young (G1 Evacuation Pause) 625M->627M(4250M) 221.090ms
[3.088s][info][gc] GC(13) Pause Young (G1 Evacuation Pause) 824M->826M(4250M) 302.307ms
[3.721s][info][gc] GC(14) Pause Young (G1 Evacuation Pause) 1011M->1013M(4250M) 250.395ms
[4.421s][info][gc] GC(15) Pause Young (G1 Evacuation Pause) 1198M->1199M(4250M) 304.642ms
[5.179s][info][gc] GC(16) Pause Young (G1 Evacuation Pause) 1384M->1386M(5418M) 334.825ms
[6.134s][info][gc] GC(17) Pause Young (G1 Evacuation Pause) 1629M->1631M(5418M) 381.155ms
[6.897s][info][gc] GC(18) Pause Young (G1 Evacuation Pause) 1867M->1868M(5418M) 309.688ms
[7.670s][info][gc] GC(19) Pause Young (G1 Evacuation Pause) 2104M->2106M(5418M) 399.689ms
[8.498s][info][gc] GC(20) Pause Young (G1 Evacuation Pause) 2342M->2344M(6118M) 388.430ms
[9.515s][info][gc] GC(21) Pause Young (G1 Evacuation Pause) 2615M->2617M(6118M) 439.557ms
[10.477s][info][gc] GC(22) Pause Young (G1 Evacuation Pause) 2883M->2884M(6118M) 451.488ms
[11.489s][info][gc] GC(23) Pause Initial Mark (G1 Evacuation Pause) 3150M->3152M(6118M) 443.329ms
[11.489s][info][gc] GC(24) Concurrent Cycle
[12.660s][info][gc] GC(25) Pause Young (G1 Evacuation Pause) 3418M->3419M(6538M) 467.964ms
[14.124s][info][gc] GC(26) Pause Young (G1 Evacuation Pause) 3706M->3708M(6538M) 454.921ms
[15.538s][info][gc] GC(27) Pause Young (G1 Evacuation Pause) 3993M->3995M(6538M) 465.929ms
[16.945s][info][gc] GC(28) Pause Young (G1 Evacuation Pause) 4280M->4281M(6538M) 460.913ms
[18.490s][info][gc] GC(29) Pause Young (G1 Evacuation Pause) 4566M->4568M(6790M) 493.803ms
[20.083s][info][gc] GC(30) Pause Young (G1 Evacuation Pause) 4866M->4868M(6790M) 491.910ms
[21.516s][info][gc] GC(31) Pause Young (G1 Evacuation Pause) 5164M->5166M(6790M) 486.847ms
[22.895s][info][gc] GC(32) Pause Young (G1 Evacuation Pause) 5462M->5464M(6790M) 443.031ms
[24.342s][info][gc] GC(33) Pause Young (G1 Evacuation Pause) 5760M->5762M(6942M) 475.235ms
[25.258s][info][gc] GC(24) Pause Remark 5988M->5988M(6942M) 0.794ms

[25.827s][info][gc] GC(34) Pause Young (G1 Evacuation Pause) 6066M->6067M(6942M) 458.463ms
[27.021s][info][gc] GC(35) Pause Young (G1 Evacuation Pause) 6370M->6372M(6942M) 448.794ms
[27.485s][info][gc] GC(24) Pause Cleanup 6484M->6484M(6942M) 28.631ms
[27.490s][info][gc] GC(24) Concurrent Cycle 16000.856ms
[28.250s][info][gc] GC(36) Pause Young (G1 Evacuation Pause) 6675M->6676M(7024M) 481.748ms
[29.651s][info][gc] GC(37) To-space exhausted
[29.651s][info][gc] GC(37) Pause Initial Mark (G1 Evacuation Pause) 6983M->7127M(7168M) 751.288ms
[29.651s][info][gc] GC(38) Concurrent Cycle
[30.135s][info][gc] GC(39) To-space exhausted
[30.135s][info][gc] GC(39) Pause Young (G1 Evacuation Pause) 7168M->7168M(7168M) 203.578ms
[30.205s][info][gc] GC(40) Pause Young (G1 Evacuation Pause) 7168M->7168M(7168M) 69.831ms
[53.924s][info][gc] GC(41) Pause Full (Allocation Failure) 7168M->6955M(7168M) 23719.072ms
[53.924s][info][gc] GC(38) Concurrent Cycle 24273.544ms
[54.654s][info][gc] GC(42) To-space exhausted
[54.654s][info][gc] GC(42) Pause Young (G1 Evacuation Pause) 7167M->7167M(7168M) 484.771ms
[54.811s][info][gc] GC(43) Pause Initial Mark (G1 Evacuation Pause) 7167M->7167M(7168M) 156.984ms
[54.811s][info][gc] GC(44) Concurrent Cycle
[75.187s][info][gc] GC(45) Pause Full (Allocation Failure) 7167M->7166M(7168M) 20375.807ms
[75.187s][info][gc] GC(44) Concurrent Cycle 20375.993ms
[75.197s][info][gc] GC(46) To-space exhausted
[75.197s][info][gc] GC(46) Pause Young (G1 Evacuation Pause) 7167M->7167M(7168M) 8.585ms
[75.199s][info][gc] GC(47) Pause Initial Mark (G1 Evacuation Pause) 7167M->7167M(7168M) 1.773ms
[75.199s][info][gc] GC(48) Concurrent Cycle
[95.382s][info][gc] GC(49) Pause Full (Allocation Failure) 7167M->7167M(7168M) 20183.050ms
[115.575s][info][gc] GC(50) Pause Full (Allocation Failure) 7167M->7167M(7168M) 20192.989ms
[115.575s][info][gc] GC(48) Concurrent Cycle 40376.227ms
[115.581s][info][gc] GC(51) Pause Young (G1 Evacuation Pause) 7167M->7167M(7168M) 2.649ms
[115.613s][info][gc] GC(52) Pause Initial Mark (G1 Evacuation Pause) 7167M->7167M(7168M) 0.629ms
[115.613s][info][gc] GC(53) Concurrent Cycle
[119.694s][info][gc] GC(54) Pause Full (Allocation Failure) 7167M->0M(8M) 4080.414ms
[119.694s][info][gc] GC(53) Concurrent Cycle 4080.622ms
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
    at java.base/java.util.LinkedList.linkBefore(LinkedList.java:162)
    at java.base/java.util.LinkedList$ListItr.add(LinkedList.java:952)
    at test.Tmp.main(Tmp.java:32)

Note the reported pauses at [53.924s], [75.187s], [95.382s], and [115.575s] of over 20 seconds each…

More Related Contents:

  1. What is the difference between Java Garbage collection and C++ object destruction? [closed]
  2. How to force garbage collection in Java?
  3. When does System.gc() do something?
  4. finalize() called on strongly reachable objects in Java 8
  5. What is the garbage collector in Java?
  6. Java Thread Garbage collected or not
  7. Java heap terminology: young, old and permanent generations?
  8. How to free memory in Java?
  9. Java 7 (JDK 7) garbage collection and documentation on G1
  10. Does setting Java objects to null do anything anymore?
  11. GC overhead limit exceeded
  12. How to monitor Java memory usage?
  13. Garbage collector in Android
  14. GC overhead of Optional in Java
  15. Analyzing gc logs
  16. kubernetes pod memory – java gc logs
  17. Garbage collection behaviour for String.intern()
  18. Java G1 garbage collection in production
  19. Is WeakHashMap ever-growing, or does it clear out the garbage keys?
  20. Know of any Java garbage collection log analysis tools? [closed]
  21. Can you get basic GC stats in Java?
  22. Will stream classes or connections considered as a resource leak in Java
  23. Why is finalize not being called?
  24. How to calculate HashMap memory usage in Java?
  25. Java Collections and Garbage Collector
  26. Reference to object during finalize
  27. What is the Metadata GC Threshold and how do I tune it?
  28. Java and manually executing finalize
  29. Java GC (Allocation Failure)
  30. How to read a verbose:GC output?

Leave a Comment