Uploaded image for project: 'JDK'
  1. JDK
  2. JDK-8273605

VM Exit does not abort concurrent mark

XMLWordPrintable

    • gc
    • b15

      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.

        1. test.log
          420 kB
          Thomas Schatzl
        2. test.out
          111 kB
          Thomas Schatzl

            tschatzl Thomas Schatzl
            tschatzl Thomas Schatzl
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

              Created:
              Updated:
              Resolved: