PERL Miscellaneous - Bug in Perl Profiler?

Author

Bug in Perl Profiler?

it_says_BALLS_on_your forehead

2006-07-27, 6:59 pm

It seems that something about the way the Perl profiler gathers
information from my script is breaking my code. The errors are
inconsistent, both in type, and location.:

bash-3.00$ alias
alias prof='perl -d:DProf'
alias tmon='dprofpp'
bash-3.00$

bash-3.00$ prof fork_titan.pl
Not a CODE reference at /export/home/a352626/titanapp/bin/fork_tools.pl
line 17, <$fh> line 755.
total processing time: 0.745739

## here is fork_tools.pl line 17
my $parsed_sHdr = parse_header( $shdr_ref, 'sHdr' );

....
sub parse_header {
my ( $header, $source ) = @_;

my $hdr = $$header;

# I think this may be the culprit, but why did it work without the
profiler
# and why does it die at different lines?
$hdr =~ s/%([0-9A-Fa-f]{2})/chr(hex($1))/eg;

...

# Success!! without Profiler
bash-3.00$ fork_titan.pl
total processing time: 173.586135

bash-3.00$ prof fork_titan.pl
Argument "main::get_facs" isn't numeric in subroutine entry at
fork_titan.pl line 66, <$fh> line 762.
Not a CODE reference at fork_titan.pl line 66, <$fh> line 762.
total processing time: 0.748186

## here is line 66
my $row_facs_ref = get_facs($FAC_FIELD,
$fields[$FAC_FIELD], \%index);

### and the sub
sub get_facs {
my ($field, $hdr, $index) = @_;

my $prefix = $field == $index->{chdr} ? 'CHDR: ' : 'SHDR: ';

if ($prefix eq 'CHDR') {
$hdr = substr($hdr, index($hdr, 'Cookie:%20'), index($hdr,
'%0d%0a%0d%0a'));
}

my %token;

# Grab the FC, SC, and MC from the header and store it in a hash
while ($hdr =~ m/(?<=%20)([FSM]C)=(?>([^;%\ ]+))(?:[;%\ ]|$)/g) {
$token{$1} = $2;
}

return \%token;
}

bash-3.00$ prof fork_titan.pl
Argument "main::get_fac_field_source" isn't numeric in subroutine entry
at fork_titan.pl line 63, <$fh> line 764.
Not a CODE reference at fork_titan.pl line 63, <$fh> line 764.
total processing time: 0.766146
bash-3.00$

## line 63
my $FAC_FIELD = get_fac_field_source(\%index,
$fields[$index{'shdr'}], $fields[$index{'chdr'}]);

### sub
sub get_fac_field_source {
my ($index, $sHdr, $cHdr) = @_;

# NOTE: assumption is that there will never be FC's or SC's without
an MC
return $index->{'shdr'} if index( $sHdr, '%20MC=' ) != -1;
return $index->{'chdr'} if index( $cHdr, '%20MC=' ) != -1;

return -1;
}

it_says_BALLS_on_your forehead

2006-07-27, 6:59 pm

it_says_BALLS_on_your forehead wrote:
> It seems that something about the way the Perl profiler gathers
> information from my script is breaking my code. The errors are
> inconsistent, both in type, and location.:
>
> bash-3.00$ alias
> alias prof='perl -d:DProf'
> alias tmon='dprofpp'
> bash-3.00$
>
> bash-3.00$ prof fork_titan.pl
> Not a CODE reference at /export/home/a352626/titanapp/bin/fork_tools.pl
> line 17, <$fh> line 755.
> total processing time: 0.745739
>
> ## here is fork_tools.pl line 17
> my $parsed_sHdr = parse_header( $shdr_ref, 'sHdr' );
>
> ...
> sub parse_header {
> my ( $header, $source ) = @_;
>
> my $hdr = $$header;
>
> # I think this may be the culprit, but why did it work without the
> profiler
> # and why does it die at different lines?
> $hdr =~ s/%([0-9A-Fa-f]{2})/chr(hex($1))/eg;
>
> ...
>
> # Success!! without Profiler
> bash-3.00$ fork_titan.pl
> total processing time: 173.586135
>
> bash-3.00$ prof fork_titan.pl
> Argument "main::get_facs" isn't numeric in subroutine entry at
> fork_titan.pl line 66, <$fh> line 762.
> Not a CODE reference at fork_titan.pl line 66, <$fh> line 762.
> total processing time: 0.748186
>
> ## here is line 66
> my $row_facs_ref = get_facs($FAC_FIELD,
> $fields[$FAC_FIELD], \%index);
>
> ### and the sub
> sub get_facs {
> my ($field, $hdr, $index) = @_;
>
> my $prefix = $field == $index->{chdr} ? 'CHDR: ' : 'SHDR: ';
>
> if ($prefix eq 'CHDR') {
> $hdr = substr($hdr, index($hdr, 'Cookie:%20'), index($hdr,
> '%0d%0a%0d%0a'));
> }
>
> my %token;
>
> # Grab the FC, SC, and MC from the header and store it in a hash
> while ($hdr =~ m/(?<=%20)([FSM]C)=(?>([^;%\ ]+))(?:[;%\ ]|$)/g) {
> $token{$1} = $2;
> }
>
> return \%token;
> }
>
> bash-3.00$ prof fork_titan.pl
> Argument "main::get_fac_field_source" isn't numeric in subroutine entry
> at fork_titan.pl line 63, <$fh> line 764.
> Not a CODE reference at fork_titan.pl line 63, <$fh> line 764.
> total processing time: 0.766146
> bash-3.00$
>
> ## line 63
> my $FAC_FIELD = get_fac_field_source(\%index,
> $fields[$index{'shdr'}], $fields[$index{'chdr'}]);
>
> ### sub
> sub get_fac_field_source {
> my ($index, $sHdr, $cHdr) = @_;
>
> # NOTE: assumption is that there will never be FC's or SC's without
> an MC
> return $index->{'shdr'} if index( $sHdr, '%20MC=' ) != -1;
> return $index->{'chdr'} if index( $cHdr, '%20MC=' ) != -1;
>
> return -1;
> }

Here's the Perl build info:
bash-3.00$ perl -V
Summary of my perl5 (revision 5.0 version 8 subversion 0)
configuration:
Platform:
osname=aix, osvers=5.2.0.0, archname=aix-thread-multi
uname='aix rocky 2 5 000ad7df4c00 '
config_args=''
hint=recommended, useposix=true, d_sigaction=define
usethreads=define use5005threads=undef useithreads=define
usemultiplicity=define
useperlio=define d_sfio=undef uselargefiles=define usesocks=undef
use64bitint=undef use64bitall=undef uselongdouble=undef
usemymalloc=n, bincompat5005=undef
Compiler:
cc='cc_r', ccflags ='-D_ALL_SOURCE -D_ANSI_C_SOURCE -D_POSIX_SOURCE
-qmaxmem=16384 -qnoansialias -DUSE_NATIVE_DLOPEN -DNEED_PTHREAD_INIT
-q32 -D_LARGE_FILES -qlonglong',
optimize='-O',
cppflags='-D_ALL_SOURCE -D_ANSI_C_SOURCE -D_POSIX_SOURCE
-qmaxmem=16384 -qnoansialias -DUSE_NATIVE_DLOPEN -DNEED_PTHREAD_INIT'
ccversion='', gccversion='', gccosandvers=''
intsize=4, longsize=4, ptrsize=4, doublesize=8, byteorder=4321
d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=8
ivtype='long', ivsize=4, nvtype='double', nvsize=8, Off_t='off_t',
ls

size=8
alignbytes=8, prototype=define
Linker and Libraries:
ld='ld', ldflags =' -brtl -b32'
libpth=/lib /usr/lib /usr/ccs/lib
libs=-lbind -lnsl -ldbm -ldl -lld -lm -lpthreads -lc_r -lcrypt
-lbsd -lPW
perllibs=-lbind -lnsl -ldl -lld -lm -lpthreads -lc_r -lcrypt -lbsd
-lPW
libc=/lib/libc.a, so=a, useshrplib=true, libperl=libperl.a
gnulibc_version=''
Dynamic Linking:
dlsrc=dl_aix.xs, dlext=so, d_dlsymun=undef, ccdlflags='
-bE:/usr/opt/perl5/lib/5.8.0/aix-thread-multi/CORE/perl.exp'
cccdlflags=' ', lddlflags='-bhalt:4 -bM:SRE
-bI:$(PERL_INC)/perl.exp -bE:$(BASEEXT).exp -bnoentry -lpthreads -lc_r'

Characteristics of this binary (from libperl):
Compile-time options: MULTIPLICITY USE_ITHREADS USE_LARGE_FILES
PERL_IMPLICIT_CONTEXT
Built under aix
Compiled at Jul 26 2002 13:48:15

xhoster@gmail.com

2006-07-27, 6:59 pm

"it_says_BALLS_on_your forehead" <simon.chao@fmr.com> wrote:
> It seems that something about the way the Perl profiler gathers
> information from my script is breaking my code. The errors are
> inconsistent, both in type, and location.:
>
> bash-3.00$ alias
> alias prof='perl -d:DProf'
> alias tmon='dprofpp'
> bash-3.00$
>
> bash-3.00$ prof fork_titan.pl

Based on the name of your program, I seems likely that it forks. It would
not suprise me at all if forking and DProf were incompatible and led
to bizarre behavior. Any chance you can create a dummy program without
forking and profile that?

Xho

--
-------------------- http://NewsReader.Com/ --------------------
Usenet Newsgroup Service $9.95/Month 30GB

xhoster@gmail.com

2006-07-27, 6:59 pm

"it_says_BALLS_on_your forehead" <simon.chao@fmr.com> wrote:
>
> Here's the Perl build info:
> bash-3.00$ perl -V
> Summary of my perl5 (revision 5.0 version 8 subversion 0)

I'd recommend testing on a newer subversion.

Xho

--
-------------------- http://NewsReader.Com/ --------------------
Usenet Newsgroup Service $9.95/Month 30GB

it_says_BALLS_on_your forehead

2006-07-27, 6:59 pm

xhoster@gmail.com wrote:
> "it_says_BALLS_on_your forehead" <simon.chao@fmr.com> wrote:
>
> Based on the name of your program, I seems likely that it forks. It would
> not suprise me at all if forking and DProf were incompatible and led
> to bizarre behavior. Any chance you can create a dummy program without
> forking and profile that?

Good suggestion, I hadn't thought of that. Will do it when time permits
and post the info. Thanks Xho.

it_says_BALLS_on_your forehead

2006-07-28, 7:59 am

xhoster@gmail.com wrote:
> "it_says_BALLS_on_your forehead" <simon.chao@fmr.com> wrote:
>
> I ran a simple forking program under 5.8.0 and 5.8.8, with and without
> DProf. I never saw the "not a CODE ref" error, but I did see some instances
> in which the *child* process seg-faulted. Segfaults only occured under
> 5.8.0 and then only in conjunction with DProf. (Could the error messages
> you saw be coming from a child?) Anyway, I'd recommend an upgrade.

Yeah, I agree that a Perl upgrade would be a smart move, unfortunately
red tape can be a sticky barrier to that path. *shrug* I've voiced that
suggestion; I'll see how that goes. Thanks for taking the time to help
test Xho.

Sponsored Links