From 7cc2387a93b1bf0c19639e1419b427bb99052953 Mon Sep 17 00:00:00 2001
From: Jim Cromie <jim.cromie@gmail.com>
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

From d852bbc04f906bb9ce4d29d33edb2bb83715cdda Mon Sep 17 00:00:00 2001
From: Jim Cromie <jim.cromie@gmail.com>
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

From 52e0cf78ffa39b31dac01b062f551dbc9f2802cd Mon Sep 17 00:00:00 2001
From: Jim Cromie <jim.cromie@gmail.com>
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

From 8e9cd987cbaec7b817132af3429f20276454853d Mon Sep 17 00:00:00 2001
From: Jim Cromie <jim.cromie@gmail.com>
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 "<optype>: 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

From 2306224df3113ef6c972f03b87285dec6a8316ea Mon Sep 17 00:00:00 2001
From: Jim Cromie <jim.cromie@gmail.com>
Date: Tue, 30 Jun 2015 23:08:15 -0600
Subject: [PATCH 1/2] PERL_TRACE_OPS: drop "<optype>: 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 "<optype>: 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

From 6e97a3faa0b5e55f177a50c69203b98fce5f4174 Mon Sep 17 00:00:00 2001
From: Jim Cromie <jim.cromie@gmail.com>
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