Mailing-List: contact cygwin-help AT sourceware DOT cygnus DOT com; run by ezmlm
List-Subscribe: <mailto:cygwin-subscribe AT sources DOT redhat DOT com>
List-Archive: <http://sources.redhat.com/ml/cygwin/>
List-Post: <mailto:cygwin AT sources DOT redhat DOT com>
List-Help: <mailto:cygwin-help AT sources DOT redhat DOT com>, <http://sources.redhat.com/ml/#faqs>
Sender: cygwin-owner AT sources DOT redhat DOT com
Delivered-To: mailing list cygwin AT sources DOT redhat DOT com
Message-ID: <000701c1158b$4ab07400$59cdfdcf@lambda>
From: "Francois Colbert" <francois DOT colbert AT videotron DOT ca>
To: <cygwin AT cygwin DOT com>
Subject: gprof prints incorrect results
Date: Thu, 26 Jul 2001 00:27:32 -0400
MIME-Version: 1.0
Content-Type: text/plain;
	charset="iso-8859-1"
Content-Transfer-Encoding: 7bit
X-Priority: 3
X-MSMail-Priority: Normal
X-Mailer: Microsoft Outlook Express 5.50.4133.2400
X-MimeOLE: Produced By Microsoft MimeOLE V5.50.4133.2400

Hi.

I tried to use the gprof utility, but I was unable to get useful
results with the Cygwin version.

I made a simple test program (see below: prof.cpp) and tried to
profile it on a Linux system (with pre-installed utilities) and on a
Windows system (with Cygwin utilities: gprof version 2.11.90, gcc
version 2.95.2-6.).  On each platform, I compiled the program using
the command line

   gcc -pg prof.cpp -o prof.exe

I executed prof.exe to generate a gmon.out file, and then I ran gprof
using the command line

   gprof --brief prof.exe gmon.out > prof-win32.txt

under Windows, and

   gprof --brief prof.exe gmon.out > prof-linux.txt

under Linux.


The two resulting text files, prof-win32.txt and prof-linux.txt, are
listed below.  I didn't expect the timing data to be similar, because
they are the result of the execution of two different executables in
two different contexts.

Nonetheless, I expected the statistics related to the call graph to be
exactly the same.  They aren't.  I identified the following anomalies
in the prof-win32.txt file:

1- In the flat profile section, number-of-calls stats are missing.

2- In the call graph section, the last column doesn't show any useful
   data, since every function either is "spontaneous" or appears to be
   called only by itself.

3- In the functions index at the end of the file, the DoSomething
   function is missing.  It wasn't missing for every execution of the
   test program, though.


I searched the mailing list for this kind of problems: a lot of people
have encountered them, but nobody found a solution. Is this still
true?


Thanks for your help.

fc


--- prof.cpp --------------------------------------------------------


void
DoSomethingElse(void){
   int* i = new int[1024];
   delete[] i;;
   }


void
DoSomething(void){
   for(int i = 0; i < 1024; i++) DoSomethingElse();
   }



int
main(void){
   for(int i = 0; i < 1024; i++) DoSomething();
   return 0;
   }



--- prof-win32.txt --------------------------------------------------


Flat profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self           self    total
 time   seconds   seconds  calls Ts/call Ts/call  name
 33.33    0.03     0.03                           __builtin_vec_new
 22.22    0.05     0.02                           DoSomethingElse(void)
 11.11    0.06     0.01                           __builtin_vec_delete
 11.11    0.07     0.01                           eh_context_static
 11.11    0.08     0.01                           malloc
 11.11    0.09     0.01                           mcount

   Call graph


granularity: each sample hit covers 4 byte(s) for 12.50% of 0.08 seconds

index % time  self  children    called     name
                                               <spontaneous>
[1]     37.5  0.03    0.00                 __builtin_vec_new [1]
---------------------------------------------
                                               <spontaneous>
[2]     25.0  0.02    0.00                 DoSomethingElse(void) [2]
---------------------------------------------
                                               <spontaneous>
[3]     12.5  0.01    0.00                 __builtin_vec_delete [3]
---------------------------------------------
                                               <spontaneous>
[4]     12.5  0.01    0.00                 eh_context_static [4]
---------------------------------------------
                                               <spontaneous>
[5]     12.5  0.01    0.00                 malloc [5]
---------------------------------------------
                           1048576             DoSomething(void) [12]
[12]     0.0  0.00    0.00       0+1048576 DoSomething(void) [12]
                           1048576             DoSomething(void) [12]
---------------------------------------------
                              1024             main [174]
[174]    0.0  0.00    0.00       0+1024    main [174]
                              1024             main [174]
---------------------------------------------

Index by function name

   [2] DoSomethingElse(void)   [1] __builtin_vec_new       [5] malloc
   [3] __builtin_vec_delete    [4] eh_context_static     (175) mcount



--- prof-linux.txt --------------------------------------------------


Flat profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self            self     total
 time   seconds   seconds  calls  ns/call  ns/call  name
 33.33    0.03     0.03     1024 29296.88 29296.88  DoSomething(void)
 33.33    0.06     0.03                             __builtin_vec_new
 16.67    0.07     0.01                             __builtin_vec_delete
 11.11    0.09     0.01                             __builtin_new
  5.56    0.09     0.01                             Letext
  0.00    0.09     0.00  1048576     0.00     0.00
DoSomethingElse(void)

   Call graph


granularity: each sample hit covers 4 byte(s) for 11.11% of 0.09 seconds

index % time   self  children    called     name
               0.03    0.00    1024/1024        main [2]
[1]     33.3   0.03    0.00    1024         DoSomething(void) [1]
               0.00    0.00 1048576/1048576     DoSomethingElse(void)
[7]
----------------------------------------------
                                                <spontaneous>
[2]     33.3   0.00    0.03                 main [2]
               0.03    0.00    1024/1024        DoSomething(void) [1]
----------------------------------------------
                                                <spontaneous>
[3]     33.3   0.03    0.00                 __builtin_vec_new [3]
----------------------------------------------
                                                <spontaneous>
[4]     16.7   0.01    0.00                 __builtin_vec_delete [4]
----------------------------------------------
                                                <spontaneous>
[5]     11.1   0.01    0.00                 __builtin_new [5]
----------------------------------------------
                                                <spontaneous>
[6]      5.6   0.01    0.00                 Letext [6]
----------------------------------------------
               0.00    0.00 1048576/1048576     DoSomething(void) [1]
[7]      0.0   0.00    0.00 1048576         DoSomethingElse(void) [7]
----------------------------------------------

Index by function name

   [7] DoSomethingElse(void) [6] Letext        [4] __builtin_vec_delete
   [1] DoSomething(void)     [5] __builtin_new [3] __builtin_vec_new





--
Unsubscribe info:      http://cygwin.com/ml/#unsubscribe-simple
Bug reporting:         http://cygwin.com/bugs.html
Documentation:         http://cygwin.com/docs.html
FAQ:                   http://cygwin.com/faq/