Skip to content

Commit

Permalink
HPCC-17326 Rationalise the use of StTimeElapsed etc
Browse files Browse the repository at this point in the history 
Signed-off-by: Gavin Halliday <gavin.halliday@lexisnexis.com>
  • Loading branch information
@ghalliday
ghalliday committed Jun 8, 2017
1 parent f3d0b1e commit 5fc13b7
Show file tree
Hide file tree
Showing 18 changed files with 61 additions and 309 deletions.
100 changes: 0 additions & 100 deletions common/workunit/workunit.cpp
View file
Expand Up @@ -5400,13 +5400,6 @@ void CLocalWorkUnit::copyWorkUnit(IConstWorkUnit *cached, bool all)
// 'all' mode is used when setting up a dali WU from the embedded wu in a workunit dll

// Merge timing info from both branches
pt = fromP->getBranch("Timings");
if (pt)
{
IPropertyTree *tgtTimings = ensurePTree(p, "Timings");
mergePTree(tgtTimings, pt);
pt->Release();
}
pt = fromP->getBranch("Statistics");
if (pt)
{
Expand Down Expand Up @@ -5960,11 +5953,6 @@ void CLocalWorkUnit::_loadStatistics() const
IConstWUStatisticIterator& CLocalWorkUnit::getStatistics(const IStatisticsFilter * filter) const
{
CriticalBlock block(crit);
//This should be deleted in version 6.0 when support for 4.x is no longer required
legacyTimings.loadBranch(p,"Timings");
if (legacyTimings.ordinality())
return *new WorkUnitStatisticsIterator(legacyTimings, 0, (IConstWorkUnit *) this, filter);

statistics.loadBranch(p,"Statistics");
Owned<IConstWUStatisticIterator> localStats = new WorkUnitStatisticsIterator(statistics, 0, (IConstWorkUnit *) this, filter);
if (!filter->recurseChildScopes(SSTgraph, nullptr))
Expand Down Expand Up @@ -8976,94 +8964,6 @@ bool CLocalWUStatistic::matches(const IStatisticsFilter * filter) const

//==========================================================================================

CLocalWULegacyTiming::CLocalWULegacyTiming(IPropertyTree *props) : p(props)
{
}

IStringVal & CLocalWULegacyTiming::getCreator(IStringVal & str) const
{
str.clear();
return str;
}


IStringVal & CLocalWULegacyTiming::getDescription(IStringVal & str, bool createDefault) const
{
str.set(p->queryProp("@name"));
return str;
}

IStringVal & CLocalWULegacyTiming::getType(IStringVal & str) const
{
str.set(queryStatisticName(StTimeElapsed));
return str;
}

IStringVal & CLocalWULegacyTiming::getFormattedValue(IStringVal & str) const
{
StringBuffer formatted;
formatStatistic(formatted, getValue(), getMeasure());
str.set(formatted);
return str;
}

StatisticCreatorType CLocalWULegacyTiming::getCreatorType() const
{
return SCTunknown;
}

StatisticScopeType CLocalWULegacyTiming::getScopeType() const
{
return SSTnone;
}

StatisticKind CLocalWULegacyTiming::getKind() const
{
return StTimeElapsed;
}

IStringVal & CLocalWULegacyTiming::getScope(IStringVal & str) const
{
str.clear();
return str;
}

StatisticMeasure CLocalWULegacyTiming::getMeasure() const
{
return SMeasureTimeNs;
}

unsigned __int64 CLocalWULegacyTiming::getValue() const
{
return p->getPropInt64("@duration", 0) * 1000000;
}

unsigned __int64 CLocalWULegacyTiming::getCount() const
{
return p->getPropInt64("@count", 0);
}

unsigned __int64 CLocalWULegacyTiming::getMax() const
{
return p->getPropInt64("@max", 0);
}

unsigned __int64 CLocalWULegacyTiming::getTimestamp() const
{
return 0;
}

bool CLocalWULegacyTiming::matches(const IStatisticsFilter * filter) const
{
if (!filter)
return true;
const char * creator = p->queryProp("@creator");
const char * scope = p->queryProp("@scope");
return filter->matches(SCTall, NULL, SSTall, NULL, getMeasure(), getKind(), getValue());
}

//==========================================================================================

extern WORKUNIT_API ILocalWorkUnit * createLocalWorkUnit(const char *xml)
{
Owned<CLocalWorkUnit> cw = new CLocalWorkUnit((ISecManager *) NULL, NULL);
Expand Down
25 changes: 0 additions & 25 deletions common/workunit/workunit.ipp
View file
Expand Up @@ -65,30 +65,6 @@ public:
virtual bool matches(const IStatisticsFilter * filter) const;
};

class WORKUNIT_API CLocalWULegacyTiming : implements IConstWUStatistic, public CInterface
{
Owned<IPropertyTree> p;
public:
IMPLEMENT_IINTERFACE;
CLocalWULegacyTiming(IPropertyTree *p);

virtual IStringVal & getCreator(IStringVal & str) const;
virtual IStringVal & getDescription(IStringVal & str, bool createDefault) const;
virtual IStringVal & getFormattedValue(IStringVal & str) const;
virtual IStringVal & getType(IStringVal & str) const;
virtual IStringVal & getScope(IStringVal & str) const;
virtual StatisticMeasure getMeasure() const;
virtual StatisticCreatorType getCreatorType() const;
virtual StatisticScopeType getScopeType() const;
virtual StatisticKind getKind() const;
virtual unsigned __int64 getValue() const;
virtual unsigned __int64 getCount() const;
virtual unsigned __int64 getMax() const;
virtual unsigned __int64 getTimestamp() const;

virtual bool matches(const IStatisticsFilter * filter) const;
};

//==========================================================================================

template <typename T, typename IT> struct CachedTags
Expand Down Expand Up @@ -241,7 +217,6 @@ protected:
mutable IArrayOf<IWUResult> variables;
mutable CachedTags<CLocalWUAppValue,IConstWUAppValue> appvalues;
mutable CachedTags<CLocalWUStatistic,IConstWUStatistic> statistics;
mutable CachedTags<CLocalWULegacyTiming,IConstWUStatistic> legacyTimings;
mutable Owned<IUserDescriptor> userDesc;
Mutex locked;
Owned<ISecManager> secMgr;
Expand Down
16 changes: 10 additions & 6 deletions ecl/eclcc/eclcc.cpp
View file
Expand Up @@ -1491,6 +1491,8 @@ void EclCC::processXmlFile(EclCompileInstance & instance, const char *archiveXML

void EclCC::processFile(EclCompileInstance & instance)
{
clearTransformStats();

const char * curFilename = instance.inputFile->queryFilename();
assertex(curFilename);

Expand Down Expand Up @@ -1594,10 +1596,15 @@ void EclCC::processFile(EclCompileInstance & instance)
processSingleQuery(instance, queryText, attributePath.str());
}

if (instance.reportErrorSummary() && !instance.archive && !(optGenerateMeta && instance.generatedMeta))
return;
if (!instance.reportErrorSummary() || instance.archive || (optGenerateMeta && instance.generatedMeta))
generateOutput(instance);

generateOutput(instance);
//Transform stats are gathered in static global variables. Revisit if the code generator is multi threaded.
if (instance.wu->getDebugValueBool("timeTransforms", false))
{
WuStatisticTarget statsTarget(instance.wu, "eclcc");
gatherTransformStats(statsTarget);
}
}


Expand Down Expand Up @@ -2516,7 +2523,6 @@ void EclCC::processBatchedFile(IFile & file, bool multiThreaded)

resetUniqueId();
resetLexerUniqueNames();
clearTransformStats();
}

Owned<IErrorReceiver> localErrs = createFileErrorReceiver(logFile);
Expand All @@ -2525,8 +2531,6 @@ void EclCC::processBatchedFile(IFile & file, bool multiThreaded)
if (info.wu &&
(info.wu->getDebugValueBool("generatePartialOutputOnError", false) || info.queryErrorProcessor().errCount() == 0))
{
WuStatisticTarget statsTarget(info.wu, "eclcc");
gatherTransformStats(statsTarget);
exportWorkUnitToXMLFile(info.wu, xmlFilename, XML_NoBinaryEncode64, true, false, false, true);
Owned<IFile> xml = createIFile(xmlFilename);
info.stats.xmlSize = xml->size();
Expand Down
1 change: 1 addition & 0 deletions ecl/eclcc/eclcc.hpp
View file
Expand Up @@ -132,6 +132,7 @@ const char * const helpText[] = {
"?! -fshowRecordCountInGraph Show estimates of record counts in the graph",
"?! -fspanMultipleCpp Generate a work unit in multiple c++ files",
"?! -fsubgraphToRegenerate=n Regenerate the ECL for a particular subgraph",
"?! -ftimeTransforms Add timings for internal transforms to the workunit",
"",
};

Expand Down
3 changes: 2 additions & 1 deletion ecl/hql/hqltrans.cpp
View file
Expand Up @@ -170,7 +170,8 @@ void HqlTransformStats::gatherTransformStats(IStatisticTarget & target, const ch
{
#ifdef TRANSFORM_STATS_TIME
target.addStatistic(SSTcompilestage, scope, StTimeTotalExecute, nullptr, cycle_to_nanosec(totalTime), 1, 0, StatsMergeSum);
target.addStatistic(SSTcompilestage, scope, StTimeLocalExecute, nullptr, cycle_to_nanosec(totalTime-(childTime-recursiveTime)), 1, 0, StatsMergeSum);
if ((childTime-recursiveTime) != 0)
target.addStatistic(SSTcompilestage, scope, StTimeLocalExecute, nullptr, cycle_to_nanosec(totalTime-(childTime-recursiveTime)), 1, 0, StatsMergeSum);
#endif
}

Expand Down
4 changes: 2 additions & 2 deletions ecl/hql/hqltrans.ipp
View file
Expand Up @@ -35,8 +35,8 @@ typedef MapOwnedToOwned<IHqlExpression, IHqlExpression> MapOwnedHqlToOwnedHql;

//NOTE: eclcc needs to be run with the --leakcheck option for the summary to be output to stdout with TRANSFORM_STATS_ONEXIT option

//#define TRANSFORM_STATS
//#define TRANSFORM_STATS_TIME
#define TRANSFORM_STATS
#define TRANSFORM_STATS_TIME
//#define TRANSFORM_STATS_DETAILS
//#define TRANSFORM_STATS_ONEXIT
//#define TRANSFORM_STATS_OPS
Expand Down
1 change: 1 addition & 0 deletions ecl/hqlcpp/hqlcpp.cpp
View file
Expand Up @@ -1804,6 +1804,7 @@ void HqlCppTranslator::cacheOptions()
DebugOption(options.addLikelihoodToGraph,"addLikelihoodToGraph", true),
DebugOption(options.varFieldAccessorThreshold,"varFieldAccessorThreshold",3), // Generate accessor classes for rows with #variable width fields >= threshold
DebugOption(options.translateDFSlayouts,"translateDFSlayouts", false),
DebugOption(options.timeTransforms,"timeTransforms", false),
DebugOption(options.reportDFSinfo,"reportDFSinfo", 0),
};

Expand Down
2 changes: 1 addition & 1 deletion ecl/hqlcpp/hqlcpp.ipp
View file
Expand Up @@ -789,6 +789,7 @@ struct HqlCppOptions
bool optimizeCriticalFunctions;
bool addLikelihoodToGraph;
bool translateDFSlayouts;
bool timeTransforms;
};

//Any information gathered while processing the query should be moved into here, rather than cluttering up the translator class
Expand Down Expand Up @@ -1102,7 +1103,6 @@ public:

HqlCppOptions const & queryOptions() const { return options; }
bool needToSerializeToSlave(IHqlExpression * expr) const;
ITimeReporter * queryTimeReporter() const { return timeReporter; }
void noteFinishedTiming(const char * name, cycle_t startCycles)
{
timeReporter->addTiming(name, get_cycles_now()-startCycles);
Expand Down
7 changes: 0 additions & 7 deletions ecl/hqlcpp/hqlcppds.cpp
View file
Expand Up @@ -1813,26 +1813,20 @@ IHqlExpression * HqlCppTranslator::getResourcedChildGraph(BuildCtx & ctx, IHqlEx
}

{
cycle_t startCycles = get_cycles_now();
CompoundSourceTransformer transformer(*this, CSFpreload|csfFlags);
resourced.setown(transformer.process(resourced));
checkNormalized(ctx, resourced);
noteFinishedTiming("workunit:tree transform: optimize disk read", startCycles);
}

bool isInsideChildQuery = (graphKind == no_childquery) || insideChildQuery(ctx);
if (options.optimizeGraph)
{
cycle_t startCycles = get_cycles_now();
traceExpression("BeforeOptimizeSub", resourced);
resourced.setown(optimizeHqlExpression(queryErrorProcessor(), resourced, getOptimizeFlags(isInsideChildQuery)|HOOcompoundproject));
traceExpression("AfterOptimizeSub", resourced);
noteFinishedTiming("workunit:optimize graph", startCycles);
}

traceExpression("BeforeResourcing Child", resourced);

cycle_t startCycles = get_cycles_now();
HqlExprCopyArray activeRows;
gatherActiveCursors(ctx, activeRows);
if (graphKind == no_loop)
Expand All @@ -1843,7 +1837,6 @@ IHqlExpression * HqlCppTranslator::getResourcedChildGraph(BuildCtx & ctx, IHqlEx
else
resourced.setown(resourceNewChildGraph(*this, activeRows, resourced, targetClusterType, graphIdExpr, numResults));

noteFinishedTiming("workunit:resource graph", startCycles);
checkNormalized(ctx, resourced);
traceExpression("AfterResourcing Child", resourced);

Expand Down

0 comments on commit 5fc13b7

Please sign in to comment.