Have you tried using Apache::DProf? Using this is a lot easier than trying to add tons of debug messages. If you haven't used it or the regular DProf, it does what your doing automatically. It generates a file of data that you run 'dprofpp' on and you can get a list of the top 10 or so most time consuming functions. Using Apache::DProf usually reveals time consuming methods in my code that I would never have expected to take so long. In your case, however thourough you were in placing debug statements, its possible (and likely) that you've missed the key subroutine.
G On Wed, 2002-03-20 at 09:59, David Brown wrote: > I've been profiling my MySQL driven Mod_Perl website by adding debug > messages throughout the code which relays what time has elapsed since the > script was invoked (using Time::HiRes) > > Now the script is pretty whizzy, serving up complete pages in circa 0.010 > seconds. > > I got to wondering how those 0.010 were being made up. Interestingly, all > of the database access is complete within 0.002 so I thought where do the > other 0.008 come from ? > > I found the following happened (pseudo code) > > # Checkpoint A - Elapsed : 0.000 > > &buildpage; > > # Checkpoint D - Elapsed 0.010 seconds > > sub buildpage > { > # Checkpoint B - Elapsed: 0.001 > > # Do some DB accessing etc. make a nice webpage > > # Checkpoint C - Elapsed 0.002 > } > > -- > > I expected all the complicated DB access stuff to make up the time, but > instead it seems to be consuming 0.005 in returning from the subroutine to > the main script. > > What's that all about ? > > Points: > > 1. A global variable exists throughout the script to build the webpage > 2. Global file handles are used to access the DB (to retain across > subsequent requests) > 3. No LOCAL or MY variables are defined in the subroutine. > 4. As the webpage is being built into a global variable, the "buildpage" > subroutine doesn't RETURN a value to the calling script. > > It SEEMS the subroutine is taking an inordinate amount of time returning to > the main procedure.. why would this be ? > > ( I'm running Free/BSD, Apache/1.3.22, Mod_perl 1.26 ) > > > >