Beefy Boxes and Bandwidth Generously Provided by pair Networks
Perl-Sensitive Sunglasses
 
PerlMonks  

Debugging script with long exec time

by Baz (Friar)
on Aug 28, 2005 at 18:41 UTC ( [id://487278]=perlquestion: print w/replies, xml ) Need Help??

Baz has asked for the wisdom of the Perl Monks concerning the following question:

Hi
I have a script which prints out a map using data from a mysql database. As the database gets bigger and bigger, the map is taking longer to plot - to long in fact. So I need to find out where in my script most of my time is being lost. I'd like to print messages to a log file, including a time stamp relating to when this message was printed. What would be a good time function for doing this? I've only ever used localtime(time) before. Am I going about this in the right fashion?
Cheers,
Barry.

Replies are listed 'Best First'.
Re: Debugging script with long exec time
by davidrw (Prior) on Aug 28, 2005 at 18:51 UTC
    Using localtime(time) is fine, but note it's only 1-sec resolution (which is probably fine for your needs). If you ever need something better, use Time::HiRes

    I would highly recommend Devel::Profile since it can tell you what subs/calls are the bottlenecks (you get this information from Devel::Cover as well), and that is probablly the most robust way to debug your issues.

    Lastly, an obligatory reminder to review your queries and schema/indices to make sure they are all appropriate.
      Why Devel::Profile? It doesn't look like it allows you to sort by wall time, which I usually find necessary.
Re: Debugging script with long exec time
by tlm (Prior) on Aug 28, 2005 at 19:07 UTC

    Don't use print for this sort of thing; use a profiler (Devel::Profile, as davidrw mentioned). Profile your program with a relatively small load (i.e. have your program print a small fraction of the map, for example). That should be enough in most cases to tell you where the bottlenecks are, without having to wait for a long run to finish.

    the lowliest monk

      print really has no problem here.

      What would be nice is to have some small scripts to analyze the log files produced. This is one of the area that perl does really good: relatively faster handing large files and has strong regexp support. With Perl it should take one no time to develop such scripts.

      This is the sort of thing I do quite often, and the programs that produce the log files are usually not even in Perl.

      What important is for the log messages to convey useful information. What to log or not to log is the key.

        Many profiling tools are log-analyzers! Take a look at the output from Devel::DProf or Devel::Profiler. The file produced is essentially a specially-formated log-file of subroutine entry and exit times. The dprofpp program is a log-analyzer which reads the log and produces summary reports.

        -sam

Re: Debugging script with long exec time
by QM (Parson) on Aug 28, 2005 at 23:44 UTC
    Then there's Devel::SmallProf, which does line-by-line profiling.

    -QM
    --
    Quantum Mechanics: The dreams stuff is made of

Re: Debugging script with long exec time
by TedPride (Priest) on Aug 29, 2005 at 06:59 UTC
    There are two things that could be causing the delay. First, your mySQL database might not be optimized well. Take the query that you're sending to the database and have the database analyze it with EXPLAIN. Like:

    EXPLAIN SELECT * FROM tablename WHERE ...

    If you have a massively large database and are selecting a relatively small number of coordinates to plot, it's possible that the delay might be here. Post the results here, and look into making an index.

    The other possibility is that your graphics rendering is just taking too long. This can't really be helped, aside from lowering the number of displayed points (either by ranking each point's importance and only displaying important ones, or by zooming in the map) or getting a more efficient rendering module. You might also look into using CSS layers to display the points, rather than actually generating a graphic for each view. This method won't be quite as compatible, but should take significantly less processing time.

Re: Debugging script with long exec time
by samtregar (Abbot) on Aug 29, 2005 at 17:27 UTC
    Here's how I'd proceed:

    1. Open up 'top' in a window and run the script. Does mysqld stay on the CPU 100% of the time? Or is it mostly Perl? Or a mix of the two?
    2. If mysqld is eating most of the CPU time I'd bust out DBI::ProfileDumper and see what the hot queries are. Then fix them and repeat.
    3. If it's mostly Perl I'd setup Devel::DProf (unless it seg-faults, and then I'd try Devel::Profiler). That will tell you what the hot subroutines are. Fix them to work faster and repeat.

    The important thing to keep in mind is that you're not trying to speed up the whole program, just the slow part. Finding the slowest part is your first priority, then you'll know where to focus your attention.

    -sam

Log In?
Username:
Password:

What's my password?
Create A New User
Domain Nodelet?
Node Status?
node history
Node Type: perlquestion [id://487278]
Approved by salva
help
Chatterbox?
and the web crawler heard nothing...

How do I use this?Last hourOther CB clients
Other Users?
Others imbibing at the Monastery: (3)
As of 2024-04-25 21:40 GMT
Sections?
Information?
Find Nodes?
Leftovers?
    Voting Booth?

    No recent polls found