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

HPROF: multiple stack traces for same method/line stack (due to different bci)

XMLWordPrintable

    • generic
    • generic

      A known issue with the current hprof is that you may see multiple stack traces to the same
      place. This is due to being different bytecode offsets in the method. It is much more likely
      to be seen with 'java -Xint'. The reason was because doing the bytecode->line mapping was
      expensive to do during sampling, so just the bci was sampled, creating multiple trace table
      entries. A fix for this would be to fold these together at the end, unless a really fast bci->line
      mechanism could be created as a class file is loaded...

      This was run with:

          java -Xint -agentlib:hprof=cpu=samples HelloWorld

      public class HelloWorld {
           private static int g;
           private static double total;
           private static void looper(int n) {
               int i;
               for(i=0; i<n; i++) {
                   total += (double)i;
               }
           }
           public static void main(String[] args) {
               System.out.println("hello world");
               for(int i=0; i< 50000; i++) {
                   g++;
                   looper(i);
               }
               System.out.println("hello world");
           }
      }

      ...

      TRACE 300043:
              HelloWorld.looper(HelloWorld.java:6)
              HelloWorld.main(HelloWorld.java:14)
      TRACE 300047:
              HelloWorld.looper(HelloWorld.java:7)
              HelloWorld.main(HelloWorld.java:14)
      TRACE 300049:
              HelloWorld.looper(HelloWorld.java:7)
              HelloWorld.main(HelloWorld.java:14)
      TRACE 300044:
              HelloWorld.looper(HelloWorld.java:6)
              HelloWorld.main(HelloWorld.java:14)
      TRACE 300046:
              HelloWorld.looper(HelloWorld.java:7)
              HelloWorld.main(HelloWorld.java:14)
      TRACE 300048:
              HelloWorld.looper(HelloWorld.java:6)
              HelloWorld.main(HelloWorld.java:14)
      TRACE 300045:
              HelloWorld.looper(HelloWorld.java:7)
              HelloWorld.main(HelloWorld.java:14)
      TRACE 300050:
              HelloWorld.looper(HelloWorld.java:7)
              HelloWorld.main(HelloWorld.java:14)
      TRACE 300052:
              HelloWorld.looper(HelloWorld.java:6)
              HelloWorld.main(HelloWorld.java:14)
      TRACE 300051:
              HelloWorld.looper(HelloWorld.java:6)
              HelloWorld.main(HelloWorld.java:14)
      TRACE 300024:
              java.util.zip.Inflater.inflateBytes(Inflater.java:Unknown line)
              java.util.zip.Inflater.inflate(Inflater.java:219)
              java.util.zip.InflaterInputStream.read(InflaterInputStream.java:128)
              java.io.DataInputStream.readFully(DataInputStream.java:176)
      CPU SAMPLES BEGIN (total = 4621) Mon Mar 21 09:54:39 2005
      rank self accum count trace method
         1 79.90% 79.90% 3692 300043 HelloWorld.looper
         2 6.02% 85.91% 278 300047 HelloWorld.looper
         3 3.57% 89.48% 165 300049 HelloWorld.looper
         4 2.86% 92.34% 132 300044 HelloWorld.looper
         5 2.19% 94.52% 101 300046 HelloWorld.looper
         6 2.08% 96.60% 96 300048 HelloWorld.looper
         7 1.93% 98.53% 89 300045 HelloWorld.looper
         8 0.61% 99.13% 28 300050 HelloWorld.looper
         9 0.56% 99.70% 26 300052 HelloWorld.looper
        10 0.28% 99.98% 13 300051 HelloWorld.looper
        11 0.02% 100.00% 1 300024 java.util.zip.Inflater.inflateBytes
      CPU SAMPLES END

      ###@###.### 2005-03-21 18:02:14 GMT

            ohair Kelly Ohair (Inactive)
            ohair Kelly Ohair (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

              Created:
              Updated:
              Resolved:
              Imported:
              Indexed: