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

VM Exit does not abort concurrent mark

    XMLWordPrintable

    Details

    • Subcomponent:
      gc
    • Resolved In Build:
      b15

      Description

      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.

        Attachments

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

          Issue Links

            Activity

              People

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

                Dates

                Created:
                Updated:
                Resolved: