Skip Menu |

Preferred bug tracker

Please visit the preferred bug tracker to report your issue.

This queue is for tickets about the devel-nytprof CPAN distribution.

Report information
The Basics
Id: 50634
Status: resolved
Priority: 0/
Queue: devel-nytprof

People
Owner: Nobody in particular
Requestors: RANDIR [...] cpan.org
Cc:
AdminCc:

Bug Information
Severity: (no value)
Broken in: 2.10
Fixed in: (no value)



Subject: Segfault when used with Scope::Upper
When using Scope::Upper's unwind under profiling, my application dumps core. This doesn't happen without profiling (it behaves correctly). Unfortunatelly, i can't provide short and simple example (it happens only in real world, short apps works OK), only stacktrace in attachment. Algorythm i use is like: 1. save current scope pointer (HERE) 2. do { call->call->call->call->unwind saved scope } 3. unwind to saved scope (here it segfaults) My enviroment is: % perl -e 'use Scope::Upper; print $Scope::Upper::VERSION' 0.09 % perl -e 'use Devel::NYTProf; print $Devel::NYTProf::VERSION' 2.10 % perl -V Summary of my perl5 (revision 5 version 8 subversion 8) configuration: Platform: osname=freebsd, osvers=7.0-release, archname=i386-freebsd-64int uname='freebsd begom.com 7.0-release freebsd 7.0-release #1: tue feb 10 11:29:32 msk 2009 inferno@begom.com:usrobjusrsrcrelease-7.0sysbegom i386 ' config_args='-sde -Dprefix=/usr/local -Darchlib=/usr/local/lib/perl5/5.8.8/mach -Dprivlib=/usr/local/lib/perl5/5.8.8 -Dman3dir=/usr/local/lib/perl5/5.8.8/perl/man/man3 -Dman1dir=/usr/local/man/man1 -Dsitearch=/usr/local/lib/perl5/site_perl/5.8.8/mach -Dsitelib=/usr/local/lib/perl5/site_perl/5.8.8 -Dscriptdir=/usr/local/bin -Dsiteman3dir=/usr/local/lib/perl5/5.8.8/man/man3 -Dsiteman1dir=/usr/local/man/man1 -Ui_malloc -Ui_iconv -Uinstallusrbinperl -Dcc=cc -Duseshrplib -Dccflags=-DAPPLLIB_EXP="/usr/local/lib/perl5/5.8.8/BSDPAN" -Doptimize=-g -ggdb -DDEBUGGING -Ud_dosuid -Ui_gdbm -Dusethreads=n -Dusemymalloc=y -Duse64bitint' 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=define use64bitall=undef uselongdouble=undef usemymalloc=y, bincompat5005=undef Compiler: cc='cc', ccflags ='-DAPPLLIB_EXP="/usr/local/lib/perl5/5.8.8/BSDPAN" -DHAS_FPSETMASK -DHAS_FLOATINGPOINT_H -DDEBUGGING -fno-strict-aliasing -pipe -Wdeclaration-after-statement -I/usr/local/include', optimize='-g -ggdb', cppflags='-DAPPLLIB_EXP="/usr/local/lib/perl5/5.8.8/BSDPAN" -DHAS_FPSETMASK -DHAS_FLOATINGPOINT_H -DDEBUGGING -fno-strict-aliasing -pipe -Wdeclaration-after-statement -I/usr/local/include' ccversion='', gccversion='4.2.1 20070719 [FreeBSD]', gccosandvers='' intsize=4, longsize=4, ptrsize=4, doublesize=8, byteorder=12345678 d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=12 ivtype='long long', ivsize=8, nvtype='double', nvsize=8, Off_t='off_t', lseeksize=8 alignbytes=4, prototype=define Linker and Libraries: ld='cc', ldflags =' -Wl,-E -L/usr/local/lib' libpth=/usr/lib /usr/local/lib libs=-lm -lcrypt -lutil perllibs=-lm -lcrypt -lutil libc=, so=so, useshrplib=true, libperl=libperl.so gnulibc_version='' Dynamic Linking: dlsrc=dl_dlopen.xs, dlext=so, d_dlsymun=undef, ccdlflags=' -Wl,-R/usr/local/lib/perl5/5.8.8/mach/CORE' cccdlflags='-DPIC -fPIC', lddlflags='-shared -L/usr/local/lib' Characteristics of this binary (from libperl): Compile-time options: DEBUGGING MYMALLOC PERL_MALLOC_WRAP USE_64_BIT_INT USE_LARGE_FILES USE_PERLIO Locally applied patches: defined-or Built under freebsd Compiled at May 27 2009 07:15:34 @INC: /usr/local/lib/perl5/5.8.8/BSDPAN /usr/local/lib/perl5/site_perl/5.8.8/mach /usr/local/lib/perl5/site_perl/5.8.8 /usr/local/lib/perl5/site_perl /usr/local/lib/perl5/5.8.8/mach /usr/local/lib/perl5/5.8.8 .
Subject: coredump.txt
% gdb /usr/local/bin/perl /var/tmp/perl5.8.8.core GNU gdb 6.1.1 [FreeBSD] Copyright 2004 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-marcel-freebsd"... warning: core file may not match specified executable file. Core was generated by `perl5.8.8'. Program terminated with signal 11, Segmentation fault. Reading symbols from /usr/local/lib/perl5/5.8.8/mach/CORE/libperl.so...done. Loaded symbols for /usr/local/lib/perl5/5.8.8/mach/CORE/libperl.so Reading symbols from /lib/libm.so.5...done. Loaded symbols for /lib/libm.so.5 Reading symbols from /lib/libcrypt.so.4...done. Loaded symbols for /lib/libcrypt.so.4 Reading symbols from /lib/libutil.so.7...done. Loaded symbols for /lib/libutil.so.7 Reading symbols from /lib/libc.so.7...done. Loaded symbols for /lib/libc.so.7 Reading symbols from /usr/local/lib/perl5/site_perl/5.8.8/mach/Devel/auto/Devel/NYTProf/NYTProf.so...done. Loaded symbols for //usr/local/lib/perl5/site_perl/5.8.8/mach/Devel/auto/Devel/NYTProf/NYTProf.so Reading symbols from /usr/lib/librt.so.1...done. Loaded symbols for /usr/lib/librt.so.1 Reading symbols from /lib/libz.so.4...done. Loaded symbols for /lib/libz.so.4 Reading symbols from /usr/local/lib/perl5/5.8.8/mach/auto/List/Util/Util.so...done. Loaded symbols for /usr/local/lib/perl5/5.8.8/mach/auto/List/Util/Util.so Reading symbols from /usr/local/lib/perl5/site_perl/5.8.8/mach/auto/B/Hooks/OP/Check/Check.so...done. Loaded symbols for //usr/local/lib/perl5/site_perl/5.8.8/mach/auto/B/Hooks/OP/Check/Check.so Reading symbols from /usr/local/lib/perl5/site_perl/5.8.8/mach/auto/Devel/Declare/Declare.so...done. Loaded symbols for //usr/local/lib/perl5/site_perl/5.8.8/mach/auto/Devel/Declare/Declare.so Reading symbols from /usr/local/lib/perl5/site_perl/5.8.8/mach/auto/DBI/DBI.so...done. Loaded symbols for /usr/local/lib/perl5/site_perl/5.8.8/mach/auto/DBI/DBI.so Reading symbols from /usr/local/lib/perl5/site_perl/5.8.8/mach/auto/Scope/Upper/Upper.so...done. Loaded symbols for //usr/local/lib/perl5/site_perl/5.8.8/mach/auto/Scope/Upper/Upper.so Reading symbols from /usr/local/lib/perl5/5.8.8/mach/auto/Time/HiRes/HiRes.so...done. Loaded symbols for /usr/local/lib/perl5/5.8.8/mach/auto/Time/HiRes/HiRes.so Reading symbols from /usr/local/lib/perl5/5.8.8/mach/auto/Encode/Encode.so...done. Loaded symbols for /usr/local/lib/perl5/5.8.8/mach/auto/Encode/Encode.so Reading symbols from /usr/local/lib/perl5/5.8.8/mach/auto/Fcntl/Fcntl.so...done. Loaded symbols for /usr/local/lib/perl5/5.8.8/mach/auto/Fcntl/Fcntl.so Reading symbols from /usr/local/lib/perl5/5.8.8/mach/auto/Storable/Storable.so...done. Loaded symbols for /usr/local/lib/perl5/5.8.8/mach/auto/Storable/Storable.so Reading symbols from /usr/local/lib/perl5/site_perl/5.8.8/mach/auto/Cache/Memcached/Fast/Fast.so...done. Loaded symbols for //usr/local/lib/perl5/site_perl/5.8.8/mach/auto/Cache/Memcached/Fast/Fast.so Reading symbols from /usr/local/lib/perl5/site_perl/5.8.8/mach/auto/Data/Dumper/Dumper.so...done. Loaded symbols for //usr/local/lib/perl5/site_perl/5.8.8/mach/auto/Data/Dumper/Dumper.so Reading symbols from /usr/local/lib/perl5/site_perl/5.8.8/mach/auto/Unix/Syslog/Syslog.so...done. Loaded symbols for //usr/local/lib/perl5/site_perl/5.8.8/mach/auto/Unix/Syslog/Syslog.so Reading symbols from /usr/local/lib/perl5/site_perl/5.8.8/mach/auto/List/MoreUtils/MoreUtils.so...done. Loaded symbols for //usr/local/lib/perl5/site_perl/5.8.8/mach/auto/List/MoreUtils/MoreUtils.so Reading symbols from /usr/local/lib/perl5/5.8.8/mach/auto/MIME/Base64/Base64.so...done. Loaded symbols for //usr/local/lib/perl5/5.8.8/mach/auto/MIME/Base64/Base64.so Reading symbols from /usr/local/lib/perl5/site_perl/5.8.8/mach/auto/Digest/SHA/SHA.so...done. Loaded symbols for //usr/local/lib/perl5/site_perl/5.8.8/mach/auto/Digest/SHA/SHA.so Reading symbols from /usr/local/lib/perl5/site_perl/5.8.8/mach/auto/IO/KQueue/KQueue.so...done. Loaded symbols for //usr/local/lib/perl5/site_perl/5.8.8/mach/auto/IO/KQueue/KQueue.so Reading symbols from /usr/local/lib/perl5/site_perl/5.8.8/mach/auto/Heap/Fibonacci/Fast/Fast.so...done. Loaded symbols for //usr/local/lib/perl5/site_perl/5.8.8/mach/auto/Heap/Fibonacci/Fast/Fast.so Reading symbols from /usr/local/lib/perl5/5.8.8/mach/auto/POSIX/POSIX.so...done. Loaded symbols for /usr/local/lib/perl5/5.8.8/mach/auto/POSIX/POSIX.so Reading symbols from /usr/local/lib/perl5/5.8.8/mach/auto/IO/IO.so...done. Loaded symbols for /usr/local/lib/perl5/5.8.8/mach/auto/IO/IO.so Reading symbols from /usr/local/lib/perl5/5.8.8/mach/auto/Socket/Socket.so...done. Loaded symbols for /usr/local/lib/perl5/5.8.8/mach/auto/Socket/Socket.so Reading symbols from /usr/local/lib/perl5/site_perl/5.8.8/mach/auto/Math/Random/ISAAC/XS/XS.so...done. Loaded symbols for //usr/local/lib/perl5/site_perl/5.8.8/mach/auto/Math/Random/ISAAC/XS/XS.so Reading symbols from /usr/local/lib/perl5/5.8.8/mach/auto/Digest/MD5/MD5.so...done. Loaded symbols for /usr/local/lib/perl5/5.8.8/mach/auto/Digest/MD5/MD5.so Reading symbols from /usr/local/lib/perl5/5.8.8/mach/auto/File/Glob/Glob.so...done. Loaded symbols for /usr/local/lib/perl5/5.8.8/mach/auto/File/Glob/Glob.so Reading symbols from /usr/local/lib/perl5/site_perl/5.8.8/mach/auto/Compress/Raw/Zlib/Zlib.so...done. Loaded symbols for //usr/local/lib/perl5/site_perl/5.8.8/mach/auto/Compress/Raw/Zlib/Zlib.so Reading symbols from /usr/local/lib/perl5/site_perl/5.8.8/mach/auto/version/vxs/vxs.so...done. Loaded symbols for //usr/local/lib/perl5/site_perl/5.8.8/mach/auto/version/vxs/vxs.so Reading symbols from /usr/local/lib/perl5/site_perl/5.8.8/mach/auto/DBD/Pg/Pg.so...done. Loaded symbols for //usr/local/lib/perl5/site_perl/5.8.8/mach/auto/DBD/Pg/Pg.so Reading symbols from /usr/local/pgsql/lib/libpq.so.5...done. Loaded symbols for /usr/local/pgsql/lib/libpq.so.5 Reading symbols from /usr/lib/libssl.so.5...done. Loaded symbols for /usr/lib/libssl.so.5 Reading symbols from /lib/libcrypto.so.5...done. Loaded symbols for /lib/libcrypto.so.5 Reading symbols from /libexec/ld-elf.so.1...done. Loaded symbols for /libexec/ld-elf.so.1 #0 0x2832a9bf in pp_entersub_profiler () at NYTProf.xs:2253 2253 NYTProf.xs: No such file or directory. in NYTProf.xs (gdb) bt full #0 0x2832a9bf in pp_entersub_profiler () at NYTProf.xs:2253 line = 132 fid_line_key = "\026(\204\023R\b\005\000\000\000`óF\t_Ã\024(\001\000\000\000\000\000\000\000\024\000\000\000\f\023R\bôì¿\177ô\207\036(¸ê¿\177\f\237\021(" file = 0x8e27148 "Game/Quests/Executor.pm" subname_sv = (SV *) 0x9481e20 subname_pv = 0x94823f0 ",$H\t" stash_name = 0x0 cv = (CV *) 0x1 is_xs = 0 saved_errno = 35 fid = 139589652 fid_line_key_len = 155689156 sv_tmp = (SV *) 0x1 op = (OP *) 0x8547848 prev_cop = (COP *) 0x8ed3888 next_op = (OP *) 0x8ed32c8 sp = (SV **) 0x851f818 sub_sv = (SV *) 0x8e28260 sub_call_start = {sub_call_time = {tv_sec = 3016320, tv_nsec = 290151516}, fid_line = "\020\037ë\b\003", '\0' <repeats 15 times>, "Ñï\2216$pH\t\000\000\000\000Xë¿\177Ç\201\022(ð#H\t\234Ðì\b\000", subname_sv = 0x3691efd1, sub_av = 0x8106008, sub_cv = 0x1, call_depth = 915533777, current_overhead_ticks = 0, current_subr_secs = 26.10449370000002} profile_sub_call = 1 #1 0x28109ecf in Perl_runops_debug () at dump.c:1459 No locals. #2 0x280a11f8 in S_run_body (oldscope=1) at perl.c:2366 No locals. #3 0x280a0c7a in perl_run (my_perl=0x28401100) at perl.c:2283 oldscope = 1 ret = 0 cur_env = {je_prev = 0x281ea640, je_buf = {{_sjb = {671747094, 673089524, 2143284204, 2143284328, 2143284468, 0, 4735, 671576576, 134527328, 2143284468, 0, 0}}}, je_ret = 0, je_mustcatch = 0 '\0'} #4 0x08049143 in main (argc=3, argv=0x7fbfece4, env=0x7fbfecf4) at #perlmain.c:99 exitstatus = 0 (gdb)
Profiling options were: PERL5OPT=-d:NYTProf NYTPROF='start=init:file=/tmp/nytprof.out:addpid=1:subs=1:stmts=0'
Realistically I'm going to need a small test case. Try running the Scope::Upper test suite with these env vars set: PERL5OPTS=-d:NYTProf NYTPROF=file=/tmp/nytprof.out:addpid=1 (meanwhile I'll mark this ticket as stalled) Good luck!
% perl -Ilib -T -d:NYTProf 85-stress-unwind.t >/dev/null 2>&1 zsh: segmentation fault (core dumped) perl -Ilib -T -d:NYTProf 85-stress-unwind.t > /dev/null 2>&1 #0 0x2812af09 in Perl_pp_leavesub () at pp_hot.c:2414 2414 pp_hot.c: No such file or directory. in pp_hot.c (gdb) bt full #0 0x2812af09 in Perl_pp_leavesub () at pp_hot.c:2414 sp = (SV **) 0x8107818 mark = (SV **) 0x810781c newsp = (SV **) 0x8107818 newpm = (PMOP *) 0x0 gimme = 1 cx = (PERL_CONTEXT *) 0x81081ac sv = (SV *) 0x1 #1 0x2832f215 in pp_leaving_profiler () at NYTProf.xs:2409 op = (OP *) 0x8107818 #2 0x28109ecf in Perl_runops_debug () at dump.c:1459 No locals. #3 0x280a11bf in S_run_body (oldscope=1) at perl.c:2361 No locals. #4 0x280a0c7a in perl_run (my_perl=0x28401100) at perl.c:2283 oldscope = 1 ret = 3 cur_env = {je_prev = 0x281ea640, je_buf = {{_sjb = {671747094, 673089524, 2143284236, 2143284360, 2143284504, 0, 4735, 671576576, 134527328, 2143284504, 0, 0}}}, je_ret = 3, je_mustcatch = 0 '\0'} #5 0x08049143 in main (argc=5, argv=0x7fbfed00, env=0x7fbfed18) at perlmain.c:99 exitstatus = 0 But this seems as another issue for me (may be there lurking many?). I'm still trying to reproduce exact case.
Another issue (not segfault, but still stops program execution): #!/usr/bin/perl use strict; use Scope::Upper qw(unwind HERE); my $scope; sub z{ unwind(2, $scope); print "not reached\n"; } sub x{ $scope = HERE; z(); } print 1; print x(); print 3; Without debug, it prints '123' as expected. But under -d:NYTProf it complains about Can't use string ("2") as a subroutine ref while "strict refs" in use at test13.pl line 7. Probably, this is source for segfaulting in complex cases.
Subject: Re: [rt.cpan.org #50634] Segfault when used with Scope::Upper
Date: Sun, 25 Oct 2009 10:03:38 +0100
To: Sergey Aleynikov via RT <bug-devel-nytprof [...] rt.cpan.org>
From: Tim Bunce <Tim.Bunce [...] pobox.com>
Thanks. Can you retry both with Devel::NYTProf 2.10_93 from cpan (ignore any 'make test' failures) Tim.
% perl -e 'use Devel::NYTProf; print $Devel::NYTProf::VERSION' 2.11 Same errors in both cases, backtrace for coredump in 85-stress-unwind.t: (gdb) bt full #0 0x2812af09 in Perl_pp_leavesub () at pp_hot.c:2414 sp = (SV **) 0x8107818 mark = (SV **) 0x810781c newsp = (SV **) 0x8107818 newpm = (PMOP *) 0x0 gimme = 1 cx = (PERL_CONTEXT *) 0x81081ac sv = (SV *) 0x1 #1 0x28330355 in pp_leave_profiler () at NYTProf.xs:2834 op = (OP *) 0x8107818 (gdb) up #1 0x28330355 in pp_leave_profiler () at NYTProf.xs:2834 2834 OP *op = run_original_op(PL_op->op_type); (gdb) print *PL_op $2 = {op_next = 0x0, op_sibling = 0x0, op_ppaddr = 0x28330320 <pp_leave_profiler>, op_targ = 2, op_type = 167, op_seq = 22827, op_flags = 4 '\004', op_private = 65 'A'}
No great progress yet, but I can give you a partial workaround: NTPROF=subs=0:leave=0 That disables the subroutine profiler and the special handling of leave operations. Realistically I'm not going to have much time to dig into this without help from someone who knows how the internals of Scope::Upper work.
subs=0:leave=0 helps, but, sadly, i'm interested in subs time only. Leave=0 without subs=0 segfaults everything immidiatelly - they must be used together only? Not mentioned in docs. I'd be happy measuring only subs time, without statements and related. Can you point out what parts of NYTProf are used in hooking pp_leave/pp_entersub? As i have 2 choices - try to fix or maintain 2 code versions, with and without unwind() calls.
Subject: Re: [rt.cpan.org #50634] Segfault when used with Scope::Upper
Date: Tue, 27 Oct 2009 09:22:51 +0000
To: Sergey Aleynikov via RT <bug-devel-nytprof [...] rt.cpan.org>
From: Tim Bunce <Tim.Bunce [...] pobox.com>
Show quoted text
> subs=0:leave=0 helps, but, sadly, i'm interested in subs time only. > Leave=0 without subs=0 segfaults everything immidiatelly - they must be > used together only? Not mentioned in docs. I'd be happy measuring only > subs time, without statements and related.
subs=0 turns off the subroutine profiler (leaving the statement profiler running) and leave=0 disables part of the statement profiler. Show quoted text
> Can you point out what parts of NYTProf are used in hooking > pp_leave/pp_entersub?
If I need to point them out then you're unlikely to be able to make much use of the information. http://code.google.com/p/perl-devel-nytprof/source/browse/trunk/NYTProf.xs pp_leave isn't hooked when leave=0 is used, so you can ignore that. Show quoted text
> As i have 2 choices - try to fix or maintain 2 code versions, with and > without unwind() calls.
Or use the subroutine timings generated by the statement profiler. Look in the file listing on the main index page of the report and you'll see a column that has links for "line . block . subs". Click on subs. It's basic but still useful. Or use another profiler. Tim.
Please retry. I think this is fixed in the repository now.
Now I come to actually test it I see it still has problems. Reopened.
Fixed, finally! Try with r908