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

VM Exit does not abort concurrent mark

    XMLWordPrintable

Details

    • gc
    • 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

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

              Dates

                Created:
                Updated:
                Resolved: