missing init in perl-clone-using for -Dusethreads -DPERL_TRACE_OPS build

[p5pRT]

Migrated from rt.perl.org#124267 (status was 'open')

Searchable as RT124267$

[p5pRT]

From @jimc

Created by @jimc

perl-clone-using is missing initialzation of PL_op_exec_cnt\, so subthreads cause perl-destruct to spew stuff like this...

Trace of all OPs executed​:   null​: 12370169555311111333   stub​: 12370169555311111086   scalar​: 12370169555311111083   pushmark​: 12370169555311135659   wantarray​: 12370169555311111289   const​: 12370169555311157759   gvsv​: 12370169555311122860   gv​: 12370169555311127042   gelem​: 12370169555311111083   padsv​: 12370169555311256467   padav​: 12370169555311117256   padhv​: 12370169555311111174   padany​: 12370169555311111083   ...

Many of the numbers convert to ABABABAB in hex\, a clear mem-poison value.

I have a patch\, will attach with ticket #

Perl Info

``` Flags: category=core severity=low Site configuration information for perl 5.21.11: Configured by jimc at Fri Apr 3 15:10:58 MDT 2015. Summary of my perl5 (revision 5 version 21 subversion 11) configuration: Commit id: c9383a794bc7e8a7016d41018dbedbd0be10b83d Platform: osname=linux, osvers=3.14.27-100.fc19.x86_64, archname=x86_64-linux-thread-multi uname='linux groucho.jimc.earth 3.14.27-100.fc19.x86_64 #1 smp wed dec 17 19:36:34 utc 2014 x86_64 x86_64 x86_64 gnulinux ' config_args='-des -Dusedevel -Dusethreads -DDEBUGGING -Accflags= -DPERL_OP_PARENT -DPERL_TRACE_OPS_EXT -DPERL_TRACE_OPS' hint=recommended, useposix=true, d_sigaction=define useithreads=define, usemultiplicity=define use64bitint=define, use64bitall=define, uselongdouble=undef usemymalloc=n, bincompat5005=undef Compiler: cc='cc', ccflags ='-D_REENTRANT -D_GNU_SOURCE -DPERL_OP_PARENT -DPERL_TRACE_OPS_EXT -DPERL_TRACE_OPS -fwrapv -DDEBUGGING -fno-strict-aliasing -pipe -fstack-protector-strong -I/usr/local/include -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 -D_FORTIFY_SOURCE=2', optimize='-O2 -g', cppflags='-D_REENTRANT -D_GNU_SOURCE -DPERL_OP_PARENT -DPERL_TRACE_OPS_EXT -DPERL_TRACE_OPS -fwrapv -DDEBUGGING -fno-strict-aliasing -pipe -fstack-protector-strong -I/usr/local/include' ccversion='', gccversion='4.8.3 20140911 (Red Hat 4.8.3-7)', gccosandvers='' intsize=4, longsize=8, ptrsize=8, doublesize=8, byteorder=12345678, doublekind=3 d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=16, longdblkind=3 ivtype='long', ivsize=8, nvtype='double', nvsize=8, Off_t='off_t', lseeksize=8 alignbytes=8, prototype=define Linker and Libraries: ld='cc', ldflags =' -fstack-protector-strong -L/usr/local/lib' libpth=/usr/local/lib /usr/lib /lib/../lib64 /usr/lib/../lib64 /lib /lib64 /usr/lib64 /usr/local/lib64 libs=-lpthread -lnsl -lgdbm -ldb -ldl -lm -lcrypt -lutil -lc -lgdbm_compat perllibs=-lpthread -lnsl -ldl -lm -lcrypt -lutil -lc libc=libc-2.17.so, so=so, useshrplib=false, libperl=libperl.a gnulibc_version='2.17' Dynamic Linking: dlsrc=dl_dlopen.xs, dlext=so, d_dlsymun=undef, ccdlflags='-Wl,-E' cccdlflags='-fPIC', lddlflags='-shared -O2 -g -L/usr/local/lib -fstack-protector-strong' @INC for perl 5.21.11: /usr/local/lib/perl5/site_perl/5.21.11/x86_64-linux-thread-multi /usr/local/lib/perl5/site_perl/5.21.11 /usr/local/lib/perl5/5.21.11/x86_64-linux-thread-multi /usr/local/lib/perl5/5.21.11 /usr/local/lib/perl5/site_perl . Environment for perl 5.21.11: HOME=/home/jimc LANG=en_US.UTF-8 LANGUAGE (unset) LD_LIBRARY_PATH=/usr/lib64/mpich/lib:/usr/lib64/alliance/lib:/usr/lib64/alliance/lib LOGDIR (unset) PATH=/usr/lib64/qt-3.3/bin:/usr/lib64/mpich/bin:/usr/lib64/ccache:/usr/local/bin:/usr/bin:/bin:/usr/local/sbin:/usr/sbin:/usr/lib64/alliance/bin:/usr/libexec/sdcc:/home/jimc/bin:./bin:.:/home/jimc/.local/bin:/home/jimc/bin:/usr/lib64/alliance/bin:/usr/libexec/sdcc:/home/jimc/bin:./bin:. PERL_BADLANG (unset) SHELL=/bin/bash ```

