Merge pull request #5168 from ghalliday/issue10414

HPCC-10414 Add general statistics to the workunit

Reviewed-By: Richard Chapman <rchapman@hpccsystems.com>

common/thorhelper/roxierow.cpp

@@ -469,7 +469,7 @@ public:
         else
         {
             //assert(false);
-            return 12345678; // Used for tracing, better than a crash...
+            return UNKNOWN_ACTIVITY; // Used for tracing, better than a crash...
         }
     }
     virtual StringBuffer &getActivityDescriptor(unsigned cacheId, StringBuffer &out) const

common/workunit/workunit.cpp

@@ -52,7 +52,6 @@
 
 static int workUnitTraceLevel = 1;
 
-
 static StringBuffer &getXPath(StringBuffer &wuRoot, const char *wuid)
 {
     // MORE - can fold in the date
@@ -440,6 +439,25 @@ public:
 };
 
 
+class CLocalWUStatistic : public CInterface, implements IConstWUStatistic
+{
+    Owned<IPropertyTree> p;
+public:
+    IMPLEMENT_IINTERFACE;
+    CLocalWUStatistic(IPropertyTree *p);
+
+    virtual IStringVal & getFullName(IStringVal & str) const;
+    virtual IStringVal & getCreator(IStringVal & str) const;
+    virtual IStringVal & getDescription(IStringVal & str) const;
+    virtual IStringVal & getName(IStringVal & str) const;
+    virtual IStringVal & getScope(IStringVal & str) const;
+    virtual StatisticMeasure getKind() const;
+    virtual unsigned __int64 getValue() const;
+    virtual unsigned __int64 getCount() const;
+    virtual unsigned __int64 getMax() const;
+};
+
+
 template <typename T, typename IT> struct CachedTags
 {
     CachedTags(): cached(false) {}
@@ -459,6 +477,11 @@ template <typename T, typename IT> struct CachedTags
         }
     }
 
+    void append(IPropertyTree * p)
+    {
+        tags.append(*new T(p));
+    }
+
     operator IArrayOf<IT>&() { return tags; }
 
     void kill()
@@ -545,6 +568,7 @@ class CLocalWorkUnit : public CInterface, implements IConstWorkUnit , implements
     mutable IArrayOf<IWUResult> variables;
     mutable CachedTags<CLocalWUTimeStamp,IConstWUTimeStamp> timestamps;
     mutable CachedTags<CLocalWUAppValue,IConstWUAppValue> appvalues;
+    mutable CachedTags<CLocalWUStatistic,IConstWUStatistic> statistics;
     mutable Owned<IUserDescriptor> userDesc;
     Mutex locked;
     Owned<ISecManager> secMgr;
@@ -629,10 +653,13 @@ public:
     virtual IStringVal & getStateDesc(IStringVal & str) const;
     virtual IConstWUResult * getTemporaryByName(const char * name) const;
     virtual IConstWUResultIterator & getTemporaries() const;
-    virtual unsigned getTimerCount(const char * timerName, const char * instance) const;
-    virtual unsigned getTimerDuration(const char * timerName, const char * instance) const;
+    virtual unsigned getTimerCount(const char * timerName) const;
+    virtual unsigned getTimerDuration(const char * timerName) const;
+    virtual IStringVal & getTimerDescription(const char * timerName, IStringVal & str) const;
     virtual IStringIterator & getTimers() const;
     virtual IConstWUTimeStampIterator & getTimeStamps() const;
+    virtual IConstWUStatisticIterator & getStatistics() const;
+    virtual IConstWUStatistic * getStatistic(const char * name) const;
     virtual IConstWUWebServicesInfo * getWebServicesInfo() const;
     virtual IConstWURoxieQueryInfo * getRoxieQueryInfo() const;
     virtual IStringVal & getXmlParams(IStringVal & params) const;
@@ -707,7 +734,8 @@ public:
     void setStateEx(const char * text);
     void setAgentSession(__int64 sessionId);
     void setSecurityToken(const char *value);
-    void setTimerInfo(const char * name, const char * instance, unsigned ms, unsigned count, unsigned __int64 max);
+    void setStatistic(const char * creator, const char * wuScope, const char * stat, const char * description, StatisticMeasure kind, unsigned __int64 value, unsigned __int64 count, unsigned __int64 maxValue, bool merge);
+    void setTimerInfo(const char * name, unsigned ms, unsigned count, unsigned __int64 max);
     void setTracingValue(const char * propname, const char * value);
     void setTracingValueInt(const char * propname, int value);
     void setUser(const char * value);
@@ -768,6 +796,9 @@ public:
     bool getAllowAutoQueueSwitch() const;
     void setLibraryInformation(const char * name, unsigned interfaceHash, unsigned definitionHash);
 
+protected:
+    IConstWUStatistic * getStatisticByDescription(const char * name) const;
+
 private:
     void init();
     IWUGraph *createGraph();
@@ -1031,16 +1062,22 @@ public:
             { return c->getStateDesc(str); }
     virtual bool getRunningGraph(IStringVal & graphName, WUGraphIDType & subId) const
             { return c->getRunningGraph(graphName, subId); }
-    virtual unsigned getTimerCount(const char * timerName, const char * instance) const
-            { return c->getTimerCount(timerName, instance); }
-    virtual unsigned getTimerDuration(const char * timerName, const char * instance) const
-            { return c->getTimerDuration(timerName, instance); }
+    virtual unsigned getTimerCount(const char * timerName) const
+            { return c->getTimerCount(timerName); }
+    virtual unsigned getTimerDuration(const char * timerName) const
+            { return c->getTimerDuration(timerName); }
+    virtual IStringVal & getTimerDescription(const char * timerName, IStringVal & str) const
+            { return c->getTimerDescription(timerName, str); }
     virtual IStringVal & getTimeStamp(const char * name, const char * instance, IStringVal & str) const
             { return c->getTimeStamp(name, instance, str); }
     virtual IStringIterator & getTimers() const
             { return c->getTimers(); }
     virtual IConstWUTimeStampIterator & getTimeStamps() const
             { return c->getTimeStamps(); }
+    virtual IConstWUStatisticIterator & getStatistics() const
+            { return c->getStatistics(); }
+    virtual IConstWUStatistic * getStatistic(const char * name) const
+            { return c->getStatistic(name); }
 
     virtual bool getWuDate(unsigned & year, unsigned & month, unsigned& day)
             { return c->getWuDate(year,month,day);}
@@ -1168,8 +1205,11 @@ public:
             { c->setStateEx(text); }
     virtual void setAgentSession(__int64 sessionId)
             { c->setAgentSession(sessionId); }
-    virtual void setTimerInfo(const char * name, const char * instance, unsigned ms, unsigned count, unsigned __int64 max)
-            { c->setTimerInfo(name, instance, ms, count, max); }
+    virtual void setTimerInfo(const char * name, unsigned ms, unsigned count, unsigned __int64 max)
+            { c->setTimerInfo(name, ms, count, max); }
+    virtual void setStatistic(const char * creator, const char * wuScope, const char * stat, const char * description, StatisticMeasure kind, unsigned __int64 value, unsigned __int64 count, unsigned __int64 maxValue, bool merge)
+            { c->setStatistic(creator, wuScope, stat, description, kind, value, count, maxValue, merge); }
+
     virtual void setTracingValue(const char * propname, const char * value)
             { c->setTracingValue(propname, value); }
     virtual void setTracingValueInt(const char * propname, int value)
@@ -2965,6 +3005,7 @@ CLocalWorkUnit::~CLocalWorkUnit()
         variables.kill();
         timestamps.kill();
         appvalues.kill();
+        statistics.kill();
 
         userDesc.clear();
         secMgr.clear();
@@ -4175,7 +4216,6 @@ IConstWUAppValueIterator& CLocalWorkUnit::getApplicationValues() const
 }
 
 
-
 void CLocalWorkUnit::setApplicationValue(const char *app, const char *propname, const char *value, bool overwrite)
 {
     CriticalBlock block(crit);
@@ -5056,6 +5096,13 @@ void CLocalWorkUnit::copyWorkUnit(IConstWorkUnit *cached, bool all)
             mergePTree(tgtTimings, pt);
             pt->Release();
         }
+        pt = fromP->getBranch("Statistics");
+        if (pt)
+        {
+            IPropertyTree *tgtStatistics = ensurePTree(p, "Statistics");
+            mergePTree(tgtStatistics, pt);
+            pt->Release();
+        }
     }
 
     updateProp(p, fromP, "@clusterName");
@@ -5382,17 +5429,54 @@ IConstWULibrary * CLocalWorkUnit::getLibraryByName(const char * search) const
     return NULL;
 }
 
-unsigned CLocalWorkUnit::getTimerDuration(const char *name, const char *_unused) const
+unsigned CLocalWorkUnit::getTimerDuration(const char *name) const
 {
+    Owned<IConstWUStatistic> stat = getStatisticByDescription(name);
+    if (stat)
+    {
+        unsigned __int64 time = stat->getValue();
+        return (unsigned)(time / 1000000);
+    }
+
+    //Backward compatibility - but only use it if no statistics
     CriticalBlock block(crit);
+    if (p->hasProp("Statistics"))
+        return 0;
+
     StringBuffer pname;
     pname.appendf("Timings/Timing[@name=\"%s\"]/@duration", name);
     return p->getPropInt(pname.str(), 0);
 }
 
-unsigned CLocalWorkUnit::getTimerCount(const char *name, const char *_unused) const
+IStringVal & CLocalWorkUnit::getTimerDescription(const char * name, IStringVal & str) const
+{
+    Owned<IConstWUStatistic> stat = getStatisticByDescription(name);
+    if (stat)
+        return stat->getDescription(str);
+
+    //Backward compatibility - but only use it if no statistics
+    CriticalBlock block(crit);
+    if (p->hasProp("Statistics"))
+    {
+        str.clear();
+        return str;
+    }
+
+    str.set(name);
+    return str;
+}
+
+unsigned CLocalWorkUnit::getTimerCount(const char *name) const
 {
+    Owned<IConstWUStatistic> stat = getStatisticByDescription(name);
+    if (stat)
+        return (unsigned)stat->getCount();
+
+    //Backward compatibility - but only use it if no statistics
     CriticalBlock block(crit);
+    if (p->hasProp("Statistics"))
+        return 0;
+
     StringBuffer pname;
     pname.appendf("Timings/Timing[@name=\"%s\"]/@count", name);
     return p->getPropInt(pname.str(), 0);
@@ -5401,6 +5485,11 @@ unsigned CLocalWorkUnit::getTimerCount(const char *name, const char *_unused) co
 IStringIterator& CLocalWorkUnit::getTimers() const
 {
     CriticalBlock block(crit);
+
+    if (p->hasProp("Statistics"))
+        return *new CStringPTreeAttrIterator(p->getElements("Statistics/Statistic[@unit=\"ns\"]"), "@desc");
+
+    //Backward compatibility - but only use it if no statistics
     return *new CStringPTreeAttrIterator(p->getElements("Timings/Timing"), "@name");
 }
 
@@ -5412,21 +5501,30 @@ StringBuffer &formatGraphTimerLabel(StringBuffer &str, const char *graphName, un
     return str;
 }
 
-bool parseGraphTimerLabel(const char *label, StringBuffer &graphName, unsigned &subGraphNum, unsigned __int64 &subId)
+StringBuffer &formatGraphTimerScope(StringBuffer &str, const char *graphName, unsigned subGraphNum, unsigned __int64 subId)
+{
+    str.append(graphName);
+    if (subId) str.append(":").append(subId);
+    return str;
+}
+
+bool parseGraphTimerLabel(const char *label, StringAttr &graphName, unsigned & graphNum, unsigned &subGraphNum, unsigned &subId)
 {
     // expects format: "Graph <graphname>[ - <subgraphnum> (<subgraphid>)]"
     unsigned len = (size32_t)strlen(label);
     if (len < 6 || (0 != memcmp(label, "Graph ", 6)))
         return false;
+    graphNum = 0;
     subGraphNum = 0;
     subId = 0;
     const char *finger = label+6;
     const char *finger2 = strchr(finger, '-');
+
     if (NULL == finger2) // just graphName
-        graphName.append(finger);
+        graphName.set(finger);
     else
     {
-        graphName.append((size32_t)((finger2-1)-finger), finger);
+        graphName.set(finger, (size32_t)((finger2-1)-finger));
         finger = finger2+2; // skip '-' and space
         finger2 = strchr(finger, ' ');
         if (finger2)
@@ -5435,40 +5533,40 @@ bool parseGraphTimerLabel(const char *label, StringBuffer &graphName, unsigned &
             finger = finger2+2; // skip space and '('
             finger2 = strchr(finger, ')');
             if (finger2)
-                subId = atoi64_l(finger, (size32_t)(finger2-finger));
+                subId = atoi_l(finger, (size32_t)(finger2-finger));
         }
         else if (((len-(finger-label))>3) && 0 == memcmp(finger, "id(", 3)) // subgraph id only, new format.
         {
             finger += 3;
             finger2 = strchr(finger, ')');
             if (finger2)
-                subId = atoi64_l(finger, (size32_t)(finger2-finger));
+                subId = atoi_l(finger, (size32_t)(finger2-finger));
         }
     }
+
+    if (graphName && memicmp(graphName, "graph", 5))
+        graphNum = atoi(graphName + 5);
+
     return true;
 }
 
-void CLocalWorkUnit::setTimerInfo(const char *name, const char *subname, unsigned ms, unsigned count, unsigned __int64 max)
+void CLocalWorkUnit::setTimerInfo(const char *name, unsigned ms, unsigned count, unsigned __int64 max)
 {
     CriticalBlock block(crit);
     IPropertyTree *timings = p->queryPropTree("Timings");
     if (!timings)
         timings = p->addPropTree("Timings", createPTree("Timings"));
-    StringBuffer fullname;
-    if (subname)
-        fullname.append('.').append(subname);
-    fullname.append(name);
     StringBuffer xpath;
-    xpath.append("Timing[@name=\"").append(fullname).append("\"]");
+    xpath.append("Timing[@name=\"").append(name).append("\"]");
     IPropertyTree *timing = timings->queryPropTree(xpath.str());
     if (!timing)
     {
         timing = timings->addPropTree("Timing", createPTree("Timing"));
-        timing->setProp("@name", fullname.str());
+        timing->setProp("@name", name);
     }
     timing->setPropInt("@count", count);
     timing->setPropInt("@duration", ms);
-    if (!max && 1==count) max = (unsigned __int64)ms * 1000000; // max is in nanoseconds
+    if (!max && 1==count) max = milliToNano(ms); // max is in nanoseconds
     if (max)
         timing->setPropInt64("@max", max);
 }
@@ -5515,6 +5613,91 @@ void CLocalWorkUnit::setTimeStamp(const char *application, const char *instance,
         ts->addPropTree("TimeStamp", t);
 }
 
+
+mapEnums queryStatMeasure[] =
+{
+    { SMEASURE_TIME_NS, "ns" },
+    { SMEASURE_COUNT, "cnt" },
+    { SMEASURE_MEM_KB, "kb" },
+    { SMEASURE_MAX, NULL},
+};
+
+void CLocalWorkUnit::setStatistic(const char * creator, const char * wuScope, const char * stat, const char * description, StatisticMeasure kind, unsigned __int64 value, unsigned __int64 count, unsigned __int64 maxValue, bool merge)
+{
+    if (!wuScope) wuScope = "workunit";
+
+    //creator. scope and name must all be present, and must not contain semi colons.
+    assertex(creator && wuScope && stat);
+    dbgassertex(!strchr(creator, ';') && !strchr(wuScope, ';') && !strchr(stat, ';'));
+    if (count == 1 && maxValue < value)
+        maxValue = value;
+
+    StringBuffer fullname;
+    fullname.append(creator).append(";").append(wuScope).append(";").append(stat);
+
+    StringBuffer xpath;
+    xpath.append("Statistic[@name=\"").append(fullname).append("\"]");
+
+    CriticalBlock block(crit);
+    IPropertyTree * stats = p->queryPropTree("Statistics");
+    if (!stats)
+        stats = p->addPropTree("Statistics", createPTree("Statistics"));
+    IPropertyTree * statTree = stats->queryPropTree(xpath.str());
+    if (!statTree)
+    {
+        //MORE: When getTimings is removed the default description could be dynamically calculated
+        StringBuffer descriptionText;
+        if (!description || !*description)
+        {
+            bool isDefaultName = streq(stat, "time");
+            bool isDefaultScope = streq(wuScope, "workunit");
+
+            descriptionText.append(creator);
+            if (isDefaultName || !isDefaultScope)
+                descriptionText.append(": ").append(wuScope);
+            if (!isDefaultName)
+                descriptionText.append(": ").append(stat);
+            description = descriptionText;
+        }
+
+        statTree = stats->addPropTree("Statistic", createPTree("Statistic"));
+        statTree->setProp("@name", fullname.str());
+
+        if (description)
+            statTree->setProp("@desc", description);
+        setEnum(statTree, "@unit", kind, queryStatMeasure);
+
+        statTree->setPropInt64("@value", value);
+        statTree->setPropInt64("@count", count);
+        if (maxValue)
+            statTree->setPropInt64("@max", maxValue);
+
+        if (statistics.cached)
+            statistics.append(LINK(statTree));
+    }
+    else
+    {
+        if (merge)
+        {
+            unsigned __int64 oldValue = statTree->getPropInt64("@value", 0);
+            unsigned __int64 oldCount = statTree->getPropInt64("@count", 0);
+            unsigned __int64 oldMax = statTree->getPropInt64("@max", 0);
+
+            statTree->setPropInt64("@value", value + oldValue);
+            statTree->setPropInt64("@count", count + oldCount);
+            if (maxValue > oldMax)
+                statTree->setPropInt64("@max", maxValue);
+        }
+        else
+        {
+            statTree->setPropInt64("@value", value);
+            statTree->setPropInt64("@count", count);
+            if (maxValue)
+                statTree->setPropInt64("@max", maxValue);
+        }
+    }
+}
+
 void CLocalWorkUnit::setTimeStamp(const char *application, const char *instance, const char *event)
 {
     setTimeStamp(application,instance,event,false);
@@ -5550,6 +5733,35 @@ IConstWUTimeStampIterator& CLocalWorkUnit::getTimeStamps() const
     return *new CArrayIteratorOf<IConstWUTimeStamp,IConstWUTimeStampIterator> (timestamps, 0, (IConstWorkUnit *) this);
 }
 
+IConstWUStatisticIterator& CLocalWorkUnit::getStatistics() const
+{
+    CriticalBlock block(crit);
+    statistics.load(p,"Statistics/*");
+    return *new CArrayIteratorOf<IConstWUStatistic,IConstWUStatisticIterator> (statistics, 0, (IConstWorkUnit *) this);
+}
+
+IConstWUStatistic * CLocalWorkUnit::getStatisticByDescription(const char * desc) const
+{
+    StringBuffer xpath;
+    xpath.appendf("Statistics/Statistic[@desc=\"%s\"]", desc);
+    CriticalBlock block(crit);
+    IPropertyTree * match = p->queryPropTree(xpath);
+    if (!match)
+        return NULL;
+    return new CLocalWUStatistic(LINK(match));
+}
+
+IConstWUStatistic * CLocalWorkUnit::getStatistic(const char * name) const
+{
+    StringBuffer xpath;
+    xpath.appendf("Statistics/Statistic[@name=\"%s\"]", name);
+    CriticalBlock block(crit);
+    IPropertyTree * match = p->queryPropTree(xpath);
+    if (!match)
+        return NULL;
+    return new CLocalWUStatistic(LINK(match));
+}
+
 bool CLocalWorkUnit::getWuDate(unsigned & year, unsigned & month, unsigned& day)
 {
     CriticalBlock block(crit);
@@ -6466,12 +6678,23 @@ unsigned CLocalWorkUnit::getVariableCount() const
 unsigned CLocalWorkUnit::getTimerCount() const
 {
     CriticalBlock block(crit);
-    if (p->hasProp("Timings"))
+
+    if (p->hasProp("Statistics"))
     {
-        return p->queryPropTree("Timings")->numChildren();
+        Owned<IPropertyTreeIterator> iter = p->getElements("Statistics/Statistic[@unit=\"ns\"]");
+        unsigned cnt =0;
+        if (iter)
+        {
+            ForEach(*iter)
+                cnt++;
+        }
+        return cnt;
     }
+
+    if (p->hasProp("Timings"))
+        return p->queryPropTree("Timings")->numChildren();
+
     return 0;
-    
 }
 
 unsigned CLocalWorkUnit::getApplicationValueCount() const
@@ -8276,6 +8499,8 @@ void CLocalWUException::setExceptionColumn(unsigned c)
     p->setPropInt("@col", c);
 }
 
+//==========================================================================================
+
 CLocalWUTimeStamp::CLocalWUTimeStamp(IPropertyTree *props) : p(props)
 {
 }
@@ -8300,6 +8525,8 @@ IStringVal & CLocalWUTimeStamp::getDate(IStringVal & str) const
     return str;
 }
 
+//==========================================================================================
+
 CLocalWUAppValue::CLocalWUAppValue(IPropertyTree *props,unsigned child): p(props)
 {
     prop.append("*[").append(child).append("]");
@@ -8325,6 +8552,79 @@ IStringVal & CLocalWUAppValue::getValue(IStringVal & str) const
     return str;
 }
 
+//==========================================================================================
+
+CLocalWUStatistic::CLocalWUStatistic(IPropertyTree *props) : p(props)
+{
+}
+
+IStringVal & CLocalWUStatistic::getFullName(IStringVal & str) const
+{
+    str.set(p->queryProp("@name"));
+    return str;
+}
+
+IStringVal & CLocalWUStatistic::getCreator(IStringVal & str) const
+{
+    const char * name = p->queryProp("@name");
+    const char * sep1 = strchr(name, ';');
+    assertex(sep1);
+    str.setLen(name, sep1-name);
+    return str;
+}
+
+IStringVal & CLocalWUStatistic::getDescription(IStringVal & str) const
+{
+    str.set(p->queryProp("@desc"));
+    return str;
+}
+
+IStringVal & CLocalWUStatistic::getName(IStringVal & str) const
+{
+    const char * name = p->queryProp("@name");
+    const char * sep1 = strchr(name, ';');
+    assertex(sep1);
+    const char * scope = sep1+1;
+    const char * sep2 = strchr(scope, ';');
+    assertex(sep2);
+    str.set(sep2+1);
+    return str;
+}
+
+IStringVal & CLocalWUStatistic::getScope(IStringVal & str) const
+{
+    const char * name = p->queryProp("@name");
+    const char * sep1 = strchr(name, ';');
+    assertex(sep1);
+    const char * scope = sep1+1;
+    const char * sep2 = strchr(scope, ';');
+    assertex(sep2);
+    str.setLen(scope, sep2-scope);
+    return str;
+}
+
+StatisticMeasure CLocalWUStatistic::getKind() const
+{
+    return (StatisticMeasure)getEnum(p, "@unit", queryStatMeasure);
+}
+
+unsigned __int64 CLocalWUStatistic::getValue() const
+{
+    return p->getPropInt64("@value", 0);
+}
+
+unsigned __int64 CLocalWUStatistic::getCount() const
+{
+    return p->getPropInt64("@count", 0);
+}
+
+unsigned __int64 CLocalWUStatistic::getMax() const
+{
+    return p->getPropInt64("@max", 0);
+}
+
+//==========================================================================================
+
 extern WORKUNIT_API ILocalWorkUnit * createLocalWorkUnit()
 {
     Owned<CLocalWorkUnit> cw = new CLocalWorkUnit("W_LOCAL", NULL, (ISecManager*)NULL, NULL);
@@ -9938,3 +10238,58 @@ extern WORKUNIT_API void descheduleWorkunit(char const * wuid)
     else
         doDescheduleWorkkunit(wuid);
 }
+
+extern WORKUNIT_API void updateWorkunitTimeStat(IWorkUnit * wu, const char * component, const char * wuScope, const char * stat, const char * description, unsigned __int64 value, unsigned __int64 count, unsigned __int64 maxValue)
+{
+    if (!wuScope)
+        wuScope = "workunit";
+    if (!stat)
+        stat = "time";
+
+    //The following line duplicates the statistics as timing information - preserved temporarily to show refactoring.
+    //wu->setTimerInfo(description, (unsigned)(value/1000000), (unsigned)count, (unsigned)maxValue);
+    wu->setStatistic(component, wuScope, stat, description, SMEASURE_TIME_NS, value, count, maxValue, false);
+}
+
+extern WORKUNIT_API void updateWorkunitTiming(IWorkUnit * wu, const char * component, const char * mangledScope, const char * description, unsigned __int64 value, unsigned __int64 count, unsigned __int64 maxValue)
+{
+    StringAttr scopeText;
+    StringAttr componentText;
+    const char * wuScope = mangledScope;
+    const char * stat = "time";
+
+    //If the scope contains a semicolon then it is taken to mean (wuScope;stat or comonent;wuScope;stat)
+    const char * sep1 = strchr(mangledScope, ';');
+    if (sep1)
+    {
+        const char * sep2 = strchr(sep1+1, ';');
+        if (sep2)
+        {
+            componentText.set(mangledScope, sep1 - mangledScope);
+            scopeText.set(sep1+1, sep2-(sep1+1));
+            component = componentText;
+            wuScope = scopeText;
+            stat = sep2+1;
+        }
+        else
+        {
+            scopeText.set(mangledScope, sep1-mangledScope);
+            wuScope = scopeText.get();
+            stat = sep1+1;
+        }
+    }
+
+    updateWorkunitTimeStat(wu, component, wuScope, stat, description, value, count, maxValue);
+}
+
+extern WORKUNIT_API void updateWorkunitTimings(IWorkUnit * wu, ITimeReporter *timer, const char * component)
+{
+    StringBuffer description;
+    StringBuffer scope;
+    for (unsigned i = 0; i < timer->numSections(); i++)
+    {
+        timer->getDescription(i, description.clear());
+        timer->getScope(i, scope.clear());
+        updateWorkunitTiming(wu, component, scope, description, timer->getTime(i), timer->getCount(i), timer->getMaxTime(i));
+    }
+}

common/workunit/workunit.hpp

@@ -36,6 +36,7 @@
 #include "errorlist.h"
 #include "jtime.hpp"
 #include "jsocket.hpp"
+#include "jstats.h"
 
 #define CHEAP_UCHAR_DEF
 #ifdef _WIN32
@@ -803,7 +804,23 @@ interface IConstWUAppValueIterator : extends IScmIterator
     virtual IConstWUAppValue & query() = 0;
 };
 
+interface IConstWUStatistic : extends IInterface
+{
+    virtual IStringVal & getFullName(IStringVal & str) const = 0;   // A unique name
+    virtual IStringVal & getCreator(IStringVal & str) const = 0;    // what component gathered the statistic e.g., roxie/eclcc/thorslave[ip]
+    virtual IStringVal & getDescription(IStringVal & str) const = 0;// Description suitable for displaying to the user
+    virtual IStringVal & getName(IStringVal & str) const = 0;       // what is the name of the statistic e.g., wall time
+    virtual IStringVal & getScope(IStringVal & str) const = 0;      // what scope is the statistic gathered over? e.g., workunit, wfid:n, graphn, graphn:m
+    virtual StatisticMeasure getKind() const = 0;
+    virtual unsigned __int64 getValue() const = 0;
+    virtual unsigned __int64 getCount() const = 0;
+    virtual unsigned __int64 getMax() const = 0;
+};
 
+interface IConstWUStatisticIterator : extends IScmIterator
+{
+    virtual IConstWUStatistic & query() = 0;
+};
 
 //! IWorkUnit
 //! Provides high level access to WorkUnit "header" data.
@@ -874,13 +891,16 @@ interface IConstWorkUnit : extends IInterface
     virtual IConstWUResult * getTemporaryByName(const char * name) const = 0;
     virtual IConstWUResultIterator & getTemporaries() const = 0;
     virtual bool getRunningGraph(IStringVal & graphName, WUGraphIDType & subId) const = 0;
-    virtual unsigned getTimerCount(const char * timerName, const char * instance) const = 0;
-    virtual unsigned getTimerDuration(const char * timerName, const char * instance) const = 0;
+    virtual unsigned getTimerCount(const char * timerName) const = 0;
+    virtual unsigned getTimerDuration(const char * timerName) const = 0;
+    virtual IStringVal & getTimerDescription(const char * timerName, IStringVal & str) const = 0;
     virtual IStringVal & getTimeStamp(const char * name, const char * instance, IStringVal & str) const = 0;
     virtual IConstWUWebServicesInfo * getWebServicesInfo() const = 0;
     virtual IConstWURoxieQueryInfo * getRoxieQueryInfo() const = 0;
     virtual IStringIterator & getTimers() const = 0;
     virtual IConstWUTimeStampIterator & getTimeStamps() const = 0;
+    virtual IConstWUStatisticIterator & getStatistics() const = 0;
+    virtual IConstWUStatistic * getStatistic(const char * name) const = 0;
     virtual IStringVal & getUser(IStringVal & str) const = 0;
     virtual IStringVal & getWuScope(IStringVal & str) const = 0;
     virtual IConstWUResult * getVariableByName(const char * name) const = 0;
@@ -958,7 +978,8 @@ interface IWorkUnit : extends IConstWorkUnit
     virtual void setState(WUState state) = 0;
     virtual void setStateEx(const char * text) = 0;
     virtual void setAgentSession(__int64 sessionId) = 0;
-    virtual void setTimerInfo(const char * name, const char * instance, unsigned ms, unsigned count, unsigned __int64 max) = 0;
+    virtual void setTimerInfo(const char * name, unsigned ms, unsigned count, unsigned __int64 max) = 0;
+    virtual void setStatistic(const char * creator_who, const char * wuScope_where, const char * stat_what, const char * description, StatisticMeasure kind, unsigned __int64 value, unsigned __int64 count, unsigned __int64 maxValue, bool merge) = 0;
     virtual void setTracingValue(const char * propname, const char * value) = 0;
     virtual void setTracingValueInt(const char * propname, int value) = 0;
     virtual void setUser(const char * value) = 0;
@@ -1161,6 +1182,22 @@ public:
     ~WorkunitUpdate() { if (get()) get()->commit(); }
 };
 
+class WuStatisticTarget : implements IStatisticTarget
+{
+public:
+    WuStatisticTarget(IWorkUnit * _wu, const char * _defaultWho) : wu(_wu), defaultWho(_defaultWho) {}
+
+    virtual void addStatistic(const char * creator_who, const char * wuScope_where, const char * stat_what, const char * description, StatisticMeasure kind, unsigned __int64 value, unsigned __int64 count, unsigned __int64 maxValue, bool merge)
+    {
+        if (!creator_who) creator_who = defaultWho;
+        wu->setStatistic(creator_who, wuScope_where, stat_what, description, kind, value, count, maxValue, merge);
+    }
+
+protected:
+    Linked<IWorkUnit> wu;
+    const char * defaultWho;
+};
+
 extern WORKUNIT_API IStringVal &getEclCCServerQueueNames(IStringVal &ret, const char *process);
 extern WORKUNIT_API IStringVal &getEclServerQueueNames(IStringVal &ret, const char *process);
 extern WORKUNIT_API IStringVal &getEclSchedulerQueueNames(IStringVal &ret, const char *process);
@@ -1190,7 +1227,8 @@ extern WORKUNIT_API IExtendedWUInterface * queryExtendedWU(IWorkUnit * wu);
 extern WORKUNIT_API unsigned getEnvironmentThorClusterNames(StringArray &thorNames, StringArray &groupNames, StringArray &targetNames, StringArray &queueNames);
 extern WORKUNIT_API unsigned getEnvironmentHThorClusterNames(StringArray &eclAgentNames, StringArray &groupNames, StringArray &targetNames);
 extern WORKUNIT_API StringBuffer &formatGraphTimerLabel(StringBuffer &str, const char *graphName, unsigned subGraphNum=0, unsigned __int64 subId=0);
-extern WORKUNIT_API bool parseGraphTimerLabel(const char *label, StringBuffer &graphName, unsigned &subGraphNum, unsigned __int64  &subId);
+extern WORKUNIT_API StringBuffer &formatGraphTimerScope(StringBuffer &str, const char *graphName, unsigned subGraphNum, unsigned __int64 subId);
+extern WORKUNIT_API bool parseGraphTimerLabel(const char *label, StringAttr &graphName, unsigned & graphNum, unsigned &subGraphNum, unsigned &subId);
 extern WORKUNIT_API void addExceptionToWorkunit(IWorkUnit * wu, WUExceptionSeverity severity, const char * source, unsigned code, const char * text, const char * filename, unsigned lineno, unsigned column);
 extern WORKUNIT_API IWorkUnitFactory * getWorkUnitFactory();
 extern WORKUNIT_API IWorkUnitFactory * getSecWorkUnitFactory(ISecManager &secmgr, ISecUser &secuser);
@@ -1272,6 +1310,11 @@ extern WORKUNIT_API void gatherLibraryNames(StringArray &names, StringArray &unr
 
 extern WORKUNIT_API void associateLocalFile(IWUQuery * query, WUFileType type, const char * name, const char * description, unsigned crc);
 
+interface ITimeReporter;
+extern WORKUNIT_API void updateWorkunitTimeStat(IWorkUnit * wu, const char * component, const char * wuScope, const char * stat, const char * description, unsigned __int64 value, unsigned __int64 count, unsigned __int64 maxValue);
+extern WORKUNIT_API void updateWorkunitTiming(IWorkUnit * wu, const char * component, const char * mangledScope, const char * description, unsigned __int64 value, unsigned __int64 count, unsigned __int64 maxValue);
+extern WORKUNIT_API void updateWorkunitTimings(IWorkUnit * wu, ITimeReporter *timer, const char * component);
+
 
 
 extern WORKUNIT_API const char *getTargetClusterComponentName(const char *clustname, const char *processType, StringBuffer &name);

dali/daliadmin/daliadmin.cpp

@@ -1657,6 +1657,22 @@ static const char *getNum(const char *s,unsigned &num)
     return s;
 }
 
+
+static void displayGraphTiming(const char * name, unsigned time)
+{
+    unsigned gn;
+    const char *s = getNum(name,gn);
+    unsigned sn;
+    s = getNum(s,sn);
+    if (gn&&sn) {
+        const char *gs = strchr(name,'(');
+        unsigned gid = 0;
+        if (gs)
+            getNum(gs+1,gid);
+        OUTLOG("\"%s\",%d,%d,%d,%d,%d",name,gn,sn,gid,time,(time/60000));
+    }
+}
+
 static void workunittimings(const char *wuid)
 {
     StringBuffer path;
@@ -1667,28 +1683,38 @@ static void workunittimings(const char *wuid)
         return;
     }
     IPropertyTree *wu = conn->queryRoot();
-    Owned<IPropertyTreeIterator> iter = wu->getElements("Timings/Timing");
     StringBuffer name;
     outln("Name,graph,sub,gid,time ms,time min");
-    ForEach(*iter) {
-        if (iter->query().getProp("@name",name.clear())) {
-            if ((name.length()>11)&&(memcmp("Graph graph",name.str(),11)==0)) {
-                unsigned gn;
-                const char *s = getNum(name.str(),gn);
-                unsigned sn;
-                s = getNum(s,sn);
-                if (gn&&sn) {
-                    const char *gs = strchr(name.str(),'(');
-                    unsigned gid = 0;
-                    if (gs)
-                        getNum(gs+1,gid);
+    if (wu->hasProp("Statistics"))
+    {
+        Owned<IPropertyTreeIterator> iter = wu->getElements("Statistics/Statistic");
+        ForEach(*iter)
+        {
+            if (iter->query().getProp("@desc",name.clear()))
+            {
+                if ((name.length()>11)&&(memcmp("Graph graph",name.str(),11)==0))
+                {
+                    unsigned time = (iter->query().getPropInt64("@value") / 1000000);
+                    displayGraphTiming(name.str(), time);
+                }
+            }
+        }
+    }
+    else
+    {
+        Owned<IPropertyTreeIterator> iter = wu->getElements("Timings/Timing");
+        ForEach(*iter)
+        {
+            if (iter->query().getProp("@name",name.clear()))
+            {
+                if ((name.length()>11)&&(memcmp("Graph graph",name.str(),11)==0))
+                {
                     unsigned time = iter->query().getPropInt("@duration");
-                    OUTLOG("\"%s\",%d,%d,%d,%d,%d",name.str(),gn,sn,gid,time,(time/60000));
+                    displayGraphTiming(name.str(), time);
                 }
             }
         }
     }
-
 }
 
 //=============================================================================

ecl/eclagent/eclagent.cpp

@@ -2065,6 +2065,8 @@ void EclAgent::runProcess(IEclProcess *process)
     memsize_t memLimitBytes = (memsize_t)memLimitMB * 1024 * 1024;
     roxiemem::setTotalMemoryLimit(allowHugePages, memLimitBytes, 0, NULL);
 
+    rowManager->setActivityTracking(queryWorkUnit()->getDebugValueBool("traceRoxiePeakMemory", false));
+
     if (debugContext)
         debugContext->checkBreakpoint(DebugStateReady, NULL, NULL);
 
@@ -2080,7 +2082,12 @@ void EclAgent::runProcess(IEclProcess *process)
         queryLibraries.item(i).updateProgress();
 
     if (rowManager)
+    {
+        WorkunitUpdate wu = updateWorkUnit();
+        WuStatisticTarget statsTarget(wu, "eclagent");
+        rowManager->reportPeakStatistics(statsTarget, 0);
         rowManager->getMemoryUsage();//Causes statistics to be written to logfile
+    }
 
 #ifdef _DEBUG_LEAKS
     rowManager.clear();//Early release of rowManager, so activity IDs of leaked blocks are available
@@ -3009,13 +3016,8 @@ char * EclAgent::getDaliServers()
 
 void EclAgent::addTimings()
 {
-    StringBuffer str;
     WorkunitUpdate w = updateWorkUnit();
-    for (unsigned i = 0; i < timer->numSections(); i++)
-    {
-        timer->getSection(i, str.clear());
-        w->setTimerInfo(str.str(), NULL, (unsigned)(timer->getTime(i)/1000000), timer->getCount(i), (unsigned)timer->getMaxTime(i));
-    }
+    updateWorkunitTimings(w, timer, "eclagent");
 }
 
 // eclagent abort monitoring

ecl/eclagent/eclgraph.cpp

@@ -980,10 +980,16 @@ void EclSubGraph::execute(const byte * parentExtract)
         cleanupActivities();
 
         {
+            unsigned elapsed = msTick()-startTime;
+
             Owned<IWorkUnit> wu(agent->updateWorkUnit());
-            StringBuffer timer;
-            timer.append("Graph ").append(parent.queryGraphName()).append(" - ").append(seqNo+1).append(" (").append(id).append(")");
-            wu->setTimerInfo(timer.str(), NULL, msTick()-startTime, 1, 0);
+            StringBuffer timerText;
+            formatGraphTimerLabel(timerText, parent.queryGraphName(), seqNo+1, id);
+
+            //graphn: id
+            StringBuffer wuScope;
+            formatGraphTimerScope(wuScope, parent.queryGraphName(), seqNo+1, id);
+            updateWorkunitTimeStat(wu, "eclagent", wuScope, "time", timerText.str(), milliToNano(elapsed), 1, 0);
         }
     }
     agent->updateWULogfile();//Update workunit logfile name in case of rollover
@@ -1188,6 +1194,7 @@ void EclGraph::execute(const byte * parentExtract)
     if (agent->queryRemoteWorkunit())
         run = new GraphRunningState(*this, 0);
 
+    unsigned startTime = msTick();
     aindex_t lastSink = -1;
     ForEachItemIn(idx, graphs)
     {
@@ -1196,6 +1203,17 @@ void EclGraph::execute(const byte * parentExtract)
             cur.execute(parentExtract);
     }
 
+    {
+        unsigned elapsed = msTick()-startTime;
+
+        Owned<IWorkUnit> wu(agent->updateWorkUnit());
+
+        StringBuffer description;
+        formatGraphTimerLabel(description, queryGraphName(), 0, 0);
+
+        updateWorkunitTimeStat(wu, "eclagent", queryGraphName(), "time", description.str(), milliToNano(elapsed), 1, 0);
+    }
+
     if (run)
     {
         run->complete();

ecl/eclcc/eclcc.cpp

@@ -1079,7 +1079,7 @@ void EclCC::processSingleQuery(EclCompileInstance & instance,
             instance.stats.parseTime = msTick()-startTime;
 
             if (instance.wu->getDebugValueBool("addTimingToWorkunit", true))
-                instance.wu->setTimerInfo("EclServer: parse query", NULL, instance.stats.parseTime, 1, 0);
+                updateWorkunitTimeStat(instance.wu, "eclcc", "workunit", "parse time", NULL, milliToNano(instance.stats.parseTime), 1, 0);
 
             if (optIncludeMeta || optGenerateMeta)
                 instance.generatedMeta.setown(parseCtx.getMetaTree());
@@ -1154,7 +1154,7 @@ void EclCC::processSingleQuery(EclCompileInstance & instance,
     unsigned totalTime = msTick() - startTime;
     instance.stats.generateTime = totalTime - instance.stats.parseTime;
     if (instance.wu->getDebugValueBool("addTimingToWorkunit", true))
-        instance.wu->setTimerInfo("EclServer: totalTime", NULL, totalTime, 1, 0);
+        updateWorkunitTimeStat(instance.wu, "eclcc", "workunit", "totalTime", NULL, milliToNano(totalTime), 1, 0);
 }
 
 void EclCC::processXmlFile(EclCompileInstance & instance, const char *archiveXML)

ecl/eclccserver/eclccserver.cpp

@@ -159,8 +159,13 @@ class EclccCompileThread : public CInterface, implements IPooledThread, implemen
                 if (workunit->getDebugValueBool("addTimingToWorkunit", true))
                 {
                     section.insert(0, "eclcc: ");
-                    unsigned __int64 umax = atoi(max); // in microseconds
-                    workunit->setTimerInfo(section.str(), NULL, atoi(total), atoi(count), umax*1000); // max is stored in nanoseconds
+
+                    unsigned __int64 mval = atoi64(total); // in milliseconds
+                    unsigned __int64 umax = atoi64(max); // in microseconds
+                    unsigned __int64 cnt = atoi64(count);
+                    const char * wuScope = section.str(); // should be different
+                    const char * description = section.str();
+                    updateWorkunitTiming(workunit, "eclcc", wuScope, description, milliToNano(mval), cnt, umax*1000);
                 }
             }
             else
@@ -344,7 +349,7 @@ class EclccCompileThread : public CInterface, implements IPooledThread, implemen
                 queryDllServer().registerDll(realdllname.str(), "Workunit DLL", dllurl.str());
                 time = msTick()-time;
                 if (workunit->getDebugValueBool("addTimingToWorkunit", true))
-                    workunit->setTimerInfo("eclccserver: create workunit", NULL, time, 1, 0);
+                    updateWorkunitTimeStat(workunit, "eclccserver", "workunit", "create workunit", NULL, milliToNano(time), 1, 0);
 
                 workunit->commit();
                 return true;

ecl/hqlcpp/hqlcpp.ipp

@@ -30,9 +30,6 @@
 #include "hqlusage.hpp"
 #include "eclrtl.hpp"
 
-#define DEBUG_TIMER(name, time)                     if (options.addTimingToWorkunit) { timeReporter->addTiming(name, time); }
-#define DEBUG_TIMERX(timeReporter, name, time)      if (timeReporter) { timeReporter->addTiming(name, time); }
-
 #ifdef _DEBUG
 //#define SPOT_POTENTIAL_COMMON_ACTIVITIES
 #endif
@@ -1040,6 +1037,11 @@ public:
     HqlCppOptions const & queryOptions() const { return options; }
     bool needToSerializeToSlave(IHqlExpression * expr) const;
     ITimeReporter * queryTimeReporter() const { return timeReporter; }
+    void updateTimer(const char * name, unsigned timems)
+    {
+        if (options.addTimingToWorkunit)
+            timeReporter->addTiming(name, NULL, timems);
+    }
 
     void updateClusterType();
     bool buildCode(HqlQueryContext & query, const char * embeddedLibraryName, bool isEmbeddedLibrary);

ecl/hqlcpp/hqlcppds.cpp

@@ -1682,7 +1682,7 @@ IHqlExpression * HqlCppTranslator::getResourcedChildGraph(BuildCtx & ctx, IHqlEx
         CompoundSourceTransformer transformer(*this, CSFpreload|csfFlags);
         resourced.setown(transformer.process(resourced));
         checkNormalized(ctx, resourced);
-        DEBUG_TIMER("EclServer: tree transform: optimize disk read", msTick()-time);
+        updateTimer("workunit;tree transform: optimize disk read", msTick()-time);
     }
 
     if (options.optimizeChildGraph)
@@ -1691,7 +1691,7 @@ IHqlExpression * HqlCppTranslator::getResourcedChildGraph(BuildCtx & ctx, IHqlEx
         traceExpression("BeforeOptimizeSub", resourced);
         resourced.setown(optimizeHqlExpression(resourced, getOptimizeFlags()|HOOcompoundproject));
         traceExpression("AfterOptimizeSub", resourced);
-        DEBUG_TIMER("EclServer: optimize graph", msTick()-time);
+        updateTimer("workunit;optimize graph", msTick()-time);
     }
 
     traceExpression("BeforeResourcing Child", resourced);
@@ -1706,7 +1706,7 @@ IHqlExpression * HqlCppTranslator::getResourcedChildGraph(BuildCtx & ctx, IHqlEx
     else
         resourced.setown(resourceNewChildGraph(*this, activeRows, resourced, targetClusterType, graphIdExpr, numResults));
 
-    DEBUG_TIMER("EclServer: resource graph", msTick()-time);
+    updateTimer("workunit;resource graph", msTick()-time);
     checkNormalized(ctx, resourced);
     traceExpression("AfterResourcing Child", resourced);
     
@@ -1717,7 +1717,7 @@ IHqlExpression * HqlCppTranslator::getResourcedChildGraph(BuildCtx & ctx, IHqlEx
     {
         cycle_t time = msTick();
         OwnedHqlExpr optimized = insertImplicitProjects(*this, resourced.get(), options.optimizeSpillProject);
-        DEBUG_TIMER("EclServer: child.implicitprojects", msTick()-time);
+        updateTimer("workunit;child.implicitprojects", msTick()-time);
         traceExpression("AfterResourcedImplicit", optimized);
         checkNormalized(ctx, optimized);
         resourced.set(optimized);
@@ -1728,7 +1728,7 @@ IHqlExpression * HqlCppTranslator::getResourcedChildGraph(BuildCtx & ctx, IHqlEx
 
         CompoundSourceTransformer transformer(*this, csfFlags);
         resourced.setown(transformer.process(resourced));
-        DEBUG_TIMER("EclServer: tree transform: optimize disk read", msTick()-time);
+        updateTimer("workunit;tree transform: optimize disk read", msTick()-time);
     }
 
     //Now call the optimizer again - the main purpose is to move projects over limits and into compound index/disk reads
@@ -1738,7 +1738,7 @@ IHqlExpression * HqlCppTranslator::getResourcedChildGraph(BuildCtx & ctx, IHqlEx
         traceExpression("BeforeOptimize2", resourced);
         resourced.setown(optimizeHqlExpression(resourced, getOptimizeFlags()|HOOcompoundproject));
         traceExpression("AfterOptimize2", resourced);
-        DEBUG_TIMER("EclServer: optimize graph", msTick()-time);
+        updateTimer("workunit;optimize graph", msTick()-time);
     }
 
     if (options.paranoidCheckNormalized || options.paranoidCheckDependencies)

ecl/hqlcpp/hqlecl.cpp

@@ -436,7 +436,10 @@ bool HqlDllGenerator::generateCode(HqlQueryContext & query)
 
         doExpand(translator);
         if (wu->getDebugValueBool("addTimingToWorkunit", true))
-            wu->setTimerInfo("EclServer: generate code", NULL, msTick()-time, 1, 0);
+        {
+            unsigned elapsed = msTick()-time;
+            updateWorkunitTimeStat(wu, "eclcc", "workunit", "GenerateCpp", "eclcc: generate code", milliToNano(elapsed), 1, 0);
+        }
 
         wu->commit();
         addWorkUnitAsResource();
@@ -484,7 +487,7 @@ void HqlDllGenerator::doExpand(HqlCppTranslator & translator)
 
     unsigned endExpandTime = msTick();
     if (wu->getDebugValueBool("addTimingToWorkunit", true))
-        wu->setTimerInfo("EclServer: write c++", NULL, endExpandTime-startExpandTime, 1, 0);
+        updateWorkunitTimeStat(wu, "eclcc", "workunit", "writeCpp", "eclcc: Time to write c++", milliToNano(endExpandTime-startExpandTime), 1, 0);
 }
 
 bool HqlDllGenerator::abortRequested()
@@ -541,7 +544,7 @@ bool HqlDllGenerator::doCompile(ICppCompiler * compiler)
         PrintLog("Failed to compile %s", wuname);
     time = msTick()-time;
     if (wu->getDebugValueBool("addTimingToWorkunit", true))
-        wu->setTimerInfo("EclServer: compile code", NULL, time, 1, 0);
+        updateWorkunitTimeStat(wu, "eclcc", "workunit", "compile", "eclcc: compile code", milliToNano(time), 1, 0);
 
     //Keep the files if there was a compile error.
     if (ok && deleteGenerated)

ecl/hqlcpp/hqlhtcpp.cpp

@@ -5548,8 +5548,7 @@ bool HqlCppTranslator::buildCode(HqlQueryContext & query, const char * embeddedL
         if (!isEmbeddedLibrary)
             updateClusterType();
 
-        if (options.addTimingToWorkunit)
-            wu()->setTimerInfo("EclServer: tree transform", NULL, msTick()-time, 1, 0);
+        updateTimer("workunit;tree transform", msTick()-time);
 
         if (insideLibrary())
         {
@@ -5596,8 +5595,7 @@ bool HqlCppTranslator::buildCode(HqlQueryContext & query, const char * embeddedL
             StringBuffer complexityText;
             complexityText.append(getComplexity(workflow));
             wu()->setDebugValue("__Calculated__Complexity__", complexityText, true);
-            if (options.addTimingToWorkunit)
-                wu()->setTimerInfo("EclServer: calculate complexity", NULL, msTick()-time, 1, 0);
+            updateTimer("workunit;calculate complexity", msTick()-time);
         }
     }
 
@@ -5677,7 +5675,7 @@ bool HqlCppTranslator::buildCpp(IHqlCppInstance & _code, HqlQueryContext & query
         {
             cycle_t time = msTick();
             peepholeOptimize(*code, *this);
-            DEBUG_TIMER("EclServer: peephole optimize", msTick()-time);
+            updateTimer("workunit;peephole optimize", msTick()-time);
         }
     }
     catch (IException * e)
@@ -5699,15 +5697,14 @@ bool HqlCppTranslator::buildCpp(IHqlCppInstance & _code, HqlQueryContext & query
     return true;
 }
 
-
 class WuTimingUpdater : implements ITimeReportInfo
 {
 public:
     WuTimingUpdater(IWorkUnit * _wu) { wu = _wu; }
 
-    virtual void report(const char *name, const __int64 totaltime, const __int64 maxtime, const unsigned count)
+    virtual void report(const char * scope, const char * description, const __int64 totaltime, const __int64 maxtime, const unsigned count)
     {
-        wu->setTimerInfo(name, NULL, (unsigned)totaltime, count, (unsigned)maxtime);
+        updateWorkunitTiming(wu, "eclcc", scope, description, milliToNano(totaltime), count, milliToNano(maxtime));
     }
 
 protected:
@@ -9005,7 +9002,7 @@ IHqlExpression * HqlCppTranslator::optimizeCompoundSource(IHqlExpression * expr,
 
     CompoundSourceTransformer transformer(*this, flags);
     OwnedHqlExpr ret = transformer.process(expr);
-    DEBUG_TIMER("EclServer: tree transform: optimize disk read", msTick()-time);
+    updateTimer("workunit;tree transform: optimize disk read", msTick()-time);
     return ret.getClear();
 }
 
@@ -9020,7 +9017,7 @@ IHqlExpression * HqlCppTranslator::optimizeGraphPostResource(IHqlExpression * ex
     {
         cycle_t time = msTick();
         OwnedHqlExpr optimized = insertImplicitProjects(*this, resourced.get(), options.optimizeSpillProject);
-        DEBUG_TIMER("EclServer: implicit projects", msTick()-time);
+        updateTimer("workunit;implicit projects", msTick()-time);
         traceExpression("AfterResourcedImplicit", resourced);
         checkNormalized(optimized);
 
@@ -9035,7 +9032,7 @@ IHqlExpression * HqlCppTranslator::optimizeGraphPostResource(IHqlExpression * ex
         traceExpression("BeforeOptimize2", resourced);
         resourced.setown(optimizeHqlExpression(resourced, getOptimizeFlags()|HOOcompoundproject));
         traceExpression("AfterOptimize2", resourced);
-        DEBUG_TIMER("EclServer: optimize graph", msTick()-time);
+        updateTimer("workunit;optimize graph", msTick()-time);
     }
     resourced.setown(optimizeCompoundSource(resourced, csfFlags));
     return resourced.getClear();
@@ -9067,7 +9064,7 @@ IHqlExpression * HqlCppTranslator::getResourcedGraph(IHqlExpression * expr, IHql
         resourced.setown(optimizeHqlExpression(resourced, optFlags|HOOfiltersharedproject));
         //have the following on an "aggressive fold" option?  If no_selects extract constants it can be quite impressive (jholt22.hql)
         //resourced.setown(foldHqlExpression(resourced));
-        DEBUG_TIMER("EclServer: optimize graph", msTick()-time);
+        updateTimer("workunit;optimize graph", msTick()-time);
     }
     traceExpression("AfterOptimize", resourced);
     checkNormalized(resourced);
@@ -9095,7 +9092,7 @@ IHqlExpression * HqlCppTranslator::getResourcedGraph(IHqlExpression * expr, IHql
     if (!resourced)
         return NULL;
 
-    DEBUG_TIMER("EclServer: resource graph", msTick()-time);
+    updateTimer("workunit;resource graph", msTick()-time);
     traceExpression("AfterResourcing", resourced);
 
     if (options.regressionTest)
@@ -9118,7 +9115,7 @@ IHqlExpression * HqlCppTranslator::getResourcedGraph(IHqlExpression * expr, IHql
         CompoundActivityTransformer transformer(targetClusterType);
         resourced.setown(transformer.transformRoot(resourced));
         traceExpression("AfterCompoundActivity", resourced);
-        DEBUG_TIMER("EclServer: tree transform: compound activity", msTick()-time);
+        updateTimer("workunit;tree transform: compound activity", msTick()-time);
     }
 
     resourced.setown(spotTableInvariant(resourced));
@@ -18172,7 +18169,7 @@ void HqlCppTranslator::spotGlobalCSE(WorkflowItem & curWorkflow)
     {
         unsigned startTime = msTick();
         spotGlobalCSE(curWorkflow.queryExprs());
-        DEBUG_TIMER("EclServer: tree transform: spot global cse", msTick()-startTime);
+        updateTimer("workunit;tree transform: spot global cse", msTick()-startTime);
     }
 }
 
@@ -18447,7 +18444,7 @@ void HqlCppTranslator::pickBestEngine(HqlExprArray & exprs)
         // if we got this far, thor not required
         setTargetClusterType(HThorCluster);
         DBGLOG("Thor query redirected to hthor instead");
-        DEBUG_TIMER("EclServer: tree transform: pick engine", msTick()-time);
+        updateTimer("workunit;tree transform: pick engine", msTick()-time);
     }
 }
 
@@ -18469,7 +18466,7 @@ void HqlCppTranslator::pickBestEngine(WorkflowArray & workflow)
         }
         setTargetClusterType(HThorCluster);
         DBGLOG("Thor query redirected to hthor instead");
-        DEBUG_TIMER("EclServer: tree transform: pick engine", msTick()-time);
+        updateTimer("workunit;tree transform: pick engine", msTick()-time);
     }
 }
 

ecl/hqlcpp/hqlnlp.cpp

@@ -716,7 +716,7 @@ ABoundActivity * HqlCppTranslator::doBuildActivityParse(BuildCtx & ctx, IHqlExpr
     doBuildParseSearchText(instance->startctx, expr);
     doBuildParseValidators(instance->nestedctx, expr);
     doBuildParseExtra(instance->startctx, expr);
-    DEBUG_TIMER("EclServer: Generate PARSE: Prepare", msTick()-startPrepareTime);
+    updateTimer("workunit;Generate PARSE: Prepare", msTick()-startPrepareTime);
     
     MemoryBuffer buffer;
     unsigned startCompileTime = msTick();
@@ -726,7 +726,7 @@ ABoundActivity * HqlCppTranslator::doBuildActivityParse(BuildCtx & ctx, IHqlExpr
         WARNING1(HQLWRN_GrammarIsAmbiguous, instance->activityId);
 
     doBuildParseCompiled(instance->classctx, buffer);
-    DEBUG_TIMER("EclServer: Generate PARSE: Compile", msTick()-startCompileTime);
+    updateTimer("workunit;Generate PARSE: Compile", msTick()-startCompileTime);
 
     nlpParse->buildProductions(*this, instance->classctx, instance->startctx);
 
@@ -759,7 +759,7 @@ ABoundActivity * HqlCppTranslator::doBuildActivityParse(BuildCtx & ctx, IHqlExpr
     nlpParse = NULL;
     buildInstanceSuffix(instance);
     buildConnectInputOutput(ctx, instance, boundDataset, 0, 0);
-    DEBUG_TIMER("EclServer: Generate PARSE", msTick()-startTime);
+    updateTimer("workunit;Generate PARSE", msTick()-startTime);
 
     return instance->getBoundActivity();
 }

ecl/hqlcpp/hqlregex.cpp

@@ -2539,7 +2539,7 @@ void RegexContext::buildStructure()
     root->setRegexOwn(rootRegex);
     named.append(*LINK(root));
 
-    DEBUG_TIMERX(timeReporter, "EclServer: Generate PARSE: Create Structure", msTick()-startTime);
+    updateTimer("workunit;Generate PARSE: Create Structure", msTick()-startTime);
 }
 
 void RegexContext::expandRecursion()
@@ -2606,7 +2606,7 @@ void RegexContext::optimizePattern()
         }
     }
     optimizeSpotDFA();
-    DEBUG_TIMERX(timeReporter, "EclServer: Generate PARSE: Optimize", msTick()-startTime);
+    updateTimer("workunit;Generate PARSE: Optimize", msTick()-startTime);
 }
 
 
@@ -2643,7 +2643,7 @@ void RegexContext::analysePattern()
     ForEachItemIn(idx3, named)
         named.item(idx3).generateDFAs();
 
-    DEBUG_TIMERX(timeReporter, "EclServer: Generate PARSE: Analyse", msTick()-startTime);
+    updateTimer("workunit;Generate PARSE: Analyse", msTick()-startTime);
 }
 
 
@@ -2664,7 +2664,7 @@ void RegexContext::generateRegex()
     parser.grammar.set(root->queryRootPattern());
     parser.minPatternLength = root->getMinLength();
 
-    DEBUG_TIMERX(timeReporter, "EclServer: Generate PARSE: Generate", msTick()-startTime);
+    updateTimer("workunit;Generate PARSE: Generate", msTick()-startTime);
 }
 
 
