[CMI.PM] Perl Debugger and finding CPU Usage

[Mitch Kutzko]

Wow -- What quick, excellent responses!  Thank you, all!

Ok -- Have found and played with the profiler and gotten results.  I was
mildly concerned that it wouldn't work properly with this script, as it's
actually one that doesn't have an ending -- It's designed to run
open-endedly for literally months on end.  Had problems with profiling via:

	$ perl -d:DProf beacon.pl

and then trying to run the profiler via:

	$ /usr/bin/dprofpp -u

That gave back:

	Garbled profile, unexpected exit time stamp at /usr/bin/dprofpp line 704,
<fh> line 680.


However, was able to run things just fine via:

	$ /usr/bin/dprofpp -u -p beacon.pl

and got the output below back.   

Now, can anyone tell me if there's an obvious way to tell where wasted
(idle?  No obvious -sleep- traps in the code, but you never know...)  CPU
is going?  

I can see that I spend most of my time in Net::RTP::rtp_recv, but that's
correct, since this is an RTP client, and spends almost all of its time
talking to the other RTP clients -- It just shouldn't be soaking up 60-80%
of my CPU doing it, that's all.

This is literally the same library that underlies vic and rat, if anybody
here has done any videoconferencing stuff...  If you've used either of
those, you know they can send and receive *LOTS* more data than this
without even being particularly noticeable.

Thanks again!

Mitch


----------------------

Total Elapsed Time = 257.3488 Seconds
         User Time = 124.1104 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 82.4   102.2 118.95   5489   0.0186 0.0217  Net::RTP::rtp_recv
 7.73   9.589  9.582   5318   0.0018 0.0018  Net::RTP::rtp_free_rtp_packet
 3.55   4.401 17.075  49029   0.0001 0.0003  main::rtp_event_handler
 2.60   3.228  3.514    131   0.0246 0.0268  Net::RTP::rtp_send_ctrl
 1.80   2.229  2.309   5358   0.0004 0.0004  Net::RTP::rtp_update
 0.39   0.480  1.548   5396   0.0001 0.0003  IO::Socket::new
 0.31   0.390  0.331  39145   0.0000 0.0000  Net::RTP::rtp_get_rr
 0.28   0.350  1.882   5396   0.0001 0.0003  IO::Socket::INET::new
 0.27   0.330  0.256  49029   0.0000 0.0000  Net::RTP::rtp_event_type_get
 0.26   0.320  0.320      6   0.0533 0.0533  main::output_data_as_web_page
 0.25   0.310  0.302   5396   0.0001 0.0001  Symbol::gensym
 0.23   0.290  2.156   5391   0.0001 0.0004  IO::Socket::accept
 0.23   0.280  2.408   5318   0.0001 0.0005  main::receive_tcp_reports
 0.21   0.260  0.563   5396   0.0000 0.0001  IO::Handle::autoflush
 0.19   0.240  0.276   5396   0.0000 0.0001  SelectSaver::new
--
Mitch Kutzko | mitch at dast.nlanr.net | mitch at ncsa.uiuc.edu | 217-333-1199
http://hobbes.ncsa.uiuc.edu/