From 0f6e24472395789310e2d1ae84ffea8625de8243 Mon Sep 17 00:00:00 2001 From: "Dan S. Camper" Date: Wed, 9 Oct 2024 13:48:32 -0500 Subject: [PATCH] HPCC-32108 Gather and report regex cache statistics --- common/thorhelper/roxiehelper.cpp | 3 ++ common/thorhelper/thorstats.cpp | 55 ++++++++++++++++++++++------- common/thorhelper/thorstats.hpp | 22 +++++++++--- ecl/eclagent/eclagent.ipp | 5 +++ ecl/hql/hqlfold.cpp | 1 + ecl/hqlcpp/hqlcatom.cpp | 2 ++ ecl/hqlcpp/hqlcatom.hpp | 1 + ecl/hqlcpp/hqlcpp.cpp | 8 +++-- ecl/hqlcpp/hqlcpp.ipp | 4 +-- ecl/hqlcpp/hqlcppsys.ecl | 7 ++-- ecl/hqlcpp/hqlhtcpp.cpp | 19 ++++++++--- roxie/ccd/ccdactivities.cpp | 5 +++ roxie/ccd/ccdcontext.cpp | 6 +++- roxie/ccd/ccdserver.cpp | 13 ++++++- roxie/ccd/ccdserver.hpp | 1 + rtl/eclrtl/eclregex.cpp | 57 +++++++++++++++++++++++-------- rtl/eclrtl/wfcontext.cpp | 5 +++ rtl/eclrtl/wfcontext.hpp | 1 + rtl/include/eclhelper.hpp | 8 ++++- system/jlib/jstatcodes.h | 3 ++ system/jlib/jstats.cpp | 4 +++ thorlcr/graph/thgraph.cpp | 7 +++- thorlcr/graph/thgraph.hpp | 1 + thorlcr/thorcodectx/thcodectx.cpp | 5 +++ thorlcr/thorcodectx/thcodectx.hpp | 1 + tools/wutool/wutool.cpp | 1 + 26 files changed, 197 insertions(+), 48 deletions(-) diff --git a/common/thorhelper/roxiehelper.cpp b/common/thorhelper/roxiehelper.cpp index 668e47d07e4..c69507b08d6 100644 --- a/common/thorhelper/roxiehelper.cpp +++ b/common/thorhelper/roxiehelper.cpp @@ -2875,6 +2875,9 @@ class NullSectionTimer : public CSimpleInterfaceOf { virtual unsigned __int64 getStartCycles() { return 0; } virtual void noteSectionTime(unsigned __int64 startCycles) {} + virtual void addStatistic(__int64 kind, unsigned __int64 value) {} + virtual void setStatistic(__int64 kind, unsigned __int64 value) {} + virtual void mergeStatistic(__int64 kind, unsigned __int64 value) {} }; static NullSectionTimer nullSectionTimer; diff --git a/common/thorhelper/thorstats.cpp b/common/thorhelper/thorstats.cpp index f623f428a7a..2124e084032 100644 --- a/common/thorhelper/thorstats.cpp +++ b/common/thorhelper/thorstats.cpp @@ -20,34 +20,63 @@ #include "thorstats.hpp" #include "jdebug.hpp" +// Available sets of statistics for a nested section +const StatisticsMapping defaultNestedSectionStatistics({StCycleLocalExecuteCycles, StTimeLocalExecute, StNumStarts, StNumStops}); +const StatisticsMapping genericCacheNestedSectionStatistics({StNumCacheAdds, StNumCacheHits, StNumPeakCacheObjects}, defaultNestedSectionStatistics); -//Cycles are accumulated locally, time is updated once it is serialized or persisted -const StatisticsMapping nestedSectionStatistics({StCycleLocalExecuteCycles, StTimeLocalExecute, StNumStarts, StNumStops}); - -ThorSectionTimer::ThorSectionTimer(const char * _name, CRuntimeStatistic & _starts, CRuntimeStatistic & _stops, CRuntimeStatistic & _elapsed) -: starts(_starts), stops(_stops), elapsed(_elapsed), name(_name) +ThorSectionTimer::ThorSectionTimer(const char * _name, CRuntimeStatisticCollection & _stats) +: name(_name), stats(_stats) { } -ThorSectionTimer * ThorSectionTimer::createTimer(CRuntimeStatisticCollection & stats, const char * name) +ThorSectionTimer * ThorSectionTimer::createTimer(CRuntimeStatisticCollection & stats, const char * name, const StatisticsMapping & nestedSectionStatistics) { StatsScopeId scope(SSTfunction, name); CRuntimeStatisticCollection & nested = stats.registerNested(scope, nestedSectionStatistics); - CRuntimeStatistic & starts = nested.queryStatistic(StNumStarts); - CRuntimeStatistic & stops = nested.queryStatistic(StNumStops); - CRuntimeStatistic & elapsed = nested.queryStatistic(StCycleLocalExecuteCycles); - return new ThorSectionTimer(name, starts, stops, elapsed); + return new ThorSectionTimer(name, nested); +} + +ThorSectionTimer * ThorSectionTimer::createTimer(CRuntimeStatisticCollection & stats, const char * name, ThorStatOption statOption) +{ + assertex(statOption < ThorStatMax); + switch (statOption) + { + case ThorStatGenericCache: + return createTimer(stats, name, genericCacheNestedSectionStatistics); + default: + return createTimer(stats, name, defaultNestedSectionStatistics); + } +} + +ThorSectionTimer * ThorSectionTimer::createTimer(CRuntimeStatisticCollection & stats, const char * name) +{ + return createTimer(stats, name, defaultNestedSectionStatistics); } unsigned __int64 ThorSectionTimer::getStartCycles() { - starts.addAtomic(1); + stats.queryStatistic(StNumStarts).addAtomic(1); return get_cycles_now(); } void ThorSectionTimer::noteSectionTime(unsigned __int64 startCycles) { cycle_t delay = get_cycles_now() - startCycles; - elapsed.addAtomic(delay); - stops.addAtomic(1); + stats.addStatisticAtomic(StCycleLocalExecuteCycles, delay); + stats.addStatisticAtomic(StNumStops, 1); +} + +void ThorSectionTimer::addStatistic(__int64 kind, unsigned __int64 value) +{ + stats.addStatisticAtomic(static_cast(kind), value); +} + +void ThorSectionTimer::setStatistic(__int64 kind, unsigned __int64 value) +{ + stats.setStatistic(static_cast(kind), value); +} + +void ThorSectionTimer::mergeStatistic(__int64 kind, unsigned __int64 value) +{ + stats.mergeStatistic(static_cast(kind), value); } diff --git a/common/thorhelper/thorstats.hpp b/common/thorhelper/thorstats.hpp index 37abe68e906..972d5a45d06 100644 --- a/common/thorhelper/thorstats.hpp +++ b/common/thorhelper/thorstats.hpp @@ -24,9 +24,22 @@ #include "eclhelper.hpp" #include "jstats.h" +// If you add values to this enum, update ThorSectionTimer::createTimer so that it can handle the new value +enum ThorStatOption +{ + ThorStatDefault, + ThorStatGenericCache, + ThorStatMax // Marker, always last +}; + class THORHELPER_API ThorSectionTimer : public CSimpleInterfaceOf { public: + // Creates an instance of the timer that tracks the statistics cited in nestedSectionStatistics + static ThorSectionTimer * createTimer(CRuntimeStatisticCollection & _stats, const char * _name, const StatisticsMapping & nestedSectionStatistics); + // Creates an instance of the timer that tracks the statistics referenced through the ThorStatOption enum + static ThorSectionTimer * createTimer(CRuntimeStatisticCollection & _stats, const char * _name, ThorStatOption statOption); + // Default instantiation of a timer; uses defaultNestedSectionStatistics static ThorSectionTimer * createTimer(CRuntimeStatisticCollection & _stats, const char * _name); bool matches(const char * _name) const @@ -36,15 +49,16 @@ class THORHELPER_API ThorSectionTimer : public CSimpleInterfaceOf virtual unsigned __int64 getStartCycles(); virtual void noteSectionTime(unsigned __int64 startCycles); + virtual void addStatistic(__int64 kind, unsigned __int64 value) override; + virtual void setStatistic(__int64 kind, unsigned __int64 value) override; + virtual void mergeStatistic(__int64 kind, unsigned __int64 value) override; protected: - ThorSectionTimer(const char * _name, CRuntimeStatistic & _starts, CRuntimeStatistic & _stops, CRuntimeStatistic & _elapsed); + ThorSectionTimer(const char * _name, CRuntimeStatisticCollection & _stats); private: - CRuntimeStatistic & starts; - CRuntimeStatistic & stops; - CRuntimeStatistic & elapsed; StringAttr name; + CRuntimeStatisticCollection & stats; }; #endif diff --git a/ecl/eclagent/eclagent.ipp b/ecl/eclagent/eclagent.ipp index 17109a2c6f4..fb5df15916a 100644 --- a/ecl/eclagent/eclagent.ipp +++ b/ecl/eclagent/eclagent.ipp @@ -547,6 +547,11 @@ public: { return queryNullSectionTimer(); } + + virtual ISectionTimer * registerStatsTimer(unsigned activityId, const char * name, unsigned int statsOption) + { + return queryNullSectionTimer(); + } // IEngineContext virtual DALI_UID getGlobalUniqueIds(unsigned num, SocketEndpoint *_foreignNode) { diff --git a/ecl/hql/hqlfold.cpp b/ecl/hql/hqlfold.cpp index 1797edcf91a..e93da9a8f60 100644 --- a/ecl/hql/hqlfold.cpp +++ b/ecl/hql/hqlfold.cpp @@ -1664,6 +1664,7 @@ class DummyContext: implements ICodeContext virtual IEngineRowAllocator * getRowAllocatorEx(IOutputMetaData * meta, unsigned activityId, unsigned flags) const { throwUnexpected(); } virtual void addWuExceptionEx(const char*, unsigned int, unsigned int, unsigned int, const char*) override { throwUnexpected(); } virtual unsigned getElapsedMs() const override { throwUnexpected(); } + virtual ISectionTimer * registerStatsTimer(unsigned activityId, const char * name, unsigned int statsOption) { throwUnexpected(); } }; diff --git a/ecl/hqlcpp/hqlcatom.cpp b/ecl/hqlcpp/hqlcatom.cpp index b4451d7d477..ad6166a9719 100644 --- a/ecl/hqlcpp/hqlcatom.cpp +++ b/ecl/hqlcpp/hqlcatom.cpp @@ -552,6 +552,7 @@ IIdAtom * regexUStrMatchSetId; IIdAtom * regexU8StrMatchSetId; IIdAtom * regexReplaceXId; IIdAtom * registerTimerId; +IIdAtom * registerStatsTimerId; IIdAtom * releaseRowId; IIdAtom * releaseRowsetId; IIdAtom * reportFieldOverflowId; @@ -1243,6 +1244,7 @@ MODULE_INIT(INIT_PRIORITY_HQLATOM-1) MAKEID(regexU8StrMatchSet); MAKEID(regexReplaceX); MAKEID(registerTimer); + MAKEID(registerStatsTimer); MAKEID(releaseRow); MAKEID(releaseRowset); MAKEID(reportFieldOverflow); diff --git a/ecl/hqlcpp/hqlcatom.hpp b/ecl/hqlcpp/hqlcatom.hpp index ed6e84f0fcd..8c93084be5a 100644 --- a/ecl/hqlcpp/hqlcatom.hpp +++ b/ecl/hqlcpp/hqlcatom.hpp @@ -550,6 +550,7 @@ extern IIdAtom * regexUStrMatchSetId; extern IIdAtom * regexU8StrMatchSetId; extern IIdAtom * regexReplaceXId; extern IIdAtom * registerTimerId; +extern IIdAtom * registerStatsTimerId; extern IIdAtom * releaseRowId; extern IIdAtom * releaseRowsetId; extern IIdAtom * reportFieldOverflowId; diff --git a/ecl/hqlcpp/hqlcpp.cpp b/ecl/hqlcpp/hqlcpp.cpp index 1995efe9672..b8206c32c4b 100644 --- a/ecl/hqlcpp/hqlcpp.cpp +++ b/ecl/hqlcpp/hqlcpp.cpp @@ -2248,7 +2248,9 @@ void HqlCppTranslator::callProcedure(BuildCtx & ctx, IIdAtom * name, HqlExprArra const char * timerName = str(external->queryId()); if (getStringValue(nameTemp, queryAttributeChild(external, timerAtom, 0)).length()) timerName = nameTemp; - buildHelperTimer(ctx, boundTimer, timerName); + // Grab optional ThorStatOption enum (as an int) + int statOption = getIntValue(queryAttributeChild(external, timerAtom, 1), 0); + buildHelperTimer(ctx, boundTimer, timerName, statOption); // We need to patch the args to include the timer; helper timers will always be the first argument // passed to the helper function, which means that it is either the first argument in the // array (for a bare function call) or the second argument (for a method call) @@ -6127,7 +6129,9 @@ void HqlCppTranslator::doBuildCall(BuildCtx & ctx, const CHqlBoundTarget * tgt, const char * name = str(external->queryId()); if (getStringValue(nameTemp, queryAttributeChild(external, timerAtom, 0)).length()) name = nameTemp; - buildHelperTimer(ctx, boundTimer, name); + // Grab optional ThorStatOption enum (as an int) + int statOption = getIntValue(queryAttributeChild(external, timerAtom, 1), 0); + buildHelperTimer(ctx, boundTimer, name, statOption); args.append(*LINK(boundTimer.expr)); } if (external->hasAttribute(userMatchFunctionAtom)) diff --git a/ecl/hqlcpp/hqlcpp.ipp b/ecl/hqlcpp/hqlcpp.ipp index fb3c2bd8470..5de1fcecdf6 100644 --- a/ecl/hqlcpp/hqlcpp.ipp +++ b/ecl/hqlcpp/hqlcpp.ipp @@ -1676,8 +1676,8 @@ public: IHqlExpression * getFirstCharacter(IHqlExpression * source); bool hasAddress(BuildCtx & ctx, IHqlExpression * expr); - void buildTimerBase(BuildCtx & ctx, CHqlBoundExpr & boundTimer, const char * name); - void buildHelperTimer(BuildCtx & ctx, CHqlBoundExpr & boundTimer, const char * name); + void buildTimerBase(BuildCtx & ctx, CHqlBoundExpr & boundTimer, const char * name, int statsOption); + void buildHelperTimer(BuildCtx & ctx, CHqlBoundExpr & boundTimer, const char * name, int statsOption); void buildStartTimer(BuildCtx & ctx, CHqlBoundExpr & boundTimer, CHqlBoundExpr & boundStart, const char * name); void buildStopTimer(BuildCtx & ctx, const CHqlBoundExpr & boundTimer, const CHqlBoundExpr & boundStart); diff --git a/ecl/hqlcpp/hqlcppsys.ecl b/ecl/hqlcpp/hqlcppsys.ecl index ca413910c08..2b6bb7d948a 100644 --- a/ecl/hqlcpp/hqlcppsys.ecl +++ b/ecl/hqlcpp/hqlcppsys.ecl @@ -553,7 +553,7 @@ const char * cppSystemText[] = { " unicode wregexReplaceX(unsigned8 compiled, const unicode text, const unicode replace) : eclrtl,pure,include='eclrtl.hpp',library='eclrtl',entrypoint='rtlWRegExprReplace';", " unicode wregexGetFindStr(unsigned8 compiled, unsigned4 idx): eclrtl,pure,include='eclrtl.hpp',library='eclrtl',entrypoint='rtlWRegExprGetFindStr';", - " regexNewSetStrPattern(const varstring _pattern, boolean isCaseSensitive) : omethod,entrypoint='setPatternTimed',timer('CompileStringRegex');" + " regexNewSetStrPattern(const varstring _pattern, boolean isCaseSensitive) : omethod,entrypoint='setPatternTimed',timer('CompileStringRegex', 1);" " regexNewStrFind(boolean _compiled, const string _search, boolean _cloneSearch) : omethod,entrypoint='findTimed',timer('REGEXFIND');" " boolean regexNewStrFound() : method,pure,entrypoint='found';" " string regexNewStrFoundX(unsigned4 idx) : method,pure,entrypoint='getMatchX';" @@ -562,7 +562,7 @@ const char * cppSystemText[] = { " regexNewStrReplaceFixed(noconst string _tgt, const string _search, const string _replace) : method,pure,entrypoint='replaceFixedTimed',timer('REGEXREPLACE');" " set of string regexMatchSet(const string _search) : method,pure,entrypoint='getMatchSetTimed',timer('REGEXFINDSET');" - " regexNewSetUStrPattern(const varunicode _pattern, boolean isCaseSensitive) : omethod,entrypoint='setPatternTimed',timer('CompileUnicodeRegex');" + " regexNewSetUStrPattern(const varunicode _pattern, boolean isCaseSensitive) : omethod,entrypoint='setPatternTimed',timer('CompileUnicodeRegex', 1);" " regexNewUStrFind(boolean _compiled, const unicode _search) : omethod,entrypoint='findTimed',timer('REGEXFIND');" " boolean regexNewUStrFound() : method,pure,entrypoint='found';" " unicode regexNewUStrFoundX(unsigned4 idx) : method,pure,entrypoint='getMatchX';" @@ -571,7 +571,7 @@ const char * cppSystemText[] = { " regexNewUStrReplaceFixed(noconst unicode _tgt, const unicode _search, const unicode _replace) : method,pure,entrypoint='replaceFixedTimed',timer('REGEXREPLACE');" " set of unicode regexUStrMatchSet(const unicode _search) : method,pure,entrypoint='getMatchSetTimed',timer('REGEXFINDSET');" - " regexNewSetU8StrPattern(const utf8 _pattern, boolean isCaseSensitive) : omethod,entrypoint='setPatternTimed',timer('CompileUTF8Regex');" + " regexNewSetU8StrPattern(const utf8 _pattern, boolean isCaseSensitive) : omethod,entrypoint='setPatternTimed',timer('CompileUTF8Regex', 1);" " regexNewU8StrFind(boolean _compiled, const utf8 _search, boolean _cloneSearch) : omethod,entrypoint='findTimed',timer('REGEXFIND');" " boolean regexNewU8StrFound() : method,pure,entrypoint='found';" " utf8 regexNewU8StrFoundX(unsigned4 idx) : method,pure,entrypoint='getMatchX';" @@ -915,6 +915,7 @@ const char * cppSystemText[] = { " varstring registerTimer(unsigned4 id, const varstring name) : ctxmethod;", " unsigned8 getStartCycles() : method;", " noteSectionTime(unsigned8 started) : method;", + " varstring registerStatsTimer(unsigned4 id, const varstring name, unsigned4 statsOption) : ctxmethod;", " END;", NULL }; diff --git a/ecl/hqlcpp/hqlhtcpp.cpp b/ecl/hqlcpp/hqlhtcpp.cpp index dd99da45897..4e8a54fdbb2 100644 --- a/ecl/hqlcpp/hqlhtcpp.cpp +++ b/ecl/hqlcpp/hqlhtcpp.cpp @@ -18814,7 +18814,7 @@ void HqlCppTranslator::doBuildExprRegexFindSet(BuildCtx & ctx, IHqlExpression * //--------------------------------------------------------------------------- -void HqlCppTranslator::buildTimerBase(BuildCtx & ctx, CHqlBoundExpr & boundTimer, const char * name) +void HqlCppTranslator::buildTimerBase(BuildCtx & ctx, CHqlBoundExpr & boundTimer, const char * name, int statsOption) { BuildCtx * initCtx = &ctx; BuildCtx * declareCtx = &ctx; @@ -18828,7 +18828,16 @@ void HqlCppTranslator::buildTimerBase(BuildCtx & ctx, CHqlBoundExpr & boundTimer HqlExprArray registerArgs; registerArgs.append(*getSizetConstant(activityId)); registerArgs.append(*createConstant(name)); - OwnedHqlExpr call = bindFunctionCall(registerTimerId, registerArgs); + OwnedHqlExpr call; + if (statsOption == 0) // enum ThorStatOption.ThorStatDefault + { + call.setown(bindFunctionCall(registerTimerId, registerArgs)); + } + else + { + registerArgs.append(*createConstant(statsOption)); + call.setown(bindFunctionCall(registerStatsTimerId, registerArgs)); + } if (!declareCtx->getMatchExpr(call, boundTimer)) { @@ -18840,14 +18849,14 @@ void HqlCppTranslator::buildTimerBase(BuildCtx & ctx, CHqlBoundExpr & boundTimer } } -void HqlCppTranslator::buildHelperTimer(BuildCtx & ctx, CHqlBoundExpr & boundTimer, const char * name) +void HqlCppTranslator::buildHelperTimer(BuildCtx & ctx, CHqlBoundExpr & boundTimer, const char * name, int statsOption) { - buildTimerBase(ctx, boundTimer, name); + buildTimerBase(ctx, boundTimer, name, statsOption); } void HqlCppTranslator::buildStartTimer(BuildCtx & ctx, CHqlBoundExpr & boundTimer, CHqlBoundExpr & boundStart, const char * name) { - buildTimerBase(ctx, boundTimer, name); + buildTimerBase(ctx, boundTimer, name, 0); HqlExprArray nowArgs; nowArgs.append(*boundTimer.getTranslatedExpr()); diff --git a/roxie/ccd/ccdactivities.cpp b/roxie/ccd/ccdactivities.cpp index 01a3fa91d90..0ca45543e1c 100644 --- a/roxie/ccd/ccdactivities.cpp +++ b/roxie/ccd/ccdactivities.cpp @@ -564,6 +564,11 @@ class CRoxieAgentActivity : implements CInterfaceOf, implem return queryNullSectionTimer(); } + virtual ISectionTimer * registerStatsTimer(unsigned activityId, const char * name, unsigned int statsOption) + { + return queryNullSectionTimer(); + } + // Not yet thought about these.... virtual char *getWuid() { throwUnexpected(); } // caller frees return string. diff --git a/roxie/ccd/ccdcontext.cpp b/roxie/ccd/ccdcontext.cpp index e064a6552cb..e03853a9537 100644 --- a/roxie/ccd/ccdcontext.cpp +++ b/roxie/ccd/ccdcontext.cpp @@ -2136,12 +2136,16 @@ class CRoxieContextBase : implements IRoxieAgentContext, implements ICodeContext return rtlVCodepageToVUnicodeX(x.str(), "utf-8"); } virtual ISectionTimer * registerTimer(unsigned activityId, const char * name) + { + return registerStatsTimer(activityId, name, 0); + } + virtual ISectionTimer * registerStatsTimer(unsigned activityId, const char * name, unsigned int statsOption) { CriticalBlock b(timerCrit); ISectionTimer *timer = functionTimers.getValue(name); if (!timer) { - timer = ThorSectionTimer::createTimer(globalStats, name); + timer = ThorSectionTimer::createTimer(globalStats, name, static_cast(statsOption)); functionTimers.setValue(name, timer); timer->Release(); // Value returned is not linked } diff --git a/roxie/ccd/ccdserver.cpp b/roxie/ccd/ccdserver.cpp index 60aa3ae2c0f..3f86811be92 100644 --- a/roxie/ccd/ccdserver.cpp +++ b/roxie/ccd/ccdserver.cpp @@ -1109,6 +1109,13 @@ class CRoxieServerActivity : implements CInterfaceOf, impl else return ctx->registerTimer(activityId, name); } + virtual ISectionTimer *registerStatsTimer(unsigned activityId, const char * name, unsigned int statsOption) + { + if (activityId == activity.queryId()) + return activity.registerStatsTimer(activityId, name, statsOption); + else + return ctx->registerStatsTimer(activityId, name, statsOption); + } private: CRoxieServerActivity &activity; } interceptedCtx; @@ -1298,12 +1305,16 @@ class CRoxieServerActivity : implements CInterfaceOf, impl return stats.toStr(ret); } virtual ISectionTimer *registerTimer(unsigned _activityId, const char * name) + { + return registerStatsTimer(_activityId, name, 0); + } + virtual ISectionTimer *registerStatsTimer(unsigned activityId, const char * name, unsigned int statsOption) { CriticalBlock b(statscrit); // reuse statscrit to protect functionTimers - it will not be held concurrently ISectionTimer *timer = functionTimers.getValue(name); if (!timer) { - timer = ThorSectionTimer::createTimer(stats, name); + timer = ThorSectionTimer::createTimer(stats, name, static_cast(statsOption)); functionTimers.setValue(name, timer); timer->Release(); // Value returned is not linked } diff --git a/roxie/ccd/ccdserver.hpp b/roxie/ccd/ccdserver.hpp index a1a5c7e452b..14ecda06816 100644 --- a/roxie/ccd/ccdserver.hpp +++ b/roxie/ccd/ccdserver.hpp @@ -204,6 +204,7 @@ interface IRoxieServerActivity : extends IActivityBase virtual void gatherStatistics(IStatisticGatherer * statsBuilder) const = 0; virtual void noteStatistic(StatisticKind kind, unsigned __int64 value) const = 0; virtual void noteLibrary(IQueryFactory *library) = 0; + virtual ISectionTimer * registerStatsTimer(unsigned activityId, const char * name, unsigned int statsOption) = 0; }; interface IRoxieServerActivityFactory : extends IActivityFactory diff --git a/rtl/eclrtl/eclregex.cpp b/rtl/eclrtl/eclregex.cpp index 5cc605c069f..a45552048d1 100644 --- a/rtl/eclrtl/eclregex.cpp +++ b/rtl/eclrtl/eclregex.cpp @@ -763,13 +763,14 @@ class CCompiledStrRegExpr final : implements ICompiledStrRegExpr * or creates a new one if it doesn't. The regular expression object is created based on the provided * regex pattern, length, and case sensitivity flag. The created object is then cached for future use. * + * @param sectionTimer Pointer to a stat-aware section timer object; may be null. * @param _regexLength The length of the regex pattern. * @param _regex The regex pattern. * @param _isCaseSensitive Flag indicating whether the regex pattern is case sensitive or not. * @return A pointer to a copy of the fetched or created CCompiledStrRegExpr object. The returned object * * must eventually be deleted. */ -CCompiledStrRegExpr* fetchOrCreateCompiledStrRegExpr(int _regexLength, const char * _regex, bool _isCaseSensitive) +CCompiledStrRegExpr* fetchOrCreateCompiledStrRegExpr(ISectionTimer * sectionTimer, int _regexLength, const char * _regex, bool _isCaseSensitive) { if (compiledCacheEnabled) { @@ -784,6 +785,9 @@ CCompiledStrRegExpr* fetchOrCreateCompiledStrRegExpr(int _regexLength, const cha if (cacheEntry && cacheEntry->hasSamePattern(_regexLength, _regex, options)) { + // Note a cache hit + if (sectionTimer) + sectionTimer->addStatistic(StNumCacheHits, 1); // Return a new compiled pattern object based on the cached information return new CCompiledStrRegExpr(*cacheEntry, false); } @@ -792,6 +796,12 @@ CCompiledStrRegExpr* fetchOrCreateCompiledStrRegExpr(int _regexLength, const cha compiledObjPtr = new CCompiledStrRegExpr(_regexLength, _regex, _isCaseSensitive, false); // Create a cache entry for the new object compiledStrRegExprCache.set(regexHash, std::make_shared(_regexLength, _regex, options, compiledObjPtr->getCompiledRegex())); + // Note a cache miss (add-to-cache) + if (sectionTimer) + { + sectionTimer->addStatistic(StNumCacheAdds, 1); + sectionTimer->mergeStatistic(StNumPeakCacheObjects, compiledStrRegExprCache.getCacheSize()); + } } return compiledObjPtr; @@ -806,24 +816,24 @@ CCompiledStrRegExpr* fetchOrCreateCompiledStrRegExpr(int _regexLength, const cha ECLRTL_API ICompiledStrRegExpr * rtlCreateCompiledStrRegExpr(const char * regExpr, bool isCaseSensitive) { - return fetchOrCreateCompiledStrRegExpr(strlen(regExpr), regExpr, isCaseSensitive); + return fetchOrCreateCompiledStrRegExpr(nullptr, strlen(regExpr), regExpr, isCaseSensitive); } ECLRTL_API ICompiledStrRegExpr * rtlCreateCompiledStrRegExprTimed(ISectionTimer * timer, const char * regExpr, bool isCaseSensitive) { SectionTimerBlock sectionTimer(timer); - return rtlCreateCompiledStrRegExpr(regExpr, isCaseSensitive); + return fetchOrCreateCompiledStrRegExpr(timer, strlen(regExpr), regExpr, isCaseSensitive); } ECLRTL_API ICompiledStrRegExpr * rtlCreateCompiledStrRegExpr(int regExprLength, const char * regExpr, bool isCaseSensitive) { - return fetchOrCreateCompiledStrRegExpr(regExprLength, regExpr, isCaseSensitive); + return fetchOrCreateCompiledStrRegExpr(nullptr, regExprLength, regExpr, isCaseSensitive); } ECLRTL_API ICompiledStrRegExpr * rtlCreateCompiledStrRegExprTimed(ISectionTimer * timer, int regExprLength, const char * regExpr, bool isCaseSensitive) { SectionTimerBlock sectionTimer(timer); - return rtlCreateCompiledStrRegExpr(regExprLength, regExpr, isCaseSensitive); + return fetchOrCreateCompiledStrRegExpr(timer, regExprLength, regExpr, isCaseSensitive); } ECLRTL_API void rtlDestroyCompiledStrRegExpr(ICompiledStrRegExpr * compiledExpr) @@ -849,13 +859,14 @@ ECLRTL_API void rtlDestroyStrRegExprFindInstance(IStrRegExprFindInstance * findI * or creates a new one if it doesn't. The regular expression object is created based on the provided * regex pattern, length, and case sensitivity flag. The created object is then cached for future use. * + * @param sectionTimer Pointer to a stat-aware section timer object; may be null. * @param _regexLength The length of the regex pattern, in code points. * @param _regex The regex pattern. * @param _isCaseSensitive Flag indicating whether the regex pattern is case sensitive or not. * @return A pointer to a copy of the fetched or created CCompiledStrRegExpr object. The returned object * * must eventually be deleted. */ -CCompiledStrRegExpr* fetchOrCreateCompiledU8StrRegExpr(int _regexLength, const char * _regex, bool _isCaseSensitive) +CCompiledStrRegExpr* fetchOrCreateCompiledU8StrRegExpr(ISectionTimer * sectionTimer, int _regexLength, const char * _regex, bool _isCaseSensitive) { if (compiledCacheEnabled) { @@ -871,6 +882,9 @@ CCompiledStrRegExpr* fetchOrCreateCompiledU8StrRegExpr(int _regexLength, const c if (cacheEntry && cacheEntry->hasSamePattern(regexSize, _regex, options)) { + // Note a cache hit + if (sectionTimer) + sectionTimer->addStatistic(StNumCacheHits, 1); // Return a new compiled pattern object based on the cached information return new CCompiledStrRegExpr(*cacheEntry, true); } @@ -879,6 +893,12 @@ CCompiledStrRegExpr* fetchOrCreateCompiledU8StrRegExpr(int _regexLength, const c compiledObjPtr = new CCompiledStrRegExpr(_regexLength, _regex, _isCaseSensitive, true); // Create a cache entry for the new object compiledStrRegExprCache.set(regexHash, std::make_shared(regexSize, _regex, options, compiledObjPtr->getCompiledRegex())); + // Note a cache miss (add-to-cache) + if (sectionTimer) + { + sectionTimer->addStatistic(StNumCacheAdds, 1); + sectionTimer->mergeStatistic(StNumPeakCacheObjects, compiledStrRegExprCache.getCacheSize()); + } } return compiledObjPtr; @@ -893,24 +913,24 @@ CCompiledStrRegExpr* fetchOrCreateCompiledU8StrRegExpr(int _regexLength, const c ECLRTL_API ICompiledStrRegExpr * rtlCreateCompiledU8StrRegExpr(const char * regExpr, bool isCaseSensitive) { - return fetchOrCreateCompiledU8StrRegExpr(rtlUtf8Length(regExpr), regExpr, isCaseSensitive); + return fetchOrCreateCompiledU8StrRegExpr(nullptr, rtlUtf8Length(regExpr), regExpr, isCaseSensitive); } ECLRTL_API ICompiledStrRegExpr * rtlCreateCompiledU8StrRegExprTimed(ISectionTimer * timer, const char * regExpr, bool isCaseSensitive) { SectionTimerBlock sectionTimer(timer); - return rtlCreateCompiledU8StrRegExpr(regExpr, isCaseSensitive); + return fetchOrCreateCompiledU8StrRegExpr(timer, rtlUtf8Length(regExpr), regExpr, isCaseSensitive); } ECLRTL_API ICompiledStrRegExpr * rtlCreateCompiledU8StrRegExpr(int regExprLength, const char * regExpr, bool isCaseSensitive) { - return fetchOrCreateCompiledU8StrRegExpr(regExprLength, regExpr, isCaseSensitive); + return fetchOrCreateCompiledU8StrRegExpr(nullptr, regExprLength, regExpr, isCaseSensitive); } ECLRTL_API ICompiledStrRegExpr * rtlCreateCompiledU8StrRegExprTimed(ISectionTimer * timer, int regExprLength, const char * regExpr, bool isCaseSensitive) { SectionTimerBlock sectionTimer(timer); - return rtlCreateCompiledU8StrRegExpr(regExprLength, regExpr, isCaseSensitive); + return fetchOrCreateCompiledU8StrRegExpr(timer, regExprLength, regExpr, isCaseSensitive); } ECLRTL_API void rtlDestroyCompiledU8StrRegExpr(ICompiledStrRegExpr * compiledExpr) @@ -1331,13 +1351,14 @@ class CCompiledUStrRegExpr final : implements ICompiledUStrRegExpr * or creates a new one if it doesn't. The regular expression object is created based on the provided * regex pattern, length, and case sensitivity flag. The created object is then cached for future use. * + * @param sectionTimer Pointer to a stat-aware section timer object; may be null. * @param _regexLength The length of the regex pattern, in code points. * @param _regex The regex pattern. * @param _isCaseSensitive Flag indicating whether the regex pattern is case sensitive or not. * @return A pointer to a copy of the fetched or created CCompiledUStrRegExpr object. The returned object * * must eventually be deleted. */ -CCompiledUStrRegExpr* fetchOrCreateCompiledUStrRegExpr(int _regexLength, const UChar * _regex, bool _isCaseSensitive) +CCompiledUStrRegExpr* fetchOrCreateCompiledUStrRegExpr(ISectionTimer * sectionTimer, int _regexLength, const UChar * _regex, bool _isCaseSensitive) { if (compiledCacheEnabled) { @@ -1353,6 +1374,9 @@ CCompiledUStrRegExpr* fetchOrCreateCompiledUStrRegExpr(int _regexLength, const U if (cacheEntry && cacheEntry->hasSamePattern(regexSize, reinterpret_cast(_regex), options)) { + // Note a cache hit + if (sectionTimer) + sectionTimer->addStatistic(StNumCacheHits, 1); // Return a new copy of the cached object return new CCompiledUStrRegExpr(*cacheEntry); } @@ -1361,6 +1385,9 @@ CCompiledUStrRegExpr* fetchOrCreateCompiledUStrRegExpr(int _regexLength, const U compiledObjPtr = new CCompiledUStrRegExpr(_regexLength, _regex, _isCaseSensitive); // Create a cache entry for the new object compiledStrRegExprCache.set(regexHash, std::make_shared(regexSize, reinterpret_cast(_regex), options, compiledObjPtr->getCompiledRegex())); + // Note a cache miss (add-to-cache) + if (sectionTimer) + sectionTimer->addStatistic(StNumCacheAdds, 1); } return compiledObjPtr; @@ -1375,24 +1402,24 @@ CCompiledUStrRegExpr* fetchOrCreateCompiledUStrRegExpr(int _regexLength, const U ECLRTL_API ICompiledUStrRegExpr * rtlCreateCompiledUStrRegExpr(const UChar * regExpr, bool isCaseSensitive) { - return fetchOrCreateCompiledUStrRegExpr(rtlUnicodeStrlen(regExpr), regExpr, isCaseSensitive); + return fetchOrCreateCompiledUStrRegExpr(nullptr, rtlUnicodeStrlen(regExpr), regExpr, isCaseSensitive); } ECLRTL_API ICompiledUStrRegExpr * rtlCreateCompiledUStrRegExprTimed(ISectionTimer * timer, const UChar * regExpr, bool isCaseSensitive) { SectionTimerBlock sectionTimer(timer); - return rtlCreateCompiledUStrRegExpr(regExpr, isCaseSensitive); + return fetchOrCreateCompiledUStrRegExpr(timer, rtlUnicodeStrlen(regExpr), regExpr, isCaseSensitive); } ECLRTL_API ICompiledUStrRegExpr * rtlCreateCompiledUStrRegExpr(int regExprLength, const UChar * regExpr, bool isCaseSensitive) { - return fetchOrCreateCompiledUStrRegExpr(regExprLength, regExpr, isCaseSensitive); + return fetchOrCreateCompiledUStrRegExpr(nullptr, regExprLength, regExpr, isCaseSensitive); } ECLRTL_API ICompiledUStrRegExpr * rtlCreateCompiledUStrRegExprTimed(ISectionTimer * timer, int regExprLength, const UChar * regExpr, bool isCaseSensitive) { SectionTimerBlock sectionTimer(timer); - return rtlCreateCompiledUStrRegExpr(regExprLength, regExpr, isCaseSensitive); + return fetchOrCreateCompiledUStrRegExpr(timer, regExprLength, regExpr, isCaseSensitive); } ECLRTL_API void rtlDestroyCompiledUStrRegExpr(ICompiledUStrRegExpr * compiledExpr) diff --git a/rtl/eclrtl/wfcontext.cpp b/rtl/eclrtl/wfcontext.cpp index 48c3db272a0..abb86ed3c71 100644 --- a/rtl/eclrtl/wfcontext.cpp +++ b/rtl/eclrtl/wfcontext.cpp @@ -366,6 +366,11 @@ unsigned IndirectCodeContext::getWorkflowId() const return ctx->getWorkflowId(); } +ISectionTimer *IndirectCodeContext::registerStatsTimer(unsigned activityId, const char * name, unsigned int statsOption) +{ + return ctx->registerStatsTimer(activityId, name, statsOption); +} + ICodeContext * GlobalCodeContextExtra::queryCodeContext() { return &codeContextEx; diff --git a/rtl/eclrtl/wfcontext.hpp b/rtl/eclrtl/wfcontext.hpp index a659d2d6c36..d05d4e01add 100644 --- a/rtl/eclrtl/wfcontext.hpp +++ b/rtl/eclrtl/wfcontext.hpp @@ -85,6 +85,7 @@ class ECLRTL_API IndirectCodeContext : implements ICodeContext virtual void addWuExceptionEx(const char * text, unsigned code, unsigned severity, unsigned audience, const char *source) override; virtual unsigned getElapsedMs() const override; virtual unsigned getWorkflowId() const override; + virtual ISectionTimer * registerStatsTimer(unsigned activityId, const char * name, unsigned int statsOption) override; }; class ECLRTL_API GlobalCodeContextExtra : implements IGlobalCodeContext diff --git a/rtl/include/eclhelper.hpp b/rtl/include/eclhelper.hpp index b312b7a3409..83754266557 100644 --- a/rtl/include/eclhelper.hpp +++ b/rtl/include/eclhelper.hpp @@ -674,6 +674,11 @@ interface ISectionTimer : public IInterface { virtual unsigned __int64 getStartCycles() = 0; virtual void noteSectionTime(unsigned __int64 startCycles) = 0; + + // arg kind is of type StatisticKind + virtual void addStatistic(__int64 kind, unsigned __int64 value) = 0; + virtual void setStatistic(__int64 kind, unsigned __int64 value) = 0; + virtual void mergeStatistic(__int64 kind, unsigned __int64 value) = 0; }; //NB: New methods must always be added at the end of this interface to retain backward compatibility @@ -787,11 +792,12 @@ interface ICodeContext : public IResourceContext virtual const void * fromJson(IEngineRowAllocator * _rowAllocator, size32_t len, const char * utf8, IXmlToRowTransformer * xmlTransformer, bool stripWhitespace) = 0; virtual void getRowJSON(size32_t & lenResult, char * & result, IOutputMetaData & info, const void * row, unsigned flags) = 0; virtual unsigned getExternalResultHash(const char * wuid, const char * name, unsigned sequence) = 0; - virtual ISectionTimer * registerTimer(unsigned activityId, const char * name) = 0; + virtual ISectionTimer * registerTimer(unsigned activityId, const char * name) = 0; // see also registerStatTimer virtual IEngineRowAllocator * getRowAllocatorEx(IOutputMetaData * meta, unsigned activityId, unsigned flags) const = 0; virtual void addWuExceptionEx(const char * text, unsigned code, unsigned severity, unsigned audience, const char * source) = 0; virtual unsigned getElapsedMs() const = 0; virtual unsigned getWorkflowId() const = 0; // Note: don't use yet as it has not been fully implemented in all derived classes + virtual ISectionTimer * registerStatsTimer(unsigned activityId, const char * name, unsigned int statsOption) = 0; }; //Provided by engine=>can extend diff --git a/system/jlib/jstatcodes.h b/system/jlib/jstatcodes.h index a4744cd246e..0c8be6186c2 100644 --- a/system/jlib/jstatcodes.h +++ b/system/jlib/jstatcodes.h @@ -321,6 +321,9 @@ enum StatisticKind StNumSoapcallConnectFailures, StTimeLookAhead, StCycleLookAheadCycles, + StNumCacheHits, // Generic 'cache hit' stats, potentially used for many caches; Roxie-specific stats are above + StNumCacheAdds, // Generic 'cache add/miss' stats, potentially used for many caches; Roxie-specific stats are above + StNumPeakCacheObjects, // Peak number of objects in a generic cache StMax, //For any quantity there is potentially the following variants. diff --git a/system/jlib/jstats.cpp b/system/jlib/jstats.cpp index 29f47ee54d9..49d01e9d3b7 100644 --- a/system/jlib/jstats.cpp +++ b/system/jlib/jstats.cpp @@ -773,6 +773,7 @@ StatisticMeasure queryMeasure(const char * measure, StatisticMeasure dft) #define ENUMSTAT(y) STAT(Enum, y, SMeasureEnum, StatsMergeKeepNonZero) #define COSTSTAT(y) STAT(Cost, y, SMeasureCost, StatsMergeSum) #define PEAKSIZESTAT(y) STAT(Size, y, SMeasureSize, StatsMergeMax) +#define PEAKNUMSTAT(y) STAT(Num, y, SMeasureCount, StatsMergeMax) //-------------------------------------------------------------------------------------------------------------------- class StatisticMeta @@ -993,6 +994,9 @@ static const constexpr StatisticMeta statsMetaData[StMax] = { { NUMSTAT(SoapcallConnectFailures), "The number of SOAPCALL connect failures" }, { TIMESTAT(LookAhead), "The total time lookahead thread spend prefetching rows from upstream activities" }, { CYCLESTAT(LookAhead) }, + { NUMSTAT(CacheHits), "The number of times an item was retrieved from a cache" }, + { NUMSTAT(CacheAdds), "The number of times an item was added to a cache" }, + { PEAKNUMSTAT(PeakCacheObjects), "High water mark for number of objects in a cache"}, }; static MapStringTo statisticNameMap(true); diff --git a/thorlcr/graph/thgraph.cpp b/thorlcr/graph/thgraph.cpp index fd2f2cfa07a..a8235c57985 100644 --- a/thorlcr/graph/thgraph.cpp +++ b/thorlcr/graph/thgraph.cpp @@ -348,6 +348,11 @@ unsigned CActivityCodeContext::getGraphLoopCounter() const } ISectionTimer * CActivityCodeContext::registerTimer(unsigned activityId, const char * name) +{ + return registerStatsTimer(activityId, name, 0); +} + +ISectionTimer * CActivityCodeContext::registerStatsTimer(unsigned activityId, const char * name, unsigned int statsOption) { if (!stats) // if master context and local CQ, there is no activity instance, and hence no setStats call return queryNullSectionTimer(); @@ -356,7 +361,7 @@ ISectionTimer * CActivityCodeContext::registerTimer(unsigned activityId, const c if (it != functionTimers.end()) return it->second; - ISectionTimer *timer = ThorSectionTimer::createTimer(*stats, name); + ISectionTimer *timer = ThorSectionTimer::createTimer(*stats, name, static_cast(statsOption)); functionTimers.insert({name, timer}); // owns return timer; } diff --git a/thorlcr/graph/thgraph.hpp b/thorlcr/graph/thgraph.hpp index 8a3ce04df21..adbffe2aa98 100644 --- a/thorlcr/graph/thgraph.hpp +++ b/thorlcr/graph/thgraph.hpp @@ -409,6 +409,7 @@ class CActivityCodeContext : implements ICodeContextExt { return ctx->getElapsedMs(); } + virtual ISectionTimer * registerStatsTimer(unsigned activityId, const char * name, unsigned int statsOption); }; diff --git a/thorlcr/thorcodectx/thcodectx.cpp b/thorlcr/thorcodectx/thcodectx.cpp index 797e1e0767a..507881c5643 100644 --- a/thorlcr/thorcodectx/thcodectx.cpp +++ b/thorlcr/thorcodectx/thcodectx.cpp @@ -165,3 +165,8 @@ ISectionTimer * CThorCodeContextBase::registerTimer(unsigned activityId, const c { return queryNullSectionTimer(); } + +ISectionTimer * CThorCodeContextBase::registerStatsTimer(unsigned activityId, const char * name, unsigned int statsOption) +{ + return queryNullSectionTimer(); +} diff --git a/thorlcr/thorcodectx/thcodectx.hpp b/thorlcr/thorcodectx/thcodectx.hpp index 1e2cae3f17d..e61b4a63073 100644 --- a/thorlcr/thorcodectx/thcodectx.hpp +++ b/thorlcr/thorcodectx/thcodectx.hpp @@ -129,6 +129,7 @@ class thcodectx_decl CThorCodeContextBase : public CSimpleInterfaceOf