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

PerfClassTraceTime slows down VM start-up

    XMLWordPrintable

    Details

    • Subcomponent:
    • Resolved In Build:
      b05

      Description

      PerfClassTraceTime consumes 0.5% of start-up time of "java -version".

      Since this is a very rarely used feature, maybe it should be enabled only if -Xlog:startuptime is specified.

      =======
      diff -r 0702191777c9 src/hotspot/share/classfile/classLoader.cpp
      --- a/src/hotspot/share/classfile/classLoader.cpp Thu May 21 15:56:27 2020 -0700
      +++ b/src/hotspot/share/classfile/classLoader.cpp Wed May 27 13:36:53 2020 -0700
      @@ -1642,7 +1642,7 @@
       // Please keep following two functions at end of this file. With them placed at top or in middle of the file,
       // they could get inlined by agressive compiler, an unknown trick, see bug 6966589.
       void PerfClassTraceTime::initialize() {
      - if (!UsePerfData) return;
      + if (!UsePerfData || !log_is_enabled(Info, startuptime)) return;
       
         if (_eventp != NULL) {
           // increment the event counter
      @@ -1671,7 +1671,7 @@
       }
       
       PerfClassTraceTime::~PerfClassTraceTime() {
      - if (!UsePerfData) return;
      + if (!UsePerfData || !log_is_enabled(Info, startuptime)) return;
       
         // stop the thread-local timer as the event completes
         // and resume the thread-local timer of the event next on the stack
      ========

      Results of " perf stat -r 200 bin/java -Xshare:on -XX:SharedArchiveFile=jdk2.jsa -Xint -version "
         1: 58501988 58181961 (-320027) ----- 40.816 40.529 ( -0.287) --
         2: 58500115 58191736 (-308379) ----- 40.160 39.960 ( -0.200) -
         3: 58504839 58180395 (-324444) ----- 40.598 40.266 ( -0.332) --
         4: 58502647 58179564 (-323083) ----- 40.372 40.173 ( -0.199) -
         5: 58496091 58181745 (-314346) ----- 40.775 40.479 ( -0.296) --
         6: 58503236 58180618 (-322618) ----- 40.227 40.321 ( 0.094) +
         7: 58498331 58186460 (-311871) ----- 40.664 39.997 ( -0.667) -----
         8: 58496502 58180974 (-315528) ----- 40.713 40.449 ( -0.264) --
         9: 58493768 58179520 (-314248) ----- 40.122 40.270 ( 0.148) +
        10: 58501299 58180943 (-320356) ----- 40.197 40.571 ( 0.374) +++
      ============================================================
                58499881 58182391 (-317490) ----- 40.464 40.301 ( -0.163) -
      instr delta = -317490 -0.5427%
      time delta = -0.163 ms -0.4017%

      PerfClassTraceTime was used 539 times during "java -version", so each instance takes about 590 instructions.

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              iklam Ioi Lam
              Reporter:
              iklam Ioi Lam
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: