Bug in Perl Profiler?

  • Thread starter it_says_BALLS_on_your forehead
  • Start date
I

it_says_BALLS_on_your forehead

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;
}
 
I

it_says_BALLS_on_your forehead

it_says_BALLS_on_your forehead said:
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',
lseeksize=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
 
X

xhoster

it_says_BALLS_on_your forehead said:
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
 
X

xhoster

it_says_BALLS_on_your forehead said:
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
 
I

it_says_BALLS_on_your forehead

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.
 
X

xhoster

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

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.

Xho


use Parallel::ForkManager;
my $p=Parallel::ForkManager->new(3);

## print if exit status, signal, or core dump are not zero.
$p->run_on_finish( sub { print "@_\n" if $_[1] or $_[3] or $_[4]});

sub foo {
my $x;
$x+=rand() foreach 1..1000;
return $x/1000
};

foreach (1..1_000_000) {
$p->start and next;
my $x=foo();
$p->finish;
};
 
I

it_says_BALLS_on_your forehead

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.
 

Ask a Question

Want to reply to this thread or ask your own question?

You'll need to choose a username for the site, which only take a couple of moments. After that, you can post your question and our members will help you out.

Ask a Question

Members online

No members online now.

Forum statistics

Threads
473,755
Messages
2,569,536
Members
45,007
Latest member
obedient dusk

Latest Threads

Top