HPCC-17461 Rationalise the use of TimeElapsed

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

common/thorhelper/thorstats.cpp

@@ -22,7 +22,7 @@
 
 
 //Cycles are accumulated locally, time is updated once it is serialized or persisted
-const StatisticsMapping nestedSectionStatistics(StCycleLocalExecuteCycles, StTimeLocalExecute, StNumStarted, StNumStopped, StKindNone);
+const StatisticsMapping nestedSectionStatistics(StCycleLocalExecuteCycles, StTimeLocalExecute, StNumStarts, StNumStops, StKindNone);
 
 ThorSectionTimer::ThorSectionTimer(const char * _name, CRuntimeStatistic & _starts, CRuntimeStatistic & _stops, CRuntimeStatistic & _elapsed)
 : starts(_starts), stops(_stops), elapsed(_elapsed), name(_name)
@@ -33,8 +33,8 @@ ThorSectionTimer * ThorSectionTimer::createTimer(CRuntimeStatisticCollection & s
 {
     StatsScopeId scope(SSTfunction, name);
     CRuntimeStatisticCollection & nested = stats.registerNested(scope, nestedSectionStatistics);
-    CRuntimeStatistic & starts = nested.queryStatistic(StNumStarted);
-    CRuntimeStatistic & stops = nested.queryStatistic(StNumStopped);
+    CRuntimeStatistic & starts = nested.queryStatistic(StNumStarts);
+    CRuntimeStatistic & stops = nested.queryStatistic(StNumStops);
     CRuntimeStatistic & elapsed = nested.queryStatistic(StCycleLocalExecuteCycles);
     return new ThorSectionTimer(name, starts, stops, elapsed);
 }

ecl/eclagent/eclagent.cpp

@@ -1824,6 +1824,7 @@ void EclAgent::doProcess()
     PrintLog ("Entering doProcess ()");
 #endif
     bool failed = true;
+    CCycleTimer elapsedTimer;
     try
     {
         LOG(MCrunlock, unknownJob, "Waiting for workunit lock");
@@ -1845,7 +1846,7 @@ void EclAgent::doProcess()
             if(noRetry && (w->getState() == WUStateFailed))
                 throw MakeStringException(0, "Ecl agent started in 'no retry' mode for failed workunit, so failing");
             w->setState(WUStateRunning);
-            addTimeStamp(w, SSTglobal, NULL, StWhenQueryStarted);
+            addTimeStamp(w, SSTglobal, NULL, StWhenStarted);
             if (isRemoteWorkunit)
             {
                 w->setAgentSession(myProcessSession());
@@ -1915,7 +1916,8 @@ void EclAgent::doProcess()
 
         WorkunitUpdate w = updateWorkUnit();
 
-        addTimeStamp(w, SSTglobal, NULL, StWhenQueryFinished);
+        addTimeStamp(w, SSTglobal, NULL, StWhenFinished);
+        updateWorkunitTimeStat(w, SSTglobal, NULL, StTimeElapsed, nullptr, elapsedTimer.elapsedNs());
         addTimings();
 
         switch (w->getState())

ecl/eclagent/eclgraph.cpp

@@ -860,7 +860,7 @@ void EclSubGraph::updateProgress(IStatisticGatherer &progress)
 {
     StatsSubgraphScope subgraph(progress, id);
     if (startGraphTime)
-        progress.addStatistic(StWhenGraphStarted, startGraphTime);
+        progress.addStatistic(StWhenStarted, startGraphTime);
     if (elapsedGraphCycles)
         progress.addStatistic(StTimeElapsed, cycle_to_nanosec(elapsedGraphCycles));
     ForEachItemIn(idx, elements)
@@ -1167,6 +1167,11 @@ void EclGraph::execute(const byte * parentExtract)
     if (agent->queryRemoteWorkunit())
         wu->setGraphState(queryGraphName(), WUGraphRunning);
 
+    {
+        Owned<IWorkUnit> wu(agent->updateWorkUnit());
+        addTimeStamp(wu, SSTgraph, queryGraphName(), StWhenStarted);
+    }
+
     try
     {
         unsigned startTime = msTick();

ecl/eclcc/eclcc.cpp

@@ -1129,6 +1129,7 @@ void EclCC::processSingleQuery(EclCompileInstance & instance,
 
     size32_t prevErrs = errorProcessor.errCount();
     cycle_t startCycles = get_cycles_now();
+    addTimeStamp(instance.wu, SSTcompilestage, "compile", StWhenStarted);
     const char * sourcePathname = queryContents ? str(queryContents->querySourcePath()) : NULL;
     const char * defaultErrorPathname = sourcePathname ? sourcePathname : queryAttributePath;
 
@@ -1171,6 +1172,7 @@ void EclCC::processSingleQuery(EclCompileInstance & instance,
         if (exportDependencies)
             parseCtx.nestedDependTree.setown(createPTree("Dependencies"));
 
+        addTimeStamp(instance.wu, SSTcompilestage, "compile:parse", StWhenStarted);
         try
         {
             HqlLookupContext ctx(parseCtx, &errorProcessor);
@@ -1228,7 +1230,7 @@ void EclCC::processSingleQuery(EclCompileInstance & instance,
             unsigned __int64 parseTimeNs = cycle_to_nanosec(get_cycles_now() - startCycles);
             instance.stats.parseTime = (unsigned)nanoToMilli(parseTimeNs);
 
-            updateWorkunitTimeStat(instance.wu, SSTcompilestage, "compile:parseTime", StTimeElapsed, NULL, parseTimeNs);
+            updateWorkunitTimeStat(instance.wu, SSTcompilestage, "compile:parse", StTimeElapsed, NULL, parseTimeNs);
 
             if (exportDependencies)
             {

ecl/eclccserver/eclccserver.cpp

@@ -208,7 +208,7 @@ class EclccCompileThread : implements IPooledThread, implements IErrorReporter,
                 unsigned __int64 cnt = atoi64(count);
                 const char * scope = section.str();
                 StatisticScopeType scopeType = SSTcompilestage;
-                StatisticKind kind = StTimeElapsed;
+                StatisticKind kind = StTimeTotalExecute;
                 workunit->setStatistic(queryStatisticsComponentType(), queryStatisticsComponentName(), scopeType, scope, kind, NULL, nval, cnt, nmax, StatsMergeReplace);
             }
             else

ecl/hql/hqltrans.cpp

@@ -241,7 +241,7 @@ void HqlTransformerInfo::gatherTransformStats(IStatisticTarget & target) const
     {
         StringBuffer scope;
         scope.append("compile:transform:").append(name);
-        target.addStatistic(SSTcompilestage, scope, StNumStarted, nullptr, numInstances, 1, 0, StatsMergeSum);
+        target.addStatistic(SSTcompilestage, scope, StNumStarts, nullptr, numInstances, 1, 0, StatsMergeSum);
         stats.gatherTransformStats(target, scope);
     }
 #endif

ecl/hqlcpp/hqlecl.cpp

@@ -398,6 +398,7 @@ bool HqlDllGenerator::generateCode(HqlQueryContext & query)
     noOutput = true;
     {
         // ensure warnings/errors are available before we do the processing...
+        addTimeStamp(wu, SSTcompilestage, "compile:generate", StWhenStarted);
         wu->commit();
 
         cycle_t startCycles = get_cycles_now();
@@ -469,7 +470,7 @@ bool HqlDllGenerator::generateCode(HqlQueryContext & query)
 
         doExpand(translator);
         unsigned __int64 elapsed = cycle_to_nanosec(get_cycles_now() - startCycles);
-        updateWorkunitTimeStat(wu, SSTcompilestage, "compile:generate c++", StTimeElapsed, NULL, elapsed);
+        updateWorkunitTimeStat(wu, SSTcompilestage, "compile:generate", StTimeElapsed, NULL, elapsed);
 
         if (wu->getDebugValueBool("addMemoryToWorkunit", true))
         {
@@ -505,7 +506,9 @@ void HqlDllGenerator::insertStandAloneCode()
 
 void HqlDllGenerator::doExpand(HqlCppTranslator & translator)
 {
-    cycle_t startCycles = get_cycles_now();
+    CCycleTimer elapsedTimer;
+    addTimeStamp(wu, SSTcompilestage, "compile:write c++", StWhenStarted);
+
     unsigned numExtraFiles = translator.getNumExtraCppFiles();
     bool isMultiFile = translator.spanMultipleCppFiles();
     CompilerType targetCompiler = translator.queryOptions().targetCompiler;
@@ -523,8 +526,7 @@ void HqlDllGenerator::doExpand(HqlCppTranslator & translator)
         }
     }
 
-    cycle_t elapsedCycles = get_cycles_now() - startCycles;
-    updateWorkunitTimeStat(wu, SSTcompilestage, "compile:write c++", StTimeElapsed, NULL, cycle_to_nanosec(elapsedCycles));
+    updateWorkunitTimeStat(wu, SSTcompilestage, "compile:write c++", StTimeElapsed, NULL, elapsedTimer.elapsedNs());
 }
 
 bool HqlDllGenerator::abortRequested()

ecl/hqlcpp/hqlhtcpp.cpp

@@ -6030,7 +6030,7 @@ public:
     virtual void report(const char * scope, const char * description, const __int64 totaltime, const __int64 maxtime, const unsigned count)
     {
         StatisticScopeType scopeType = SSTcompilestage;
-        StatisticKind kind = StTimeElapsed;
+        StatisticKind kind = StTimeTotalExecute;
         wu->setStatistic(queryStatisticsComponentType(), queryStatisticsComponentName(), scopeType, scope, kind, description, totaltime, count, maxtime, StatsMergeReplace);
     }
 

ecl/hthor/hthor.cpp

@@ -236,8 +236,8 @@ void CHThorActivityBase::updateProgressForOther(IStatisticGatherer &progress, un
 {
     StatsEdgeScope scope(progress, otherActivity, whichOutput);
     progress.addStatistic(StNumRowsProcessed, numProcessed);
-    progress.addStatistic(StNumStarted, 1);  // wrong for an activity in a subquery
-    progress.addStatistic(StNumStopped, 1);
+    progress.addStatistic(StNumStarts, 1);  // wrong for an activity in a subquery
+    progress.addStatistic(StNumStops, 1);
     progress.addStatistic(StNumSlaves, 1);  // MORE: A bit pointless for an hthor graph
 }
 

esp/services/ws_workunits/ws_workunitsHelpers.cpp

@@ -757,8 +757,13 @@ void WsWuInfo::doGetGraphs(IArrayOf<IEspECLGraph>& graphs)
         if (version >= 1.53)
         {
             SCMStringBuffer s;
-            Owned<IConstWUStatistic> whenGraphStarted = cw->getStatistic(NULL, name.str(), StWhenGraphStarted);
-            Owned<IConstWUStatistic> whenGraphFinished = cw->getStatistic(NULL, name.str(), StWhenGraphFinished);
+            Owned<IConstWUStatistic> whenGraphStarted = cw->getStatistic(NULL, name.str(), StWhenStarted);
+            if (!whenGraphStarted) // 6.x backward compatibility
+                whenGraphStarted.setown(cw->getStatistic(NULL, name.str(), StWhenGraphStarted));
+            Owned<IConstWUStatistic> whenGraphFinished = cw->getStatistic(NULL, name.str(), StWhenFinished);
+            if (!whenGraphFinished) // 6.x backward compatibility
+                whenGraphFinished.setown(cw->getStatistic(NULL, name.str(), StWhenGraphFinished));
+
             if (whenGraphStarted)
                 g->setWhenStarted(whenGraphStarted->getFormattedValue(s).str());
             if (whenGraphFinished)

roxie/ccd/ccdcontext.cpp

@@ -1143,6 +1143,7 @@ protected:
     unsigned lastWuAbortCheck;
     unsigned startTime;
     unsigned totSlavesReplyLen;
+    CCycleTimer elapsedTimer;
 
     QueryOptions options;
     Owned<IConstWorkUnit> workUnit;
@@ -1437,7 +1438,7 @@ public:
             graphStats.setown(workUnit->updateStats(graph->queryName(), SCTroxie, queryStatisticsComponentName(), 0));
     }
 
-    virtual void endGraph(cycle_t startCycles, bool aborting)
+    virtual void endGraph(unsigned __int64 startTimeStamp, cycle_t startCycles, bool aborting)
     {
         if (graph)
         {
@@ -1460,6 +1461,7 @@ public:
                     StringBuffer graphDesc;
                     formatGraphTimerLabel(graphDesc, graphName);
                     WorkunitUpdate progressWorkUnit(&workUnit->lock());
+                    progressWorkUnit->setStatistic(queryStatisticsComponentType(), queryStatisticsComponentName(), SSTgraph, graphName, StWhenStarted, NULL, startTimeStamp, 1, 0, StatsMergeAppend);
                     updateWorkunitTimeStat(progressWorkUnit, SSTgraph, graphName, StTimeElapsed, graphDesc, elapsedTime);
                     updateWorkunitTimeStat(progressWorkUnit, SSTglobal, GLOBAL_SCOPE, StTimeElapsed, NULL, totalThisTimeNs+elapsedTime);
                     progressWorkUnit->setStatistic(SCTsummary, "roxie", SSTglobal, GLOBAL_SCOPE, StTimeElapsed, totalTimeStr, totalTimeNs+elapsedTime, 1, 0, StatsMergeReplace);
@@ -1515,6 +1517,7 @@ public:
         {
             bool created = false;
             cycle_t startCycles = get_cycles_now();
+            unsigned __int64 startTimeStamp = getTimeStampNowValue();
             try
             {
                 beginGraph(name);
@@ -1531,7 +1534,7 @@ public:
                     CTXLOG("Exception thrown in query - cleaning up: %d: %s", e->errorCode(), e->errorMessage(s).str());
                 }
                 if (created)  // Partially-created graphs are liable to crash if you call abort() on them...
-                    endGraph(startCycles, true);
+                    endGraph(startTimeStamp, startCycles, true);
                 else
                 {
                     // Bit of a hack... needed to avoid pure virtual calls if these are left to the CRoxieContextBase destructor
@@ -1544,7 +1547,7 @@ public:
             {
                 CTXLOG("Exception thrown in query - cleaning up");
                 if (created)
-                    endGraph(startCycles, true);
+                    endGraph(startTimeStamp, startCycles, true);
                 else
                 {
                     // Bit of a hack... needed to avoid pure virtual calls if these are left to the CRoxieContextBase destructor
@@ -1553,7 +1556,7 @@ public:
                 CTXLOG("Done cleaning up");
                 throw;
             }
-            endGraph(startCycles, false);
+            endGraph(startTimeStamp, startCycles, false);
         }
     }
 
@@ -2682,7 +2685,7 @@ protected:
     {
         WorkunitUpdate wu(&workUnit->lock());
         wu->subscribe(SubscribeOptionAbort);
-        addTimeStamp(wu, SSTglobal, NULL, StWhenQueryStarted);
+        addTimeStamp(wu, SSTglobal, NULL, StWhenStarted);
         if (!context->getPropBool("@outputToSocket", false))
             protocol = NULL;
         updateSuppliedXmlParams(wu);
@@ -2815,8 +2818,8 @@ public:
                 if (_strands)
                     builder.addStatistic(StNumStrands, _strands);
                 builder.addStatistic(StNumRowsProcessed, _processed);
-                builder.addStatistic(StNumStarted, 1);
-                builder.addStatistic(StNumStopped, 1);
+                builder.addStatistic(StNumStarts, 1);
+                builder.addStatistic(StNumStops, 1);
                 builder.addStatistic(StNumSlaves, 1);  // Arguable
             }
             logctx.noteStatistic(StNumRowsProcessed, _processed);
@@ -3011,12 +3014,13 @@ public:
             }
             while (clusterNames.ordinality())
                 restoreCluster();
-            addTimeStamp(w, SSTglobal, NULL, StWhenQueryFinished);
+            addTimeStamp(w, SSTglobal, NULL, StWhenFinished);
             updateWorkunitTimings(w, myTimer);
             Owned<IStatisticGatherer> gatherer = createGlobalStatisticGatherer(w);
             CRuntimeStatisticCollection merged(allStatistics);
             logctx.gatherStats(merged);
             merged.recordStatistics(*gatherer);
+            gatherer->addStatistic(StTimeElapsed, elapsedTimer.elapsedNs());
 
             WuStatisticTarget statsTarget(w, "roxie");
             rowManager->reportPeakStatistics(statsTarget, 0);
@@ -3583,10 +3587,10 @@ public:
         return factory->queryPackage().createFileName(filename, overwrite, extend, clusters, workUnit);
     }
 
-    virtual void endGraph(cycle_t startCycles, bool aborting)
+    virtual void endGraph(unsigned __int64 startTimeStamp, cycle_t startCycles, bool aborting) override
     {
         fileCache.kill();
-        CRoxieContextBase::endGraph(startCycles, aborting);
+        CRoxieContextBase::endGraph(startTimeStamp, startCycles, aborting);
     }
 
     virtual void onFileCallback(const RoxiePacketHeader &header, const char *lfn, bool isOpt, bool isLocal)

roxie/ccd/ccdserver.cpp

@@ -349,7 +349,7 @@ protected:
 // General activity statistics
 
 static const StatisticsMapping actStatistics(StWhenFirstRow, StTimeElapsed, StTimeLocalExecute, StTimeTotalExecute, StSizeMaxRowSize,
-                                              StNumRowsProcessed, StNumSlaves, StNumStarted, StNumStopped, StNumStrands,
+                                              StNumRowsProcessed, StNumSlaves, StNumStarts, StNumStops, StNumStrands,
                                               StNumScansPerRow, StNumAllocations, StNumAllocationScans,
                                               StTimeFirstExecute, StCycleLocalExecuteCycles, StCycleTotalExecuteCycles, StKindNone);
 static const StatisticsMapping joinStatistics(&actStatistics, StNumAtmostTriggered, StKindNone);

system/jlib/jdebug.cpp

@@ -565,7 +565,7 @@ public:
     }
     virtual StatisticKind getTimerType(unsigned idx __attribute__((unused)))
     {
-        return StTimeElapsed;
+        return StTimeTotalExecute;
     }
     virtual StatisticScopeType getScopeType(unsigned idx __attribute__((unused)))
     {

system/jlib/jstatcodes.h

@@ -106,15 +106,15 @@ enum StatisticKind
 {
     StKindNone,
     StKindAll,
-    StWhenGraphStarted,                 // When a graph starts
-    StWhenGraphFinished,                // When a graph stopped
+  StWhenGraphStarted,                   // Deprecated use StWhenStarted
+  StWhenGraphFinished,                  // Deprecated use StWhenFinished
     StWhenFirstRow,                     // When the first row is processed by slave activity
-    StWhenQueryStarted,
-    StWhenQueryFinished,
+  StWhenQueryStarted,                   // Deprecated use StWhenStarted
+  StWhenQueryFinished,                  // Deprecated use StWhenFinished
     StWhenCreated,
     StWhenCompiled,
     StWhenWorkunitModified,             // Not sure this is very useful
-    StTimeElapsed,                      // Elapsed wall time between first row and last row
+    StTimeElapsed,                      // An elapsed time - should always have a corresponding StWhenStarted...
     StTimeLocalExecute,                 // Time spend processing just this activity
     StTimeTotalExecute,                 // Time executing this activity and all inputs
     StTimeRemaining,
@@ -123,8 +123,8 @@ enum StatisticKind
     StSizeMaxRowSize,
     StNumRowsProcessed,                 // on edge
     StNumSlaves,                        // on edge
-    StNumStarted,                       // on edge
-    StNumStopped,                       // on edge
+    StNumStarts,                        // on edge
+    StNumStops,                         // on edge
     StNumIndexSeeks,
     StNumIndexScans,
     StNumIndexWildSeeks,
@@ -191,6 +191,8 @@ enum StatisticKind
     StCycleTotalNestedCycles,
     StTimeGenerate,
     StCycleGenerateCycles,
+    StWhenStarted,                      // When a graph/query etc. starts
+    StWhenFinished,                     // When a graph stopped
 
     StMax,
 

system/jlib/jstats.cpp

@@ -541,11 +541,11 @@ public:
 static const StatisticMeta statsMetaData[StMax] = {
     { StKindNone, SMeasureNone, StKindNone, StKindNone, { "none" }, { "@none" } },
     { StKindAll, SMeasureAll, StKindAll, StKindAll, { "all" }, { "@all" } },
-    { WHENSTAT(GraphStarted) },
-    { WHENSTAT(GraphFinished) },
+    { WHENSTAT(GraphStarted) }, // Deprecated - use WhenStart
+    { WHENSTAT(GraphFinished) }, // Deprecated - use WhenFinished
     { WHENSTAT(FirstRow) },
-    { WHENSTAT(QueryStarted) },
-    { WHENSTAT(QueryFinished) },
+    { WHENSTAT(QueryStarted) }, // Deprecated - use WhenStart
+    { WHENSTAT(QueryFinished) }, // Deprecated - use WhenFinished
     { WHENSTAT(Created) },
     { WHENSTAT(Compiled) },
     { WHENSTAT(WorkunitModified) },
@@ -558,8 +558,8 @@ static const StatisticMeta statsMetaData[StMax] = {
     { SIZESTAT(MaxRowSize) },
     { NUMSTAT(RowsProcessed) },
     { NUMSTAT(Slaves) },
-    { NUMSTAT(Started) },
-    { NUMSTAT(Stopped) },
+    { NUMSTAT(Starts) },
+    { NUMSTAT(Stops) },
     { NUMSTAT(IndexSeeks) },
     { NUMSTAT(IndexScans) },
     { NUMSTAT(IndexWildSeeks) },
@@ -626,7 +626,8 @@ static const StatisticMeta statsMetaData[StMax] = {
     { CYCLESTAT(TotalNested) },
     { TIMESTAT(Generate) },
     { CYCLESTAT(Generate) },
-
+    { WHENSTAT(Started) },
+    { WHENSTAT(Finished) },
 };
 
 

thorlcr/graph/thgraphmaster.cpp

@@ -2911,8 +2911,8 @@ void ProgressInfo::getStats(IStatisticGatherer & stats)
     CThorStats::getStats(stats, true);
     stats.addStatistic(kind, tot);
     stats.addStatistic(StNumSlaves, counts.ordinality());
-    stats.addStatistic(StNumStarted, startcount);
-    stats.addStatistic(StNumStopped, stopcount);
+    stats.addStatistic(StNumStarts, startcount);
+    stats.addStatistic(StNumStops, stopcount);
 }
 
 

thorlcr/master/thdemonserver.cpp

@@ -150,7 +150,7 @@ private:
             }
         }
     }
-    void reportGraph(CGraphBase *graph, bool finished, bool success, unsigned startTime)
+    void reportGraph(CGraphBase *graph, bool finished, bool success, unsigned startTime, unsigned __int64 startTimeStamp)
     {
         try
         {
@@ -162,6 +162,13 @@ private:
             }
 
             Owned<IWorkUnit> wu = &currentWU.lock();
+            if (startTimeStamp)
+            {
+                StringBuffer graphScope;
+                const char *graphname = graph->queryJob().queryGraphName();
+                formatGraphTimerScope(graphScope, graphname, 0, graph->queryGraphId());
+                wu->setStatistic(queryStatisticsComponentType(), queryStatisticsComponentName(), SSTsubgraph, graphScope, StWhenStarted, NULL, getTimeStampNowValue(), 1, 0, StatsMergeAppend);
+            }
             reportStatus(wu, *graph, startTime, finished, success);
 
             queryServerStatus().commitProperties();
@@ -230,7 +237,7 @@ public:
         activeGraphs.append(*LINK(graph));
         unsigned startTime = msTick();
         graphStarts.append(startTime);
-        reportGraph(graph, false, true, startTime);
+        reportGraph(graph, false, true, startTime, getTimeStampNowValue());
         const char *graphname = graph->queryJob().queryGraphName();
         if (memcmp(graphname,"graph",5)==0)
             graphname+=5;
@@ -247,7 +254,7 @@ public:
         if (NotFound != g)
         {
             unsigned startTime = graphStarts.item(g);
-            reportGraph(graph, true, success, startTime);
+            reportGraph(graph, true, success, startTime, 0);
             activeGraphs.remove(g);
             graphStarts.remove(g);
         }

thorlcr/master/thgraphmanager.cpp

@@ -825,7 +825,7 @@ bool CJobManager::executeGraph(IConstWorkUnit &workunit, const char *graphName,
     {
         Owned<IWorkUnit> wu = &workunit.lock();
         wu->setTracingValue("ThorBuild", BUILD_TAG);
-        addTimeStamp(wu, SSTgraph, graphName, StWhenGraphStarted);
+        addTimeStamp(wu, SSTgraph, graphName, StWhenStarted);
         updateWorkUnitLog(*wu);
     }
     Owned<IException> exception;
@@ -915,7 +915,7 @@ bool CJobManager::executeGraph(IConstWorkUnit &workunit, const char *graphName,
         updateWorkunitTimeStat(wu, SSTglobal, GLOBAL_SCOPE, StTimeElapsed, NULL, totalThisTimeNs+graphTimeNs);
         wu->setStatistic(SCTsummary, "thor", SSTglobal, GLOBAL_SCOPE, StTimeElapsed, totalTimeStr, totalTimeNs+graphTimeNs, 1, 0, StatsMergeReplace);
 
-        addTimeStamp(wu, SSTgraph, graphName, StWhenGraphFinished);
+        addTimeStamp(wu, SSTgraph, graphName, StWhenFinished);
         
         removeJob(*job);
     }