[p5pRT]

From @jimc

4 patches actually

1. the bug fix\, add Zero to perl-clone-using\, to silence ABAB... count errors 2. harmless\, helpful\, not necessary 3. noticed while doing next 4. probably wants discussion

On Wed\, Apr 8\, 2015 at 5​:49 PM\, Jim Cromie \perlbug\-followup@​perl\.org wrote​:

# New Ticket Created by Jim Cromie # Please include the string​: [perl #124267] # in the subject line of all future correspondence about this issue. # \<URL​: https://rt-archive.perl.org/perl5/Ticket/Display.html?id=124267 >

Reply-To​: jim.cromie@​gmail.com From​: jim.cromie@​gmail.com Cc​: jim.cromie@​gmail.com Subject​: perl-clone-using missing Zero\, seen in -DPERL_TRACE_OPS -Dusethreads builds To​: perlbug@​perl.org Message-Id​: \5\.21\.11\_4278\_1428343855@&#8203;groucho\.jimc\.earth

This is a bug report for perl from jim.cromie@​gmail.com\, generated with the help of perlbug 1.40 running under perl 5.21.11.

----------------------------------------------------------------- [Please describe your issue here]

perl-clone-using is missing initialzation of PL_op_exec_cnt\, so subthreads cause perl-destruct to spew stuff like this...

Trace of all OPs executed​: null​: 12370169555311111333 stub​: 12370169555311111086 scalar​: 12370169555311111083 pushmark​: 12370169555311135659 wantarray​: 12370169555311111289 const​: 12370169555311157759 gvsv​: 12370169555311122860 gv​: 12370169555311127042 gelem​: 12370169555311111083 padsv​: 12370169555311256467 padav​: 12370169555311117256 padhv​: 12370169555311111174 padany​: 12370169555311111083 ...

Many of the numbers convert to ABABABAB in hex\, a clear mem-poison value.

I have a patch\, will attach with ticket #

[Please do not change anything below this line] ----------------------------------------------------------------- --- Flags​: category=core severity=low --- Site configuration information for perl 5.21.11​:

Configured by jimc at Fri Apr 3 15​:10​:58 MDT 2015.

Summary of my perl5 (revision 5 version 21 subversion 11) configuration​: Commit id​: c9383a794bc7e8a7016d41018dbedbd0be10b83d Platform​: osname=linux\, osvers=3.14.27-100.fc19.x86_64\, archname=x86_64-linux-thread-multi uname='linux groucho.jimc.earth 3.14.27-100.fc19.x86_64 #1 smp wed dec 17 19​:36​:34 utc 2014 x86_64 x86_64 x86_64 gnulinux ' config_args='-des -Dusedevel -Dusethreads -DDEBUGGING -Accflags= -DPERL_OP_PARENT -DPERL_TRACE_OPS_EXT -DPERL_TRACE_OPS' hint=recommended\, useposix=true\, d_sigaction=define useithreads=define\, usemultiplicity=define use64bitint=define\, use64bitall=define\, uselongdouble=undef usemymalloc=n\, bincompat5005=undef Compiler​: cc='cc'\, ccflags ='-D_REENTRANT -D_GNU_SOURCE -DPERL_OP_PARENT -DPERL_TRACE_OPS_EXT -DPERL_TRACE_OPS -fwrapv -DDEBUGGING -fno-strict-aliasing -pipe -fstack-protector-strong -I/usr/local/include -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 -D_FORTIFY_SOURCE=2'\, optimize='-O2 -g'\, cppflags='-D_REENTRANT -D_GNU_SOURCE -DPERL_OP_PARENT -DPERL_TRACE_OPS_EXT -DPERL_TRACE_OPS -fwrapv -DDEBUGGING -fno-strict-aliasing -pipe -fstack-protector-strong -I/usr/local/include' ccversion=''\, gccversion='4.8.3 20140911 (Red Hat 4.8.3-7)'\, gccosandvers='' intsize=4\, longsize=8\, ptrsize=8\, doublesize=8\, byteorder=12345678\, doublekind=3 d_longlong=define\, longlongsize=8\, d_longdbl=define\, longdblsize=16\, longdblkind=3 ivtype='long'\, ivsize=8\, nvtype='double'\, nvsize=8\, Off_t='off_t'\, lseeksize=8 alignbytes=8\, prototype=define Linker and Libraries​: ld='cc'\, ldflags =' -fstack-protector-strong -L/usr/local/lib' libpth=/usr/local/lib /usr/lib /lib/../lib64 /usr/lib/../lib64 /lib /lib64 /usr/lib64 /usr/local/lib64 libs=-lpthread -lnsl -lgdbm -ldb -ldl -lm -lcrypt -lutil -lc -lgdbm_compat perllibs=-lpthread -lnsl -ldl -lm -lcrypt -lutil -lc libc=libc-2.17.so\, so=so\, useshrplib=false\, libperl=libperl.a gnulibc_version='2.17' Dynamic Linking​: dlsrc=dl_dlopen.xs\, dlext=so\, d_dlsymun=undef\, ccdlflags='-Wl\,-E' cccdlflags='-fPIC'\, lddlflags='-shared -O2 -g -L/usr/local/lib -fstack-protector-strong'

--- @​INC for perl 5.21.11​: /usr/local/lib/perl5/site_perl/5.21.11/x86_64-linux-thread-multi /usr/local/lib/perl5/site_perl/5.21.11 /usr/local/lib/perl5/5.21.11/x86_64-linux-thread-multi /usr/local/lib/perl5/5.21.11 /usr/local/lib/perl5/site_perl .

--- Environment for perl 5.21.11​: HOME=/home/jimc LANG=en_US.UTF-8 LANGUAGE (unset)

LD_LIBRARY_PATH=/usr/lib64/mpich/lib​:/usr/lib64/alliance/lib​:/usr/lib64/alliance/lib LOGDIR (unset)

PATH=/usr/lib64/qt-3.3/bin​:/usr/lib64/mpich/bin​:/usr/lib64/ccache​:/usr/local/bin​:/usr/bin​:/bin​:/usr/local/sbin​:/usr/sbin​:/usr/lib64/alliance/bin​:/usr/libexec/sdcc​:/home/jimc/bin​:./bin​:.​:/home/jimc/.local/bin​:/home/jimc/bin​:/usr/lib64/alliance/bin​:/usr/libexec/sdcc​:/home/jimc/bin​:./bin​:. PERL_BADLANG (unset) SHELL=/bin/bash

[p5pRT]

From @jimc

0001-perl_clone_using-Zero-DPERL_TRACE_OPS-mem-for-sub-th.patch

```diff From 7cc2387a93b1bf0c19639e1419b427bb99052953 Mon Sep 17 00:00:00 2001 From: Jim Cromie Date: Wed, 3 Dec 2014 10:34:36 -0700 Subject: [PATCH 1/6] perl_clone_using: Zero -DPERL_TRACE_OPS mem for sub-threads perl_clone_using() is missing Zero init of PL_op_exec_cnt[]. This causes sub-threads in threaded -DPERL_TRACE_OPS builds to spew exceedingly large op-counts at destruct. These counts would print %x as "ABABABAB", clearly a mem-poison value. --- sv.c | 3 +++ 1 file changed, 3 insertions(+) diff --git a/sv.c b/sv.c index 467dc24..9584e31 100644 --- a/sv.c +++ b/sv.c @@ -14448,6 +14448,9 @@ perl_clone_using(PerlInterpreter *proto_perl, UV flags, # ifdef DEBUG_LEAKING_SCALARS PL_sv_serial = (((UV)my_perl >> 2) & 0xfff) * 1000000; # endif +# ifdef PERL_TRACE_OPS + Zero(PL_op_exec_cnt, OP_max+2, UV); +# endif #else /* !DEBUGGING */ Zero(my_perl, 1, PerlInterpreter); #endif /* DEBUGGING */ -- 1.8.3.1 ```

[p5pRT]

From @jimc

0002-intrpvar.h-add-error-on-DPERL_TRACE_OPS-w-o-DDEBUGGI.patch

```diff From d852bbc04f906bb9ce4d29d33edb2bb83715cdda Mon Sep 17 00:00:00 2001 From: Jim Cromie Date: Thu, 11 Dec 2014 12:34:51 -0700 Subject: [PATCH 2/6] intrpvar.h: add #error on -DPERL_TRACE_OPS w/o -DDEBUGGING While its possible to compile a -DPERL_TRACE_OPS build w/o -DDEBUGGING, theres no point in doing so; the OP-counting is done only in Perl_runops_debug, which is only used in -DDEBUGGING builds. --- intrpvar.h | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/intrpvar.h b/intrpvar.h index 86c3fd7..49175e3 100644 --- a/intrpvar.h +++ b/intrpvar.h @@ -785,12 +785,14 @@ PERLVARI(I, sv_serial, U32, 0) /* SV serial number, used in sv.c */ PERLVARA(I, sv_consts, SV_CONSTS_COUNT, SV*) /* constant SVs with precomputed hash value */ #ifdef PERL_TRACE_OPS +#ifndef DEBUGGING +#error "-DPERL_TRACE_OPS needs -DDEBUGGING to work" +#endif PERLVARA(I, op_exec_cnt, OP_max+2, UV) /* Counts of executed OPs of the given type. If PERL_TRACE_OPS is enabled, we'll dump a summary count of all ops executed in the - program at perl_destruct time. For - profiling/debugging only. Works only if - DEBUGGING is enabled, too. */ + program at perl_destruct time. + For profiling/debugging only. */ #endif PERLVAR(I, random_state, PL_RANDOM_STATE_TYPE) -- 1.8.3.1 ```

[p5pRT]

From @jimc

0003-fix-XXX-on-DEBUG_TOP_FLAG-comment.patch

```diff From 52e0cf78ffa39b31dac01b062f551dbc9f2802cd Mon Sep 17 00:00:00 2001 From: Jim Cromie Date: Sat, 4 Apr 2015 12:49:27 -0600 Subject: [PATCH 3/6] fix XXX on DEBUG_TOP_FLAG comment DEBUG_TOP_FLAG is ORd into PL_debug when -D option is used, so that "if (PL_debug)" can be used, w/o also enabling (or requiring) any specific DEBUG_(.)_FLAGs. It is used in Perl_runops_debug to short-circuit several DEBUG_(.)_TESTs. --- perl.h | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/perl.h b/perl.h index dcb184b..0f6f679 100644 --- a/perl.h +++ b/perl.h @@ -4007,8 +4007,7 @@ Gid_t getegid (void); #define DEBUG_MASK 0x07FFEFFF /* mask of all the standard flags */ #define DEBUG_DB_RECURSE_FLAG 0x40000000 -#define DEBUG_TOP_FLAG 0x80000000 /* XXX what's this for ??? Signal - that something was done? */ +#define DEBUG_TOP_FLAG 0x80000000 /* -D was given --> PL_debug |= FLAG */ # define DEBUG_p_TEST_ (PL_debug & DEBUG_p_FLAG) # define DEBUG_s_TEST_ (PL_debug & DEBUG_s_FLAG) -- 1.8.3.1 ```

[p5pRT]

From @jimc

0004-tweak-DPERL_TRACE_OPS-for-usability.patch

```diff From 8e9cd987cbaec7b817132af3429f20276454853d Mon Sep 17 00:00:00 2001 From: Jim Cromie Date: Mon, 24 Nov 2014 21:31:32 -0700 Subject: [PATCH 4/6] tweak -DPERL_TRACE_OPS for usability Currently with -DPERL_TRACE_OPS builds, PL_op_exec_cnt[] counts are always printed by perl_destruct(). Since this also affects miniperl, it causes make, make minitest, make test to all be exceedingly noisy, and failed ~120 tests, apparently due to unexpected output. Although such builds arent meant for production, we can still make them more usable by simple tweaks; 1- dont print 0 PL_op_exec_cnt[] counts in perl_destruct(). This cuts `make` output by ~40k lines of ": 0" output, and `./perl -D0 -e1` by ~395 lines. 2- in perl_destruct(), gate the printing with PL_debug. this suppresses all TRACE output unless -D is given (or -D0 -Dq -Dv) Using -D alone "if (PL_debug)" to enable printing is wierd, but the output is only present in -DPERL_TRACE_OPS builds (which is rare, and explicitly requested), and the output is much smaller[1], so is less distracting. Its open to debate, but on balance I think its a usability win. Notes: op-counting is still always done in a -DPERL_TRACE_OPS build, making it available for inspection, manipulation, and reset by XS code. Printed output has preceding '#:' to be TAP friendly and to convey JSON-ish name:value pairs, and is wrapped with '#{' and '#}' lines. This helps avoid tickling test harness failures. PERL_TRACE_OPS_INC() macro hides the #ifdeffery around bare PL_op_exec_cnt[foo]++ statements. I used it to redo count-by-optype, and add total-ops-executed count in OP_max+1 (ie "SPECIAL" slot). --- dump.c | 5 ++--- intrpvar.h | 3 +++ perl.c | 20 +++++++++++--------- 3 files changed, 16 insertions(+), 12 deletions(-) diff --git a/dump.c b/dump.c index 52d897f..3eb6f58 100644 --- a/dump.c +++ b/dump.c @@ -2207,9 +2207,8 @@ Perl_runops_debug(pTHX) DEBUG_l(Perl_deb(aTHX_ "Entering new RUNOPS level\n")); do { -#ifdef PERL_TRACE_OPS - ++PL_op_exec_cnt[PL_op->op_type]; -#endif + PERL_TRACE_OPS_INC(PL_op->op_type); /* count exec per optype */ + PERL_TRACE_OPS_INC(OP_max+1); /* total ops execd, in legacy SPECIAL */ if (PL_debug) { if (PL_watchaddr && (*PL_watchaddr != PL_watchok)) PerlIO_printf(Perl_debug_log, diff --git a/intrpvar.h b/intrpvar.h index 49175e3..8814f11 100644 --- a/intrpvar.h +++ b/intrpvar.h @@ -793,6 +793,9 @@ PERLVARA(I, op_exec_cnt, OP_max+2, UV) /* Counts of executed OPs of the given ty a summary count of all ops executed in the program at perl_destruct time. For profiling/debugging only. */ +# define PERL_TRACE_OPS_INC(ix) PL_op_exec_cnt[ix]++ +#else +# define PERL_TRACE_OPS_INC(ix) NOOP #endif PERLVAR(I, random_state, PL_RANDOM_STATE_TYPE) diff --git a/perl.c b/perl.c index 086645b..6b8b560 100644 --- a/perl.c +++ b/perl.c @@ -587,16 +587,18 @@ perl_destruct(pTHXx) my_fflush_all(); #ifdef PERL_TRACE_OPS - /* If we traced all Perl OP usage, report and clean up */ - PerlIO_printf(Perl_debug_log, "Trace of all OPs executed:\n"); - for (i = 0; i <= OP_max; ++i) { - PerlIO_printf(Perl_debug_log, " %s: %"UVuf"\n", PL_op_name[i], PL_op_exec_cnt[i]); - PL_op_exec_cnt[i] = 0; + if (PL_debug) { + /* If we traced all Perl OP usage, report and clean up */ + PerlIO_printf(Perl_debug_log, "#{ Trace of all OPs executed:\n"); + for (i = 0; i <= OP_max; ++i) + if (PL_op_exec_cnt[i]) + PerlIO_printf(Perl_debug_log, "#: %s: %"UVuf"\n", PL_op_name[i], PL_op_exec_cnt[i]); + + /* Utility slot for easily doing little tracing experiments in the runloop: */ + if (PL_op_exec_cnt[OP_max+1]) + PerlIO_printf(Perl_debug_log, "#: SPECIAL: %"UVuf"\n", PL_op_exec_cnt[OP_max+1]); + PerlIO_printf(Perl_debug_log, "#}\n"); } - /* Utility slot for easily doing little tracing experiments in the runloop: */ - if (PL_op_exec_cnt[OP_max+1] != 0) - PerlIO_printf(Perl_debug_log, " SPECIAL: %"UVuf"\n", PL_op_exec_cnt[OP_max+1]); - PerlIO_printf(Perl_debug_log, "\n"); #endif -- 1.8.3.1 ```

[p5pRT]

From @tonycoz

On Wed Apr 08 22​:47​:09 2015\, yoduh wrote​:

4 patches actually

1. the bug fix\, add Zero to perl-clone-using\, to silence ABAB... count errors

This one make sense.

2. harmless\, helpful\, not necessary

An alternative might be to add the op-counting to the regular run loop\, since it's only done when PERL_TRACE_OPS is defined it makes no performance difference to a standard build.

3. noticed while doing next

This is good.

4. probably wants discussion

If we allow counting in the standard loop this would need to be triggered by something else\, maybe an environment variable.

Tony

[p5pRT]

The RT System itself - Status changed from 'new' to 'open'

[p5pRT]

From @jimc

On Tue\, Apr 14\, 2015 at 9​:55 PM\, Tony Cook via RT \<perlbug-followup@​perl.org

wrote​:

On Wed Apr 08 22​:47​:09 2015\, yoduh wrote​:

4 patches actually

1. the bug fix\, add Zero to perl-clone-using\, to silence ABAB... count errors

This one make sense.

do you want to take the good parts now\, or wait for a fully cooked set ?

2. harmless\, helpful\, not necessary

An alternative might be to add the op-counting to the regular run loop\, since it's only done when PERL_TRACE_OPS is defined it makes no performance difference to a standard build.

In 75d476e24 Steffen chose to do it only in runops_debug\, I didnt see any reason to expand its scope. Basically\, the patch upgrades his DEBUGGING only comment to a compiler directive.

3. noticed while doing next

This is good.

4. probably wants discussion

If we allow counting in the standard loop this would need to be triggered by something else\, maybe an environment variable.

If we were to go that way\, the -D flag could trigger the same behavior\, but we'd have to at least silence the warning issued about recompiling with -DDEBUGGING. And Id prefer not to have 2 separate op-countings which should/have-to be kept in sync.

thanks Jim

Tony

--- via perlbug​: queue​: perl5 status​: new https://rt-archive.perl.org/perl5/Ticket/Display.html?id=124267

[p5pRT]

From @tonycoz

On Wed Apr 15 09​:19​:49 2015\, yoduh wrote​:

On Tue\, Apr 14\, 2015 at 9​:55 PM\, Tony Cook via RT \<perlbug-followup@​perl.org

wrote​:

On Wed Apr 08 22​:47​:09 2015\, yoduh wrote​:

4 patches actually

1. the bug fix\, add Zero to perl-clone-using\, to silence ABAB... count errors

This one make sense.

do you want to take the good parts now\, or wait for a fully cooked set ?

2. harmless\, helpful\, not necessary

An alternative might be to add the op-counting to the regular run loop\, since it's only done when PERL_TRACE_OPS is defined it makes no performance difference to a standard build.

In 75d476e24 Steffen chose to do it only in runops_debug\, I didnt see any reason to expand its scope. Basically\, the patch upgrades his DEBUGGING only comment to a compiler directive.

3. noticed while doing next

This is good.

4. probably wants discussion

If we allow counting in the standard loop this would need to be triggered by something else\, maybe an environment variable.

If we were to go that way\, the -D flag could trigger the same behavior\, but we'd have to at least silence the warning issued about recompiling with -DDEBUGGING. And Id prefer not to have 2 separate op-countings which should/have-to be kept in sync.

I applied the "good bits" as 440568ac3ea48995957904d59ba142ce1ae72d90 and 440568ac3ea48995957904d59ba142ce1ae72d90\, and thought I'd commented here.

As to the -D flag\, it is possible to use the debug run loop on a non-debugging perl - Devel​::Peek has a function that can switch back and forth​:

tony@​mars​:.../git/perl$ ./perl -Ilib -e 'print "Foo"' 2>&1 | grep print   sprintf​: 0   print​: 0 tony@​mars​:.../git/perl$ ./perl -Ilib -MDevel​::Peek -e 'BEGIN { runops_debug(1) } print "Foo"' 2>&1 | grep print   sprintf​: 0   print​: 1 tony@​mars​:.../git/perl$ ./perl -Ilib -V​:ccflags 2>/dev/null ccflags='-DPERL_TRACE_OPS -fwrapv -fno-strict-aliasing -pipe -fstack-protector -I/usr/local/include -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 -D_FORTIFY_SOURCE=2';

Tony

[p5pRT]

From @jimc

ok\, this revises the bits of my previous PERL_TRACE_OPS patchset which you declined last time.

- drops the #ifdeffery patch that would break Devel​::Peek - thanks for the example Tony.

1 - silence "\​: 0" lines. These provide no real info\, and on a non-DEBUG build are the only lines issued by the -DPERL_TRACE_OPS printing (since OP-counting is done by Perl_runops_debug). So this eliminates up to 5M lines of stderr\, wo any real cost.

make test still fails\, just "Trace of all OPs executed​:" is enough to trigger this.

2- suppress printing if $ENV{PERL_TRACE_OPS} == 0 based upon Tony's suggestion This is far cleaner than messing with -D flags as in 1st rev\, esp as -D is ignored unless -DDEUBGGING

with both patches\, (just 2nd really)\, this will pass​:   PERL_TRACE_OPS=0 make test

On Tue\, Jun 9\, 2015 at 7​:25 PM\, Tony Cook via RT \perlbug\-followup@&#8203;perl\.org wrote​:

An alternative might be to add the op-counting to the regular run loop\, since it's only done when PERL_TRACE_OPS is defined it makes no performance difference to a standard build.

given your Devel​::Peek usage below\, I think its best to leave runops-standard alone\, and let those who want TRACE_OPS counting get it your way. We dont need counting done 2x\, differently.

4. probably wants discussion

If we allow counting in the standard loop this would need to be triggered by something else\, maybe an environment variable.

[p5pRT]

From @jimc

0001-PERL_TRACE_OPS-drop-optype-0-output-lines.patch

```diff From 2306224df3113ef6c972f03b87285dec6a8316ea Mon Sep 17 00:00:00 2001 From: Jim Cromie Date: Tue, 30 Jun 2015 23:08:15 -0600 Subject: [PATCH 1/2] PERL_TRACE_OPS: drop ": 0" output lines. In -DPERL_TRACE_OPS builds, PL_op_exec_cnt[] counts are always printed by perl_destruct(). This causes make & make test to be exceedingly noisy; non-threaded and threaded builds print opcts 7k and 14k times respectively, each with ~450 optypes, ie worst case of 5M lines of stderr output. Further, non-debugging -DPERL_TRACE_OPS builds still dump opcts, all 0, cuz no counting was done (since Perl_runops_debug wasnt used). Since ": 0" lines provide no useful information, eliminate them to reduce stderr dramatically, and improve info density. Now `./perl -e 'print "foo"'` output becomes readably, usefully small: Trace of all OPs executed: pushmark: 1 gvsv: 1 nextstate: 1 enter: 1 leave: 1 print: 1 NOTE: this patch doesnt fix the ~122 make test failures against blead, but this seemed like low-hanging fruit, to be taken 1st. --- perl.c | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/perl.c b/perl.c index 303e1f2..7f9124a 100644 --- a/perl.c +++ b/perl.c @@ -590,8 +590,10 @@ perl_destruct(pTHXx) /* If we traced all Perl OP usage, report and clean up */ PerlIO_printf(Perl_debug_log, "Trace of all OPs executed:\n"); for (i = 0; i <= OP_max; ++i) { - PerlIO_printf(Perl_debug_log, " %s: %"UVuf"\n", PL_op_name[i], PL_op_exec_cnt[i]); - PL_op_exec_cnt[i] = 0; + if (PL_op_exec_cnt[i]) { + PerlIO_printf(Perl_debug_log, " %s: %"UVuf"\n", PL_op_name[i], PL_op_exec_cnt[i]); + PL_op_exec_cnt[i] = 0; + } } /* Utility slot for easily doing little tracing experiments in the runloop: */ if (PL_op_exec_cnt[OP_max+1] != 0) -- 2.1.0 ```

[p5pRT]

From @jimc

0002-PERL_TRACE_OPS-quiet-OP-count-printing-if-ENV-PERL_T.patch

```diff From 6e97a3faa0b5e55f177a50c69203b98fce5f4174 Mon Sep 17 00:00:00 2001 From: Jim Cromie Date: Wed, 1 Jul 2015 01:15:22 -0600 Subject: [PATCH 2/2] PERL_TRACE_OPS: quiet OP-count printing if $ENV{PERL_TRACE_OPS}==0 This patch checks $ENV{PERL_TRACE_OPS}==0, and skips PERL_TRACE_OPS printing if its true. With this, `PERL_TRACE_OPS=0 make test` will pass. It doesnt change the default -DPERL_TRACE_OPS behavior, so plain make test fails ~122 tests; just "Trace of all OPs executed:" is enough to cause this. Note also that this only silences the output, the runloop counting is still done with -DPERL_TRACE_OPS. So these counts are available to an XS module (say Devel::TraceOps), and at basically any phase of perl's compile/run. I chose gotos to clarify what felt too fiddly and opaque when written as a single if statement. This seems obvious and flexible in the face of ENVAR name and value bikeshedding. --- perl.c | 37 ++++++++++++++++++++++++++----------- 1 file changed, 26 insertions(+), 11 deletions(-) diff --git a/perl.c b/perl.c index 7f9124a..2279a64 100644 --- a/perl.c +++ b/perl.c @@ -584,21 +584,36 @@ perl_destruct(pTHXx) assert(PL_scopestack_ix == 0); /* Need to flush since END blocks can produce output */ + my_fflush_all(); #ifdef PERL_TRACE_OPS - /* If we traced all Perl OP usage, report and clean up */ - PerlIO_printf(Perl_debug_log, "Trace of all OPs executed:\n"); - for (i = 0; i <= OP_max; ++i) { - if (PL_op_exec_cnt[i]) { - PerlIO_printf(Perl_debug_log, " %s: %"UVuf"\n", PL_op_name[i], PL_op_exec_cnt[i]); - PL_op_exec_cnt[i] = 0; - } + /* dump OP-counts, unless $ENV{PERL_TRACE_OPS}=0 */ + { + const char * const ptoenv = PerlEnv_getenv("PERL_TRACE_OPS"); + UV uv = 1; + + if (!ptoenv) + goto dump; + if (!Perl_grok_atoUV(ptoenv, &uv, NULL)) + goto dump; + if (!uv) /* $ENV{PERL_TRACE_OPS}==0 */ + goto no_dump; + dump: + PerlIO_printf(Perl_debug_log, "Trace of all OPs executed:\n"); + for (i = 0; i <= OP_max; ++i) { + if (PL_op_exec_cnt[i]) { + PerlIO_printf(Perl_debug_log, " %s: %"UVuf"\n", PL_op_name[i], PL_op_exec_cnt[i]); + PL_op_exec_cnt[i] = 0; + } + } + /* Utility slot for easily doing little tracing experiments in the runloop: */ + if (PL_op_exec_cnt[OP_max+1] != 0) + PerlIO_printf(Perl_debug_log, " SPECIAL: %"UVuf"\n", PL_op_exec_cnt[OP_max+1]); + PerlIO_printf(Perl_debug_log, "\n"); + } - /* Utility slot for easily doing little tracing experiments in the runloop: */ - if (PL_op_exec_cnt[OP_max+1] != 0) - PerlIO_printf(Perl_debug_log, " SPECIAL: %"UVuf"\n", PL_op_exec_cnt[OP_max+1]); - PerlIO_printf(Perl_debug_log, "\n"); + no_dump: #endif -- 2.1.0 ```

[p5pRT]

From @jimc

it has been superceded by [perl #127880]

124267 missing init in perl-clone-using for -Dusethreads -DPERL_TRACE_OPS build open