HPCC-16517 Continue refactoring the roxie stats

Signed-off-by: Gavin Halliday <gavin.halliday@lexisnexis.com>

common/thorhelper/roxiehelper.ipp

@@ -82,7 +82,7 @@ interface IRoxieContextLogger : extends IContextLogger
     virtual void CTXLOGaeva(IException *E, const char *file, unsigned line, const char *prefix, const char *format, va_list args) const = 0;
     virtual void CTXLOGl(LogItem *) const = 0;
     virtual bool isBlind() const = 0;
-    virtual const CRuntimeStatisticCollection &queryStats() const = 0;
+    virtual void gatherStats(CRuntimeStatisticCollection & merged) const = 0;
 };
 
 //===================================================================================

common/thorhelper/thorcommon.cpp

@@ -1728,6 +1728,17 @@ void ActivityTimeAccumulator::addStatistics(IStatisticGatherer & builder) const
     }
 }
 
+void ActivityTimeAccumulator::addStatistics(CRuntimeStatisticCollection & merged) const
+{
+    if (totalCycles)
+    {
+        merged.mergeStatistic(StWhenFirstRow, firstRow);
+        merged.mergeStatistic(StTimeElapsed, elapsed());
+        merged.mergeStatistic(StTimeTotalExecute, cycle_to_nanosec(totalCycles));
+        merged.mergeStatistic(StTimeFirstExecute, latency());
+    }
+}
+
 void ActivityTimeAccumulator::merge(const ActivityTimeAccumulator & other)
 {
     if (other.totalCycles)

common/thorhelper/thorcommon.hpp

@@ -203,6 +203,7 @@ public:
     inline cycle_t latencyCycles() const { return firstExitCycles-startCycles; }
 
     void addStatistics(IStatisticGatherer & builder) const;
+    void addStatistics(CRuntimeStatisticCollection & merged) const;
     void merge(const ActivityTimeAccumulator & other);
 
     void reset()

roxie/ccd/ccd.hpp

@@ -668,9 +668,9 @@ public:
     {
         stats.merge(from);
     }
-    virtual const CRuntimeStatisticCollection &queryStats() const
+    virtual void gatherStats(CRuntimeStatisticCollection & merged) const override
     {
-        return stats;
+        merged.merge(stats);
     }
 
     virtual unsigned queryTraceLevel() const
@@ -720,9 +720,9 @@ public:
     void putStats(unsigned subGraphId, unsigned actId, const CRuntimeStatisticCollection &stats) const;
     void flush();
     inline bool queryDebuggerActive() const { return debuggerActive; }
-    inline const CRuntimeStatisticCollection &queryStats() const
+    virtual void gatherStats(CRuntimeStatisticCollection & merged) const override
     {
-        return stats;
+        merged.merge(stats);
     }
     inline const char *queryWuid()
     {

roxie/ccd/ccdactivities.cpp

@@ -384,10 +384,16 @@ protected:
 
     ~CRoxieSlaveActivity()
     {
-        basefactory->mergeStats(logctx.queryStats());
         ::Release(basehelper);
     }
 
+    virtual void beforeDispose() override
+    {
+        CRuntimeStatisticCollection merged(allStatistics);
+        logctx.gatherStats(merged);
+        basefactory->mergeStats(merged);
+    }
+
 public:
     IMPLEMENT_IINTERFACE_USING(CInterfaceOf<IRoxieSlaveActivity>)
 

roxie/ccd/ccdcontext.cpp

@@ -1245,9 +1245,9 @@ public:
         logctx.mergeStats(from);
     }
 
-    virtual const CRuntimeStatisticCollection &queryStats() const
+    virtual void gatherStats(CRuntimeStatisticCollection & merged) const override
     {
-        return logctx.queryStats();
+        logctx.gatherStats(merged);
     }
 
     virtual void CTXLOGa(TracingCategory category, const char *prefix, const char *text) const
@@ -2450,7 +2450,7 @@ public:
         slaveLogCtx.putStatProcessed(subgraphId, activityId, _idx, _processed, _strands);
     }
 
-    virtual void mergeActivityStats(const CRuntimeStatisticCollection &fromStats, unsigned subgraphId, unsigned activityId, const ActivityTimeAccumulator &_totalCycles, cycle_t _localCycles) const
+    virtual void mergeActivityStats(const CRuntimeStatisticCollection &fromStats, unsigned subgraphId, unsigned activityId) const
     {
         const SlaveContextLogger &slaveLogCtx = static_cast<const SlaveContextLogger &>(logctx);
         slaveLogCtx.putStats(subgraphId, activityId, fromStats);
@@ -2823,7 +2823,7 @@ public:
         }
     }
 
-    virtual void mergeActivityStats(const CRuntimeStatisticCollection &fromStats, unsigned subgraphId, unsigned activityId, const ActivityTimeAccumulator &_totalCycles, cycle_t _localCycles) const
+    virtual void mergeActivityStats(const CRuntimeStatisticCollection &fromStats, unsigned subgraphId, unsigned activityId) const
     {
         if (graphStats)
         {
@@ -2831,9 +2831,6 @@ public:
             IStatisticGatherer & builder = graphStats->queryStatsBuilder();
             StatsSubgraphScope graphScope(builder, subgraphId);
             StatsActivityScope scope(builder, activityId);
-            _totalCycles.addStatistics(builder);
-            if (_localCycles)
-                builder.addStatistic(StTimeLocalExecute, cycle_to_nanosec(_localCycles));
             fromStats.recordStatistics(builder);
         }
         logctx.mergeStats(fromStats);
@@ -2987,7 +2984,9 @@ public:
             addTimeStamp(w, SSTglobal, NULL, StWhenQueryFinished);
             updateWorkunitTimings(w, myTimer);
             Owned<IStatisticGatherer> gatherer = createGlobalStatisticGatherer(w);
-            logctx.queryStats().recordStatistics(*gatherer);
+            CRuntimeStatisticCollection merged(allStatistics);
+            logctx.gatherStats(merged);
+            merged.recordStatistics(*gatherer);
 
             WuStatisticTarget statsTarget(w, "roxie");
             rowManager->reportPeakStatistics(statsTarget, 0);

roxie/ccd/ccdcontext.hpp

@@ -59,7 +59,7 @@ interface IRoxieSlaveContext : extends IRoxieContextLogger
     virtual void onFileCallback(const RoxiePacketHeader &header, const char *lfn, bool isOpt, bool isLocal) = 0;
     virtual IActivityGraph * getLibraryGraph(const LibraryCallFactoryExtra &extra, IRoxieServerActivity *parentActivity) = 0;
     virtual void noteProcessed(unsigned subgraphId, unsigned activityId, unsigned _idx, unsigned _processed, unsigned _strands) const = 0;
-    virtual void mergeActivityStats(const CRuntimeStatisticCollection &fromStats, unsigned subgraphId, unsigned activityId, const ActivityTimeAccumulator &_totalCycles, cycle_t _localCycles) const = 0;
+    virtual void mergeActivityStats(const CRuntimeStatisticCollection &fromStats, unsigned subgraphId, unsigned activityId) const = 0;
     virtual IProbeManager *queryProbeManager() const = 0;
     virtual IDebuggableContext *queryDebugContext() const = 0;
     virtual void printResults(IXmlWriter *output, const char *name, unsigned sequence) = 0;

roxie/ccd/ccdquery.hpp

@@ -234,6 +234,7 @@ protected:
     ActivityArrayArray childQueries;
     UnsignedArray childQueryIndexes;
     CachedOutputMetaData meta;
+    mutable CriticalSection statsCrit;
     mutable CRuntimeStatisticCollection mystats;
     // MORE: Could be CRuntimeSummaryStatisticCollection to include derived stats, but stats are currently converted
     // to IPropertyTrees.  Would need to serialize/deserialize and then merge/derived so that they merged properly
@@ -256,6 +257,7 @@ public:
 
     virtual void mergeStats(const CRuntimeStatisticCollection &from) const
     {
+        CriticalBlock b(statsCrit);
         mystats.merge(from);
     }
 

roxie/ccd/ccdserver.cpp

@@ -210,9 +210,9 @@ public:
     {
         ctx->mergeStats(from);
     }
-    virtual const CRuntimeStatisticCollection &queryStats() const
+    virtual void gatherStats(CRuntimeStatisticCollection & merged) const override
     {
-        return ctx->queryStats();
+        ctx->gatherStats(merged);
     }
     virtual void CTXLOGva(const char *format, va_list args) const __attribute__((format(printf,2,0)))
     {
@@ -282,9 +282,9 @@ public:
     {
         ctx->noteProcessed(subgraphId, activityId, _idx, _processed, _strands);
     }
-    virtual void mergeActivityStats(const CRuntimeStatisticCollection &fromStats, unsigned subgraphId, unsigned activityId, const ActivityTimeAccumulator &_totalCycles, cycle_t _localCycles) const
+    virtual void mergeActivityStats(const CRuntimeStatisticCollection &fromStats, unsigned subgraphId, unsigned activityId) const
     {
-        ctx->mergeActivityStats(fromStats, subgraphId, activityId, _totalCycles, _localCycles);
+        ctx->mergeActivityStats(fromStats, subgraphId, activityId);
     }
     virtual IProbeManager *queryProbeManager() const
     {
@@ -350,7 +350,8 @@ protected:
 
 static const StatisticsMapping actStatistics(StWhenFirstRow, StTimeElapsed, StTimeLocalExecute, StTimeTotalExecute, StSizeMaxRowSize,
                                               StNumRowsProcessed, StNumSlaves, StNumStarted, StNumStopped, StNumStrands,
-                                              StNumScansPerRow, StNumAllocations, StNumAllocationScans, StKindNone);
+                                              StNumScansPerRow, StNumAllocations, StNumAllocationScans,
+                                              StTimeFirstExecute, StCycleLocalExecuteCycles, StCycleTotalExecuteCycles, StKindNone);
 static const StatisticsMapping joinStatistics(&actStatistics, StNumAtmostTriggered, StKindNone);
 static const StatisticsMapping keyedJoinStatistics(&joinStatistics, StNumServerCacheHits, StNumIndexSeeks, StNumIndexScans, StNumIndexWildSeeks,
                                                     StNumIndexSkips, StNumIndexNullSkips, StNumIndexMerges, StNumIndexMergeCompares,
@@ -388,11 +389,8 @@ protected:
     bool optUnordered = false; // is the output specified as unordered?
     unsigned heapFlags;
 
-    mutable CriticalSection statsCrit;
     mutable __int64 processed;
     mutable __int64 started;
-    mutable __int64 totalCycles;
-    mutable __int64 localCycles;
 
 public:
     IMPLEMENT_IINTERFACE;
@@ -402,8 +400,6 @@ public:
     {
         processed = 0;
         started = 0;
-        totalCycles = 0;
-        localCycles = 0;
         dependentCount = 0;
         optParallel = _graphNode.getPropInt("att[@name='parallel']/@value", 0);
         optUnordered = !_graphNode.getPropBool("att[@name='ordered']/@value", true);
@@ -490,18 +486,6 @@ public:
         }
     }
 
-    virtual void mergeActivityStats(const CRuntimeStatisticCollection &fromStats, const ActivityTimeAccumulator &_totalCycles, cycle_t _localCycles) const
-    {
-        if (_totalCycles.totalCycles || _localCycles)
-        {
-            CriticalBlock b(statsCrit);
-            dbgassertex(_totalCycles.totalCycles >= _localCycles);
-            totalCycles += _totalCycles.totalCycles;
-            localCycles += _localCycles;
-        }
-        CActivityFactory::mergeStats(fromStats);
-    }
-
     virtual void noteStarted() const
     {
         CriticalBlock b(statsCrit);
@@ -532,10 +516,13 @@ public:
         CriticalBlock b(statsCrit);
         if (started)
             putStatsValue(&node, "_roxieStarted", "sum", started);
-        if (totalCycles)
-            putStatsValue(&node, "totalTime", "sum", (unsigned) (cycle_to_nanosec(totalCycles)/1000));
-        if (localCycles)
-            putStatsValue(&node, "localTime", "sum", (unsigned) (cycle_to_nanosec(localCycles)/1000));
+        //MORE: The following is information is now duplicated
+        unsigned __int64 totalNs = mystats.getSerialStatisticValue(StTimeTotalExecute);
+        unsigned __int64 localNs = mystats.getSerialStatisticValue(StTimeLocalExecute);
+        if (totalNs)
+            putStatsValue(&node, "totalTime", "sum", (unsigned) (totalNs/1000));
+        if (localNs)
+            putStatsValue(&node, "localTime", "sum", (unsigned) (localNs/1000));
     }
 
     virtual void resetNodeProgressInfo()
@@ -544,22 +531,19 @@ public:
         CriticalBlock b(statsCrit);
         processed = 0;
         started = 0;
-        totalCycles = 0;
-        localCycles = 0;
     }
     virtual void getActivityMetrics(StringBuffer &reply) const
     {
         CActivityFactory::getActivityMetrics(reply);
         CriticalBlock b(statsCrit);
         putStatsValue(reply, "_roxieStarted", "sum", started);
-        putStatsValue(reply, "totalTime", "sum", (unsigned) (cycle_to_nanosec(totalCycles)/1000));
-        putStatsValue(reply, "localTime", "sum", (unsigned) (cycle_to_nanosec(localCycles)/1000));
+        putStatsValue(reply, "totalTime", "sum", (unsigned) (mystats.getSerialStatisticValue(StTimeTotalExecute)/1000));
+        putStatsValue(reply, "localTime", "sum", (unsigned) (mystats.getSerialStatisticValue(StTimeLocalExecute)/1000));
     }
-    virtual unsigned __int64 queryLocalCycles() const
+    virtual unsigned __int64 queryLocalTimeNs() const
     {
-        return localCycles;
+        return mystats.getSerialStatisticValue(StTimeLocalExecute);
     }
-
     virtual IQueryFactory &queryQueryFactory() const
     {
         return CActivityFactory::queryQueryFactory();
@@ -936,7 +920,6 @@ protected:
     MapStringToMyClass<ThorSectionTimer> functionTimers;
     unsigned processed;
     ActivityTimeAccumulator totalCycles;
-    cycle_t localCycles;
     unsigned activityId;
     activityState state;
     bool createPending;
@@ -962,7 +945,6 @@ public:
         inputStream = NULL;
         meta.set(basehelper.queryOutputMeta());
         processed = 0;
-        localCycles = 0;
         state=STATEreset;
         rowAllocator = NULL;
         debugging = _probeManager != NULL; // Don't want to collect timing stats from debug sessions
@@ -981,7 +963,6 @@ public:
         ctx = NULL;
         meta.set(basehelper.queryOutputMeta());
         processed = 0;
-        localCycles = 0;
         state=STATEreset;
         rowAllocator = NULL;
         debugging = false;
@@ -993,6 +974,12 @@ public:
 
     ~CRoxieServerActivity()
     {
+        basehelper.Release();
+        ::Release(rowAllocator);
+    }
+
+    virtual void beforeDispose() override
+    {
         if (traceStartStop)
         {
             // There was an old comment here stating // Note- CTXLOG may not be safe
@@ -1010,20 +997,25 @@ public:
             DBGLOG("STATE: Activity %d destroyed but not reset", activityId);
             state = STATEreset;  // bit pointless but there you go... 
         }
+    }
+
+    virtual void updateFactoryStatistics() override
+    {
+        CRuntimeStatisticCollection mergedStats(stats.queryMapping());
+        gatherStats(mergedStats);
+
         if (factory && !debugging)
         {
             if (processed)
                 factory->noteProcessed(0, processed);
-            factory->mergeActivityStats(stats, totalCycles, localCycles);
+            factory->mergeStats(mergedStats);
         }
         if (ctx && factory)
         {
             if (processed)
                 ctx->noteProcessed(factory->querySubgraphId(), activityId, 0, processed, 0);
-            ctx->mergeActivityStats(stats, factory->querySubgraphId(), activityId, totalCycles, localCycles);
+            ctx->mergeActivityStats(mergedStats, factory->querySubgraphId(), activityId);
         }
-        basehelper.Release();
-        ::Release(rowAllocator);
     }
 
     virtual const IRoxieContextLogger &queryLogCtx()const
@@ -1063,12 +1055,11 @@ public:
 #endif
         return nullptr;
     }
-    void mergeStrandStats(unsigned strandProcessed, const ActivityTimeAccumulator & strandCycles, const CRuntimeStatisticCollection & strandStats)
+    void mergeStrandStats(unsigned strandProcessed, const ActivityTimeAccumulator & strandCycles)
     {
         CriticalBlock cb(statscrit);
         processed += strandProcessed;
         totalCycles.merge(strandCycles);
-        stats.merge(strandStats);
     }
     inline void ensureRowAllocator()
     {
@@ -1140,9 +1131,14 @@ public:
     {
         stats.merge(from);
     }
-    virtual const CRuntimeStatisticCollection &queryStats() const
+    virtual void gatherStats(CRuntimeStatisticCollection & merged) const override
     {
-        return stats;
+        merged.merge(stats);
+        if (rowAllocator)
+            rowAllocator->gatherStats(merged);
+
+        totalCycles.addStatistics(merged);
+        merged.mergeStatistic(StCycleLocalExecuteCycles, queryLocalCycles());
     }
 
     virtual StringBuffer &getLogPrefix(StringBuffer &ret) const
@@ -1340,11 +1336,6 @@ public:
                 }
                 if (inputStream)
                     inputStream->stop();
-                if (rowAllocator)
-                {
-                    stats.reset(heapStatistics);
-                    rowAllocator->gatherStats(stats);
-                }
             }
         }
     }
@@ -1383,7 +1374,6 @@ public:
                 resetJunction(junction);
                 ForEachItemIn(idx, dependencies)
                     dependencies.item(idx).reset();
-                localCycles = queryLocalCycles();  // We can't call queryLocalCycles() in the destructor, so save the information here when we can.
                 if (input)
                     input->reset();
             }
@@ -1681,7 +1671,6 @@ public:
         processed = 0;
         numProcessedLastGroup = 0;
         totalCycles.reset();
-        stats.reset();
     }
     virtual void stop()
     {
@@ -1690,11 +1679,9 @@ public:
             if (inputStream)
                 inputStream->stop();
 
-            stats.reset(heapStatistics); // Heap stats are always gathered from scratch each time
-            if (rowAllocator)
-                rowAllocator->gatherStats(stats);
             parent.stop();
-            parent.mergeStrandStats(processed, totalCycles, stats);
+            //MORE: Move totalCycles (+processed?) to gatherStats()
+            parent.mergeStrandStats(processed, totalCycles);
         }
         stopped = true;
     }
@@ -1709,6 +1696,14 @@ public:
     }
     inline void requestAbort() { abortRequested.store(true, std::memory_order_relaxed); }
     inline bool isAborting() { return abortRequested.load(std::memory_order_relaxed); }
+
+    //MORE: processed and totalCycles should be included here, and not merged in stop()
+    void gatherStats(CRuntimeStatisticCollection & mergedStats) const
+    {
+        mergedStats.merge(stats);
+        if (rowAllocator)
+            rowAllocator->gatherStats(mergedStats);
+    }
 };
 
 class CRoxieServerStrandedActivity : public CRoxieServerActivity
@@ -1740,6 +1735,13 @@ public:
         }
     }
 
+    virtual void gatherStats(CRuntimeStatisticCollection & merged) const override
+    {
+        CRoxieServerActivity::gatherStats(merged);
+        ForEachItemIn(i, strands)
+            strands.item(i).gatherStats(merged);
+    }
+
     virtual void onCreate(IHThorArg *_colocalArg)
     {
         CRoxieServerActivity::_onCreate(_colocalArg, strands.ordinality());
@@ -4758,7 +4760,6 @@ public:
                                     }
                                     else
                                     {
-                                        ActivityTimeAccumulator dummy; // We could serialize from slave? Would get confusing though
                                         CRuntimeStatisticCollection childStats(allStatistics);
                                         childStats.deserialize(buf);
                                         if (traceLevel > 5)
@@ -4766,7 +4767,7 @@ public:
                                             StringBuffer s;
                                             activity.queryLogCtx().CTXLOG("Processing ChildStats for child %d subgraph %d: %s", childId, graphId, childStats.toStr(s).str());
                                         }
