18346 dumps core intermittently

[p5pRT]

Migrated from rt.perl.org#19385 (status was 'resolved')

Searchable as RT19385$

[p5pRT]

From blair@orcaware.com

Created by blair@orcaware.com

With bleadperl patch level #18346, the following script dumps core
intermittently when run as

perl -d​:DProf test.pl

I use this little shell script to run it till it dumps core​:

while test "`ls -1 core* 2>/dev/null | wc -l`" -eq 0; do
  /opt/i386-linux/installed/perl-bleadperl/bin/perl -d​:DProf test.pl
done

require 5.005_03;

use strict;

$| = 1;

use Storable 2.06;

my $force_find_files = 0;
sub handle_hup {
  $force_find_files = 1;
}
sub catch_signal {
  my $signal = shift;
  print "$0​: caught signal $signal.\n";
  exit 0;
}
$SIG{HUP} = \&handle_hup;
$SIG{INT} = \&catch_signal;

Here's a backtrace​:
(gdb) bt
#0 0x4207434f in _int_realloc () from /lib/i686/libc.so.6
#1 0x42073416 in realloc () from /lib/i686/libc.so.6
#2 0x4008a738 in Perl_safesysrealloc (where=0x805e680, size=1776)
  at util.c​:113
#3 0x400adac8 in Perl_sv_grow (sv=0x8097624, newlen=1776) at sv.c​:1606
#4 0x400b3c4d in Perl_sv_catpvn_flags (dsv=0x8097624,
  sstr=0x81729f8 "archname64=''\n", slen=14, flags=0) at sv.c​:4459
#5 0x400b3f08 in Perl_sv_catsv_flags (dsv=0x8097624, ssv=0x808b4b4, flags=2)
  at sv.c​:4533
#6 0x4005ab70 in S_scan_heredoc (s=0x8172a06 "") at toke.c​:6647
#7 0x40049b69 in Perl_yylex () at toke.c​:3390
#8 0x4005dd94 in Perl_yyparse () at perly.c​:1569
#9 0x400deaac in S_doeval (gimme=0, startop=0x0, outside=0x0, seq=421)
  at pp_ctl.c​:2746
#10 0x400e0a9c in Perl_pp_require () at pp_ctl.c​:3213
#11 0x4008a01e in Perl_runops_debug () at dump.c​:1396
#12 0x4003641d in S_call_body (myop=0xbfffe0a0, is_eval=0) at perl.c​:1915
#13 0x40035c27 in Perl_call_sv (sv=0x808b3e8, flags=32) at perl.c​:1794
#14 0x40156182 in XS_DB_sub (cv=0x806d3ac) at DProf.xs​:555
#15 0x400aa8c7 in Perl_pp_entersub () at pp_hot.c​:2656
#16 0x400363fe in S_call_body (myop=0xbfffe2e0, is_eval=0) at perl.c​:1912
#17 0x40036035 in Perl_call_sv (sv=0x808b3e8, flags=6) at perl.c​:1833
#18 0x4003a543 in S_call_list_body (cv=0x808b3e8) at perl.c​:3978
#19 0x4003a098 in Perl_call_list (oldscope=8, paramList=0x808b394)
  at perl.c​:3906
#20 0x4006bfed in Perl_newATTRSUB (floor=453, o=0x80c81a0, proto=0x0,
  attrs=0x0, block=0x80c8178) at op.c​:4217
#21 0x40067f98 in Perl_utilize (aver=1, floor=453, version=0x0, id=0x80c7fd0,
  arg=0x0) at op.c​:2869
#22 0x4005f163 in Perl_yyparse () at perly.y​:412
#23 0x400deaac in S_doeval (gimme=0, startop=0x0, outside=0x0, seq=41)
  at pp_ctl.c​:2746
#24 0x400e0ad6 in Perl_pp_require () at pp_ctl.c​:3213
#25 0x4008a01e in Perl_runops_debug () at dump.c​:1396
#26 0x400ddd00 in S_docatch_body () at pp_ctl.c​:2498
#27 0x400dde1f in S_docatch (o=0x805bff0) at pp_ctl.c​:2534
#28 0x400e0aa4 in Perl_pp_require () at pp_ctl.c​:3213
#29 0x4008a01e in Perl_runops_debug () at dump.c​:1396
#30 0x4003641d in S_call_body (myop=0xbfffeb40, is_eval=0) at perl.c​:1915
#31 0x40035c27 in Perl_call_sv (sv=0x805fdf8, flags=32) at perl.c​:1794
#32 0x40156182 in XS_DB_sub (cv=0x806d3ac) at DProf.xs​:555
#33 0x400aa8c7 in Perl_pp_entersub () at pp_hot.c​:2656
#34 0x400363fe in S_call_body (myop=0xbfffed80, is_eval=0) at perl.c​:1912
#35 0x40036035 in Perl_call_sv (sv=0x805fdf8, flags=6) at perl.c​:1833
#36 0x4003a543 in S_call_list_body (cv=0x805fdf8) at perl.c​:3978
#37 0x4003a098 in Perl_call_list (oldscope=1, paramList=0x8059550)
  at perl.c​:3906
#38 0x4006bfed in Perl_newATTRSUB (floor=103, o=0x8072d80, proto=0x0,
  attrs=0x0, block=0x8088418) at op.c​:4217
#39 0x40067f98 in Perl_utilize (aver=1, floor=103, version=0x8060510,
  id=0x8064da0, arg=0x0) at op.c​:2869
#40 0x4005f163 in Perl_yyparse () at perly.y​:412
#41 0x40034d9c in S_parse_body (env=0x0, xsinit=0x804918f <xs_init>)
  at perl.c​:1395
#42 0x40033df1 in perl_parse (my_perl=0x804b8d8, xsinit=0x804918f <xs_init>,
  argc=3, argv=0xbffff284, env=0x0) at perl.c​:932
#43 0x0804914e in main (argc=3, argv=0xbffff284, env=0xbffff294)
  at perlmain.c​:83
#44 0x420158d4 in __libc_start_main () from /lib/i686/libc.so.6

Perl Info

Flags:
    category=core
    severity=medium

Site configuration information for perl v5.9.0:

Configured by blair at Sun Dec 22 12:31:48 PST 2002.

Summary of my perl5 (revision 5.0 version 9 subversion 0 patch 18335) configuration:
  Platform:
    osname=linux, osvers=2.4.18-19.8.0, archname=i686-linux
    uname='linux orcaware.com 2.4.18-19.8.0 #1 thu dec 12 05:39:29 est 2002 i686 i686 i386 gnulinux '
    config_args='-Dusedevel -Uversiononly -Uinstallusrbinperl -Dprefix=/opt/i386-linux/installed/perl-bleadperl -Dcc=/opt/i386-linux/gcc/bin/gcc -Doptimize=-g -Ulocincpth -Dlibpth=/lib /usr/lib -Dlibspath=/lib /usr/lib -Duseshrplib -Dcf_email=blair@orcaware.com'
    hint=recommended, useposix=true, d_sigaction=define
    usethreads=undef useithreads=undef usemultiplicity=undef
    useperlio=define d_sfio=undef uselargefiles=define usesocks=undef
    use64bitint=undef use64bitall=undef uselongdouble=undef
    usemymalloc=n, bincompat5005=undef
  Compiler:
    cc='/opt/i386-linux/gcc/bin/gcc', ccflags ='-DDEBUGGING -fno-strict-aliasing -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 -I/usr/include/gdbm',
    optimize='-g',
    cppflags='-DDEBUGGING -fno-strict-aliasing -I/usr/include/gdbm'
    ccversion='', gccversion='3.2.1', gccosandvers=''
    intsize=4, longsize=4, ptrsize=4, doublesize=8, byteorder=1234
    d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=12
    ivtype='long', ivsize=4, nvtype='double', nvsize=8, Off_t='off_t', lseeksize=8
    alignbytes=4, prototype=define
  Linker and Libraries:
    ld='/opt/i386-linux/gcc/bin/gcc', ldflags =''
    libpth=/lib /usr/lib
    libs=-lnsl -lgdbm -ldl -lm -lc -lcrypt -lutil -lrt
    perllibs=-lnsl -ldl -lm -lc -lcrypt -lutil -lrt
    libc=/lib/libc-2.2.93.so, so=so, useshrplib=true, libperl=libperl.so
    gnulibc_version='2.2.93'
  Dynamic Linking:
    dlsrc=dl_dlopen.xs, dlext=so, d_dlsymun=undef, ccdlflags='-rdynamic -Wl,-rpath,/opt/i386-linux/installed/perl-bleadperl/lib/5.9.0/i686-linux/CORE'
    cccdlflags='-fpic', lddlflags='-shared'

Locally applied patches:
    DEVEL17881


@INC for perl v5.9.0:
    /opt/i386-linux/installed/perl-bleadperl/lib/5.9.0/i686-linux
    /opt/i386-linux/installed/perl-bleadperl/lib/5.9.0
    /opt/i386-linux/installed/perl-bleadperl/lib/site_perl/5.9.0/i686-linux
    /opt/i386-linux/installed/perl-bleadperl/lib/site_perl/5.9.0
    /opt/i386-linux/installed/perl-bleadperl/lib/site_perl
    .


Environment for perl v5.9.0:
    HOME=/export/home1/blair
    LANG=en_US
    LANGUAGE (unset)
    LD_LIBRARY_PATH (unset)
    LOGDIR (unset)
    PATH=/export/home1/blair/bin:/export/home1/blair/opt-i386-linux/frotz/bin:/export/home1/blair/opt-i386-linux/util/bin:/opt/any-platform/util/bin:/opt/i386-linux/acrobat/bin:/opt/i386-linux/amanda/bin:/opt/i386-linux/analog/bin:/opt/i386-linux/apache-1.3/bin:/opt/i386-linux/autoconf/bin:/opt/i386-linux/bitkeeper/bin:/opt/i386-linux/cronolog/bin:/opt/i386-linux/db-4.1/bin:/opt/i386-linux/gcc/bin:/opt/i386-linux/httperf/bin:/opt/i386-linux/imagemagick/bin:/opt/i386-linux/j2sdk/bin:/opt/i386-linux/ocaml/bin:/opt/i386-linux/perl/bin:/opt/i386-linux/python/bin:/opt/i386-linux/rmagic/bin:/opt/i386-linux/subversion/bin:/opt/i386-linux/swig/bin:/opt/i386-linux/tcl/bin:/opt/i386-linux/util/bin:/opt/i386-linux/valgrind/bin:/opt/i386-linux/webalizer/bin:/opt/i386-linux/web_log_manage/bin:/opt/i386-linux/wml/bin:/opt/java/ant/bin:/opt/java/j2sdkee/bin:/opt/java/jakarta-tomcat-4/bin:/usr/local/bin:/usr/local/bin:/usr/X11R6/bin:/usr/bin/X11:/usr/bin:/bin:/usr/sbin:/sbin:/usr/etc:/etc
    PERL_BADLANG (unset)
    SHELL=/bin/tcsh

[p5pRT]

From blair@orcaware.com

Blair Zajac wrote​:

I'm getting an intermittent core dump with a small script in patch
level 18346 running as​:

perl \-d​:DProf test\.pl

I use this little shell script to run it till it dumps core. It can
take 20 times to run it or more.

while test "\`ls \-1 core\* 2>/dev/null | wc \-l\`" \-eq 0; do
  /opt/i386\-linux/installed/perl\-bleadperl/bin/perl \-d​:DProf test\.pl
done

Here's the script​:

require 5.005_03;

use strict;

$| = 1;

use Storable 2.06;

my $force_find_files = 0;
sub handle_hup {
$force_find_files = 1;
}
sub catch_signal {
my $signal = shift;
print "$0​: caught signal $signal.\n";
exit 0;
}
$SIG{HUP} = \&handle_hup;
$SIG{INT} = \&catch_signal;

Turns out that signal handlers aren't even required here to get
a core dump. This simple script​:

  use Storable 2.04;

will core dump when run with -d​:DProf, it'll just take several
hundred runs of Perl to get it to core dump. It appears that the
longer the script or the more it does, the sooner it'll core dump.

Here's a core dump with perl 5.8.0​:

% gdb /opt/i386-linux/installed/perl-5.8.0-g/bin/perl core.*
GNU gdb Red Hat Linux (5.2.1-4)
Copyright 2002 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB. Type "show warranty" for details.
This GDB was configured as "i386-redhat-linux"...
Core was generated by `/opt/i386-linux/installed/perl-5.8.0-g/bin/perl
-d​:DProf /tmp/blair/Orca/i27/bi'.
Program terminated with signal 11, Segmentation fault.
Reading symbols from
/opt/i386-linux/installed/perl-5.8.0-g/lib/5.8.0/i686-linux/CORE/libperl.so...done.
Loaded symbols for
/opt/i386-linux/installed/perl-5.8.0-g/lib/5.8.0/i686-linux/CORE/libperl.so
Reading symbols from /lib/libnsl.so.1...done.
Loaded symbols for /lib/libnsl.so.1
Reading symbols from /lib/libdl.so.2...done.
Loaded symbols for /lib/libdl.so.2
Reading symbols from /lib/i686/libm.so.6...done.
Loaded symbols for /lib/i686/libm.so.6
Reading symbols from /lib/i686/libc.so.6...
done.
Loaded symbols for /lib/i686/libc.so.6
Reading symbols from /lib/libcrypt.so.1...done.
Loaded symbols for /lib/libcrypt.so.1
Reading symbols from /lib/libutil.so.1...done.
Loaded symbols for /lib/libutil.so.1
Reading symbols from /lib/ld-linux.so.2...done.
Loaded symbols for /lib/ld-linux.so.2
Reading symbols from
/opt/i386-linux/installed/perl-5.8.0-g/lib/5.8.0/i686-linux/auto/Devel/DProf/DProf.so...done.
Loaded symbols for
/opt/i386-linux/installed/perl-5.8.0-g/lib/5.8.0/i686-linux/auto/Devel/DProf/DProf.so
Reading symbols from
/opt/i386-linux/installed/perl-5.8.0-g/lib/5.8.0/i686-linux/auto/Fcntl/Fcntl.so...done.
Loaded symbols for
/opt/i386-linux/installed/perl-5.8.0-g/lib/5.8.0/i686-linux/auto/Fcntl/Fcntl.so
Reading symbols from
/opt/i386-linux/installed/perl-5.8.0-g/lib/5.8.0/i686-linux/auto/Storable/Storable.so...done.
Loaded symbols for
/opt/i386-linux/installed/perl-5.8.0-g/lib/5.8.0/i686-linux/auto/Storable/Storable.so
#0 0x42074038 in _int_free () from /lib/i686/libc.so.6
(gdb) bt
#0 0x42074038 in _int_free () from /lib/i686/libc.so.6
#1 0x420744a3 in _int_realloc () from /lib/i686/libc.so.6
#2 0x42073416 in realloc () from /lib/i686/libc.so.6
#3 0x40088f80 in Perl_safesysrealloc (where=0x805d820, size=2592)
  at util.c​:122
#4 0x40150699 in prof_mark (ptype=167) at DProf.xs​:302
#5 0x40151194 in XS_DB_sub (cv=0x806af68) at DProf.xs​:557
#6 0x400a7d42 in Perl_pp_entersub () at pp_hot.c​:2773
#7 0x40088878 in Perl_runops_debug () at dump.c​:1398
#8 0x40035f3d in S_call_body (myop=0xbfffeb20, is_eval=0) at perl.c​:2045
#9 0x40035747 in Perl_call_sv (sv=0x805a3f4, flags=32) at perl.c​:1924
#10 0x4015117d in XS_DB_sub (cv=0x806af68) at DProf.xs​:555
#11 0x400a7d42 in Perl_pp_entersub () at pp_hot.c​:2773
#12 0x40035f1e in S_call_body (myop=0xbfffed70, is_eval=0) at perl.c​:2042
#13 0x40035b55 in Perl_call_sv (sv=0x805a3f4, flags=6) at perl.c​:1963
#14 0x40039f84 in S_call_list_body (cv=0x805a3f4) at perl.c​:4081
#15 0x40039aea in Perl_call_list (oldscope=1, paramList=0x805a490)
  at perl.c​:4009
#16 0x4006dd19 in Perl_newATTRSUB (floor=107, o=0x805b2a0, proto=0x0,
  attrs=0x0, block=0x8063998) at op.c​:5131
#17 0x40068e99 in Perl_utilize (aver=1, floor=107, version=0x8063de8,
  id=0x80636b0, arg=0x0) at op.c​:3437
#18 0x4005eb30 in Perl_yyparse () at perly.y​:414
#19 0x400348bb in S_parse_body (env=0x0, xsinit=0x804916f <xs_init>)
  at perl.c​:1519
#20 0x4003391d in perl_parse (my_perl=0x804b888, xsinit=0x804916f <xs_init>,
  argc=3, argv=0xbffff284, env=0x0) at perl.c​:1041
#21 0x0804912e in main (argc=3, argv=0xbffff284, env=0xbffff294)
  at perlmain.c​:83
#22 0x420158d4 in __libc_start_main () from /lib/i686/libc.so.6

Best,
Blair

[p5pRT]

From arthur@contiller.se

On fredag, jan 3, 2003, at 07​:13 Europe/Stockholm, Blair Zajac wrote​:

Turns out that signal handlers aren't even required here to get
a core dump. This simple script​:

use Storable 2\.04;

will core dump when run with -d​:DProf, it'll just take several

DProf has been unstable for as long as I remember on larger scripts.

Arthur

[p5pRT]

From blair@orcaware.com

Ilya Zakharevich wrote​:

On Thu, Dec 26, 2002 at 10​:21​:04AM -0800, Blair Zajac wrote​:

Hello,

I'm seeing core dumps with the one line Perl script​:

use Storable 2\.04;

when I run it as

perl \-d​:DProf script\.pl

I'm using perl 5.8.0 compiled out of the box with debugging on RedHat
8.0 using Storable 2.04.

Given that the problem appears within realloc(), did you try to
recompile with Perl malloc() [which in DEBUGGING mode would make some
- sparse - sanity checks]? Or, alternatively, compile with debugging
malloc library (e.g., dbmalloc)?

Yours,
ilya

[cc'ing the RT bug system so this will be logged there]

Ilya,

Thanks. I'll give that a shot and see what I can find. Maybe
I'll try vgrind also.

Best,
Blair

--
Blair Zajac <blair@​orcaware.com>
Plots of your system's performance - http​://www.orcaware.com/orca/

[p5pRT]

From blair@orcaware.com

Blair Zajac wrote​:

Ilya Zakharevich wrote​:

On Thu, Dec 26, 2002 at 10​:21​:04AM -0800, Blair Zajac wrote​:

Hello,

I'm seeing core dumps with the one line Perl script​:

use Storable 2\.04;

when I run it as

perl \-d​:DProf script\.pl

I'm using perl 5.8.0 compiled out of the box with debugging on RedHat
8.0 using Storable 2.04.

Given that the problem appears within realloc(), did you try to
recompile with Perl malloc() [which in DEBUGGING mode would make some
- sparse - sanity checks]? Or, alternatively, compile with debugging
malloc library (e.g., dbmalloc)?

Yours,
ilya

[cc'ing the RT bug system so this will be logged there]

Ilya,

Thanks. I'll give that a shot and see what I can find. Maybe
I'll try vgrind also.

Best,
Blair

Ilya,

OK. Using another freshly compiled Perl 5.8.0 with -g -DDEBUGGING
and using the Perl allocator, I get this message after 85 runs
of the script

  use Storable 2.04;

using "perl -d​:DProf script.pl".

assertion botched (chunk's tail overwrite?)​:
*(unsigned int *)((caddr_t)ovp + nbytes - sizeof (unsigned int)) == 0x55555555

What's the next step???

Another stack backtrace​:

(gdb) bt
#0 0x42028cc1 in kill () from /lib/i686/libc.so.6
#1 0x42028ac8 in raise () from /lib/i686/libc.so.6
#2 0x4202a019 in abort () from /lib/i686/libc.so.6
#3 0x4003a914 in Perl_malloc (nbytes=1074972199) at malloc.c​:1011
#4 0x4003baa9 in Perl_mfree (mp=0x806c008) at malloc.c​:1640
#5 0x4003c058 in Perl_realloc (mp=0x806c008, nbytes=2592) at malloc.c​:1842
#6 0x40153689 in prof_mark (ptype=167) at DProf.xs​:302
#7 0x40154184 in XS_DB_sub (cv=0x8078780) at DProf.xs​:557
#8 0x400a9d5e in Perl_pp_entersub () at pp_hot.c​:2773
#9 0x400360c3 in S_call_body (myop=0xbffff050, is_eval=0) at perl.c​:2042
#10 0x40035cfa in Perl_call_sv (sv=0x80b3798, flags=22) at perl.c​:1963
#11 0x400b4e48 in Perl_sv_clear (sv=0x80b4540) at sv.c​:4961
#12 0x400b5658 in Perl_sv_free (sv=0x80b4540) at sv.c​:5192
#13 0x400ab68f in do_clean_objs (sv=0x80b454c) at sv.c​:346
#14 0x400ab52c in S_visit (f=0x400ab5ba <do_clean_objs>) at sv.c​:292
#15 0x400ab837 in Perl_sv_clean_objs () at sv.c​:385
#16 0x40032768 in perl_destruct (my_perl=0x804b888) at perl.c​:469
#17 0x08049153 in main (argc=3, argv=0xbffff2f4, env=0xbffff304)
  at perlmain.c​:87
#18 0x420158d4 in __libc_start_main () from /lib/i686/libc.so.6

Running under valgrind doesn't show anything extra.

% /opt/i386-linux/installed/perl-5.8.0-g/bin/perl -V
Summary of my perl5 (revision 5.0 version 8 subversion 0) configuration​:
  Platform​:
  osname=linux, osvers=2.4.18-19.8.0, archname=i686-linux
  uname='linux orcaware.com 2.4.18-19.8.0 #1 thu dec 12 05​:39​:29 est 2002 i686 i686 i386 gnulinux '
  config_args='-Dusedevel -Uversiononly -Uinstallusrbinperl -Dprefix=/opt/i386-linux/installed/perl-5.8.0-g -Dcc=/opt/i386-linux/gcc/bin/gcc -Doptimize=-g -Ulocincpth -Duseshrplib -Dcf_email=blair@​orcaware.com -Ui_db -Dlibpth=/lib /usr/lib -Dlibspath=/lib /usr/lib'
  hint=recommended, useposix=true, d_sigaction=define
  usethreads=undef use5005threads=undef useithreads=undef usemultiplicity=undef
  useperlio=define d_sfio=undef uselargefiles=define usesocks=undef
  use64bitint=undef use64bitall=undef uselongdouble=undef
  usemymalloc=y, bincompat5005=undef
  Compiler​:
  cc='/opt/i386-linux/gcc/bin/gcc', ccflags ='-DDEBUGGING -fno-strict-aliasing -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 -I/usr/include/gdbm',
  optimize='-g',
  cppflags='-DDEBUGGING -fno-strict-aliasing -I/usr/include/gdbm'
  ccversion='', gccversion='3.2.1', gccosandvers=''
  intsize=4, longsize=4, ptrsize=4, doublesize=8, byteorder=1234
  d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=12
  ivtype='long', ivsize=4, nvtype='double', nvsize=8, Off_t='off_t', lseeksize=8
  alignbytes=4, prototype=define
  Linker and Libraries​:
  ld='/opt/i386-linux/gcc/bin/gcc', ldflags =''
  libpth=/lib /usr/lib
  libs=-lnsl -lgdbm -ldl -lm -lc -lcrypt -lutil
  perllibs=-lnsl -ldl -lm -lc -lcrypt -lutil
  libc=/lib/libc-2.2.93.so, so=so, useshrplib=true, libperl=libperl.so
  gnulibc_version='2.2.93'
  Dynamic Linking​:
  dlsrc=dl_dlopen.xs, dlext=so, d_dlsymun=undef, ccdlflags='-rdynamic -Wl,-rpath,/opt/i386-linux/installed/perl-5.8.0-g/lib/5.8.0/i686-linux/CORE'
  cccdlflags='-fpic', lddlflags='-shared'

Characteristics of this binary (from libperl)​:
  Compile-time options​: DEBUGGING USE_LARGE_FILES
  Built under linux
  Compiled at Jan 7 2003 11​:36​:57
  @​INC​:
  /opt/i386-linux/installed/perl-5.8.0-g/lib/5.8.0/i686-linux
  /opt/i386-linux/installed/perl-5.8.0-g/lib/5.8.0
  /opt/i386-linux/installed/perl-5.8.0-g/lib/site_perl/5.8.0/i686-linux
  /opt/i386-linux/installed/perl-5.8.0-g/lib/site_perl/5.8.0
  /opt/i386-linux/installed/perl-5.8.0-g/lib/site_perl
  .

Best,
Blair

--
Blair Zajac <blair@​orcaware.com>
Plots of your system's performance - http​://www.orcaware.com/orca/

[p5pRT]

From goldbb2@earthlink.net

Blair Zajac wrote​:
[snip]

using "perl -d​:DProf script.pl".

assertion botched (chunk's tail overwrite?)​:
*(unsigned int *)(
(caddr_t)ovp + nbytes - sizeof (unsigned int)
) == 0x55555555

What's the next step???

When perl's malloc returns a block of bytes, it's actually sizeof(int)
bytes longer than what was requested; in those end bytes, malloc stores
the magic number 0x55555555. If something writes past the end of a
malloc'ed string, that magic gets overwritten. Whenever perl's malloc
library free()s or realloc()s data, it checks that those ends bytes
still contain the magic number 0x55555555. If they don't, then perl
aborts.

The next step, then, is to find out when that particular buffer was
malloc()ed in the first place (to see how large it is), and track each
and every occasion where it is written to. One of those places where
it's written to, it's a write beyond the end of the buffer.

Or, given that you now know that it's a buffer overrun, you could try
and find out why valgrind didn't work, and try and make it work.

I'm not *entirely* sure why valgrind doesn't show anything extra -- as a
*guess,* it doesn't recognize perl's malloc as, well, being a malloc
library, so it can't do proper bounds checking. As a further guess,
this is because the memory allocation functions are named "Perl_malloc",
"Perl_calloc", "Perl_realloc", and "Perl_mfree" instead of "malloc",
"calloc", "realloc", and "free", as valgrind expects.

Since I can't find anything in valgrind's docs for telling it to look
for differently named functions, I would suggest recompiling perl to use
the system's malloc, instead of perl's malloc, and *then* run it under
valgrind.

--
$..='(?​:(?{local$^C=$^C|'.(1<<$_).'})|)'for+a..4;
$..='(?{print+substr"\n !,$^C,1 if $^C<26})(?!)';
$.=s'!'haktrsreltanPJ,r coeueh"';BEGIN{${"\cH"}
|=(1<<21)}""=$.;qw(Just another Perl hacker,\n);

[p5pRT]

From ilya@Math.Berkeley.EDU

On Tue, Jan 07, 2003 at 06​:33​:12PM -0800, Blair Zajac wrote​:

OK. Using another freshly compiled Perl 5.8.0 with -g -DDEBUGGING
and using the Perl allocator, I get this message after 85 runs
of the script

use Storable 2\.04;

using "perl -d​:DProf script.pl".

assertion botched (chunk's tail overwrite?)​:
*(unsigned int *)((caddr_t)ovp + nbytes - sizeof (unsigned int)) == 0x55555555

What's the next step???

In addition to what Benjamin wrote​: you can set a breakpoint inside
the assertion (in botch()); then you can look into the tail of the
allocated chunk and check by what the tail was actually overwritten.

#0 0x42028cc1 in kill () from /lib/i686/libc.so.6
#1 0x42028ac8 in raise () from /lib/i686/libc.so.6
#2 0x4202a019 in abort () from /lib/i686/libc.so.6
#3 0x4003a914 in Perl_malloc (nbytes=1074972199) at malloc.c​:1011

Do not see botch() here; strange...

#4 0x4003baa9 in Perl_mfree (mp=0x806c008) at malloc.c​:1640
#5 0x4003c058 in Perl_realloc (mp=0x806c008, nbytes=2592) at malloc.c​:1842
#6 0x40153689 in prof_mark (ptype=167) at DProf.xs​:302

As "voodoo programming goes", I would try to replace 5 in

  if (g_profstack_ix + 5 > g_profstack_max) {

by 50, and redo `make' in ext/Devel/DProf. If the problem disappears,
some logic did change from the time when 5 was OK...