@@ -2745,6 +2745,12 @@ void RegexContext::generateLexer(IDfaPattern * builder)
     lexerRoot->generateDFA(builder);
 }
 
+void RegexContext::updateTimer(const char * name, unsigned timems)
+{
+    if (timeReporter)
+        timeReporter->addTiming(name, NULL, timems);
+}
+
 /*
 ToDo:
 

ecl/hqlcpp/hqlregex.ipp

@@ -331,6 +331,7 @@ protected:
     void insertSeparators();
     void optimizePattern();
     void optimizeSpotDFA();
+    void updateTimer(const char * name, unsigned timems);
     HqlNamedRegex * queryNamed(IHqlExpression * defn, IAtom * name, node_operator op, bool caseSensitive);
     HqlNamedRegex * createNamed(IHqlExpression * expr, IAtom * name, node_operator op, bool caseSensitive);
 

ecl/hqlcpp/hqlttcpp.cpp

@@ -3626,7 +3626,7 @@ void HqlCppTranslator::convertLogicalToActivities(WorkflowItem & curWorkflow)
         transformer.transformRoot(exprs, transformed);
 
         replaceArray(exprs, transformed);
-        DEBUG_TIMER("EclServer: tree transform: convert logical", msTick()-time);
+        updateTimer("workunit;tree transform: convert logical", msTick()-time);
     }
 
     if (queryOptions().normalizeLocations)
@@ -10153,7 +10153,7 @@ void normalizeAnnotations(HqlCppTranslator & translator, HqlExprArray & exprs)
     normalizer.analyseArray(exprs, 0);
     normalizer.transformRoot(exprs, transformed);
     replaceArray(exprs, transformed);
-    DEBUG_TIMERX(translator.queryTimeReporter(), "EclServer: tree transform: normalize.annotations", msTick()-time);
+    translator.updateTimer("workunit;tree transform: normalize.annotations", msTick()-time);
 }
 
 //---------------------------------------------------------------------------
@@ -12568,7 +12568,7 @@ void normalizeHqlTree(HqlCppTranslator & translator, HqlExprArray & exprs)
         replaceArray(exprs, transformed);
         seenForceLocal = normalizer.querySeenForceLocal();
         seenLocalUpload = normalizer.querySeenLocalUpload();
-        DEBUG_TIMERX(translator.queryTimeReporter(), "EclServer: tree transform: normalize.initial", msTick()-time);
+        translator.updateTimer("workunit;tree transform: normalize.initial", msTick()-time);
     }
 
     if (translator.queryOptions().constantFoldPostNormalize)
@@ -12577,7 +12577,7 @@ void normalizeHqlTree(HqlCppTranslator & translator, HqlExprArray & exprs)
         HqlExprArray transformed;
         quickFoldExpressions(transformed, exprs, NULL, 0);
         replaceArray(exprs, transformed);
-        DEBUG_TIMERX(translator.queryTimeReporter(), "EclServer: tree transform: normalize.fold", msTick()-time);
+        translator.updateTimer("workunit;tree transform: normalize.fold", msTick()-time);
     }
 
     translator.traceExpressions("before scope tag", exprs);
@@ -12588,7 +12588,7 @@ void normalizeHqlTree(HqlCppTranslator & translator, HqlExprArray & exprs)
         HqlExprArray transformed;
         normalizer.transformRoot(exprs, transformed);
         replaceArray(exprs, transformed);
-        DEBUG_TIMERX(translator.queryTimeReporter(), "EclServer: tree transform: normalize.scope", msTick()-time);
+        translator.updateTimer("workunit;tree transform: normalize.scope", msTick()-time);
         normalizer.reportWarnings();
     }
 
@@ -12603,7 +12603,7 @@ void normalizeHqlTree(HqlCppTranslator & translator, HqlExprArray & exprs)
         HqlExprArray transformed;
         transformer.transformArray(exprs, transformed);
         replaceArray(exprs, transformed);
-        DEBUG_TIMERX(translator.queryTimeReporter(), "EclServer: tree transform: normalize.linkedChildRows", msTick()-time);;
+        translator.updateTimer("workunit;tree transform: normalize.linkedChildRows", msTick()-time);;
     }
 
     if (seenLocalUpload)
@@ -12832,13 +12832,13 @@ bool HqlCppTranslator::transformGraphForGeneration(HqlQueryContext & query, Work
 
     unsigned timeCall = msTick();
     expandDelayedFunctionCalls(queryErrors(), exprs);
-    DEBUG_TIMER("EclServer: tree transform: expand delayed calls", msTick()-timeCall);
+    updateTimer("workunit;tree transform: expand delayed calls", msTick()-timeCall);
 
 
     unsigned time1 = msTick();
     traceExpressions("before normalize", exprs);
     normalizeHqlTree(*this, exprs);
-    DEBUG_TIMER("EclServer: tree transform: normalize", msTick()-time1);
+    updateTimer("workunit;tree transform: normalize", msTick()-time1);
 
     if (wu()->getDebugValueBool("dumpIR", false))
         EclIR::dbglogIR(exprs);
@@ -12868,7 +12868,7 @@ bool HqlCppTranslator::transformGraphForGeneration(HqlQueryContext & query, Work
     {
         unsigned startTime = msTick();
         substituteClusterSize(exprs);
-        DEBUG_TIMER("EclServer: tree transform: substituteClusterSize", msTick()-startTime);
+        updateTimer("workunit;tree transform: substituteClusterSize", msTick()-startTime);
     }
 
     {
@@ -12882,7 +12882,7 @@ bool HqlCppTranslator::transformGraphForGeneration(HqlQueryContext & query, Work
             foldOptions = options.globalFoldOptions;
         foldHqlExpression(folded, exprs, foldOptions);
         replaceArray(exprs, folded);
-        DEBUG_TIMER("EclServer: tree transform: global fold", msTick()-startTime);
+        updateTimer("workunit;tree transform: global fold", msTick()-startTime);
     }
 
     traceExpressions("after global fold", exprs);
@@ -12894,7 +12894,7 @@ bool HqlCppTranslator::transformGraphForGeneration(HqlQueryContext & query, Work
         HqlExprArray folded;
         optimizeHqlExpression(folded, exprs, HOOfold);
         replaceArray(exprs, folded);
-        DEBUG_TIMER("EclServer: tree transform: global optimize", msTick()-startTime);
+        updateTimer("workunit;tree transform: global optimize", msTick()-startTime);
     }
 
     traceExpressions("alloc", exprs);
@@ -12909,7 +12909,7 @@ bool HqlCppTranslator::transformGraphForGeneration(HqlQueryContext & query, Work
 
     traceExpressions("workflow", workflow);
     checkNormalized(workflow);
-    DEBUG_TIMER("EclServer: tree transform: stored results", msTick()-time4);
+    updateTimer("workunit;tree transform: stored results", msTick()-time4);
 
     if (outputLibrary && workflow.ordinality() > 1)
     {
@@ -12937,7 +12937,7 @@ bool HqlCppTranslator::transformGraphForGeneration(HqlQueryContext & query, Work
             unsigned time = msTick();
             LeftRightTransformer normalizer;
             normalizer.process(curWorkflow.queryExprs());
-            DEBUG_TIMERX(queryTimeReporter(), "EclServer: tree transform: left right", msTick()-time);
+            updateTimer("workunit;tree transform: left right", msTick()-time);
             //traceExpressions("after implicit alias", workflow);
         }
 #endif
@@ -12947,21 +12947,21 @@ bool HqlCppTranslator::transformGraphForGeneration(HqlQueryContext & query, Work
             unsigned time = msTick();
             ImplicitAliasTransformer normalizer;
             normalizer.process(curWorkflow.queryExprs());
-            DEBUG_TIMERX(queryTimeReporter(), "EclServer: tree transform: implicit alias", msTick()-time);
+            updateTimer("workunit;tree transform: implicit alias", msTick()-time);
             //traceExpressions("after implicit alias", workflow);
         }
 
         {
             unsigned startTime = msTick();
             hoistNestedCompound(*this, curWorkflow.queryExprs());
-            DEBUG_TIMER("EclServer: tree transform: hoist nested compound", msTick()-startTime);
+            updateTimer("workunit;tree transform: hoist nested compound", msTick()-startTime);
         }
 
         if (options.optimizeNestedConditional)
         {
             cycle_t time = msTick();
             optimizeNestedConditional(curWorkflow.queryExprs());
-            DEBUG_TIMER("EclServer: optimize nested conditional", msTick()-time);
+            updateTimer("workunit;optimize nested conditional", msTick()-time);
             traceExpressions("nested", curWorkflow);
             checkNormalized(curWorkflow);
         }
@@ -12971,20 +12971,20 @@ bool HqlCppTranslator::transformGraphForGeneration(HqlQueryContext & query, Work
         {
             unsigned startTime = msTick();
             optimizeActivities(curWorkflow.queryExprs(), !targetThor(), options.optimizeNonEmpty);
-            DEBUG_TIMER("EclServer: tree transform: optimize activities", msTick()-startTime);
+            updateTimer("workunit;tree transform: optimize activities", msTick()-startTime);
         }
         checkNormalized(curWorkflow);
 
         unsigned time5 = msTick();
         migrateExprToNaturalLevel(curWorkflow, wu(), *this);       // Ensure expressions are evaluated at the best level - e.g., counts moved to most appropriate level.
-        DEBUG_TIMER("EclServer: tree transform: migrate", msTick()-time5);
+        updateTimer("workunit;tree transform: migrate", msTick()-time5);
         //transformToAliases(exprs);
         traceExpressions("migrate", curWorkflow);
         checkNormalized(curWorkflow);
 
         unsigned time2 = msTick();
         markThorBoundaries(curWorkflow);                                               // work out which engine is going to perform which operation.
-        DEBUG_TIMER("EclServer: tree transform: thor hole", msTick()-time2);
+        updateTimer("workunit;tree transform: thor hole", msTick()-time2);
         traceExpressions("boundary", curWorkflow);
         checkNormalized(curWorkflow);
 
@@ -12992,14 +12992,14 @@ bool HqlCppTranslator::transformGraphForGeneration(HqlQueryContext & query, Work
         {
             cycle_t time = msTick();
             insertImplicitProjects(*this, curWorkflow.queryExprs());
-            DEBUG_TIMER("EclServer: global implicit projects", msTick()-time);
+            updateTimer("workunit;global implicit projects", msTick()-time);
             traceExpressions("implicit", curWorkflow);
             checkNormalized(curWorkflow);
         }
 
         unsigned time3 = msTick();
         normalizeResultFormat(curWorkflow, options);
-        DEBUG_TIMER("EclServer: tree transform: normalize result", msTick()-time3);
+        updateTimer("workunit;tree transform: normalize result", msTick()-time3);
         traceExpressions("results", curWorkflow);
         checkNormalized(curWorkflow);
 
@@ -13013,7 +13013,7 @@ bool HqlCppTranslator::transformGraphForGeneration(HqlQueryContext & query, Work
         {
             unsigned startTime = msTick();
             mergeThorGraphs(curWorkflow, options.resourceConditionalActions, options.resourceSequential);          // reduces number of graphs sent to thor
-            DEBUG_TIMER("EclServer: tree transform: merge thor", msTick()-startTime);
+            updateTimer("workunit;tree transform: merge thor", msTick()-startTime);
         }
 
         traceExpressions("merged", curWorkflow);
@@ -13030,7 +13030,7 @@ bool HqlCppTranslator::transformGraphForGeneration(HqlQueryContext & query, Work
         {
             unsigned startTime = msTick();
             mergeThorGraphs(curWorkflow, options.resourceConditionalActions, options.resourceSequential);
-            DEBUG_TIMER("EclServer: tree transform: merge thor", msTick()-startTime);
+            updateTimer("workunit;tree transform: merge thor", msTick()-startTime);
         }
         checkNormalized(curWorkflow);
 
@@ -13058,7 +13058,7 @@ bool HqlCppTranslator::transformGraphForGeneration(HqlQueryContext & query, Work
         {
             unsigned startTime = msTick();
             checkDependencyConsistency(curWorkflow.queryExprs());
-            DEBUG_TIMER("EclServer: tree transform: check dependency", msTick()-startTime);
+            updateTimer("workunit;tree transform: check dependency", msTick()-startTime);
         }
 
         traceExpressions("end transformGraphForGeneration", curWorkflow);

ecl/hthor/hthor.ipp

@@ -1085,7 +1085,7 @@ class CSimpleSorterBase : public CInterface, public ISorter
 {
 public:
     CSimpleSorterBase(ICompare * _compare, roxiemem::IRowManager * _rowManager, size32_t _initialSize, size32_t _commitDelta) : compare(_compare), finger(0), rowManager(_rowManager),
-        rowsToSort(_rowManager, _initialSize, _commitDelta) {}
+        rowsToSort(_rowManager, _initialSize, _commitDelta, UNKNOWN_ROWSET_ID) {}
     virtual ~CSimpleSorterBase()                            { killSorted(); }
     IMPLEMENT_IINTERFACE;
     virtual bool addRow(const void * next)                  { return rowsToSort.append(next); }
@@ -1106,7 +1106,7 @@ public:
     virtual const DynamicRoxieOutputRowArray & getRowArray()     { return rowsToSort; }
     virtual void flushRows()                                { rowsToSort.flush(); }
     virtual size32_t numCommitted() const                   { return rowsToSort.numCommitted(); }
-    virtual void setActivityId(unsigned _activityId)        { activityId = _activityId; }
+    virtual void setActivityId(unsigned _activityId)        { activityId = _activityId; rowsToSort.setAllocatorId(_activityId); }
 
 protected:
     roxiemem::IRowManager * rowManager;

ecllibrary/std/system/Workunit.ecl

@@ -16,7 +16,9 @@ EXPORT FileReadRecord := lib_workunitservices.WsFileRead;
 
 EXPORT FileWrittenRecord := lib_workunitservices.WsFileWritten;
 
-EXPORT TimingRecord := WsTiming;
+EXPORT TimingRecord := lib_workunitservices.WsTiming;
+
+EXPORT StatisticRecord := lib_workunitservices.WsStatistic;
 
 /*
  * Returns a Boolean indication whether the work unit exists.
@@ -135,4 +137,14 @@ EXPORT dataset(FileWrittenRecord) WorkunitFilesWritten(varstring wuid) :=
 EXPORT dataset(TimingRecord) WorkunitTimings(varstring wuid) :=
   lib_workunitservices.WorkUnitServices.WorkunitTimings(wuid); 
 
+/*
+ * Returns the statistics from a particular workunit.
+ *
+ * @param wuid          the name of the workunit
+*/
+
+EXPORT dataset(StatisticRecord) WorkunitStatistics(varstring wuid, boolean includeActivities = false) :=
+  lib_workunitservices.WorkUnitServices.WorkunitStatistics(wuid, includeActivities);
+
+
 END;

esp/bindings/http/platform/httpprot.cpp

@@ -491,7 +491,7 @@ CPooledHttpThread::~CPooledHttpThread()
 
 void CPooledHttpThread::main()
 {
-    MTimeSection timing(NULL, "CPooledHttpThread::main()");
+    TimeSection timing("CPooledHttpThread::main()");
     Owned<CEspHttpServer> httpserver;
     
     Owned<ISecureSocket> secure_sock;

esp/clients/LoggingClient/LogThread.cpp

@@ -822,7 +822,7 @@ void CLogThread::checkRollOver()
             localtime_r(&tNow, &m_startTime);  // reset the start time for next rollover check
             int numNewArrivals = m_pServiceLog.ordinality();
             {
-                MTimeSection mt(NULL, "Tank file rollover");
+                TimeSection mt("Tank file rollover");
                 m_LogFailSafe->SafeRollover();
             }
             if(numNewArrivals > 0)

esp/services/ws_smc/ws_smcService.hpp

@@ -79,7 +79,6 @@ class CWsSMCEx : public CWsSMC
 {
     long m_counter;
     CTpWrapper m_ClusterStatus;
-    CWUXMLInfo m_WuidInfo;
 
     StringBuffer m_ChatURL;
     StringBuffer m_Banner;

esp/services/ws_workunits/ws_workunitsHelpers.cpp

@@ -368,20 +368,71 @@ void WsWuInfo::getTimers(IEspECLWorkunit &info, unsigned flags)
         StringBuffer totalThorTimeValue;
         unsigned totalThorTimerCount = 0; //Do we need this?
 
+        //This should be switched to using getStatistics() once backward compatibility is no longer required. (5.0?)
+        //The code inside the #if 0 is equivalent.
         IArrayOf<IEspECLTimer> timers;
+#if 0
+        Owned<IConstWUStatisticIterator> it = &cw->getStatistics();
+        ForEach(*it)
+        {
+            IConstWUStatistic & cur = it->query();
+            //Only interested in timings...
+            if (cur.getKind() != SMEASURE_TIME_NS)
+                continue;
+
+            SCMStringBuffer name;
+            cur.getDescription(name);
+            name.s.replace('_', ' ');
+
+            unsigned __int64 count = cur.getCount();
+            unsigned __int64 duration = nanoToMilli(cur.getValue());
+            StringBuffer fd;
+            formatDuration(fd, duration);
+
+            if (strieq(name.str(), TOTALTHORTIME))
+            {
+                totalThorTimeValue = fd;
+                totalThorTimerCount = count;
+                continue;
+            }
+
+            Owned<IEspECLTimer> t= createECLTimer("","");
+            t->setName(name.str());
+            t->setValue(fd.str());
+            t->setCount(count);
+
+            if (version > 1.19)
+            {
+                StringAttr graphName;
+                unsigned graphNum;
+                unsigned subGraphNum;
+                unsigned subId;
+                if (parseGraphTimerLabel(name.str(), graphName, graphNum, subGraphNum, subId))
+                {
+                    if (graphName.length() > 0)
+                    {
+                        t->setGraphName(graphName);
+                    }
+                    if (subId > 0)
+                    {
+                        t->setSubGraphId((int)subId);
+                    }
+                }
+            }
+
+            timers.append(*t.getLink());
+        }
+#else
         Owned<IStringIterator> it = &cw->getTimers();
         ForEach(*it)
         {
             SCMStringBuffer name;
             it->str(name);
-            SCMStringBuffer value;
-            unsigned count = cw->getTimerCount(name.str(), NULL);
-            unsigned duration = cw->getTimerDuration(name.str(), NULL);
+            unsigned count = cw->getTimerCount(name.str());
+            unsigned duration = cw->getTimerDuration(name.str());
             StringBuffer fd;
             formatDuration(fd, duration);
-            for (unsigned i = 0; i < name.length(); i++)
-             if (name.s.charAt(i)=='_')
-                 name.s.setCharAt(i, ' ');
+            name.s.replace('_', ' ');
 
             if (strieq(name.str(), TOTALTHORTIME))
             {
@@ -397,14 +448,15 @@ void WsWuInfo::getTimers(IEspECLWorkunit &info, unsigned flags)
 
             if (version > 1.19)
             {
-                StringBuffer graphName;
+                StringAttr graphName;
+                unsigned graphNum;
                 unsigned subGraphNum;
-                unsigned __int64 subId;
-                if (parseGraphTimerLabel(name.str(), graphName, subGraphNum, subId))
+                unsigned subId;
+                if (parseGraphTimerLabel(name.str(), graphName, graphNum, subGraphNum, subId))
                 {
                     if (graphName.length() > 0)
                     {
-                        t->setGraphName(graphName.str());
+                        t->setGraphName(graphName);
                     }
                     if (subId > 0)
                     {
@@ -415,6 +467,7 @@ void WsWuInfo::getTimers(IEspECLWorkunit &info, unsigned flags)
 
             timers.append(*t.getLink());
         }
+#endif
 
         if (totalThorTimeValue.length() > 0)
         {
@@ -655,42 +708,21 @@ void WsWuInfo::getGraphInfo(IEspECLWorkunit &info, unsigned flags)
      if (version > 1.01)
      {
         info.setHaveSubGraphTimings(false);
-        StringBuffer xpath("/WorkUnits/");
-        xpath.append(wuid.str());
-        Owned<IRemoteConnection> conn = querySDS().connect(xpath.str(), myProcessSession(), 0, 5*60*1000);
-        if (!conn)
-        {
-            DBGLOG("Cannot connect to SDS");
-            info.setGraphsDesc("Cannot connect to SDS");
-            return;
-        }
-        IPropertyTree *wpt = conn->queryRoot();
-        if (!wpt)
-        {
-            DBGLOG("Cannot get data from SDS");
-            info.setGraphsDesc("Cannot get data from SDS");
-            return;
-        }
 
-        Owned<IPropertyTreeIterator> iter = wpt->getElements("Timings/Timing");
-        StringBuffer name;
-        IArrayOf<IConstECLTimingData> timingdatarray;
-        ForEach(*iter)
+        Owned<IStringIterator> times = &cw->getTimers();
+        ForEach(*times)
         {
-            if (iter->query().getProp("@name",name.clear()))
+            SCMStringBuffer name;
+            times->str(name);
+
+            StringAttr graphName;
+            unsigned graphNum;
+            unsigned subGraphNum;
+            unsigned subId;
+            if (parseGraphTimerLabel(name.str(), graphName, graphNum, subGraphNum, subId))
             {
-                if ((name.length()>11) && (strncmp("Graph graph", name.str(), 11)==0))
-                {
-                    unsigned gn;
-                    const char *s = getGraphNum(name.str()+11, gn);
-                    unsigned sn;
-                    s = getGraphNum(s,sn);
-                    if (gn && sn)
-                    {
-                        info.setHaveSubGraphTimings(true);
-                        break;
-                    }
-                }
+                info.setHaveSubGraphTimings(true);
+                break;
             }
         }
      }
@@ -756,48 +788,29 @@ void WsWuInfo::getGraphInfo(IEspECLWorkunit &info, unsigned flags)
 
 void WsWuInfo::getGraphTimingData(IArrayOf<IConstECLTimingData> &timingData, unsigned flags)
 {
-    StringBuffer xpath("/WorkUnits/");
-    xpath.append(wuid.str());
-
-    Owned<IRemoteConnection> conn = querySDS().connect(xpath.str(), myProcessSession(), 0, 5*60*1000);
-    if (!conn)
+    Owned<IStringIterator> times = &cw->getTimers();
+    ForEach(*times)
     {
-        DBGLOG("Could not connect to SDS");
-        throw MakeStringException(ECLWATCH_CANNOT_CONNECT_DALI, "Cannot connect to dali server.");
-    }
+        SCMStringBuffer name;
+        times->str(name);
 
-    IPropertyTree *wpt = conn->queryRoot();
-    Owned<IPropertyTreeIterator> iter = wpt->getElements("Timings/Timing");
+        StringAttr graphName;
+        unsigned graphNum;
+        unsigned subGraphNum;
+        unsigned subId;
 
-    ForEach(*iter)
-    {
-        StringBuffer name;
-        if (iter->query().getProp("@name", name))
+        if (parseGraphTimerLabel(name.str(), graphName, graphNum, subGraphNum, subId))
         {
-            if ((name.length()>11)&&(strncmp("Graph graph", name.str(), 11)==0))
-            {
-                unsigned gn;
-                const char *s = getGraphNum(name.str(),gn);
-                unsigned sn;
-                s = getGraphNum(s, sn);
-                if (gn && sn)
-                {
-                    const char *gs = strchr(name.str(),'(');
-                    unsigned gid = 0;
-                    if (gs)
-                        getGraphNum(gs+1, gid);
-                    unsigned time = iter->query().getPropInt("@duration");
-
-                    Owned<IEspECLTimingData> g = createECLTimingData();
-                    g->setName(name.str());
-                    g->setGraphNum(gn);
-                    g->setSubGraphNum(sn);
-                    g->setGID(gid);
-                    g->setMS(time);
-                    g->setMin(time/60000);
-                    timingData.append(*g.getClear());
-                }
-            }
+            unsigned time = cw->getTimerDuration(name.str());
+
+            Owned<IEspECLTimingData> g = createECLTimingData();
+            g->setName(name.str());
+            g->setGraphNum(graphNum);
+            g->setSubGraphNum(subGraphNum);
+            g->setGID(subId);
+            g->setMS(time);
+            g->setMin(time/60000);
+            timingData.append(*g.getClear());
         }
     }
 }
@@ -879,7 +892,7 @@ void WsWuInfo::getCommon(IEspECLWorkunit &info, unsigned flags)
     if (version > 1.27)
     {
         StringBuffer totalThorTimeStr;
-        unsigned totalThorTimeMS = cw->getTimerDuration(TOTALTHORTIME, NULL);
+        unsigned totalThorTimeMS = cw->getTimerDuration(TOTALTHORTIME);
         formatDuration(totalThorTimeStr, totalThorTimeMS);
         info.setTotalThorTime(totalThorTimeStr.str());
     }

esp/smc/SMCLib/WUXMLInfo.cpp

@@ -308,9 +308,12 @@ bool CWUXMLInfo::buildXmlResultList(IConstWorkUnit &wu,IPropertyTree& XMLStructu
     return true;
 }
 
+//GH: MORE - this whole class looks as if it is unused, and should be deleted.  If that is not true the
+//following function needs to be rewritten to take into account the statistics
 bool CWUXMLInfo::buildXmlTimimgList(IConstWorkUnit &wu,IPropertyTree& XMLStructure)
 {
     try{
+
         IPropertyTree* timingTree = XMLStructure.addPropTree("Timings", createPTree(ipt_caseInsensitive));
         Owned<IStringIterator> times = &wu.getTimers();
         ForEach(*times)
@@ -318,8 +321,8 @@ bool CWUXMLInfo::buildXmlTimimgList(IConstWorkUnit &wu,IPropertyTree& XMLStructu
             SCMStringBuffer name;
             times->str(name);
             SCMStringBuffer value;
-            unsigned count = wu.getTimerCount(name.str(), NULL);
-            unsigned duration = wu.getTimerDuration(name.str(), NULL);
+            unsigned count = wu.getTimerCount(name.str());
+            unsigned duration = wu.getTimerDuration(name.str());
             StringBuffer fd;
             formatDuration(fd, duration);
             for (unsigned i = 0; i < name.length(); i++)

plugins/fileservices/fileservices.cpp

@@ -566,11 +566,14 @@ static void blockUntilComplete(const char * label, IClientFileSpray &server, ICo
         IConstDFUWorkunit & dfuwu = result->getResult();
 
         if (wu.get()) { // if updatable (e.g. not hthor with no agent context)
-            StringBuffer ElapsedLabel, RemainingLabel;
-            ElapsedLabel.appendf("%s-%s (Elapsed) ", label, dfuwu.getID());
-            RemainingLabel.appendf("%s-%s (Remaining) ", label, dfuwu.getID());
-            wu->setTimerInfo(ElapsedLabel.str(), "", time.elapsed(), 1, 0);
-            wu->setTimerInfo(RemainingLabel.str(), "", dfuwu.getSecsLeft()*1000, 1, 0);
+            StringBuffer wuScope, ElapsedLabel, RemainingLabel;
+            wuScope.appendf("%s-%s", label, dfuwu.getID());
+            ElapsedLabel.append(wuScope).append(" (Elapsed) ");
+            RemainingLabel.append(wuScope).append(" (Remaining) ");
+
+            //MORE: I think this are intended to replace the timing information, but will currently combine
+            updateWorkunitTimeStat(wu, "fileservices", wuScope, "elapsed", ElapsedLabel, milliToNano(time.elapsed()), 1, 0);
+            updateWorkunitTimeStat(wu, "fileservices", wuScope, "remaining", RemainingLabel, milliToNano(dfuwu.getSecsLeft()*1000), 1, 0);
             wu->setApplicationValue(label, dfuwu.getID(), dfuwu.getSummaryMessage(), true);
             wu->commit();
         }

plugins/workunitservices/workunitservices.cpp

@@ -107,6 +107,16 @@ static const char * EclDefinition =
                             " unsigned4 max;"
                             " string name{maxlength(64)};"
                         " end;\n"
+"export WsStatistic := record "
+                            " unsigned8 value;"
+                            " unsigned8 count;"
+                            " unsigned8 maxValue;"
+                            " string creator;"
+                            " string scope;"
+                            " string name;"
+                            " string description;"
+                            " string unit;"
+                        " end;\n"
 "export WorkunitServices := SERVICE\n"
 "   boolean WorkunitExists(const varstring wuid, boolean online=true, boolean archived=false) : c,entrypoint='wsWorkunitExists'; \n"
 "   dataset(WsWorkunitRecord) WorkunitList("
@@ -131,6 +141,7 @@ static const char * EclDefinition =
 "  dataset(WsFileRead) WorkunitFilesRead(const varstring wuid) : c,context,entrypoint='wsWorkunitFilesRead'; \n"
 "  dataset(WsFileWritten) WorkunitFilesWritten(const varstring wuid) : c,context,entrypoint='wsWorkunitFilesWritten'; \n"
 "  dataset(WsTiming) WorkunitTimings(const varstring wuid) : c,context,entrypoint='wsWorkunitTimings'; \n"
+"  streamed dataset(WsStatistic) WorkunitStatistics(const varstring wuid, boolean includeActivities = false) : c,context,entrypoint='wsWorkunitStatistics'; \n"
     
 "END;";
 
@@ -679,20 +690,40 @@ WORKUNITSERVICES_API void wsWorkunitTimings( ICodeContext *ctx, size32_t & __len
 {
     unsigned tmp;
     MemoryBuffer mb;
-    Owned<IPropertyTree> pt = getWorkUnitBranch(ctx,wuid,"Timings");
-    if (pt) {
-        Owned<IPropertyTreeIterator> iter = pt->getElements("Timing");
+    Owned<IPropertyTree> st = getWorkUnitBranch(ctx,wuid,"Statistics");
+    if (st)
+    {
+        Owned<IPropertyTreeIterator> iter = st->getElements("Statistic[@unit=\"ns\"]");
         ForEach(*iter) {
             IPropertyTree &item = iter->query();
             if (&item==NULL)
                 continue; // paranoia
             tmp = (unsigned)item.getPropInt("@count");
             mb.append(sizeof(tmp),&tmp);
-            tmp = (unsigned)item.getPropInt("@duration");
+            tmp = (unsigned)(item.getPropInt64("@value") / 1000000);
             mb.append(sizeof(tmp),&tmp);
             tmp = (unsigned)item.getPropInt("@max");
             mb.append(sizeof(tmp),&tmp);
-            varAppend(mb, 64, item, "@name");               
+            varAppend(mb, 64, item, "@desc");
+        }
+    }
+    else
+    {
+        Owned<IPropertyTree> pt = getWorkUnitBranch(ctx,wuid,"Timings");
+        if (pt) {
+            Owned<IPropertyTreeIterator> iter = pt->getElements("Timing");
+            ForEach(*iter) {
+                IPropertyTree &item = iter->query();
+                if (&item==NULL)
+                    continue; // paranoia
+                tmp = (unsigned)item.getPropInt("@count");
+                mb.append(sizeof(tmp),&tmp);
+                tmp = (unsigned)item.getPropInt("@duration");
+                mb.append(sizeof(tmp),&tmp);
+                tmp = (unsigned)item.getPropInt("@max");
+                mb.append(sizeof(tmp),&tmp);
+                varAppend(mb, 64, item, "@name");
+            }
         }
     }
     __lenResult = mb.length();
@@ -700,6 +731,84 @@ WORKUNITSERVICES_API void wsWorkunitTimings( ICodeContext *ctx, size32_t & __len
 }
 
 
+class StreamedStatistics : public CInterfaceOf<IRowStream>
+{
+public:
+    StreamedStatistics(IEngineRowAllocator * _resultAllocator, IPropertyTreeIterator * _iter)
+    : resultAllocator(_resultAllocator),iter(_iter)
+    {
+    }
+
+    virtual const void *nextRow()
+    {
+        if (!iter || !iter->isValid())
+            return NULL;
+
+        IPropertyTree & cur = iter->query();
+        unsigned __int64 value = cur.getPropInt64("@value", 0);
+        unsigned __int64 count = cur.getPropInt64("@count", 0);
+        unsigned __int64 max = cur.getPropInt64("@max", 0);
+        const char * uid = cur.queryProp("@name");
+        const char * sep1 = strchr(uid, ';');
+        const char * scope = sep1+1;
+        const char * sep2 = strchr(scope, ';');
+        const char * name = sep2+1;
+        const char * desc = cur.queryProp("@desc");
+        const char * unit = cur.queryProp("@unit");
+        if (!desc) desc = "";
+
+        size32_t lenComponent = sep1-uid;
+        size32_t lenScope = sep2-scope;
+        size32_t lenName = strlen(name);
+        size32_t lenUnit = strlen(unit);
+
+        MemoryBuffer mb;
+        mb.append(sizeof(value),&value);
+        mb.append(sizeof(count),&count);
+        mb.append(sizeof(max),&max);
+        varAppend(mb, lenComponent, uid);
+        varAppend(mb, lenScope, scope);
+        varAppend(mb, lenName, name);
+        varAppend(mb, desc);
+        varAppend(mb, unit);
+
+        size32_t len = mb.length();
+        size32_t newSize;
+        void * row = resultAllocator->createRow(newSize);
+        row = resultAllocator->resizeRow(len, row, newSize);
+        memcpy(row, mb.bufferBase(), len);
+
+        iter->next();
+        return resultAllocator->finalizeRow(len, row, newSize);
+    }
+    virtual void stop()
+    {
+        iter.clear();
+    }
+
+
+protected:
+    Linked<IEngineRowAllocator> resultAllocator;
+    Linked<IPropertyTreeIterator> iter;
+};
+
+WORKUNITSERVICES_API IRowStream * wsWorkunitStatistics( ICodeContext *ctx, IEngineRowAllocator * allocator, const char *wuid, bool includeActivities)
+{
+    unsigned tmp;
+    MemoryBuffer mb;
+    Owned<IPropertyTree> pt = getWorkUnitBranch(ctx,wuid,"Statistics");
+    Owned<IPropertyTreeIterator> iter;
+    if (pt)
+    {
+        iter.setown(pt->getElements("Statistic"));
+
+        //MORE - it includeActivities create an iterator over the progress information, and create a union iterator.
+        iter->first();
+    }
+    return new StreamedStatistics(allocator, iter);
+}
+
+
 WORKUNITSERVICES_API void setPluginContext(IPluginContext * _ctx) { parentCtx = _ctx; }
 
 WORKUNITSERVICES_API char * WORKUNITSERVICES_CALL fsGetBuildInfo(void)

plugins/workunitservices/workunitservices.hpp

@@ -67,6 +67,7 @@ WORKUNITSERVICES_API void WORKUNITSERVICES_CALL wsWorkunitMessages( ICodeContext
 WORKUNITSERVICES_API void WORKUNITSERVICES_CALL wsWorkunitFilesRead( ICodeContext *ctx, size32_t & __lenResult, void * & __result, const char *wuid );
 WORKUNITSERVICES_API void WORKUNITSERVICES_CALL wsWorkunitFilesWritten( ICodeContext *ctx, size32_t & __lenResult, void * & __result, const char *wuid );
 WORKUNITSERVICES_API void WORKUNITSERVICES_CALL wsWorkunitTimings( ICodeContext *ctx, size32_t & __lenResult, void * & __result, const char *wuid );
+WORKUNITSERVICES_API IRowStream * WORKUNITSERVICES_CALL wsWorkunitStatistics( ICodeContext *ctx, IEngineRowAllocator * allocator, const char *wuid );
 
 
 }

plugins/workunitservices/workunitservices.ipp

@@ -45,6 +45,16 @@ inline void fixedAppend(MemoryBuffer &mb,unsigned w,IPropertyTree &pt,const char
     fixedAppend(mb,w,s.str(),s.length());
 }
 
+inline void varAppend(MemoryBuffer &mb,size32_t sz, const char * s)
+{
+    mb.append(sz).append(sz,s);
+}
+
+inline void varAppend(MemoryBuffer &mb,const char * s)
+{
+    varAppend(mb, strlen(s), s);
+}
+
 inline void varAppend(MemoryBuffer &mb,unsigned w,IPropertyTree &pt,const char *prop)
 {
     StringBuffer s;

roxie/ccd/ccd.hpp

@@ -704,7 +704,7 @@ public:
             for (unsigned i = 0; i < STATS_SIZE; i++)
             {
                 if (counts[i])
-                    wu->setTimerInfo(getStatName(i), NULL, 0, cumulative[i], 0);
+                    wu->setStatistic("roxie", "workunit", getStatShortName(i), getStatName(i), getStatMeasure(i), cumulative[i], counts[i], 0, false);
             }
         }
     }

roxie/ccd/ccdcontext.cpp

@@ -985,10 +985,11 @@ public:
     }
 
     Owned<IWUGraphProgress> graphProgress; // could make local to endGraph and pass to reset - might be cleaner
-    void endGraph(bool aborting)
+    void endGraph(cycle_t startCycles, bool aborting)
     {
         if (graph)
         {
+            unsigned __int64 elapsedTime = cycle_to_nanosec(get_cycles_now() - startCycles);
             if (debugContext)
                 debugContext->checkBreakpoint(aborting ? DebugStateGraphAbort : DebugStateGraphEnd, NULL, graph->queryName());
             if (aborting)
@@ -1000,6 +1001,11 @@ public:
                 progressWorkUnit.setown(&workUnit->lock());
                 progress.setown(progressWorkUnit->getGraphProgress(graph->queryName()));
                 graphProgress.setown(progress->update());
+
+                const char * graphName = graph->queryName();
+                StringBuffer graphDesc;
+                formatGraphTimerLabel(graphDesc, graphName);
+                updateWorkunitTimeStat(progressWorkUnit, "roxie", graphName, "time", graphDesc, elapsedTime, 1, 0);
             }
             graph->reset();
             if (graphProgress)
@@ -1038,6 +1044,7 @@ public:
 
         assertex(!realThor);
         bool created = false;
+        cycle_t startCycles = get_cycles_now();
         try
         {
             beginGraph(name);
@@ -1054,7 +1061,7 @@ public:
                 CTXLOG("Exception thrown in query - cleaning up: %d: %s", e->errorCode(), e->errorMessage(s).str());
             }
             if (created)
-                endGraph(true);
+                endGraph(startCycles, true);
             CTXLOG("Done cleaning up");
             throw;
         }
@@ -1062,11 +1069,11 @@ public:
         {
             CTXLOG("Exception thrown in query - cleaning up");
             if (created)
-                endGraph(true);
+                endGraph(startCycles, true);
             CTXLOG("Done cleaning up");
             throw;
         }
-        endGraph(false);
+        endGraph(startCycles, false);
     }
 
     virtual IActivityGraph * queryChildGraph(unsigned  id)
@@ -1970,6 +1977,10 @@ public:
         rowManager->setMemoryLimit(serverQueryFactory->getMemoryLimit());
         workflow.setown(_factory->createWorkflowMachine(false, logctx));
         context.setown(createPTree(ipt_caseInsensitive));
+
+        //MORE: Use various debug settings to override settings:
+        rowManager->setActivityTracking(workUnit->getDebugValueBool("traceRoxiePeakMemory", false));
+
         startWorkUnit();
     }
 
@@ -2152,13 +2163,11 @@ public:
             w->setState(aborted ? WUStateAborted : (failed ? WUStateFailed : WUStateCompleted));
             w->addTimeStamp("Roxie", GetCachedHostName(), "Finished");
             ITimeReporter *timer = logctx.queryTimer();
-            for (unsigned i = 0; i < timer->numSections(); i++)
-            {
-                StringBuffer str("roxie: ");
-                timer->getSection(i, str);
-                w->setTimerInfo(str, NULL, (unsigned)(timer->getTime(i)/1000000), timer->getCount(i), (unsigned)timer->getMaxTime(i));
-            }
-            // logctx.dumpStats(w);
+            updateWorkunitTimings(w, timer, "roxie");
+            logctx.dumpStats(w);
+
+            WuStatisticTarget statsTarget(w, "roxie");
+            rowManager->reportPeakStatistics(statsTarget, 0);
         }
     }
 

roxie/ccd/ccdfile.cpp

@@ -753,7 +753,7 @@ class CRoxieFileCache : public CInterface, implements ICopyFileProgress, impleme
                     {
                         StringBuffer str;
                         str.appendf("doCopyFile %s", sourceFile->queryFilename());
-                        MTimeSection timing(NULL, str.str());
+                        TimeSection timing(str.str());
                         if (useTreeCopy)
                             sourceFile->treeCopyTo(destFile, subnet, fromip, true);
                         else

roxie/ccd/ccdserver.cpp

@@ -7321,7 +7321,7 @@ class CSpillingQuickSortAlgorithm : implements CInterfaceOf<ISortAlgorithm>, imp
 
 public:
     CSpillingQuickSortAlgorithm(ICompare *_compare, IRoxieSlaveContext * _ctx, IOutputMetaData * _rowMeta, unsigned _activityId)
-        : rowsToSort(&_ctx->queryRowManager(), InitialSortElements, CommitStep), ctx(_ctx), compare(_compare), rowMeta(_rowMeta), activityId(_activityId)
+        : rowsToSort(&_ctx->queryRowManager(), InitialSortElements, CommitStep, _activityId), ctx(_ctx), compare(_compare), rowMeta(_rowMeta), activityId(_activityId)
     {
         ctx->queryRowManager().addRowBuffer(this);
     }

roxie/ccd/ccdstate.cpp

@@ -2211,6 +2211,7 @@ private:
                 else
                     stopPerformanceMonitor();
             }
+            //MORE: control:stats??
             else
                 unknown = true;
             break;

roxie/roxiemem/roxiemem.cpp

@@ -1213,17 +1213,17 @@ public:
         {
             const char *block = data() + base;
             ChunkHeader * header = (ChunkHeader *)block;
-            unsigned activityId = getActivityId(header->allocatorId);
+            unsigned allocatorId = header->allocatorId;
             //Potential race condition - a block could become allocated between these two lines.
             //That may introduce invalid activityIds (from freed memory) in the memory tracing.
             unsigned rowCount = atomic_read(&header->count);
             if (ROWCOUNT(rowCount) != 0)
             {
-                if (activityId != lastId)
+                if (allocatorId != lastId)
                 {
                     if (lastId)
                         map->noteMemUsage(lastId, running, runningCount);
-                    lastId = activityId;
+                    lastId = allocatorId;
                     running = chunkSize;
                     runningCount = 1;
                 }
@@ -1410,8 +1410,7 @@ public:
         unsigned numAllocs = queryCount()-1;
         if (numAllocs)
         {
-            unsigned activityId = getActivityId(sharedAllocatorId);
-            map->noteMemUsage(activityId, numAllocs * chunkSize, numAllocs);
+            map->noteMemUsage(sharedAllocatorId, numAllocs * chunkSize, numAllocs);
         }
     }
 };
@@ -1539,8 +1538,7 @@ public:
 
     virtual void getPeakActivityUsage(IActivityMemoryUsageMap *map) const 
     {
-        unsigned activityId = getActivityId(allocatorId);
-        map->noteMemUsage(activityId, chunkCapacity, 1);
+        map->noteMemUsage(allocatorId, chunkCapacity, 1);
         map->noteHeapUsage(chunkCapacity, RHFpacked, _sizeInPages(), chunkCapacity);
     }
 
@@ -1564,7 +1562,7 @@ public:
 //
 struct ActivityEntry 
 {
-    unsigned activityId;
+    unsigned allocatorId;
     unsigned allocations;
     memsize_t usage;
 };
@@ -1591,7 +1589,7 @@ class CActivityMemoryUsageMap : public CInterface, implements IActivityMemoryUsa
     CIArrayOf<HeapEntry> heaps;
     memsize_t maxUsed;
     memsize_t totalUsed;
-    unsigned maxActivity;
+    unsigned allocatorIdMax;
 
 public:
     IMPLEMENT_IINTERFACE;
@@ -1599,13 +1597,13 @@ public:
     {
         maxUsed = 0;
         totalUsed = 0;
-        maxActivity = 0;
+        allocatorIdMax = 0;
     }
 
-    virtual void noteMemUsage(unsigned activityId, memsize_t memUsed, unsigned numAllocs)
+    virtual void noteMemUsage(unsigned allocatorId, memsize_t memUsed, unsigned numAllocs)
     {
         totalUsed += memUsed;
-        ActivityEntry *ret = map.getValue(activityId);
+        ActivityEntry *ret = map.getValue(allocatorId);
         if (ret)
         {
             memUsed += ret->usage;
@@ -1614,13 +1612,13 @@ public:
         }
         else
         {
-            ActivityEntry e = {activityId, numAllocs, memUsed};
-            map.setValue(activityId, e);
+            ActivityEntry e = {allocatorId, numAllocs, memUsed};
+            map.setValue(allocatorId, e);
         }
         if (memUsed > maxUsed)
         {
             maxUsed = memUsed;
-            maxActivity = activityId;
+            allocatorIdMax = allocatorId;
         }
     }
 
@@ -1654,7 +1652,8 @@ public:
             while (j)
             {
                 j--;
-                logctx.CTXLOG("%"I64F"u bytes allocated by activity %u (%u allocations)", (unsigned __int64) results[j]->usage, getRealActivityId(results[j]->activityId, allocatorCache), results[j]->allocations);
+                unsigned activityId = getRealActivityId(results[j]->allocatorId, allocatorCache);
+                logctx.CTXLOG("%"I64F"u bytes allocated by activity %u (%u allocations)", (unsigned __int64) results[j]->usage, activityId, results[j]->allocations);
             }
 
             memsize_t totalHeapPages = 0;
@@ -1690,6 +1689,38 @@ public:
             delete [] results;
         }
     }
+
+    virtual void reportStatistics(IStatisticTarget & target, unsigned detailtarget, const IRowAllocatorCache *allocatorCache)
+    {
+        ActivityEntry **results = new ActivityEntry *[map.count()];
+        HashIterator i(map);
+        unsigned j = 0;
+        for(i.first();i.isValid();i.next())
+        {
+            IMapping &cur = i.query();
+            results[j] = map.mapToValue(&cur);
+            j++;
+        }
+        qsort(results, j, sizeof(results[0]), sortUsage);
+        StringBuffer activityText;
+        while (j)
+        {
+            j--;
+            unsigned allocatorId = results[j]->allocatorId;
+            unsigned activityId = getRealActivityId(allocatorId, allocatorCache);
+            activityText.clear();
+            if (allocatorId & ACTIVITY_FLAG_ISREGISTERED)
+                activityText.append("ac").append(activityId);
+            else if ((allocatorId & MAX_ACTIVITY_ID) == UNKNOWN_ROWSET_ID)
+                activityText.append("rowset");
+            else
+                activityText.append("ac").append(allocatorId & MAX_ACTIVITY_ID);
+            target.addStatistic(NULL, activityText.str(), "roxiepeakmem", NULL, SMEASURE_MEM_KB, results[j]->usage / 1024, results[j]->allocations, 0, false);
+        }
+        delete [] results;
+
+        target.addStatistic(NULL, NULL, "roxiepeakmem", NULL, SMEASURE_MEM_KB, totalUsed / 1024, 1, 0, false);
+    }
 };
 
 //================================================================================
@@ -3172,6 +3203,18 @@ public:
         return true;
     }
 
+    virtual void reportPeakStatistics(IStatisticTarget & target, unsigned detail)
+    {
+        Owned<IActivityMemoryUsageMap> map;
+        {
+            SpinBlock block(peakSpinLock);
+            map.set(peakUsageMap);
+        }
+        if (map)
+            map->reportStatistics(target, detail, allocatorCache);
+        target.addStatistic(NULL, NULL, "roxiehwm", NULL, SMEASURE_MEM_KB, peakPages * (HEAP_ALIGNMENT_SIZE / 1024), 1, 0, false);
+    }
+
     void restoreLimit(unsigned numRequested)
     {
         atomic_add(&totalHeapPages, -(int)numRequested);
@@ -4135,7 +4178,7 @@ namespace roxiemem {
 class SimpleRowBuffer : implements IBufferedRowCallback
 {
 public:
-    SimpleRowBuffer(IRowManager * rowManager, unsigned _priority) : priority(_priority), rows(rowManager, 0, 1)
+    SimpleRowBuffer(IRowManager * rowManager, unsigned _priority) : priority(_priority), rows(rowManager, 0, 1, UNKNOWN_ROWSET_ID)
     {
     }
 

roxie/roxiemem/roxiemem.hpp

@@ -20,6 +20,7 @@
 #include "jlib.hpp"
 #include "jlog.hpp"
 #include "jdebug.hpp"
+#include "jstats.h"
 #include "errorlist.h"
 
 #ifdef _WIN32
@@ -55,6 +56,8 @@
 // MAX_ACTIVITY_ID is further subdivided:
 #define ALLOCATORID_CHECK_MASK          0x00300000
 #define ALLOCATORID_MASK                0x000fffff
+#define UNKNOWN_ROWSET_ID               0x000F8421              // Use as the allocatorId for a rowset from an unknown activity
+#define UNKNOWN_ACTIVITY                123456789
 
 #define ALLOC_ALIGNMENT                 sizeof(void *)          // Minimum alignment of data allocated from the heap manager
 #define PACKED_ALIGNMENT                4                       // Minimum alignment of packed blocks
@@ -446,6 +449,7 @@ interface IRowManager : extends IInterface
     virtual bool compactRows(memsize_t count, const void * * rows) = 0;
     virtual memsize_t getExpectedCapacity(memsize_t size, unsigned heapFlags) = 0; // what is the expected capacity for a given size allocation
     virtual memsize_t getExpectedFootprint(memsize_t size, unsigned heapFlags) = 0; // how much memory will a given size allocation actually use.
+    virtual void reportPeakStatistics(IStatisticTarget & target, unsigned detail) = 0;
 
 //Allow various options to be configured
     virtual void setActivityTracking(bool val) = 0;
@@ -475,6 +479,7 @@ interface IActivityMemoryUsageMap : public IInterface
     virtual void noteMemUsage(unsigned activityId, memsize_t memUsed, unsigned numAllocs) = 0;
     virtual void noteHeapUsage(memsize_t allocatorSize, RoxieHeapFlags heapFlags, memsize_t memReserved, memsize_t memUsed) = 0;
     virtual void report(const IContextLogger &logctx, const IRowAllocatorCache *allocatorCache) = 0;
+    virtual void reportStatistics(IStatisticTarget & target, unsigned detailtarget, const IRowAllocatorCache *allocatorCache) = 0;
 };
 
 extern roxiemem_decl IRowManager *createRowManager(memsize_t memLimit, ITimeLimiter *tl, const IContextLogger &logctx, const IRowAllocatorCache *allocatorCache, bool ignoreLeaks = false);

roxie/roxiemem/roxierowbuff.cpp

@@ -24,16 +24,14 @@
 #include <sys/mman.h>
 #endif
 
-const unsigned RowArrayActivityId = 0xc3f7;
-
 namespace roxiemem {
 
-RoxieOutputRowArray::RoxieOutputRowArray(IRowManager * _rowManager, rowidx_t initialSize, size32_t _commitDelta) :
-    rowManager(_rowManager), commitDelta(_commitDelta)
+RoxieOutputRowArray::RoxieOutputRowArray(IRowManager * _rowManager, rowidx_t initialSize, size32_t _commitDelta, unsigned _allocatorId) :
+    rowManager(_rowManager), commitDelta(_commitDelta), allocatorId(_allocatorId)
 {
     if (initialSize)
     {
-        rows = static_cast<const void * *>(rowManager->allocate(initialSize * sizeof(void*), RowArrayActivityId));
+        rows = static_cast<const void * *>(rowManager->allocate(initialSize * sizeof(void*), allocatorId));
         maxRows = RoxieRowCapacity(rows) / sizeof(void *);
     }
     else
@@ -158,7 +156,7 @@ bool DynamicRoxieOutputRowArray::ensure(rowidx_t requiredRows)
     const void * * newRows;
     try
     {
-        newRows = static_cast<const void * *>(rowManager->allocate(newSize * sizeof(void*), RowArrayActivityId));
+        newRows = static_cast<const void * *>(rowManager->allocate(newSize * sizeof(void*), allocatorId));
         if (!newRows)
             return false;
     }

roxie/roxiemem/roxierowbuff.hpp

@@ -46,7 +46,7 @@ typedef size32_t rowidx_t;
 class roxiemem_decl RoxieOutputRowArray
 {
 public:
-    RoxieOutputRowArray(IRowManager * _rowManager, rowidx_t _initialSize, size32_t _commitDelta);
+    RoxieOutputRowArray(IRowManager * _rowManager, rowidx_t _initialSize, size32_t _commitDelta, unsigned _allocatorId);
     inline ~RoxieOutputRowArray() { kill(); }
 
     //The following can be called from the writer, without any need to lock first.
@@ -93,6 +93,8 @@ public:
     inline void lock() const { cs.enter(); }
     inline void unlock() const { cs.leave(); }
 
+    virtual void setAllocatorId(unsigned _allocatorId)        { allocatorId = _allocatorId; }
+
 protected:
     virtual bool ensure(rowidx_t requiredRows) { return false; }
 
@@ -103,6 +105,7 @@ protected:
     rowidx_t firstRow; // Only rows firstRow..numRows are considered initialized.  Only read/write within cs.
     rowidx_t numRows;  // rows that have been added can only be updated by writing thread.
     rowidx_t commitRows;  // can only be updated by writing thread within a critical section
+    unsigned allocatorId;
     const size32_t commitDelta;  // How many rows need to be written before they are added to the committed region?
     mutable CriticalSection cs;
 };
@@ -110,8 +113,8 @@ protected:
 class roxiemem_decl DynamicRoxieOutputRowArray : public RoxieOutputRowArray
 {
 public:
-    DynamicRoxieOutputRowArray(IRowManager * _rowManager, rowidx_t _initialSize, size32_t _commitDelta)
-        : RoxieOutputRowArray(_rowManager, _initialSize, _commitDelta) {}
+    DynamicRoxieOutputRowArray(IRowManager * _rowManager, rowidx_t _initialSize, size32_t _commitDelta, unsigned _allocatorId)
+        : RoxieOutputRowArray(_rowManager, _initialSize, _commitDelta, _allocatorId) {}
 
 protected:
     virtual bool ensure(rowidx_t requiredRows);

system/jlib/jbroadcast.cpp

@@ -840,7 +840,7 @@ public:
         unsigned offset = 0;
 
 #ifdef _DEBUG
-        MTimeSection * mt = new MTimeSection(defaultTimer, "SERVER BROADCAST");
+        MTimeSection * mt = new MTimeSection(defaultTimer, "ServerBroadcast", "SERVER BROADCAST"); // MORE is ServerBroadcast a scope (where) or a name (what)?
 #endif
 
         unsigned maxDataSz = MC_PACKET_SIZE-sizeof(MCPacketHeader);

system/jlib/jdebug.cpp

@@ -391,7 +391,7 @@ TimeSection::~TimeSection()
     display_time(title, end_time-start_time);
 }
 
-MTimeSection::MTimeSection(ITimeReporter *_master, const char * _title) : title(_title), master(_master)
+MTimeSection::MTimeSection(ITimeReporter *_master, const char * _scope, const char * _title) : scope(_scope), title(_title), master(_master)
 {
   start_time = get_cycles_now();
 }
@@ -400,7 +400,7 @@ MTimeSection::~MTimeSection()
 {
     cycle_t end_time = get_cycles_now();
     if (master)
-        master->addTiming(title, end_time-start_time);
+        master->addTiming(scope, title, end_time-start_time);
     else
         display_time(title, end_time-start_time);
 }
@@ -408,20 +408,22 @@ MTimeSection::~MTimeSection()
 class TimeSectionInfo : public MappingBase 
 {
 public:
-    TimeSectionInfo(const char *_name, __int64 _time) : name(_name), totaltime(_time), count(1), maxtime(_time) {};
-    TimeSectionInfo(const char *_name, __int64 _time, __int64 _maxtime, unsigned _count) : name(_name), totaltime(_time), count(_count), maxtime(_maxtime) {};
+    TimeSectionInfo(const char * _scope, const char *_description, __int64 _cycles) : scope(_scope), description(_description), totalcycles(_cycles), count(1), maxcycles(_cycles) {};
+    TimeSectionInfo(const char * _scope, const char *_description, __int64 _cycles, __int64 _maxcycles, unsigned _count)
+    : scope(_scope), description(_description), totalcycles(_cycles), count(_count), maxcycles(_maxcycles) {};
     TimeSectionInfo(MemoryBuffer &mb)
     {
-        mb.read(name).read(totaltime).read(maxtime).read(count);
+        mb.read(scope).read(description).read(totalcycles).read(maxcycles).read(count);
     }
     void serialize(MemoryBuffer &mb)
     {
-        mb.append(name).append(totaltime).append(maxtime).append(count);
+        mb.read(scope).read(description).append(totalcycles).append(maxcycles).append(count);
     }
-    virtual const void * getKey() const { return name.get(); }
-    StringAttr  name;
-    __int64 totaltime;
-    __int64 maxtime;
+    virtual const void * getKey() const { return scope.get(); }
+    StringAttr  scope;
+    StringAttr  description;
+    __int64 totalcycles;
+    __int64 maxcycles;
     unsigned count;
 };
 
@@ -469,22 +471,22 @@ public:
         for(iter.first(); iter.isValid(); iter.next())
         {
             TimeSectionInfo &ts = (TimeSectionInfo &)iter.query();
-            cb.report(ts.name, ts.totaltime, ts.maxtime, ts.count);
+            cb.report(ts.scope, ts.description, ts.totalcycles, ts.maxcycles, ts.count);
         }
     }
-    virtual void addTiming(const char *title, __int64 time)
+    virtual void addTiming(const char * scope, const char *desc, unsigned __int64 cycles)
     {
         CriticalBlock b(c);
-        TimeSectionInfo *info = sections->find(title);
+        TimeSectionInfo *info = sections->find(scope);
         if (info)
         {
-            info->totaltime += time;
-            if (time > info->maxtime) info->maxtime = time;
+            info->totalcycles += cycles;
+            if (cycles > info->maxcycles) info->maxcycles = cycles;
             info->count++;
         }
         else
         {
-            TimeSectionInfo &newinfo = * new TimeSectionInfo(title, time);
+            TimeSectionInfo &newinfo = * new TimeSectionInfo(scope, desc, cycles);
             sections->replaceOwn(newinfo);
         }
     }
@@ -496,22 +498,27 @@ public:
     virtual __int64 getTime(unsigned idx)
     {
         CriticalBlock b(c);
-        return cycle_to_nanosec(findSection(idx).totaltime);
+        return cycle_to_nanosec(findSection(idx).totalcycles);
     }
     virtual __int64 getMaxTime(unsigned idx)
     {
         CriticalBlock b(c);
-        return cycle_to_nanosec(findSection(idx).maxtime);
+        return cycle_to_nanosec(findSection(idx).maxcycles);
     }
     virtual unsigned getCount(unsigned idx)
     {
         CriticalBlock b(c);
         return findSection(idx).count;
     }
-    virtual StringBuffer &getSection(unsigned idx, StringBuffer &s)
+    virtual StringBuffer &getScope(unsigned idx, StringBuffer &s)
     {
         CriticalBlock b(c);
-        return s.append(findSection(idx).name);
+        return s.append(findSection(idx).scope);
+    }
+    virtual StringBuffer &getDescription(unsigned idx, StringBuffer &s)
+    {
+        CriticalBlock b(c);
+        return s.append(findSection(idx).description);
     }
     virtual void reset()
     {
@@ -525,7 +532,7 @@ public:
         if (numSections())
         {
             for (unsigned i = 0; i < numSections(); i++)
-                getSection(i, str.append("Timing: ")).append(" total=")
+                getDescription(i, str.append("Timing: ")).append(" total=")
                                          .append(getTime(i)/1000000)
                                          .append("ms max=")
                                          .append(getMaxTime(i)/1000)
@@ -546,19 +553,19 @@ public:
             PrintLog(getTimings(str).str());
         }
     }
-    virtual void addTiming(const char *name, const __int64 totaltime, const __int64 maxtime, const unsigned count)
+    virtual void mergeTiming(const char * scope, const char *desc, const __int64 totalcycles, const __int64 maxcycles, const unsigned count)
     {
         CriticalBlock b(c);
-        TimeSectionInfo *info = sections->find(name);
+        TimeSectionInfo *info = sections->find(scope);
         if (!info)
         {
-            info = new TimeSectionInfo(name, totaltime, maxtime, count);
+            info = new TimeSectionInfo(scope, desc, totalcycles, maxcycles, count);
             sections->replaceOwn(*info);
         }
         else
         {
-            info->totaltime += totaltime;
-            if (maxtime > info->maxtime) info->maxtime = maxtime;
+            info->totalcycles += totalcycles;
+            if (maxcycles > info->maxcycles) info->maxcycles = maxcycles;
             info->count += count;
         }
     }
@@ -569,7 +576,7 @@ public:
         for(iter.first(); iter.isValid(); iter.next())
         {
             TimeSectionInfo &ts = (TimeSectionInfo &) iter.query();
-            other.addTiming(ts.name, ts.totaltime, ts.maxtime, ts.count);
+            other.mergeTiming(ts.scope, ts.description, ts.totalcycles, ts.maxcycles, ts.count);
         }
     }
     virtual void merge(ITimeReporter &other)

system/jlib/jdebug.hpp

@@ -74,19 +74,20 @@ public:
 
 interface ITimeReportInfo
 {
-    virtual void report(const char *name, const __int64 totaltime, const __int64 maxtime, const unsigned count) = 0;
+    virtual void report(const char * scope, const char * description, const __int64 totaltime, const __int64 maxtime, const unsigned count) = 0;
 };
 class StringBuffer;
 class MemoryBuffer;
 struct ITimeReporter : public IInterface
 {
-  virtual void addTiming(const char *title, __int64 time) = 0;
-  virtual void addTiming(const char *title, const __int64 totaltime, const __int64 maxtime, const unsigned count) = 0;
+  virtual void addTiming(const char * scope, const char *desc, unsigned __int64 cycles) = 0;
+  virtual void mergeTiming(const char * scope, const char *desc, const __int64 totalcycles, const __int64 maxcycles, const unsigned count) = 0;
   virtual unsigned numSections() = 0;
   virtual __int64 getTime(unsigned idx) = 0;
   virtual __int64 getMaxTime(unsigned idx) = 0;
   virtual unsigned getCount(unsigned idx) = 0;
-  virtual StringBuffer &getSection(unsigned idx, StringBuffer &s) = 0;
+  virtual StringBuffer &getScope(unsigned idx, StringBuffer &s) = 0;
+  virtual StringBuffer &getDescription(unsigned idx, StringBuffer &s) = 0;
   virtual StringBuffer &getTimings(StringBuffer &s) = 0;
   virtual void printTimings() = 0;
   virtual void reset() = 0;
@@ -134,9 +135,10 @@ protected:
 class jlib_decl MTimeSection
 {
 public:
-  MTimeSection(ITimeReporter *_master, const char * _title);
+  MTimeSection(ITimeReporter *_master, const char * scope, const char * _title);
   ~MTimeSection();
 protected:
+  const char * scope;
   const char *    title;
   cycle_t         start_time;
   ITimeReporter *master;
@@ -149,7 +151,7 @@ extern jlib_decl ITimeReporter *timer;
 extern jlib_decl ITimeReporter *createStdTimeReporter();
 extern jlib_decl ITimeReporter *createStdTimeReporter(MemoryBuffer &mb);
 #define TIME_SECTION(title)   TimeSection   glue(_timer,__LINE__)(title);
-#define MTIME_SECTION(master,title)  MTimeSection   glue(mtimer,__LINE__)(master, title);
+#define MTIME_SECTION(master,title)  MTimeSection   glue(mtimer,__LINE__)(master, "workunit;" title, title);
 #else
 #define TIME_SECTION(title)   
 #define MTIME_SECTION(master,title)

system/jlib/jstats.cpp

@@ -87,6 +87,11 @@ extern jlib_decl const char *getStatShortName(unsigned i)
     }
 }
 
+extern jlib_decl StatisticMeasure getStatMeasure(unsigned i)
+{
+    return SMEASURE_COUNT;
+}
+
 extern jlib_decl StatisticCombineType getStatCombineMode(unsigned  i)
 {
     switch (i)

system/jlib/jstats.h

@@ -60,8 +60,25 @@ enum StatisticType
     STATS_SIZE
 };
 
+enum StatisticMeasure
+{
+    SMEASURE_TIME_NS,
+    SMEASURE_COUNT,
+    SMEASURE_MEM_KB,
+    SMEASURE_MAX
+};
+
 extern jlib_decl const char *getStatName(unsigned i);
 extern jlib_decl const char *getStatShortName(unsigned i);
+extern jlib_decl StatisticMeasure getStatMeasure(unsigned i);
 extern jlib_decl StatisticCombineType getStatCombineMode(unsigned i);
+inline unsigned __int64 milliToNano(unsigned __int64 value) { return value * 1000000; } // call avoids need to upcast values
+inline unsigned __int64 nanoToMilli(unsigned __int64 value) { return value / 1000000; }
+
+//This interface is primarily here to reduce the dependency between the different components.
+interface IStatisticTarget
+{
+    virtual void addStatistic(const char * creator_who, const char * wuScope_where, const char * stat_what, const char * description, StatisticMeasure kind, unsigned __int64 value, unsigned __int64 count, unsigned __int64 maxValue, bool merge) = 0;
+};
 
 #endif

system/xmllib/xerces_validator.cpp

@@ -272,7 +272,7 @@ int CDomXmlValidator::setSchemaSource(const char *pszBuffer, unsigned int nSize)
 void CDomXmlValidator::validate()
 {
     // use entity resolver so we can use file/buffer for xml and xsd
-    MTimeSection timing(NULL, "CDomXmlValidator::validate()");
+    TimeSection timing("CDomXmlValidator::validate()");
 
     // error handling
     ParseErrorHandler eh;

thorlcr/graph/thgraphmaster.cpp

@@ -2585,12 +2585,17 @@ void CMasterGraph::done()
                     {
                         wu.setown(&graph.queryJob().queryWorkUnit().lock());
                     }
-                    virtual void report(const char *name, const __int64 totaltime, const __int64 maxtime, const unsigned count)
+                    virtual void report(const char * stat, const char *description, const __int64 totaltime, const __int64 maxtime, const unsigned count)
                     {
                         StringBuffer timerStr(graph.queryJob().queryGraphName());
                         timerStr.append("(").append(graph.queryGraphId()).append("): ");
-                        timerStr.append(name);
-                        wu->setTimerInfo(timerStr.str(), NULL, (unsigned)totaltime, count, (unsigned)maxtime);
+                        timerStr.append(description);
+
+                        StringBuffer wuScope;
+                        wuScope.append(graph.queryJob().queryGraphName()).append("(").append(graph.queryGraphId()).append(")");
+
+                        updateWorkunitTimeStat(wu, "thor", wuScope, stat, timerStr.str(), totaltime, count, maxtime);
+
                     }
                 } wureport(*this);
                 queryJob().queryTimeReporter().report(wureport);

thorlcr/master/thdemonserver.cpp

@@ -88,10 +88,12 @@ private:
     void reportStatus(IWorkUnit *wu, CGraphBase &graph, unsigned startTime, bool finished, bool success=true)
     {
         const char *graphname = graph.queryJob().queryGraphName();
-        StringBuffer timer;
+        StringBuffer timer, graphScope;
         formatGraphTimerLabel(timer, graphname, 0, graph.queryGraphId());
+        formatGraphTimerScope(graphScope, graphname, 0, graph.queryGraphId());
         unsigned duration = msTick()-startTime;
-        wu->setTimerInfo(timer.str(), NULL, duration, 1, 0);
+        updateWorkunitTimeStat(wu, "thor", graphScope, "totalTime", timer, milliToNano(duration), 1, 0);
+
         if (finished)
         {
             if (memcmp(graphname,"graph",5)==0)

thorlcr/master/thgraphmanager.cpp

@@ -663,7 +663,7 @@ bool CJobManager::executeGraph(IConstWorkUnit &workunit, const char *graphName,
     workunit.getWuid(wuid);
     const char *totalTimeStr = "Total thor time";
     unsigned startTime = msTick();
-    unsigned totalTimeMs = workunit.getTimerDuration(totalTimeStr, NULL);
+    unsigned totalTimeMs = workunit.getTimerDuration(totalTimeStr);
 
     Owned<IConstWUQuery> query = workunit.getQuery(); 
     SCMStringBuffer soName;
@@ -741,8 +741,10 @@ bool CJobManager::executeGraph(IConstWorkUnit &workunit, const char *graphName,
         unsigned graphTimeMs = msTick()-startTime;
         StringBuffer graphTimeStr;
         formatGraphTimerLabel(graphTimeStr, graphName);
-        wu->setTimerInfo(graphTimeStr, NULL, graphTimeMs, 1, 0);
-        wu->setTimerInfo(totalTimeStr, NULL, totalTimeMs+graphTimeMs, 1, 0);
+
+        updateWorkunitTimeStat(wu, "thor", graphName, "time", graphTimeStr, milliToNano(graphTimeMs), 1, 0);
+        updateWorkunitTimeStat(wu, "thor", "workunit", "ThorTime", totalTimeStr, milliToNano(totalTimeMs+graphTimeMs), 1, 0);
+
         StringBuffer tsStr("Thor - ");
         wu->setTimeStamp(tsStr.append(graphName).str(), GetCachedHostName(), "Finished");