-                                        activity.queryContext()->mergeActivityStats(childStats, graphId, childId, dummy, 0);
+                                        activity.queryContext()->mergeActivityStats(childStats, graphId, childId);
                                     }
                                 }
                                 ReleaseRoxieRow(rowlen);
@@ -26930,6 +26931,8 @@ public:
 
     ~CActivityGraph()
     {
+        ForEachItemIn(i, activities)
+            activities.item(i).updateFactoryStatistics();
         if (probeManager)
             probeManager->deleteGraph((IArrayOf<IActivityBase>*)&activities, (IArrayOf<IInputBase>*)&probes);
     }
@@ -28063,7 +28066,7 @@ protected:
         qsort(output, 2000, sizeof(output[0]), compareFunc);
         testActivity(activity, input, output);
 
-        unsigned __int64 us = cycle_to_nanosec(factory->queryLocalCycles()/1000);
+        unsigned __int64 us = factory->queryLocalTimeNs();
         DBGLOG("Simple %s sorts: activity time %u.%u ms", type==2?"Heap" : (type==1 ? "Insertion" : "Quick"), (int)(us/1000), (int)(us%1000));
         factory->resetNodeProgressInfo();
         if (type)

roxie/ccd/ccdserver.hpp

@@ -186,6 +186,7 @@ interface IRoxieServerActivity : extends IActivityBase
     virtual ISectionTimer * registerTimer(unsigned activityId, const char * name) = 0;
     virtual IRoxieServerActivity * queryChildActivity(unsigned activityId) = 0;
     virtual IEngineRowAllocator * createRowAllocator(IOutputMetaData * metadata) = 0;
+    virtual void updateFactoryStatistics() = 0;
 };
 
 interface IRoxieServerActivityFactory : extends IActivityFactory
@@ -207,13 +208,12 @@ interface IRoxieServerActivityFactory : extends IActivityFactory
     virtual IHThorArg &getHelper() const = 0;
     virtual IRoxieServerActivity *createFunction(IHThorArg &helper, IProbeManager *_probeManager) const = 0;
     virtual void noteProcessed(unsigned idx, unsigned processed) const = 0;
-    virtual void mergeActivityStats(const CRuntimeStatisticCollection &fromStats, const ActivityTimeAccumulator &totalCycles, cycle_t localCycles) const = 0;
     virtual void onCreateChildQueries(IRoxieSlaveContext *ctx, IHThorArg *colocalArg, IArrayOf<IActivityGraph> &childGraphs, IRoxieServerActivity *parentActivity, IProbeManager *_probeManager, const IRoxieContextLogger &_logctx, unsigned numParallel) const = 0;
     virtual void noteStarted() const = 0;
     virtual void noteStarted(unsigned idx) const = 0;
     virtual void noteDependent(unsigned target) = 0;
     virtual IActivityGraph * createChildGraph(IRoxieSlaveContext * ctx, IHThorArg *colocalArg, unsigned childId, IRoxieServerActivity *parentActivity, IProbeManager * _probeManager, const IRoxieContextLogger &_logctx) const = 0;
-    virtual unsigned __int64 queryLocalCycles() const = 0;
+    virtual unsigned __int64 queryLocalTimeNs() const = 0;
     virtual bool isGraphInvariant() const = 0;
     virtual IRoxieServerSideCache *queryServerSideCache() const = 0;
     virtual IDefRecordMeta *queryActivityMeta() const = 0;

system/jlib/jstatcodes.h

@@ -184,6 +184,11 @@ enum StatisticKind
     StNumAllocations,
     StNumAllocationScans,
     StNumDiskRetries,
+    StCycleElapsedCycles,
+    StCycleRemainingCycles,
+    StCycleSoapcallCycles,
+    StCycleFirstExecuteCycles,
+    StCycleTotalNestedCycles,
 
     StMax,
 

system/jlib/jstats.cpp

@@ -506,14 +506,15 @@ extern jlib_decl StatsMergeAction queryMergeMode(StatisticKind kind)
     "@TimeDelta" # y, \
     "@TimeStdDev" # y,
 
-#define CORESTAT(x, y, m)     St##x##y, m, St##x##y, { NAMES(x, y) }, { TAGS(x, y) }
+#define CORESTAT(x, y, m)     St##x##y, m, St##x##y, St##x##y, { NAMES(x, y) }, { TAGS(x, y) }
 #define STAT(x, y, m)         CORESTAT(x, y, m)
 
 //--------------------------------------------------------------------------------------------------------------------
 
 //These are the macros to use to define the different entries in the stats meta table
-#define TIMESTAT(y) STAT(Time, y, SMeasureTimeNs)
-#define WHENSTAT(y) St##When##y, SMeasureTimestampUs, St##When##y, { WHENNAMES(When, y) }, { WHENTAGS(When, y) }
+//#define TIMESTAT(y) STAT(Time, y, SMeasureTimeNs)
+#define TIMESTAT(y) St##Time##y, SMeasureTimeNs, St##Time##y, St##Cycle##y##Cycles, { NAMES(Time, y) }, { TAGS(Time, y) }
+#define WHENSTAT(y) St##When##y, SMeasureTimestampUs, St##When##y, St##When##y, { WHENNAMES(When, y) }, { WHENTAGS(When, y) }
 #define NUMSTAT(y) STAT(Num, y, SMeasureCount)
 #define SIZESTAT(y) STAT(Size, y, SMeasureSize)
 #define LOADSTAT(y) STAT(Load, y, SMeasureLoad)
@@ -521,7 +522,7 @@ extern jlib_decl StatsMergeAction queryMergeMode(StatisticKind kind)
 #define NODESTAT(y) STAT(Node, y, SMeasureNode)
 #define PERSTAT(y) STAT(Per, y, SMeasurePercent)
 #define IPV4STAT(y) STAT(IPV4, y, SMeasureIPV4)
-#define CYCLESTAT(y) St##Cycle##y##Cycles, SMeasureCycle, St##Time##y, { NAMES(Cycle, y##Cycles) }, { TAGS(Cycle, y##Cycles) }
+#define CYCLESTAT(y) St##Cycle##y##Cycles, SMeasureCycle, St##Time##y, St##Cycle##y##Cycles, { NAMES(Cycle, y##Cycles) }, { TAGS(Cycle, y##Cycles) }
 
 //--------------------------------------------------------------------------------------------------------------------
 
@@ -531,14 +532,15 @@ public:
     StatisticKind kind;
     StatisticMeasure measure;
     StatisticKind serializeKind;
