gprof profiler does not print the time summary

Question

I created a simple program:

#include <unistd.h>

void ssleep(unsigned int s)
{
  usleep(1000000*s);
}

int main(int, char**)
{
  ssleep(1);
}

After these commands:

sch@sch-K52F:~/test$ g++ -pedantic -Wall main.cpp -pg
sch@sch-K52F:~/test$ ./a.out 
sch@sch-K52F:~/test$ gprof -b a.out > profile

I get a profile without time summary:

  %   cumulative   self              self     total           
 time   seconds   seconds    calls  Ts/call  Ts/call  name    
  0.00      0.00     0.00        1     0.00     0.00  ssleep(unsigned int)

The same situation with any other code. Am I missing something?

My system:

sch@sch-K52F:~/test$ uname -a
Linux sch-K52F 3.2.0-45-generic-pae #70-Ubuntu SMP Wed May 29 20:31:05 UTC 2013 i686 i686 i386 GNU/Linux
sch@sch-K52F:~/test$ gprof -v
GNU gprof (GNU Binutils for Ubuntu) 2.22
Based on BSD gprof, copyright 1983 Regents of the University of California.
This program is free software.  This program has absolutely no warranty.

thank you

edit 1)

other example:

 time   seconds   seconds    calls  Ts/call  Ts/call  name
  0.00      0.00     0.00     1482     0.00     0.00  std::_Iter_base<unsigned char*, false>::_S_base(unsigned char*)
  0.00      0.00     0.00     1482     0.00     0.00  std::_Niter_base<unsigned char*>::iterator_type std::__niter_base<unsigned char*>(unsigned char*)
  0.00      0.00     0.00     1247     0.00     0.00  std::_Vector_base<unsigned char, std::allocator<unsigned char> >::_M_get_Tp_allocator()
  0.00      0.00     0.00      988     0.00     0.00  __gnu_cxx::__normal_iterator<unsigned char*, std::vector<unsigned char, std::allocator<unsigned char> > >::base() const
  0.00      0.00     0.00      988     0.00     0.00  std::move_iterator<unsigned char*>::base() const
  0.00      0.00     0.00      988     0.00     0.00  std::vector<unsigned char, std::allocator<unsigned char> >::size() const
  0.00      0.00     0.00      988     0.00     0.00  std::_Iter_base<std::move_iterator<unsigned char*>, true>::_S_base(std::move_iterator<unsigned char*>)
  0.00      0.00     0.00      988     0.00     0.00  std::move_iterator<unsigned char*>::move_iterator(unsigned char*)
  0.00      0.00     0.00      988     0.00     0.00  std::_Miter_base<std::move_iterator<unsigned char*> >::iterator_type std::__miter_base<std::move_iterator<unsigned char*> >(std::move_iterator<unsigned char*>)
  0.00      0.00     0.00      988     0.00     0.00  std::move_iterator<unsigned char*> std::make_move_iterator<unsigned char*>(unsigned char* const&)
  0.00      0.00     0.00      741     0.00     0.00  __gnu_cxx::new_allocator<unsigned char>::max_size() const
  0.00      0.00     0.00      555     0.00     0.00  operator new(unsigned int, void*)
  0.00      0.00     0.00      541     0.00     0.00  void std::_Destroy_aux<true>::__destroy<unsigned char*>(unsigned char*, unsigned char*)
  0.00      0.00     0.00      541     0.00     0.00  std::_Vector_base<unsigned char, std::allocator<unsigned char> >::_M_deallocate(unsigned char*, unsigned int)
  0.00      0.00     0.00      541     0.00     0.00  void std::_Destroy<unsigned char*>(unsigned char*, unsigned char*)

I always get zero time, for any code, any function ;/

wldsvc has the right answer, and the reason you get zero time is because `gprof` samples the PC 100 times per second, and the actual amount of CPU your program uses is much less than 1/100 of a second. However, `gprof` also counts calls, and you can see those. — Mike Dunlavey, Jun 04 '13 at 12:22

score 1 · Answer 1 · edited May 23 '17 at 10:25

1

This is because sleep() does not count as part of your process execution time, but as sleep. i.e. your process is put to sleep by the kernel for the requested duration and does not use any CPU cycles. Try with some loop that does real computations. Also, gprof does not seem to take be able to time system calls and other things. It also has other issues. Gprof is meant to compare the performance gain in successive refactoring of your own code, not as an all purpose benchmarking tool.

edited May 23 '17 at 10:25

Community

1
1

answered Jun 04 '13 at 00:21

wldsvc

1,242
9
13

Looks like you are yousing the STL, which has lots of inlined methods. Not sure that gprof can handle this properly either. As an example that it works in some cases, just write a 1 to 1,000,000,000 dummy loop in your example program. You'll see some timing information. – wldsvc Jun 04 '13 at 00:37

gprof profiler does not print the time summary

1 Answers1