Following log on a 50gb HeapRAMTester, running for 10s (actual runtime):
2021-09-13 09:57:45 - Hit rate = 0.2001949695124563; total hits = 350550; total misses = 1400493; total reads = 1751043; free memory = 3619MB; max time taken = 0.977226ms; uptime = 29 s; tp
2021-09-13 09:57:46 - Hit rate = 0.19992681200864684; total hits = 82497; total misses = 330139; total reads = 412636; free memory = 3643MB; max time taken = 615.887194ms; uptime = 30 s; tp
2021-09-13 09:57:47 - Hit rate = 0.19931418396618797; total hits = 248948; total misses = 1000075; total reads = 1249023; free memory = 2906MB; max time taken = 615.887194ms; uptime = 31 s;
2021-09-13 09:57:48 - Hit rate = 0.19986780274836977; total hits = 251881; total misses = 1008357; total reads = 1260238; free memory = 2162MB; max time taken = 615.887194ms; uptime = 32 s;
2021-09-13 09:57:49 - Hit rate = 0.20071151200371223; total hits = 123274; total misses = 490911; total reads = 614185; free memory = 1988MB; max time taken = 615.887194ms; uptime = 33 s; t
2021-09-13 09:57:50 - Hit rate = 0.19965430015393493; total hits = 229051; total misses = 918187; total reads = 1147238; free memory = 1400MB; max time taken = 615.887194ms; uptime = 34 s;
2021-09-13 09:57:51 - Hit rate = 0.20023346984418983; total hits = 187652; total misses = 749514; total reads = 937166; free memory = 897MB; max time taken = 615.887194ms; uptime = 35 s; tp
1437112360
2021-09-13 09:57:52 - Hit rate = 0.19942183763963975; total hits = 144454; total misses = 579910; total reads = 724364; free memory = 503MB; max time taken = 615.8871
I.e. on 9:57:52 the last log message from the program occurred (and that "1437112360" string is a printout at the end of the application).
Relevant application code here:
private void go(int seconds) throws InterruptedException {
int keys = createData();
accessCache(keys, seconds);
exit = true;
System.out.println(totalSum); <-------- this is that 143...60 printout; after that the application exits.
}
Looking at the corresponding gc log show that the last message is at
[...]
[2021-09-13T09:58:20.184+0200] GC(23) Finalize Concurrent Mark Cleanup 5.291ms
[2021-09-13T09:58:20.184+0200] GC(23) Pause Cleanup 50694M->50694M(51200M) 6.816ms
[2021-09-13T09:58:20.184+0200] GC(23) Concurrent Cleanup for Next Mark
[2021-09-13T09:58:20.185+0200] GC(23) Running G1 Clear Bitmap with 5 workers for 800 work units.
[2021-09-13T09:58:20.222+0200] GC(23) Concurrent Cleanup for Next Mark 37.406ms
[2021-09-13T09:58:20.222+0200] GC(23) Concurrent Mark Cycle 34499.877ms
right after completion of a mark cycle (also attached, test.log).
I.e. the VM exited only 30s after application exit.