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

PrintGCTaskTimeStamps: amount of tasks reported for GC-thread sometimes differs from expected value

    XMLWordPrintable

    Details

    • Subcomponent:
      gc

      Description

      With -XX:+PrintGCTaskTimeStamps VM prints task timestamps for each GC thread:

      GC-Thread 0 entries: 25
      [ waitfor-barrier-task 835107 837942 ]
      [ mark-from-roots-task 837949 839568 ]
      [ mark-from-roots-task 839573 839579 ]
              ...

      Sometime, amount of printed task timestamps differs from "entries" value from GC-thread entry:

      VM-Thread 837915 842469 845162
      GC-Thread 0 entries: 25
      [ waitfor-barrier-task 835107 837942 ]
      [ mark-from-roots-task 837949 839568 ]
      [ mark-from-roots-task 839573 839579 ]
      [ thread-roots-marking-task 839583 839591 ]
      [ thread-roots-marking-task 839596 839603 ]
      [ thread-roots-marking-task 839608 839615 ]
      [ thread-roots-marking-task 839619 839625 ]
      [ thread-roots-marking-task 839629 839651 ]
      [ thread-roots-marking-task 839656 839667 ]
      [ thread-roots-marking-task 839672 839771 ]
      [ thread-roots-marking-task 839775 839781 ]
      [ mark-from-roots-task 839785 839791 ]
      [ mark-from-roots-task 839796 839840 ]
      [ mark-from-roots-task 839845 839851 ]
      [ mark-from-roots-task 839855 839880 ]
      [ mark-from-roots-task 839885 839890 ]
      [ mark-from-roots-task 839894 839899 ]
      [ mark-from-roots-task 839904 839908 ]
      [ waitfor-barrier-task 839912 842540 ]
      [ drain-region-task 842546 842613 ]
      [ update-dense_prefix-task 842617 844174 ]
      [ update-dense_prefix-task 844179 844395 ]
      [ update-dense_prefix-task 844399 844428 ]
      [ update-dense_prefix-task 844433 844461 ]
      [ update-dense_prefix-task 844466 844474 ]
      [ waitfor-barrier-task 844478 847184 ]
      VM-Thread 847480 852621 865459
      GC-Thread 0 entries: 24

      There are 26 task timestamps, while it is expected to see only 25. And it is definitely not a timestamps from some other thread, because if you look into attached log and compare amount of all task timestamps with sum of all "entries" values, then these values will be different (293 vs 291).

      I was able to reproduce issue with jdk8-b106.

        Attachments

        1. test.sh
          1 kB
        2. test.sh
          1 kB
        3. TestPrintGCTaskTimeStampsFlag.jtr
          15 kB

          Issue Links

            Activity

              People

              Assignee:
              Unassigned Unassigned
              Reporter:
              fzhinkin Filipp Zhinkin
              Votes:
              0 Vote for this issue
              Watchers:
              7 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: