Stories
Slash Boxes
Comments
NOTE: use Perl; is on undef hiatus. You can read content, but you can't post it. More info will be forthcoming forthcomingly.

All the Perl that's Practical to Extract and Report

use Perl Log In

Log In

[ Create a new account ]

geoff (2013)

geoff
  {geoff} {at} {modperlcookbook.org}
http://www.modperlcookbook.org/

see http://www.modperlcookbook.org/~geoff/ [modperlcookbook.org] for personal information, links to presentations, GPG key, and so on.

Journal of geoff (2013)

Friday September 28, 2007
10:07 AM

on garbled profiles

[ #34562 ]
anyone who has used dprofpp has seen entries like this:

Garbled profile, missing an enter time stamp at /usr/bin/dprofpp line 785, <fh> line 144174.

or

Modification of non-creatable array value attempted, subscript -1 at /usr/bin/dprofpp line 679, <fh> line 142590

ungarbling a profile is a lesson in patience and rote: you go down to the line in question, figure out what sub it's talking about (the number at that line), go to the top of the file, grep for that number, find the subroutine it's talking about, add that sub to your ignore list, lather, rinse, repeat until the problems go away.

ugh

while overloaded subroutines are notorious for this behavior, they are easy to weed out via a simple code scan. but once you remove the low-hanging fruit, it's a chore to ungarble a profile if your codebase is anything more than something very simple. and, for some reason, it always seems to boil down to DBI-based calls once I get to the bottom of things.

well, this morning I decided enough was enough, I'm going to figure this out.I generally don't care about specific, low-level DBI-ish things - the amount of time (and number of calls) to fetch() is much more important to see than what DBI is doing under the hood in that mire of package madness. so, using a lot of verbose Devel::Profiler tracing and some moxy, I was able to add these packages to by bad_pkgs entry:

  DBD::_::st
  DBD::_::db
  DBD::st
  DBD::db
  DBI::st
  DBI::db
  DBI::dr)

which hides low-level DBI calls from the profiler but not those from specific drivers (which contain enough of the database overhead to be interesting). so, with my profiling back in order, I can see all the stuff I'm interested in, including entries like

  1.31   0.293  0.293   2365   0.0001 0.0001  DBD::mysql::st::execute
  1.02   0.229  0.229   4942   0.0000 0.0000  DBD::mysql::st::fetch

anyway, I hope this helps some of you out there. happy profiling :)

The Fine Print: The following comments are owned by whoever posted them. We are not responsible for them in any way.
 Full
 Abbreviated
 Hidden
More | Login | Reply
Loading... please wait.