understanding the output of gprof on solaris

Question

I thought of learning gprof.so i started with a simple program. I have written a small program in c below:

#include<stdio.h>
#include<unistd.h>

void hello(void);

int main()
{

hello();
return 0;

}

void hello()
{
int i; 

for(i=0; i<60; i++) 
{     
sleep(1);     
printf("hello world\n"); 
} 

}

i compiled my program using -pg option. and i executed it to make sure that its working fine.

then i did

gprof -f hello a.out > gout

this gives me gout file created. inside the gout file i can see the below information.

   %  cumulative    self              self    total          
 time   seconds   seconds    calls  ms/call  ms/call name    
 -nan       0.00     0.00        3     0.00     0.00  __1cH__CimplWnew_atexit_implemented6F_b_ (1561)
 -nan       0.00     0.00        1     0.00     0.00  __1cFhello6F_v_ (1562)
 -nan       0.00     0.00        1     0.00     0.00  __1cG__CrunMdo_exit_code6F_v_ (1563)
 -nan       0.00     0.00        1     0.00     0.00  __1cG__CrunSregister_exit_code6FpG_v_v_ (1564)
 -nan       0.00     0.00        1     0.00     0.00  __1cG__CrunVdo_exit_code_in_range6Fpv1_v_ (1565)
 -nan       0.00     0.00        1     0.00     0.00  __1cH__CimplKcplus_fini6F_v_ (1566)
 -nan       0.00     0.00        1     0.00     0.00  __1cH__CimplQ__type_info_hash2t5B6M_v_ (1567)
 -nan       0.00     0.00        1     0.00     0.00  __1cU__STATIC_CONSTRUCTOR6F_v_ (1568)
 -nan       0.00     0.00        1     0.00     0.00  __SLIP.FINAL__A (1569)
 -nan       0.00     0.00        1     0.00     0.00  __SLIP.INIT_A (1570)
 -nan       0.00     0.00        1     0.00     0.00  __cplus_fini_at_exit (1571)
 -nan       0.00     0.00        1     0.00     0.00  _ex_deregister (1572)
 -nan       0.00     0.00        1     0.00     0.00  main (1)
^L
Index by function name

(1562) __1cFhello6F_v_    (1567) __1cH__CimplQ__type(1571) __cplus_fini_at_exi
(1563) __1cG__CrunMdo_exit(1561) __1cH__CimplWnew_at(1572) _ex_deregister     
(1564) __1cG__CrunSregiste(1568) __1cU__STATIC_CONST   (1) main               
(1565) __1cG__CrunVdo_exit(1569) __SLIP.FINAL__A    
(1566) __1cH__CimplKcplus_(1570) __SLIP.INIT_A      

i have given a sleep time of 60 sec. and i am not seeing that 60 sec in the gprof output. i believe its probably hidden inside the output. could anybody pls help me understand the output of gprof?

Answer 1

gprof's sample doesn't consider I/O, sleep, and other async or blocked OS syscalls, so you can't see related time cost in gprof's report.