|
Re: Devel::Profiler and dprofpp Garbled profile
by BrowserUk (Patriarch) on Mar 25, 2004 at 10:31 UTC
|
-F
Force the generation of fake exit timestamps if dprofpp reports that t
+he profile
is garbled. This is only useful if dprofpp determines that the profile
+ is
garbled due to missing exit timestamps. You're on your own if you do t
+his.
Consult the BUGS section.
Examine what is said, not who speaks.
"Efficiency is intelligent laziness." -David Dunham
"Think for yourself!" - Abigail
| [reply]
[d/l] |
|
|
Thanks for the help - I have more information, but not a working result yet.
With the -F option, I get a little further, and then:
Garbled profile, missing an enter time stamp at /usr/bin/dprofpp line 690, <fh> line 323.
With the -T option, I get a trace that seems to indicate that the problem is in DBD::mysql ?
DBD::_::common::errstr
DBI::st::finish
DBD::mysql::st::finish
Database::getClientByCd
Garbled profile, unexpected exit time stamp
I have also found that the only way I can create the tmon.out is with Devel::Profiler - if I switch to
perl -d:DProf myscript.pl
I just get segfault, coredump. The code is all strict and zero warnings. Further, it does not do anything I would consider exotic or difficult. I did have one instance where overload was being used - this is now removed. :(
| [reply]
[d/l] |
|
|
I've never used Profiler, but after a quick squint at the docs one possible way forward would be to use the bad_pkgs option to stop it from profiling everything except your main line code. If that is successful, then you could remove packages from the option until you break it again. Once you know which package(s) are causing problems, then you could try using the bad_subs option to exclude stuff in the bad package and then put them back until you break again.
It might be a rather tedious process, but you might find that you don't need to be profiling much below your main-line code anyway.
Examine what is said, not who speaks.
"Efficiency is intelligent laziness." -David Dunham
"Think for yourself!" - Abigail
| [reply]
[d/l] |
Re: Devel::Profiler and dprofpp Garbled profile
by jaa (Friar) on Mar 25, 2004 at 14:27 UTC
|
I have created a very small program that calls fetchrow_hashref using MySQL that gives dprofpp the heebie-geebies:
#!/usr/local/bin/perl -w
use strict;
use DBI;
use Devel::Profiler;
sub logGeneral { print @_,"\n"; };
sub logFatal { logGeneral @_; die };
my $dbhost = 'localhost';
my $dbname = 'mydatabase';
my $dbuser = 'myuser';
my $dbpasswd = 'mypassword';
my $sql = 'select * from mytable';
my $dsn = "DBI:mysql:host=$dbhost;database=$dbname";
my $dbh = DBI->connect($dsn, $dbuser, $dbpasswd, { RaiseError => 0} )
or logFatal "DBI->Connect failed: DSN='$dsn' User='$dbuser' Error='$
+DBI::errstr'";
logGeneral "database opened";
my $sth = $dbh->prepare( $sql )
or logFatal("prepare failed: '$sql'\n ", $dbh->errstr);
logGeneral "statement prepared";
my $result = $sth->execute()
or logFatal("execute of '$sql' failed\n ", $dbh->errstr);
logGeneral "statement executed: result $result";
my $row = $sth->fetchrow_hashref;
logGeneral "row fetched:";
logFatal "no columns found" unless $sth->{NAME_lc};
for my $field ( @{$sth->{NAME_lc}} ) {
logGeneral sprintf(" %-15s %s", $field, $row->{$field});
}
Can anyone else profile this ok? You just need to slot in your MYSQL db connection details, run the script and then run dprofpp in the same directory.
Thanks a bunch!
| [reply]
[d/l] |
|
|
My little test dprofpp scambler produces a 133 line tmon.out. Here is the section of tmon.out that causes dprofpp a problem:
@ 10 0 0
& 14 DBI::st execute
+ 14
@ 0 0 2
- 14
+ 11
- 11
& 15 DBI::st fetchrow_hashref
+ 15
& 16 DBD::_::st fetchrow_hashref
* 16
& 17 DBI::st fetch
* 17
- 17
& 18 DBI::st FETCH
* 18 << here is the line dprofdd complains about
- 18
+ 11
- 11
Interestingly, the three lines for sub 18 appear to be the same as the three lines for sub 17. Unfortunately, I dont really understand the tmon.out '*' mark enought to know if the first occurance is ok and the second is faulty. If I change the '*' mark to a '+' mark, dprofpp has no problems.
I am leaning towards a dprofpp bug?
| [reply] |
Re: Devel::Profiler and dprofpp Garbled profile
by jaa (Friar) on Mar 25, 2004 at 14:04 UTC
|
More investigation seems to indicate that the problem is in the DBI/DBD calls. The DProf docs explain the tmon.out format. My quickndandy parser shows...
Indentation represents nested subroutines
+ enter sub
- exit sub
* goto sub
Perl code: my $row = $sth->fetchrow_hashref;
+DBI::st::fetchrow_hashref
*DBD::_::st::fetchrow_hashref
*DBI::st::fetch
*DBD::mysql::st::fetch
-DBD::mysql::st::fetch << this is the error
*DBI::st::FETCH
*DBD::mysql::st::FETCH
-DBD::mysql::st::FETCH
I read this as:
- call DBI::st::fetchrow_hashref
- goto DBD::_::st::fetchrow_hashref
- goto DBI::st::fetch
- goto DBD::mysql::st::fetch
- return from DBD::mysql::st::fetch
- goto DBI::st::FETCH
- goto DBD::mysql::st::FETCH
- return from DBD::mysql::st::FETCH
There should only be one return for a call, so the first return for DBD::mysql::st::fetch upsets the profilers righteous sense of indentation!
So either
- DProf - details incorrectly captured
- dprofpp - details incorrectly interpreted
- DBD::mysql - call/goto/return problem
What should I do next?
| [reply] |