Ilya

[p5pRT]

From goldbb2@earthlink.net

Ilya Zakharevich wrote​:

On Tue, Jan 07, 2003 at 06​:33​:12PM -0800, Blair Zajac wrote​:

OK. Using another freshly compiled Perl 5.8.0 with -g -DDEBUGGING
and using the Perl allocator, I get this message after 85 runs
of the script

use Storable 2\.04;

using "perl -d​:DProf script.pl".

assertion botched (chunk's tail overwrite?)​:
*(unsigned int *)((caddr_t)ovp + nbytes - sizeof (unsigned int)) == 0x55555555

What's the next step???

In addition to what Benjamin wrote​: you can set a breakpoint inside
the assertion (in botch()); then you can look into the tail of the
allocated chunk and check by what the tail was actually overwritten.

#0 0x42028cc1 in kill () from /lib/i686/libc.so.6
#1 0x42028ac8 in raise () from /lib/i686/libc.so.6
#2 0x4202a019 in abort () from /lib/i686/libc.so.6
#3 0x4003a914 in Perl_malloc (nbytes=1074972199) at malloc.c​:1011

Do not see botch() here; strange...

#4 0x4003baa9 in Perl_mfree (mp=0x806c008) at malloc.c​:1640
#5 0x4003c058 in Perl_realloc (mp=0x806c008, nbytes=2592) at malloc.c​:1842
#6 0x40153689 in prof_mark (ptype=167) at DProf.xs​:302

As "voodoo programming goes", I would try to replace 5 in

    if \(g\_profstack\_ix \+ 5 > g\_profstack\_max\) \{

Actualy, ignore the concept of "voodoo programming". Look through the
prof_mark function, and count the maximum number of different times that
the g_profstack_ix variable can get incremented (taking into account
that if certain code paths are taken, certain others cannot).

First, there's the 4 in the 'if (rdelta || udelta || sdelta) {' branch,
which one assumes is almost always entered (since it only depends on the
times being different, not on data).

Then, 4 more in the 'if (!SvOK(*svp)) {', which is entered if the
mapping from coderef addresses to per-subroutine data doesn't contain
that address.

Then 2 more.

That means, it's at least 2, and at most 10. (Assuming that no
function call that prof_mark makes adds more data to g_profstack).

by 50, and redo `make' in ext/Devel/DProf. If the problem disappears,
some logic did change from the time when 5 was OK...

Right; it should now be 10 instead of 5. (50 would be overkill).

It seems to me, the problem of spotting the need to increase that '5'
to whatever could have been avoided if some assertions of the form​:
  assert(g_profstack_ix + N <= g_profstack_max);
were added in each place where there are about to be N items added.

If this type of assertion had been there, it would have been much easier
to spot what was wrong, without the memory corruption having taken place.

--
$..='(?​:(?{local$^C=$^C|'.(1<<$_).'})|)'for+a..4;
$..='(?{print+substr"\n !,$^C,1 if $^C<26})(?!)';
$.=s'!'haktrsreltanPJ,r coeueh"';BEGIN{${"\cH"}
|=(1<<21)}""=$.;qw(Just another Perl hacker,\n);

[p5pRT]

From blair@orcaware.com

Benjamin Goldberg wrote​:

I'm not *entirely* sure why valgrind doesn't show anything extra -- as a
*guess,* it doesn't recognize perl's malloc as, well, being a malloc
library, so it can't do proper bounds checking. As a further guess,
this is because the memory allocation functions are named "Perl_malloc",
"Perl_calloc", "Perl_realloc", and "Perl_mfree" instead of "malloc",
"calloc", "realloc", and "free", as valgrind expects.

Valgrind may not flag an error because Perl extended the amount of
memory to malloc to include the 0x55555555 and writing into that
space doesn't cause a problem from valgrind's point of view, since
its valid initialized memory.

Since I can't find anything in valgrind's docs for telling it to look
for differently named functions, I would suggest recompiling perl to use
the system's malloc, instead of perl's malloc, and *then* run it under
valgrind.

Here's the valgrind output from using the system's malloc​:

==17462== Invalid write of size 4
==17462== at 0x417F9A12​: prof_mark (DProf.xs​:368)
==17462== by 0x417FA0B7​: XS_DB_sub (DProf.xs​:554)
==17462== by 0x40327D42​: Perl_pp_entersub (pp_hot.c​:2776)
==17462== by 0x402B5F1E​: S_call_body (perl.c​:2042)
==17462== Address 0x412A3FC4 is 0 bytes after a block of size 2592 alloc'd
==17462== at 0x40061973​: realloc (vg_clientfuncs.c​:270)
==17462== by 0x40308F80​: Perl_safesysrealloc (util.c​:122)
==17462== by 0x417F9699​: prof_mark (DProf.xs​:302)
==17462== by 0x417FA0B7​: XS_DB_sub (DProf.xs​:554)
==17462==
==17462== Invalid write of size 4
==17462== at 0x417F9A34​: prof_mark (DProf.xs​:369)
==17462== by 0x417FA0B7​: XS_DB_sub (DProf.xs​:554)
==17462== by 0x40327D42​: Perl_pp_entersub (pp_hot.c​:2776)
==17462== by 0x402B5F1E​: S_call_body (perl.c​:2042)
==17462== Address 0x412A3FC8 is 4 bytes after a block of size 2592 alloc'd
==17462== at 0x40061973​: realloc (vg_clientfuncs.c​:270)
==17462== by 0x40308F80​: Perl_safesysrealloc (util.c​:122)
==17462== by 0x417F9699​: prof_mark (DProf.xs​:302)
==17462== by 0x417FA0B7​: XS_DB_sub (DProf.xs​:554)

DProf.xs line 368 is

  g_total++;
  if (g_SAVE_STACK) { /* Store it for later recording -JH */
  g_profstack[g_profstack_ix++].ptype = ptype;
  g_profstack[g_profstack_ix++].id = id;

I attached gdb at this point and got the following values​:

(gdb) p g_prof_state
$3 = {dprof_ticks = 100, out_file_name = 0x4129ebf0 "tmon.out",
  fp = 0x4126d114, TIMES_LOCATION = 152, SAVE_STACK = 16384, prof_pid = 19339,
  prof_start = {tms_utime = 854, tms_stime = 15, tms_cutime = 0,
  tms_cstime = 0}, prof_end = {tms_utime = 1333, tms_stime = 18,
  tms_cutime = 0, tms_cstime = 0}, rprof_start = 151476340,
  rprof_end = 151476822, wprof_u = 6, wprof_s = 0, wprof_r = 7,
  otms_utime = 1343, otms_stime = 19, orealtime = 151476832,
  profstack = 0x412a35a0, profstack_max = 648, profstack_ix = 648,
  cv_hash = 0x4129762c, total = 115, lastid = 41, default_perldb = 193,
  depth = 1}
(gdb) p ptype
$4 = 166
(gdb) p id
$5 = 41

Here,

#define g_total g_prof_state.total
#define g_profstack_ix g_prof_state.profstack_ix

Best,
Blair

--
Blair Zajac <blair@​orcaware.com>
Plots of your system's performance - http​://www.orcaware.com/orca/

[p5pRT]

From goldbb2@earthlink.net

Blair Zajac wrote​:

Benjamin Goldberg wrote​:

I'm not *entirely* sure why valgrind doesn't show anything extra -- as a
*guess,* it doesn't recognize perl's malloc as, well, being a malloc
library, so it can't do proper bounds checking. As a further guess,
this is because the memory allocation functions are named "Perl_malloc",
"Perl_calloc", "Perl_realloc", and "Perl_mfree" instead of "malloc",
"calloc", "realloc", and "free", as valgrind expects.

Valgrind may not flag an error because Perl extended the amount of
memory to malloc to include the 0x55555555 and writing into that
space doesn't cause a problem from valgrind's point of view, since
its valid initialized memory.

No, read the documentation of valgrind.

It intercepts calls to malloc, calloc, realloc, valloc, memalign, free,
new and delete. Nothing more, nothing less.

Perl, using it's own memory allocation library, does not define or use
any function with any of those names. There is a function whose name
is "Perl_malloc", and there is a "#define malloc Perl_malloc", but there
is *no* function named "malloc". Thus, valgrind does not see perl
allocating memory.

PS​: Perl's memory, when using it's own malloc library, is allocated with
the sbrk function. As I'm sure you can see from the docs of valgrind,
that function isn't watched. IMHO, valgrind ought to detect the use
of sbrk, and output an error saying that it's only designed to work with
malloc & friends, not with home-brew memory allocators.

Since I can't find anything in valgrind's docs for telling it to look
for differently named functions, I would suggest recompiling perl to use
the system's malloc, instead of perl's malloc, and *then* run it under
valgrind.

Here's the valgrind output from using the system's malloc​:

==17462== Invalid write of size 4
==17462== at 0x417F9A12​: prof_mark (DProf.xs​:368)
==17462== by 0x417FA0B7​: XS_DB_sub (DProf.xs​:554)
==17462== by 0x40327D42​: Perl_pp_entersub (pp_hot.c​:2776)
==17462== by 0x402B5F1E​: S_call_body (perl.c​:2042)
==17462== Address 0x412A3FC4 is 0 bytes after a block of size 2592 alloc'd
==17462== at 0x40061973​: realloc (vg_clientfuncs.c​:270)
==17462== by 0x40308F80​: Perl_safesysrealloc (util.c​:122)
==17462== by 0x417F9699​: prof_mark (DProf.xs​:302)
==17462== by 0x417FA0B7​: XS_DB_sub (DProf.xs​:554)
==17462==
==17462== Invalid write of size 4
==17462== at 0x417F9A34​: prof_mark (DProf.xs​:369)
==17462== by 0x417FA0B7​: XS_DB_sub (DProf.xs​:554)
==17462== by 0x40327D42​: Perl_pp_entersub (pp_hot.c​:2776)
==17462== by 0x402B5F1E​: S_call_body (perl.c​:2042)
==17462== Address 0x412A3FC8 is 4 bytes after a block of size 2592 alloc'd
==17462== at 0x40061973​: realloc (vg_clientfuncs.c​:270)
==17462== by 0x40308F80​: Perl_safesysrealloc (util.c​:122)
==17462== by 0x417F9699​: prof_mark (DProf.xs​:302)
==17462== by 0x417FA0B7​: XS_DB_sub (DProf.xs​:554)

DProf.xs line 368 is

g\_total\+\+;
if \(g\_SAVE\_STACK\) \{ /\* Store it for later recording  \-JH \*/
    g\_profstack\[g\_profstack\_ix\+\+\]\.ptype = ptype;
    g\_profstack\[g\_profstack\_ix\+\+\]\.id = id;

If I'm not mistaken, this is the 6th time that something is stored into
g_profstack, and the code only ensures that there's 5 places to store
stuff.

I attached gdb at this point and got the following values​:

(gdb) p g_prof_state
[snip]
profstack = 0x412a35a0, profstack_max = 648, profstack_ix = 648,

Indeed. According to profstack_max, there are 648 slots, which means
indices 0 through 647 of profstack are valid. Index 648, the value
in profstack_ix, is beyond the end of the array.

--
$..='(?​:(?{local$^C=$^C|'.(1<<$_).'})|)'for+a..4;
$..='(?{print+substr"\n !,$^C,1 if $^C<26})(?!)';
$.=s'!'haktrsreltanPJ,r coeueh"';BEGIN{${"\cH"}
|=(1<<21)}""=$.;qw(Just another Perl hacker,\n);

[p5pRT]

From blair@orcaware.com

Benjamin Goldberg wrote​:

Ilya Zakharevich wrote​:

As "voodoo programming goes", I would try to replace 5 in

    if \(g\_profstack\_ix \+ 5 > g\_profstack\_max\) \{

That means, it's at least 2, and at most 10. (Assuming that no
function call that prof_mark makes adds more data to g_profstack).

by 50, and redo `make' in ext/Devel/DProf. If the problem disappears,
some logic did change from the time when 5 was OK...

Right; it should now be 10 instead of 5. (50 would be overkill).

It seems to me, the problem of spotting the need to increase that '5'
to whatever could have been avoided if some assertions of the form​:
assert(g_profstack_ix + N <= g_profstack_max);
were added in each place where there are about to be N items added.

If this type of assertion had been there, it would have been much easier
to spot what was wrong, without the memory corruption having taken place.

I changed the 5 to a 10 and ran the test program several thousand
times and there were no core dumps. Could this modification, and
possibly the assert, be added to perlblead?

Should we push a CPAN release of Devel​::DProf with this fix in it?
I'd be happy to do this if anybody else doesn't want to take it on.

Best,
Blair

--
Blair Zajac <blair@​orcaware.com>
Plots of your system's performance - http​://www.orcaware.com/orca/

[p5pRT]

From goldbb2@earthlink.net

Blair Zajac wrote​:

Benjamin Goldberg wrote​:

Ilya Zakharevich wrote​:

As "voodoo programming goes", I would try to replace 5 in

    if \(g\_profstack\_ix \+ 5 > g\_profstack\_max\) \{

That means, it's at least 2, and at most 10. (Assuming that no
function call that prof_mark makes adds more data to g_profstack).

by 50, and redo `make' in ext/Devel/DProf. If the problem disappears,
some logic did change from the time when 5 was OK...

Right; it should now be 10 instead of 5. (50 would be overkill).

It seems to me, the problem of spotting the need to increase that '5'
to whatever could have been avoided if some assertions of the form​:
assert(g_profstack_ix + N <= g_profstack_max);
were added in each place where there are about to be N items added.

If this type of assertion had been there, it would have been much easier
to spot what was wrong, without the memory corruption having taken place.

I changed the 5 to a 10 and ran the test program several thousand
times and there were no core dumps. Could this modification, and
possibly the assert, be added to perlblead?

Should we push a CPAN release of Devel​::DProf with this fix in it?
I'd be happy to do this if anybody else doesn't want to take it on.

Sure, provide a patch (using diff -u, or something like that) and submit
it to p5p.

--
$..='(?​:(?{local$^C=$^C|'.(1<<$_).'})|)'for+a..4;
$..='(?{print+substr"\n !,$^C,1 if $^C<26})(?!)';
$.=s'!'haktrsreltanPJ,r coeueh"';BEGIN{${"\cH"}
|=(1<<21)}""=$.;qw(Just another Perl hacker,\n);

[p5pRT]

From blair@orcaware.com

Benjamin Goldberg wrote​:

Sure, provide a patch (using diff -u, or something like that) and submit
it to p5p.

Patch attached below.

Also, will the bleadperl Devel​::DProf work with perl 5.6.1 and
greater? That way the bleadperl version could be pushed to CPAN
and replace the Devel​::DProf on those Perl versions.

To make life easier for the Perl developers, I've attached the diffs
between perl 5.6.1's Devel​::DProf and 5.8.0 and bleadperl so that
people can take a quick look at the diffs to see if newer DProf's
will break on older Perls.

Best,
Blair

--
Blair Zajac <blair@​orcaware.com>
Plots of your system's performance - http​://www.orcaware.com/orca/

[p5pRT]

From blair@orcaware.com

Inline Patch

diff -ru ../bleadperl.0/ext/Devel/DProf/Changes ext/Devel/DProf/Changes
--- ../bleadperl.0/ext/Devel/DProf/Changes	2000-07-31 19:31:39.000000000 -0700
+++ ext/Devel/DProf/Changes	2003-01-08 12:07:20.000000000 -0800
@@ -1,3 +1,12 @@
+2003 Jan 8
+
+ Blair Zajac:
+  DProf.xs:
+    - To avoid core dumps, increase stack size by 10 instead of 5.
+    - Assert that g_profstack is large enough when DEBUGGING is defined
+  DProf.pm:
+    - Bump VERSION.
+
 1999 Jan 8
 
  Ilya Zakharevich:
diff -ru ../bleadperl.0/ext/Devel/DProf/DProf.pm ext/Devel/DProf/DProf.pm
--- ../bleadperl.0/ext/Devel/DProf/DProf.pm	2001-09-21 11:11:58.000000000 -0700
+++ ext/Devel/DProf/DProf.pm	2003-01-08 11:48:12.000000000 -0800
@@ -188,7 +188,7 @@
 use XSLoader ();
 
 # Underscore to allow older Perls to access older version from CPAN
-$Devel::DProf::VERSION = '20000000.00_01';  # this version not authorized by
+$Devel::DProf::VERSION = '20030108.00_00';  # this version not authorized by
 				     # Dean Roehrich. See "Changes" file.
 
 XSLoader::load 'Devel::DProf', $Devel::DProf::VERSION;
diff -ru ../bleadperl.0/ext/Devel/DProf/DProf.xs ext/Devel/DProf/DProf.xs
--- ../bleadperl.0/ext/Devel/DProf/DProf.xs	2002-12-17 19:20:13.000000000 -0800
+++ ext/Devel/DProf/DProf.xs	2003-01-08 12:06:33.000000000 -0800
@@ -9,6 +9,12 @@
 /* define DBG_TIMER to cause a warning when the timer is turned on and off. */
 /*#define DBG_TIMER 1  */
 
+#ifdef DEBUGGING
+#define ASSERT(x) assert(x)
+#else
+#define ASSERT(x)
+#endif
+
 #ifdef DBG_SUB
 #  define DBG_SUB_NOTIFY(A) dprof_dbg_sub_notify(A)
 void
@@ -297,7 +303,7 @@
     SV *Sub = GvSV(PL_DBsub);	/* name of current sub */
 
     if (g_SAVE_STACK) {
-	if (g_profstack_ix + 5 > g_profstack_max) {
+	if (g_profstack_ix + 10 > g_profstack_max) {
 		g_profstack_max = g_profstack_max * 3 / 2;
 		Renew(g_profstack, g_profstack_max, PROFANY);
 	}
@@ -309,6 +315,7 @@
     sdelta = t.tms_stime - g_otms_stime;
     if (rdelta || udelta || sdelta) {
 	if (g_SAVE_STACK) {
+	    ASSERT(g_profstack_ix + 4 <= g_profstack_max);
 	    g_profstack[g_profstack_ix++].ptype = OP_TIME;
 	    g_profstack[g_profstack_ix++].tms_utime = udelta;
 	    g_profstack[g_profstack_ix++].tms_stime = sdelta;
@@ -343,6 +350,7 @@
 	    if (CvXSUB(cv) == XS_Devel__DProf_END)
 		return;
 	    if (g_SAVE_STACK) { /* Store it for later recording  -JH */
+		ASSERT(g_profstack_ix + 4 <= g_profstack_max);
 		g_profstack[g_profstack_ix++].ptype = OP_GV;
 		g_profstack[g_profstack_ix++].id = id;
 		g_profstack[g_profstack_ix++].name = pname;
@@ -365,6 +373,7 @@
 
     g_total++;
     if (g_SAVE_STACK) { /* Store it for later recording  -JH */
+	ASSERT(g_profstack_ix + 2 <= g_profstack_max);
 	g_profstack[g_profstack_ix++].ptype = ptype;
 	g_profstack[g_profstack_ix++].id = id;
 
diff -ru ../bleadperl.0/ext/Devel/DProf/Makefile.PL ext/Devel/DProf/Makefile.PL
--- ../bleadperl.0/ext/Devel/DProf/Makefile.PL	2000-07-31 19:31:39.000000000 -0700
+++ ext/Devel/DProf/Makefile.PL	2003-01-08 12:23:50.000000000 -0800
@@ -1,3 +1,7 @@
+BEGIN {
+	require 5.006;
+}
+
 use ExtUtils::MakeMaker;
 
 WriteMakefile(

[p5pRT]

From blair@orcaware.com

Inline Patch

diff -ru perl-5.6.1/ext/Devel/DProf/DProf.pm perl-5.8.0/ext/Devel/DProf/DProf.pm
--- perl-5.6.1/ext/Devel/DProf/DProf.pm	2001-02-22 18:57:54.000000000 -0800
+++ perl-5.8.0/ext/Devel/DProf/DProf.pm	2002-06-01 10:02:53.000000000 -0700
@@ -1,4 +1,4 @@
-require 5.005_64;
+use 5.006_001;
 
 =head1 NAME
 
@@ -188,7 +188,7 @@
 use XSLoader ();
 
 # Underscore to allow older Perls to access older version from CPAN
-$Devel::DProf::VERSION = '20000000.00_00';  # this version not authorized by
+$Devel::DProf::VERSION = '20000000.00_01';  # this version not authorized by
 				     # Dean Roehrich. See "Changes" file.
 
 XSLoader::load 'Devel::DProf', $Devel::DProf::VERSION;

Only in perl-5.8.0/ext/Devel/DProf: DProf.t

Inline Patch

diff -ru perl-5.6.1/ext/Devel/DProf/DProf.xs perl-5.8.0/ext/Devel/DProf/DProf.xs
--- perl-5.6.1/ext/Devel/DProf/DProf.xs	2001-04-05 21:38:46.000000000 -0700
+++ perl-5.8.0/ext/Devel/DProf/DProf.xs	2002-06-01 10:02:53.000000000 -0700
@@ -3,15 +3,32 @@
 #include "perl.h"
 #include "XSUB.h"
 
+/* define DBG_SUB to cause a warning on each subroutine entry. */
 /*#define DBG_SUB 1      */
-/*#define DBG_TIMER 1    */
+
+/* define DBG_TIMER to cause a warning when the timer is turned on and off. */
+/*#define DBG_TIMER 1  */
 
 #ifdef DBG_SUB
-#  define DBG_SUB_NOTIFY(A,B) warn(A, B)
+#  define DBG_SUB_NOTIFY(A) dprof_dbg_sub_notify(A)
+void
+dprof_dbg_sub_notify(SV *Sub) {
+    CV   *cv = INT2PTR(CV*,SvIVX(Sub));
+    GV   *gv = cv ? CvGV(cv) : NULL;
+    if (cv && gv) {
+	warn("XS DBsub(%s::%s)\n",
+	     ((GvSTASH(gv) && HvNAME(GvSTASH(gv))) ?
+	      HvNAME(GvSTASH(gv)) : "(null)"),
+	     GvNAME(gv));
+    } else {
+	warn("XS DBsub(unknown) at %x", Sub);
+    }
+}
 #else
-#  define DBG_SUB_NOTIFY(A,B)  /* nothing */
+#  define DBG_SUB_NOTIFY(A)  /* nothing */
 #endif
 
+
 #ifdef DBG_TIMER
 #  define DBG_TIMER_NOTIFY(A) warn(A)
 #else
@@ -87,7 +104,7 @@
     U32		total;
     U32		lastid;
     U32		default_perldb;
-    U32		depth;
+    UV		depth;
 #ifdef OS2
     ULONG	frequ;
     long long	start_cnt;
@@ -384,7 +401,7 @@
     int i, j, k = 0;
     HV *oldstash = PL_curstash;
     struct tms t1, t2;
-    clock_t realtime1, realtime2;
+    clock_t realtime1 = 0, realtime2 = 0;
     U32 ototal = g_total;
     U32 ostack = g_SAVE_STACK;
     U32 operldb = PL_perldb;
@@ -497,7 +514,7 @@
 	    warn("garbled call depth when profiling");
 	}
 	else {
-	    I32 marks = g_depth - need_depth;
+	    IV marks = g_depth - need_depth;
 
 /* 	    warn("Check_depth: got %d, expected %d\n", g_depth, need_depth); */
 	    while (marks--) {
@@ -513,7 +530,7 @@
 
 XS(XS_DB_sub)
 {
-    dXSARGS;
+    dMARK;
     dORIGMARK;
     SV *Sub = GvSV(PL_DBsub);		/* name of current sub */
 
@@ -521,21 +538,21 @@
     /* profile only the interpreter that loaded us */
     if (g_THX != aTHX) {
         PUSHMARK(ORIGMARK);
-        perl_call_sv(INT2PTR(SV*,SvIV(Sub)), GIMME | G_NODEBUG);
+        perl_call_sv(INT2PTR(SV*,SvIV(Sub)), GIMME_V | G_NODEBUG);
     }
     else
 #endif
     {
 	HV *oldstash = PL_curstash;
 
-        DBG_SUB_NOTIFY("XS DBsub(%s)\n", SvPV_nolen(Sub));
+        DBG_SUB_NOTIFY(Sub);
 
-	SAVEDESTRUCTOR_X(check_depth, (void*)g_depth);
+	SAVEDESTRUCTOR_X(check_depth, INT2PTR(void*,g_depth));
 	g_depth++;
 
         prof_mark(aTHX_ OP_ENTERSUB);
         PUSHMARK(ORIGMARK);
-        perl_call_sv(INT2PTR(SV*,SvIV(Sub)), GIMME | G_NODEBUG);
+        perl_call_sv(INT2PTR(SV*,SvIV(Sub)), GIMME_V | G_NODEBUG);
         PL_curstash = oldstash;
         prof_mark(aTHX_ OP_LEAVESUB);
 	g_depth--;
@@ -568,7 +585,7 @@
                 HV *oldstash = PL_curstash;
 		SV *Sub = GvSV(PL_DBsub);	/* name of current sub */
                 /* SP -= items;  added by xsubpp */
-                DBG_SUB_NOTIFY("XS DBsub(%s)\n", SvPV_nolen(Sub));
+                DBG_SUB_NOTIFY(Sub);
 
                 sv_setiv(PL_DBsingle, 0);	/* disable DB single-stepping */
 
@@ -576,7 +593,7 @@
                 PUSHMARK(ORIGMARK);
 
                 PL_curstash = PL_debstash;	/* To disable debugging of perl_call_sv */
-                perl_call_sv(Sub, GIMME);
+                perl_call_sv(Sub, GIMME_V);
                 PL_curstash = oldstash;
 
                 prof_mark(aTHX_ OP_LEAVESUB);
@@ -632,7 +649,7 @@
          * while we do this.
          */
         {
-	    I32 warn_tmp = PL_dowarn;
+	    bool warn_tmp = PL_dowarn;
 	    PL_dowarn = 0;
 	    newXS("DB::sub", XS_DB_sub, file);
 	    newXS("DB::goto", XS_DB_goto, file);