1 files changed, 55 insertions, 11 deletions

diff --git a/src/root.c b/src/root.c
index d7113c0..5b51009 100755
--- a/src/root.c
+++ b/src/root.c
@@ -549,15 +549,47 @@ Return value:
     Trace("First move beta cutoff rate was %5.3f percent.\n",
           ((n / d) * 100.0));
 #ifdef LAZY_EVAL
-    d = (double)ctx->sCounters.tree.u64LazyEvals;
-    d += (double)ctx->sCounters.tree.u64FullEvals;
-    d += (double)ctx->sCounters.tree.u64EvalHashHits;
-    d += 1;
-    ASSERT(d);
-    Trace("Eval percentages: (%5.2f hash, %5.2f lazy, %5.2f full)\n",
-          ((double)ctx->sCounters.tree.u64EvalHashHits / d) * 100.0,
-          ((double)ctx->sCounters.tree.u64LazyEvals / d) * 100.0,
-          ((double)ctx->sCounters.tree.u64FullEvals / d) * 100.0);
+    {
+        // u64CyclesSuperLazyExit/u64CyclesLazyExit/u64CyclesFullEvalExit
+        // are each the *total call cost* (entry to exit) of Eval()
+        // calls that left via that specific path -- mutually exclusive
+        // and summing to u64CyclesInEval, so dividing each by its own
+        // matching call count gives a real per-path average, and
+        // u64CyclesInEval / dRealTotal gives a real overall average --
+        // unlike averaging u64CyclesInEval (which used to only
+        // accumulate on the full-eval path) against the total call
+        // count across all three paths.
+        double dSuperLazy = (double)ctx->sCounters.tree.u64SuperLazyEvals;
+        double dLazy = (double)ctx->sCounters.tree.u64LazyEvals;
+        double dFull = (double)ctx->sCounters.tree.u64FullEvals;
+        double dRealTotal = dSuperLazy + dLazy + dFull;
+        d = dRealTotal + 1;
+        Trace("Eval exit breakdown: (%5.2f%% super lazy, %5.2f%% lazy, "
+              "%5.2f%% full)\n",
+              (dSuperLazy / d) * 100.0,
+              (dLazy / d) * 100.0,
+              (dFull / d) * 100.0);
+#ifdef EVAL_TIME
+        {
+            UINT64 u64SLCyc = ctx->sCounters.tree.u64CyclesSuperLazyExit;
+            UINT64 u64LCyc = ctx->sCounters.tree.u64CyclesLazyExit;
+            UINT64 u64FCyc = ctx->sCounters.tree.u64CyclesFullEvalExit;
+            UINT64 u64AllCyc = ctx->sCounters.tree.u64CyclesInEval;
+            Trace("Avg. cpu cycles in eval, by exit path:\n"
+                  "  super lazy: %8.1f  (%5.1f%% of total eval cycles)\n"
+                  "  lazy:       %8.1f  (%5.1f%% of total eval cycles)\n"
+                  "  full:       %8.1f  (%5.1f%% of total eval cycles)\n"
+                  "  overall:    %8.1f\n",
+                  (dSuperLazy ? (double)u64SLCyc / dSuperLazy : 0.0),
+                  (u64AllCyc ? 100.0 * (double)u64SLCyc / (double)u64AllCyc : 0.0),
+                  (dLazy ? (double)u64LCyc / dLazy : 0.0),
+                  (u64AllCyc ? 100.0 * (double)u64LCyc / (double)u64AllCyc : 0.0),
+                  (dFull ? (double)u64FCyc / dFull : 0.0),
+                  (u64AllCyc ? 100.0 * (double)u64FCyc / (double)u64AllCyc : 0.0),
+                  (dRealTotal ? (double)u64AllCyc / dRealTotal : 0.0));
+        }
+#endif
+    }
 #endif
     Trace("Extensions: (%u +, %u q+, %u 1mv, %u !kmvs, %u mult+, %u pawn\n"
           "             %u threat, %u zug, %u sing, %u endg, %u bm, %u recap)\n",
@@ -574,8 +606,6 @@ Return value:
           ctx->sCounters.extension.uBotvinnikMarkoff,
           ctx->sCounters.extension.uRecapture);
 #ifdef EVAL_TIME
-    n = (double)ctx->sCounters.tree.u64CyclesInEval;
-    Trace("Avg. cpu cycles in eval: %8.1f.\n", (n / d));
     {
         //
         // Per-term breakdown of the average above -- board_
@@ -631,9 +661,14 @@ Return value:
             UINT64 u64LazyDecision = ctx->sCounters.tree.u64CyclesEvalLazyDecision;
             UINT64 u64CKSD = ctx->sCounters.tree.u64CyclesEvalCountKingSafetyDefects;
             UINT64 u64Storm = ctx->sCounters.tree.u64CyclesEvalFileStormDefects;
+            UINT64 u64SuperLazy = ctx->sCounters.tree.u64CyclesEvalSuperLazy;
             UINT64 u64PreLazyRest = (u64PreLazyOther >= u64LazyDecision) ?
                 (u64PreLazyOther - u64LazyDecision) : 0;
+            u64PreLazyRest = (u64PreLazyRest >= u64SuperLazy) ?
+                (u64PreLazyRest - u64SuperLazy) : 0;
             Trace("    -- of which, pre-lazy breakdown --\n");
+            Trace("    super lazy check:                       %5.1f%%\n",
+                  (u64Total ? (100.0 * (double)u64SuperLazy / (double)u64Total) : 0.0));
             Trace("    material/passers/badtrades/bishoppairs: %5.1f%%\n",
                   (u64Total ? (100.0 * (double)u64PreLazyRest / (double)u64Total) : 0.0));
             Trace("    lazy gate + EstimatePositionalScore:    %5.1f%%  "
@@ -662,6 +697,15 @@ Return value:
     }
 #endif
 #endif
+    // Unconditional, build-flag-independent end-of-report marker. Every
+    // block above this point is gated behind some #ifdef (PERF_COUNTERS,
+    // LAZY_EVAL, EVAL_TIME, ...), so the exact shape/length of this
+    // report varies build to build -- a tool driving this engine over
+    // the xboard protocol (e.g. eval_tune/match_play.py) has no
+    // build-flag-independent way to know the report is fully drained
+    // before sending its next command otherwise. This line is always
+    // printed exactly once, always last, regardless of build profile.
+    Trace("ReportEnd\n");
 }