+    StatisticKind rawKind;
     const char * names[StNextModifier/StVariantScale];
     const char * tags[StNextModifier/StVariantScale];
 };
 
 //The order of entries in this table must match the order in the enumeration
 static const StatisticMeta statsMetaData[StMax] = {
-    { StKindNone, SMeasureNone, StKindNone, { "none" }, { "@none" } },
-    { StKindAll, SMeasureAll, StKindAll, { "all" }, { "@all" } },
+    { StKindNone, SMeasureNone, StKindNone, StKindNone, { "none" }, { "@none" } },
+    { StKindAll, SMeasureAll, StKindAll, StKindAll, { "all" }, { "@all" } },
     { WHENSTAT(GraphStarted) },
     { WHENSTAT(GraphFinished) },
     { WHENSTAT(FirstRow) },
@@ -617,6 +619,11 @@ static const StatisticMeta statsMetaData[StMax] = {
     { NUMSTAT(Allocations) },
     { NUMSTAT(AllocationScans) },
     { NUMSTAT(DiskRetries) },
+    { CYCLESTAT(Elapsed) },
+    { CYCLESTAT(Remaining) },
+    { CYCLESTAT(Soapcall) },
+    { CYCLESTAT(FirstExecute) },
+    { CYCLESTAT(TotalNested) },
 };
 
 
@@ -715,7 +722,7 @@ static double convertSquareMeasure(StatisticKind from, StatisticKind to, double
 }
 
 
-StatisticKind querySerializedKind(StatisticKind kind)
+static StatisticKind querySerializedKind(StatisticKind kind)
 {
     StatisticKind rawkind = (StatisticKind)(kind & StKindMask);
     if (rawkind >= StMax)
@@ -724,6 +731,15 @@ StatisticKind querySerializedKind(StatisticKind kind)
     return (StatisticKind)(serialKind | (kind & ~StKindMask));
 }
 
+static StatisticKind queryRawKind(StatisticKind kind)
+{
+    StatisticKind basekind = (StatisticKind)(kind & StKindMask);
+    if (basekind >= StMax)
+        return kind;
+    StatisticKind rawKind = statsMetaData[basekind].rawKind;
+    return (StatisticKind)(rawKind | (kind & ~StKindMask));
+}
+
 //--------------------------------------------------------------------------------------------------------------------
 
 void queryLongStatisticName(StringBuffer & out, StatisticKind kind)
@@ -1637,14 +1653,39 @@ CNestedRuntimeStatisticMap & CRuntimeStatisticCollection::ensureNested()
     return *nested;
 }
 
+unsigned __int64 CRuntimeStatisticCollection::getSerialStatisticValue(StatisticKind kind) const
+{
+    unsigned __int64 value = getStatisticValue(kind);
+    StatisticKind rawKind= queryRawKind(kind);
+    if (kind == rawKind)
+        return value;
+    unsigned __int64 rawValue = getStatisticValue(rawKind);
+    return value + convertMeasure(rawKind, kind, rawValue);
+}
+
 void CRuntimeStatisticCollection::merge(const CRuntimeStatisticCollection & other)
 {
-    ForEachItemIn(i, other)
+    if (&mapping == &other.mapping)
     {
-        StatisticKind kind = other.getKind(i);
-        unsigned __int64 value = other.getStatisticValue(kind);
-        if (value)
-            mergeStatistic(kind, value);
+        ForEachItemIn(i, other)
+        {
+            unsigned __int64 value = other.values[i].get();
+            if (value)
+            {
+                StatisticKind kind = getKind(i);
+                values[i].merge(value, queryMergeMode(kind));
+            }
+        }
+    }
+    else
+    {
+        ForEachItemIn(i, other)
+        {
+            StatisticKind kind = other.getKind(i);
+            unsigned __int64 value = other.getStatisticValue(kind);
+            if (value)
+                mergeStatistic(kind, value);
+        }
     }
     if (other.nested)
     {
@@ -2576,6 +2617,13 @@ static void checkKind(StatisticKind kind)
             throw makeStringExceptionV(0, "Statistic %u in the wrong order", kind);
     }
 
+    StatisticKind serialKind = querySerializedKind(kind);
+    StatisticKind rawKind = queryRawKind(kind);
+    if (kind != serialKind)
+        assertex(queryRawKind(serialKind) == kind);
+    if (kind != rawKind)
+        assertex(querySerializedKind(rawKind) == kind);
+
     StatisticMeasure measure = queryMeasure(kind);
     const char * shortName = queryStatisticName(kind);
     StringBuffer longName;

system/jlib/jstats.h

@@ -370,6 +370,7 @@ public:
     {
         return queryStatistic(kind).get();
     }
+    unsigned __int64 getSerialStatisticValue(StatisticKind kind) const;
     void reset();
     void reset(const StatisticsMapping & toClear);