diff --git a/common/thorhelper/thorcommon.hpp b/common/thorhelper/thorcommon.hpp index 2378dc4ae8b..5ddc7e762a8 100644 --- a/common/thorhelper/thorcommon.hpp +++ b/common/thorhelper/thorcommon.hpp @@ -18,6 +18,7 @@ #ifndef THORCOMMON_HPP #define THORCOMMON_HPP +#include "jlog.hpp" #include "jiface.hpp" #include "jcrc.hpp" #include "jlzw.hpp" @@ -672,6 +673,92 @@ class THORHELPER_API IndirectCodeContext : implements ICodeContext protected: ICodeContext * ctx; }; +class CStatsContextLogger : public CSimpleInterfaceOf +{ +protected: + const LogMsgJobInfo job; + unsigned traceLevel = 1; + Owned activeSpan; + mutable CRuntimeStatisticCollection stats; +public: + CStatsContextLogger(const CRuntimeStatisticCollection &_mapping, const LogMsgJobInfo & _job=unknownJob) : job(_job), stats(_mapping) {} + + virtual void CTXLOGva(const LogMsgCategory & cat, const LogMsgJobInfo & job, LogMsgCode code, const char *format, va_list args) const override __attribute__((format(printf,5,0))) + { + VALOG(cat, job, code, format, args); + } + virtual void logOperatorExceptionVA(IException *E, const char *file, unsigned line, const char *format, va_list args) const __attribute__((format(printf,5,0))) + { + StringBuffer ss; + ss.append("ERROR"); + if (E) + ss.append(": ").append(E->errorCode()); + if (file) + ss.appendf(": %s(%d) ", file, line); + if (E) + E->errorMessage(ss.append(": ")); + if (format) + ss.append(": ").valist_appendf(format, args); + LOG(MCoperatorProgress, queryJob(), "%s", ss.str()); + } + virtual void noteStatistic(StatisticKind kind, unsigned __int64 value) const override + { + stats.addStatisticAtomic(kind, value); + } + virtual void setStatistic(StatisticKind kind, unsigned __int64 value) const override + { + stats.setStatistic(kind, value); + } + virtual void mergeStats(const CRuntimeStatisticCollection &from) const override + { + stats.merge(from); + } + virtual unsigned queryTraceLevel() const override + { + return traceLevel; + } + virtual void setActiveSpan(ISpan * span) override + { + activeSpan.set(span); + } + virtual IProperties * getClientHeaders() const override + { + if (!activeSpan) + return nullptr; + return ::getClientHeaders(activeSpan); + } + virtual const char *queryGlobalId() const override + { + if (!activeSpan) + return nullptr; + return activeSpan->queryGlobalId(); + } + virtual const char *queryLocalId() const override + { + if (!activeSpan) + return nullptr; + return activeSpan->queryLocalId(); + } + virtual const char *queryCallerId() const override + { + if (!activeSpan) + return nullptr; + return activeSpan->queryCallerId(); + } + virtual const CRuntimeStatisticCollection &queryStats() const override + { + return stats; + } + virtual void recordStatistics(IStatisticGatherer &progress) const override + { + stats.recordStatistics(progress, false); + } + void updateStatsDeltaTo(CRuntimeStatisticCollection &to, CRuntimeStatisticCollection &previous) + { + previous.updateDelta(to, stats); + } + virtual const LogMsgJobInfo & queryJob() const override { return job; } +}; extern THORHELPER_API bool isActivitySink(ThorActivityKind kind); extern THORHELPER_API bool isActivitySource(ThorActivityKind kind); diff --git a/ecl/hthor/hthorkey.cpp b/ecl/hthor/hthorkey.cpp index 9f5b46155ad..16ea4aee6ab 100644 --- a/ecl/hthor/hthorkey.cpp +++ b/ecl/hthor/hthorkey.cpp @@ -27,6 +27,7 @@ #include "thorcommon.hpp" #include "rtldynfield.hpp" #include "thorfile.hpp" +#include "jstats.h" #define MAX_FETCH_LOOKAHEAD 1000 @@ -200,24 +201,10 @@ class CHThorIndexReadActivityBase : public CHThorActivityBase { CHThorActivityBase::updateProgress(progress); StatsActivityScope scope(progress, activityId); + contextLogger.recordStatistics(progress); progress.addStatistic(StNumPostFiltered, queryPostFiltered()); - progress.addStatistic(StNumIndexSeeks, querySeeks()); - progress.addStatistic(StNumIndexScans, queryScans()); - progress.addStatistic(StNumIndexWildSeeks, queryWildSeeks()); } - virtual unsigned querySeeks() const - { - return seeks + (klManager ? klManager->querySeeks() : 0); - } - virtual unsigned queryScans() const - { - return scans + (klManager ? klManager->queryScans() : 0); - } - virtual unsigned queryWildSeeks() const - { - return wildseeks + (klManager ? klManager->queryWildSeeks() : 0); - } virtual unsigned queryPostFiltered() const { return postFiltered; @@ -281,10 +268,8 @@ class CHThorIndexReadActivityBase : public CHThorActivityBase UnsignedArray superIndexCache; unsigned keyIndexCacheIdx = 0; - unsigned seeks; - unsigned scans; unsigned postFiltered; - unsigned wildseeks; + CStatsContextLogger contextLogger; bool singlePart = false; // a single part index, not part of a super file - optimize so never reload the part. bool localSortKey = false; bool initializedFileInfo = false; @@ -306,16 +291,13 @@ class CHThorIndexReadActivityBase : public CHThorActivityBase }; CHThorIndexReadActivityBase::CHThorIndexReadActivityBase(IAgentContext &_agent, unsigned _activityId, unsigned _subgraphId, IHThorIndexReadBaseArg &_arg, ThorActivityKind _kind, EclGraph & _graph, IPropertyTree *_node) - : CHThorActivityBase(_agent, _activityId, _subgraphId, _arg, _kind, _graph), helper(_arg) + : CHThorActivityBase(_agent, _activityId, _subgraphId, _arg, _kind, _graph), helper(_arg), contextLogger(jhtreeCacheStatistics) { nextPartNumber = 0; eclKeySize.set(helper.queryDiskRecordSize()); postFiltered = 0; - seeks = 0; - scans = 0; - wildseeks = 0; helper.setCallback(&callback); limitTransformExtra = nullptr; if (_node) @@ -437,7 +419,7 @@ bool CHThorIndexReadActivityBase::doPreopenLimitFile(unsigned __int64 & count, u { Owned tlk = openKeyFile(df->queryPart(num)); verifyIndex(tlk); - Owned tlman = createLocalKeyManager(eclKeySize.queryRecordAccessor(true), tlk, NULL, helper.hasNewSegmentMonitors(), false); + Owned tlman = createLocalKeyManager(eclKeySize.queryRecordAccessor(true), tlk, &contextLogger, helper.hasNewSegmentMonitors(), false); initManager(tlman, true); while(tlman->lookup(false) && (count<=limit)) { @@ -473,7 +455,7 @@ IKeyIndex * CHThorIndexReadActivityBase::doPreopenLimitPart(unsigned __int64 & r verifyIndex(kidx); if (limit != (unsigned) -1) { - Owned kman = createLocalKeyManager(eclKeySize.queryRecordAccessor(true), kidx, NULL, helper.hasNewSegmentMonitors(), false); + Owned kman = createLocalKeyManager(eclKeySize.queryRecordAccessor(true), kidx, &contextLogger, helper.hasNewSegmentMonitors(), false); initManager(kman, false); result += kman->checkCount(limit-result); } @@ -572,10 +554,10 @@ void CHThorIndexReadActivityBase::initManager(IKeyManager *manager, bool isTlk) manager->reset(); } -void CHThorIndexReadActivityBase::initPart() -{ +void CHThorIndexReadActivityBase::initPart() +{ assertex(!keyIndex->isTopLevelKey()); - klManager.setown(createLocalKeyManager(eclKeySize.queryRecordAccessor(true), keyIndex, NULL, helper.hasNewSegmentMonitors(), false)); + klManager.setown(createLocalKeyManager(eclKeySize.queryRecordAccessor(true), keyIndex, &contextLogger, helper.hasNewSegmentMonitors(), false)); initManager(klManager, false); callback.setManager(klManager, nullptr); } @@ -584,12 +566,7 @@ void CHThorIndexReadActivityBase::killPart() { callback.setManager(nullptr, nullptr); if (klManager) - { - seeks += klManager->querySeeks(); - scans += klManager->queryScans(); - wildseeks += klManager->queryWildSeeks(); klManager.clear(); - } } bool CHThorIndexReadActivityBase::setCurrentPart(unsigned whichPart) @@ -614,7 +591,7 @@ bool CHThorIndexReadActivityBase::firstMultiPart() if(!tlk) openTlk(); verifyIndex(tlk); - tlManager.setown(createLocalKeyManager(eclKeySize.queryRecordAccessor(true), tlk, NULL, helper.hasNewSegmentMonitors(), false)); + tlManager.setown(createLocalKeyManager(eclKeySize.queryRecordAccessor(true), tlk, &contextLogger, helper.hasNewSegmentMonitors(), false)); initManager(tlManager, true); nextPartNumber = 0; return nextMultiPart(); @@ -3044,11 +3021,11 @@ class KeyedLookupPartHandler : extends ThreadedPartHandler, implements Owned manager; IAgentContext &agent; DistributedKeyLookupHandler * tlk; - + IContextLogger &contextLogger; public: IMPLEMENT_IINTERFACE; - KeyedLookupPartHandler(IJoinProcessor &_owner, IDistributedFilePart *_part, DistributedKeyLookupHandler * _tlk, unsigned _subno, IThreadPool * _threadPool, IAgentContext &_agent); + KeyedLookupPartHandler(IJoinProcessor &_owner, IDistributedFilePart *_part, DistributedKeyLookupHandler * _tlk, unsigned _subno, IThreadPool * _threadPool, IAgentContext &_agent, IContextLogger & _contextLogger); ~KeyedLookupPartHandler() { @@ -3098,6 +3075,7 @@ class DistributedKeyLookupHandler : public CInterface, implements IThreadedExcep Owned threadPool; IntArray subSizes; IAgentContext &agent; + IContextLogger &contextLogger; void addFile(IDistributedFile &f) { @@ -3108,7 +3086,7 @@ class DistributedKeyLookupHandler : public CInterface, implements IThreadedExcep for (unsigned idx = 0; idx < numParts; idx++) { IDistributedFilePart *part = f.getPart(idx); - parts.append(*new KeyedLookupPartHandler(owner, part, this, tlks.ordinality(), threadPool, agent)); + parts.append(*new KeyedLookupPartHandler(owner, part, this, tlks.ordinality(), threadPool, agent, contextLogger)); } keyFiles.append(OLINK(f)); tlks.append(*f.getPart(numParts)); @@ -3118,8 +3096,8 @@ class DistributedKeyLookupHandler : public CInterface, implements IThreadedExcep public: IMPLEMENT_IINTERFACE; - DistributedKeyLookupHandler(IDistributedFile *f, IJoinProcessor &_owner, IAgentContext &_agent) - : owner(_owner), file(f), agent(_agent) + DistributedKeyLookupHandler(IDistributedFile *f, IJoinProcessor &_owner, IAgentContext &_agent, IContextLogger & _contextLogger) + : owner(_owner), file(f), agent(_agent), contextLogger(_contextLogger) { threadPool.setown(createThreadPool("hthor keyed join lookup thread pool", &threadFactory)); IDistributedSuperFile *super = f->querySuperFile(); @@ -3184,7 +3162,7 @@ class DistributedKeyLookupHandler : public CInterface, implements IThreadedExcep //Owned trans.setown(owner.getLayoutTranslator(&f)); owner.verifyIndex(&f, index, trans); - Owned manager = createLocalKeyManager(owner.queryIndexRecord(), index, NULL, owner.hasNewSegmentMonitors(), false); + Owned manager = createLocalKeyManager(owner.queryIndexRecord(), index, &contextLogger, owner.hasNewSegmentMonitors(), false); managers.append(*manager.getLink()); } opened = true; @@ -3213,8 +3191,8 @@ class DistributedKeyLookupHandler : public CInterface, implements IThreadedExcep const IDynamicTransform * queryRecordLayoutTranslator() const { return trans; } }; -KeyedLookupPartHandler::KeyedLookupPartHandler(IJoinProcessor &_owner, IDistributedFilePart *_part, DistributedKeyLookupHandler * _tlk, unsigned _subno, IThreadPool * _threadPool, IAgentContext &_agent) - : ThreadedPartHandler(_part, _tlk, _threadPool), owner(_owner), agent(_agent), tlk(_tlk) +KeyedLookupPartHandler::KeyedLookupPartHandler(IJoinProcessor &_owner, IDistributedFilePart *_part, DistributedKeyLookupHandler * _tlk, unsigned _subno, IThreadPool * _threadPool, IAgentContext &_agent, IContextLogger & _contextLogger) + : ThreadedPartHandler(_part, _tlk, _threadPool), owner(_owner), agent(_agent), tlk(_tlk), contextLogger(_contextLogger) { } @@ -3223,7 +3201,7 @@ void KeyedLookupPartHandler::openPart() if(manager) return; Owned index = openKeyFile(*part); - manager.setown(createLocalKeyManager(owner.queryIndexRecord(), index, NULL, owner.hasNewSegmentMonitors(), false)); + manager.setown(createLocalKeyManager(owner.queryIndexRecord(), index, &contextLogger, owner.hasNewSegmentMonitors(), false)); const IDynamicTransform * trans = tlk->queryRecordLayoutTranslator(); if(trans && !index->isTopLevelKey()) manager->setLayoutTranslator(trans); @@ -3238,13 +3216,14 @@ class MonolithicKeyLookupHandler : public CInterface, implements IKeyLookupHandl IJoinProcessor &owner; IAgentContext &agent; bool opened; + IContextLogger &contextLogger; public: IMPLEMENT_IINTERFACE; - MonolithicKeyLookupHandler(IDistributedFile *f, IJoinProcessor &_owner, IAgentContext &_agent) - : file(f), owner(_owner), agent(_agent), opened(false) + MonolithicKeyLookupHandler(IDistributedFile *f, IJoinProcessor &_owner, IAgentContext &_agent, IContextLogger & _contextLogger) + : file(f), owner(_owner), agent(_agent), opened(false), contextLogger(_contextLogger) { super = f->querySuperFile(); if (super) @@ -3303,7 +3282,7 @@ class MonolithicKeyLookupHandler : public CInterface, implements IKeyLookupHandl { Owned index = openKeyFile(f.queryPart(0)); owner.verifyIndex(&f, index, trans); - manager.setown(createLocalKeyManager(owner.queryIndexRecord(), index, NULL, owner.hasNewSegmentMonitors(), false)); + manager.setown(createLocalKeyManager(owner.queryIndexRecord(), index, &contextLogger, owner.hasNewSegmentMonitors(), false)); } else { @@ -3316,7 +3295,7 @@ class MonolithicKeyLookupHandler : public CInterface, implements IKeyLookupHandl parts->addIndex(index.getLink()); } owner.verifyIndex(&f, index, trans); - manager.setown(createKeyMerger(owner.queryIndexRecord(), parts, 0, nullptr, owner.hasNewSegmentMonitors(), false)); + manager.setown(createKeyMerger(owner.queryIndexRecord(), parts, 0, &contextLogger, owner.hasNewSegmentMonitors(), false)); } if(trans) manager->setLayoutTranslator(trans); @@ -3412,9 +3391,6 @@ class CHThorKeyedJoinActivity : public CHThorThreadedActivityBase, implements I RelaxedAtomic prefiltered; RelaxedAtomic postfiltered; RelaxedAtomic skips; - unsigned seeks; - unsigned scans; - unsigned wildseeks; OwnedRowArray extractedRows; Owned ldFile; IDistributedFile * dFile; @@ -3426,15 +3402,15 @@ class CHThorKeyedJoinActivity : public CHThorThreadedActivityBase, implements I Owned translator; RecordTranslationMode recordTranslationModeHint = RecordTranslationMode::Unspecified; bool isCodeSigned = false; + CStatsContextLogger contextLogger; + public: CHThorKeyedJoinActivity(IAgentContext &_agent, unsigned _activityId, unsigned _subgraphId, IHThorKeyedJoinArg &_arg, ThorActivityKind _kind, EclGraph & _graph, IPropertyTree *_node) - : CHThorThreadedActivityBase(_agent, _activityId, _subgraphId, _arg, _arg, _kind, _graph, _arg.queryDiskRecordSize(), _node), helper(_arg) + : CHThorThreadedActivityBase(_agent, _activityId, _subgraphId, _arg, _arg, _kind, _graph, _arg.queryDiskRecordSize(), _node), helper(_arg), contextLogger(jhtreeCacheStatistics) { prefiltered = 0; postfiltered = 0; skips = 0; - seeks = 0; - scans = 0; eclKeySize.set(helper.queryIndexRecordSize()); if (_node) { @@ -3990,9 +3966,9 @@ class CHThorKeyedJoinActivity : public CHThorThreadedActivityBase, implements I mono = useMonolithic(*dFile); } if (mono) - lookup.setown(new MonolithicKeyLookupHandler(dFile, *this, agent)); + lookup.setown(new MonolithicKeyLookupHandler(dFile, *this, agent, contextLogger)); else - lookup.setown(new DistributedKeyLookupHandler(dFile, *this, agent)); + lookup.setown(new DistributedKeyLookupHandler(dFile, *this, agent, contextLogger)); agent.logFileAccess(dFile, "HThor", "READ", graph); } else @@ -4015,10 +3991,6 @@ class CHThorKeyedJoinActivity : public CHThorThreadedActivityBase, implements I virtual void doneManager(IKeyManager * manager) { manager->releaseSegmentMonitors(); - CriticalBlock b(statsCrit); - seeks += manager->querySeeks(); - scans += manager->queryScans(); - wildseeks += manager->queryWildSeeks(); } virtual bool addMatch(MatchSet * ms, IKeyManager * manager) @@ -4089,9 +4061,7 @@ class CHThorKeyedJoinActivity : public CHThorThreadedActivityBase, implements I progress.addStatistic(StNumPreFiltered, prefiltered); progress.addStatistic(StNumPostFiltered, postfiltered); progress.addStatistic(StNumIndexSkips, skips); - progress.addStatistic(StNumIndexSeeks, seeks); - progress.addStatistic(StNumIndexScans, scans); - progress.addStatistic(StNumIndexWildSeeks, wildseeks); + contextLogger.recordStatistics(progress); } protected: diff --git a/fs/dafsclient/rmtfile.cpp b/fs/dafsclient/rmtfile.cpp index 92f3cbe16cc..2371442edda 100644 --- a/fs/dafsclient/rmtfile.cpp +++ b/fs/dafsclient/rmtfile.cpp @@ -2587,10 +2587,6 @@ class CRemoteKey : public CSimpleInterfaceOf pending = true; return prefetchBuffer.queryRow(); } - virtual unsigned querySeeks() const override { return 0; } // not sure how best to handle these, perhaps should log/record somewhere on server-side - virtual unsigned queryScans() const override { return 0; } - virtual unsigned querySkips() const override { return 0; } - virtual unsigned queryWildSeeks() const override { return 0; } }; diff --git a/roxie/ccd/ccd.hpp b/roxie/ccd/ccd.hpp index 1999986d9e5..422153cdfb8 100644 --- a/roxie/ccd/ccd.hpp +++ b/roxie/ccd/ccd.hpp @@ -774,6 +774,10 @@ class ContextLogger : implements IRoxieContextLogger, public CInterface { return stats; } + virtual void recordStatistics(IStatisticGatherer &progress) const override + { + stats.recordStatistics(progress, false); + } }; class StringContextLogger : public ContextLogger diff --git a/roxie/ccd/ccdactivities.cpp b/roxie/ccd/ccdactivities.cpp index 3f91de618c6..3d0f364e604 100644 --- a/roxie/ccd/ccdactivities.cpp +++ b/roxie/ccd/ccdactivities.cpp @@ -2996,7 +2996,13 @@ class CRoxieIndexReadActivity : public CRoxieIndexActivity, implements IIndexRea if (continuationNeeded && !continuationFailed) { if (doTrace(traceSmartStepping, TraceFlags::Detailed)) - logctx.CTXLOG("Indexread returning partial result set %d rows from %d seeks, %d scans, %d skips", processed-processedBefore, tlk->querySeeks(), tlk->queryScans(), tlk->querySkips()); + { + const CRuntimeStatisticCollection & stats = logctx.queryStats(); + unsigned __int64 seeks = stats.getStatisticValue(StNumIndexSeeks); + unsigned __int64 scans = stats.getStatisticValue(StNumIndexScans); + unsigned __int64 skips = stats.getStatisticValue(StNumIndexSkips); + logctx.CTXLOG("Indexread returning partial result set %d rows from %" I64F"u seeks, %" I64F"u scans, %" I64F"u skips", processed-processedBefore, seeks, scans, skips); + } if (sendContinuation(output)) { noteStats(keyprocessed-keyprocessedBefore, skipped); @@ -3023,7 +3029,11 @@ class CRoxieIndexReadActivity : public CRoxieIndexActivity, implements IIndexRea { if (doTrace(traceSmartStepping, TraceFlags::Max) && !aborted) { - logctx.CTXLOG("Indexread returning result set %d rows from %d seeks, %d scans, %d skips", processed-processedBefore, tlk->querySeeks(), tlk->queryScans(), tlk->querySkips()); + const CRuntimeStatisticCollection & stats = logctx.queryStats(); + unsigned __int64 seeks = stats.getStatisticValue(StNumIndexSeeks); + unsigned __int64 scans = stats.getStatisticValue(StNumIndexScans); + unsigned __int64 skips = stats.getStatisticValue(StNumIndexSkips); + logctx.CTXLOG("Indexread returning result set %d rows from %" I64F"u seeks, %" I64F"u scans, %" I64F"u skips", processed-processedBefore, seeks, scans, skips); if (steppingOffset) logctx.CTXLOG("Indexread return: steppingOffset %d, steppingRow %p, stepExtra.returnMismatches() %d",steppingOffset, steppingRow, (int) stepExtra.returnMismatches()); } diff --git a/roxie/ccd/ccdcontext.cpp b/roxie/ccd/ccdcontext.cpp index 70afbbb7148..e4ce9360790 100644 --- a/roxie/ccd/ccdcontext.cpp +++ b/roxie/ccd/ccdcontext.cpp @@ -1327,7 +1327,10 @@ class CRoxieContextBase : implements IRoxieAgentContext, implements ICodeContext { return logctx.getStats(ret); } - + virtual void recordStatistics(IStatisticGatherer &progress) const override + { + globalStats.recordStatistics(progress, false); + } virtual void CTXLOGa(TracingCategory category, const LogMsgCategory & cat, const LogMsgJobInfo & job, LogMsgCode code, const char *prefix, const char *text) const override { logctx.CTXLOGa(category, cat, job, code, prefix, text); diff --git a/roxie/ccd/ccdserver.cpp b/roxie/ccd/ccdserver.cpp index c7333050318..e710f8448b6 100644 --- a/roxie/ccd/ccdserver.cpp +++ b/roxie/ccd/ccdserver.cpp @@ -231,6 +231,10 @@ class IndirectAgentContext : implements IRoxieAgentContext, public CInterface { ctx->gatherStats(merged); } + virtual void recordStatistics(IStatisticGatherer &progress) const override + { + ctx->recordStatistics(progress); + } virtual bool collectingDetailedStatistics() const { return ctx->collectingDetailedStatistics(); @@ -1374,6 +1378,10 @@ class CRoxieServerActivity : implements CInterfaceOf, impl { return stats; } + virtual void recordStatistics(IStatisticGatherer &progress) const + { + stats.recordStatistics(progress, false); + } virtual bool isPassThrough() { return false; diff --git a/system/jhtree/jhtree.cpp b/system/jhtree/jhtree.cpp index 22daf58860a..d1cc840d080 100644 --- a/system/jhtree/jhtree.cpp +++ b/system/jhtree/jhtree.cpp @@ -390,31 +390,11 @@ class jhtree_decl CKeyLevelManager : implements IKeyManager, public CInterface return keyCursor ? 1 : 0; } - virtual unsigned querySeeks() const - { - return stats.seeks; - } - - virtual unsigned queryScans() const - { - return stats.scans; - } - - virtual unsigned querySkips() const - { - return stats.skips; - } - virtual void resetCounts() { stats.reset(); } - virtual unsigned queryWildSeeks() const - { - return stats.wildseeks; - } - void setKey(IKeyIndexBase * _key) { ::Release(keyCursor); @@ -1525,7 +1505,6 @@ bool CKeyIndex::prewarmPage(offset_t offset, NodeType type) const CJHSearchNode *CKeyIndex::locateFirstLeafNode(KeyStatsCollector &stats) const { keySeeks++; - stats.seeks++; offset_t leafOffset = keyHdr->getFirstLeafPos(); if (leafOffset != (offset_t)-1) @@ -1556,7 +1535,7 @@ const CJHSearchNode *CKeyIndex::locateFirstLeafNode(KeyStatsCollector &stats) co const CJHSearchNode *CKeyIndex::locateLastLeafNode(KeyStatsCollector &stats) const { keySeeks++; - stats.seeks++; + stats.noteSeeks(1, 0, 0); //Unusual - an index with no elements if (keyHdr->getNumRecords() == 0) @@ -1588,9 +1567,6 @@ const CJHSearchNode *CKeyIndex::locateLastLeafNode(KeyStatsCollector &stats) con void KeyStatsCollector::noteSeeks(unsigned lseeks, unsigned lscans, unsigned lwildseeks) { - seeks += lseeks; - scans += lscans; - wildseeks += lwildseeks; if (ctx) { if (lseeks) ctx->noteStatistic(StNumIndexSeeks, lseeks); @@ -1601,7 +1577,6 @@ void KeyStatsCollector::noteSeeks(unsigned lseeks, unsigned lscans, unsigned lwi void KeyStatsCollector::noteSkips(unsigned lskips, unsigned lnullSkips) { - skips += lskips; if (ctx) { if (lskips) ctx->noteStatistic(StNumIndexSkips, lskips); @@ -1611,11 +1586,6 @@ void KeyStatsCollector::noteSkips(unsigned lskips, unsigned lnullSkips) void KeyStatsCollector::reset() { - seeks = 0; - scans = 0; - wildseeks = 0; - skips = 0; - nullskips = 0; } CKeyCursor::CKeyCursor(CKeyIndex &_key, const IIndexFilterList *_filter, bool _logExcessiveSeeks) @@ -2016,7 +1986,18 @@ bool CKeyCursor::lookupSkip(const void *seek, size32_t seekOffset, size32_t seek { recstr.appendf("%02x ", ((unsigned char *) recordBuffer)[i]); } - DBGLOG("SKIP: Got skips=%02d seeks=%02d scans=%02d : %s", stats.skips, stats.seeks, stats.scans, recstr.str()); + if (stats.ctx) + { + const CRuntimeStatisticCollection &statsCollection = stats.ctx->queryStats(); + unsigned __int64 seeks = statsCollection.getStatisticValue(StNumIndexSeeks); + unsigned __int64 scans = statsCollection.getStatisticValue(StNumIndexScans); + unsigned __int64 skips = statsCollection.getStatisticValue(StNumIndexSkips); + DBGLOG("SKIP: Got skips=%" I64F "u seeks=%" I64F "u scans=%" I64F "u : %s", skips, seeks, scans, recstr.str()); + } + else + { + DBGLOG("SKIP: (no ContextLogger - not tracking stats) : %s", recstr.str()); + } } #endif return ret; @@ -2980,7 +2961,18 @@ class CKeyMerger : public CKeyLevelManager { recstr.appendf("%02x ", ((unsigned char *) keyBuffer)[i]); } - DBGLOG("SKIP: Out skips=%02d seeks=%02d scans=%02d : %s", stats.skips, stats.seeks, stats.scans, recstr.str()); + if (stats.ctx) + { + const CRuntimeStatisticCollection &statsCollection = stats.ctx->queryStats(); + unsigned __int64 seeks = statsCollection.getStatisticValue(StNumIndexSeeks); + unsigned __int64 scans = statsCollection.getStatisticValue(StNumIndexScans); + unsigned __int64 skips = statsCollection.getStatisticValue(StNumIndexSkips); + DBGLOG("SKIP: Out skips=%" I64F "u seeks=%" I64F "u scans=%" I64F "u : %s", skips, seeks, scans, recstr.str()); + } + else + { + DBGLOG("SKIP: (no ContextLogger - not tracking stats) : %s", recstr.str()); + } } #endif if (stats.ctx) @@ -3352,10 +3344,6 @@ extern jhtree_decl IIndexLookup *createIndexLookup(IKeyManager *keyManager) else return nullptr; } - virtual unsigned querySeeks() const override { return keyManager->querySeeks(); } - virtual unsigned queryScans() const override { return keyManager->queryScans(); } - virtual unsigned querySkips() const override { return keyManager->querySkips(); } - virtual unsigned queryWildSeeks() const override { return keyManager->queryWildSeeks(); } }; return new CIndexLookup(keyManager); } diff --git a/system/jhtree/jhtree.hpp b/system/jhtree/jhtree.hpp index 9338cc85278..32aca365da0 100644 --- a/system/jhtree/jhtree.hpp +++ b/system/jhtree/jhtree.hpp @@ -45,11 +45,6 @@ class KeyStatsCollector { public: IContextLogger *ctx; - unsigned seeks = 0; - unsigned scans = 0; - unsigned wildseeks = 0; - unsigned skips = 0; - unsigned nullskips = 0; KeyStatsCollector(IContextLogger *_ctx) : ctx(_ctx) {} void reset(); @@ -258,10 +253,6 @@ interface IIndexLookup : extends IInterface // similar to a small subset of IKey virtual const void *nextKey() = 0; virtual unsigned __int64 getCount() = 0; virtual unsigned __int64 checkCount(unsigned __int64 limit) = 0; - virtual unsigned querySeeks() const = 0; - virtual unsigned queryScans() const = 0; - virtual unsigned querySkips() const = 0; - virtual unsigned queryWildSeeks() const = 0; }; interface IKeyManager : public IInterface, extends IIndexReadContext @@ -283,10 +274,6 @@ interface IKeyManager : public IInterface, extends IIndexReadContext virtual unsigned __int64 checkCount(unsigned __int64 limit) = 0; virtual void serializeCursorPos(MemoryBuffer &mb) = 0; virtual void deserializeCursorPos(MemoryBuffer &mb) = 0; - virtual unsigned querySeeks() const = 0; - virtual unsigned queryScans() const = 0; - virtual unsigned querySkips() const = 0; - virtual unsigned queryWildSeeks() const = 0; virtual const byte *loadBlob(unsigned __int64 blobid, size32_t &blobsize, IContextLogger *ctx) = 0; virtual void releaseBlobs() = 0; virtual void resetCounts() = 0; diff --git a/system/jlib/jlog.cpp b/system/jlib/jlog.cpp index e3f82189d26..61f5aa69c1b 100644 --- a/system/jlib/jlog.cpp +++ b/system/jlib/jlog.cpp @@ -2776,7 +2776,7 @@ void IContextLogger::CTXLOG(const char *format, ...) const { va_list args; va_start(args, format); - CTXLOGva(MCdebugInfo, unknownJob, NoLogMsgCode, format, args); + CTXLOGva(MCdebugInfo, queryJob(), NoLogMsgCode, format, args); va_end(args); } @@ -2853,7 +2853,7 @@ class DummyLogCtx : implements IContextLogger E->errorMessage(ss.append(": ")); if (format) ss.append(": ").valist_appendf(format, args); - LOG(MCoperatorProgress, unknownJob, "%s", ss.str()); + LOG(MCoperatorProgress, queryJob(), "%s", ss.str()); } virtual void noteStatistic(StatisticKind kind, unsigned __int64 value) const { @@ -2900,6 +2900,10 @@ class DummyLogCtx : implements IContextLogger { throwUnexpected(); } + virtual void recordStatistics(IStatisticGatherer &progress) const override + { + throwUnexpected(); + } } dummyContextLogger; extern jlib_decl const IContextLogger &queryDummyContextLogger() diff --git a/system/jlib/jlog.hpp b/system/jlib/jlog.hpp index efc0d327fbe..582aebdbced 100644 --- a/system/jlib/jlog.hpp +++ b/system/jlib/jlog.hpp @@ -1259,6 +1259,8 @@ interface jlib_decl IContextLogger : extends IInterface virtual const CRuntimeStatisticCollection & queryStats() const = 0; virtual void setActiveSpan(ISpan * span) = 0; virtual IProperties * getClientHeaders() const = 0; + virtual void recordStatistics(IStatisticGatherer &progress) const = 0; + virtual const LogMsgJobInfo & queryJob() const { return unknownJob; } }; extern jlib_decl StringBuffer &appendGloballyUniqueId(StringBuffer &s); diff --git a/system/jlib/jstats.cpp b/system/jlib/jstats.cpp index 79d2944334d..8ebcdcadef5 100644 --- a/system/jlib/jstats.cpp +++ b/system/jlib/jstats.cpp @@ -1319,6 +1319,11 @@ bool StatisticsMapping::equals(const StatisticsMapping & other) } const StatisticsMapping noStatistics({}); +const StatisticsMapping jhtreeCacheStatistics({ StNumIndexSeeks, StNumIndexScans, StNumPostFiltered, StNumIndexWildSeeks, + StNumNodeCacheAdds, StNumLeafCacheAdds, StNumBlobCacheAdds, StNumNodeCacheHits, StNumLeafCacheHits, StNumBlobCacheHits, StCycleNodeLoadCycles, StCycleLeafLoadCycles, + StCycleBlobLoadCycles, StCycleNodeReadCycles, StCycleLeafReadCycles, StCycleBlobReadCycles, StNumNodeDiskFetches, StNumLeafDiskFetches, StNumBlobDiskFetches, + StCycleNodeFetchCycles, StCycleLeafFetchCycles, StCycleBlobFetchCycles}); + const StatisticsMapping allStatistics(StKindAll); const StatisticsMapping heapStatistics({StNumAllocations, StNumAllocationScans}); const StatisticsMapping diskLocalStatistics({StCycleDiskReadIOCycles, StSizeDiskRead, StNumDiskReads, StCycleDiskWriteIOCycles, StSizeDiskWrite, StNumDiskWrites, StNumDiskRetries}); diff --git a/system/jlib/jstats.h b/system/jlib/jstats.h index 503ae25a612..c86d18c1937 100644 --- a/system/jlib/jstats.h +++ b/system/jlib/jstats.h @@ -492,6 +492,7 @@ extern const jlib_decl StatisticsMapping diskLocalStatistics; extern const jlib_decl StatisticsMapping diskRemoteStatistics; extern const jlib_decl StatisticsMapping diskReadRemoteStatistics; extern const jlib_decl StatisticsMapping diskWriteRemoteStatistics; +extern const jlib_decl StatisticsMapping jhtreeCacheStatistics; //--------------------------------------------------------------------------------------------------------------------- @@ -531,7 +532,6 @@ class jlib_decl CRuntimeStatistic RelaxedAtomic value; }; -interface IContextLogger; class CNestedRuntimeStatisticMap; //The CRuntimeStatisticCollection used to gather statistics for an activity - it has no notion of its scope, but can contain nested scopes. diff --git a/system/jlib/jtrace.hpp b/system/jlib/jtrace.hpp index 34ab6100f19..ce59750d8f0 100644 --- a/system/jlib/jtrace.hpp +++ b/system/jlib/jtrace.hpp @@ -213,7 +213,7 @@ extern jlib_decl TraceFlags queryDefaultTraceFlags(); extern jlib_decl TraceFlags loadTraceFlags(const IPropertyTree * globals, const std::initializer_list & y, TraceFlags dft); // Temporarily modify the trace context and/or flags for the current thread, for the lifetime of the LogContextScope object - +interface IContextLogger; class jlib_decl LogContextScope { public: diff --git a/thorlcr/activities/hashdistrib/thhashdistribslave.cpp b/thorlcr/activities/hashdistrib/thhashdistribslave.cpp index 5abef028f6f..6413f395132 100644 --- a/thorlcr/activities/hashdistrib/thhashdistribslave.cpp +++ b/thorlcr/activities/hashdistrib/thhashdistribslave.cpp @@ -2454,7 +2454,7 @@ class ReDistributeSlaveActivity : public HashDistributeSlaveActivity class IndexDistributeSlaveActivity : public HashDistributeSlaveBase { typedef HashDistributeSlaveBase PARENT; - CThorContextLogger contextLogger; + CStatsContextLogger contextLogger; CStatsCtxLoggerDeltaUpdater statsUpdater; class CKeyLookup : implements IHash @@ -2487,7 +2487,7 @@ class IndexDistributeSlaveActivity : public HashDistributeSlaveBase } *lookup; public: - IndexDistributeSlaveActivity(CGraphElementBase *container) : PARENT(container, indexDistribActivityStatistics), lookup(NULL), contextLogger(jhtreeCacheStatistics), statsUpdater(jhtreeCacheStatistics, *this, contextLogger) + IndexDistributeSlaveActivity(CGraphElementBase *container) : PARENT(container, indexDistribActivityStatistics), lookup(NULL), contextLogger(jhtreeCacheStatistics, thorJob), statsUpdater(jhtreeCacheStatistics, *this, contextLogger) { } ~IndexDistributeSlaveActivity() diff --git a/thorlcr/activities/indexread/thindexreadslave.cpp b/thorlcr/activities/indexread/thindexreadslave.cpp index 26f06cfd2c5..b4c7d0cd7cc 100644 --- a/thorlcr/activities/indexread/thindexreadslave.cpp +++ b/thorlcr/activities/indexread/thindexreadslave.cpp @@ -78,7 +78,7 @@ class CIndexReadSlaveBase : public CSlaveActivity Owned lazyIFileIO; mutable CriticalSection ioStatsCS; unsigned fileTableStart = NotFound; - CThorContextLogger contextLogger; + CStatsContextLogger contextLogger; CStatsCtxLoggerDeltaUpdater statsUpdater; class TransformCallback : implements IThorIndexCallback , public CSimpleInterface @@ -528,8 +528,7 @@ class CIndexReadSlaveBase : public CSlaveActivity } public: CIndexReadSlaveBase(CGraphElementBase *container) - : CSlaveActivity(container, indexReadActivityStatistics), callback(*this), - contextLogger(jhtreeCacheStatistics), statsUpdater(jhtreeCacheStatistics, *this, contextLogger) + : CSlaveActivity(container, indexReadActivityStatistics), callback(*this), contextLogger(jhtreeCacheStatistics, thorJob), statsUpdater(jhtreeCacheStatistics, *this, contextLogger) { helper = (IHThorIndexReadBaseArg *)container->queryHelper(); limitTransformExtra = nullptr; diff --git a/thorlcr/activities/keyedjoin/thkeyedjoinslave-legacy.cpp b/thorlcr/activities/keyedjoin/thkeyedjoinslave-legacy.cpp index ecc0fe24159..481abecda01 100644 --- a/thorlcr/activities/keyedjoin/thkeyedjoinslave-legacy.cpp +++ b/thorlcr/activities/keyedjoin/thkeyedjoinslave-legacy.cpp @@ -1206,7 +1206,7 @@ class CKeyedJoinSlave : public CSlaveActivity, implements IJoinProcessor, implem unsigned candidateCount; __int64 lastSeeks, lastScans; IConstPointerArrayOf translators; - CThorContextLogger contextLogger; + CStatsContextLogger contextLogger; inline void updateJhTreeStats() { @@ -1253,7 +1253,7 @@ class CKeyedJoinSlave : public CSlaveActivity, implements IJoinProcessor, implem public: IMPLEMENT_IINTERFACE_USING(CSimpleInterface); - CKeyLocalLookup(CKeyedJoinSlave &_owner, const RtlRecord &_keyRecInfo) : owner(_owner), keyRecInfo(_keyRecInfo), indexReadFieldsRow(_owner.indexInputAllocator), contextLogger(jhtreeCacheStatistics) + CKeyLocalLookup(CKeyedJoinSlave &_owner, const RtlRecord &_keyRecInfo) : owner(_owner), keyRecInfo(_keyRecInfo), indexReadFieldsRow(_owner.indexInputAllocator), contextLogger(jhtreeCacheStatistics, thorJob) { tlkManager.setown(owner.keyHasTlk ? createLocalKeyManager(keyRecInfo, nullptr, &contextLogger, owner.helper->hasNewSegmentMonitors(), false) : nullptr); reset(); @@ -1363,7 +1363,7 @@ class CKeyedJoinSlave : public CSlaveActivity, implements IJoinProcessor, implem ++candidateCount; if (candidateCount > owner.atMost) break; - KLBlobProviderAdapter adapter(partManager, & contextLogger); + KLBlobProviderAdapter adapter(partManager, &contextLogger); byte const * keyRow = partManager->queryKeyBuffer(); size_t fposOffset = partManager->queryRowSize() - sizeof(offset_t); offset_t fpos = rtlReadBigUInt8(keyRow + fposOffset); diff --git a/thorlcr/activities/keyedjoin/thkeyedjoinslave.cpp b/thorlcr/activities/keyedjoin/thkeyedjoinslave.cpp index 72422294d1d..e9903b4ecb4 100644 --- a/thorlcr/activities/keyedjoin/thkeyedjoinslave.cpp +++ b/thorlcr/activities/keyedjoin/thkeyedjoinslave.cpp @@ -2222,7 +2222,7 @@ class CKeyedJoinSlave : public CSlaveActivity, implements IJoinProcessor, implem CPartDescriptorArray allIndexParts; std::vector localIndexParts, localFetchPartMap; IArrayOf tlkKeyIndexes; - CThorContextLogger contextLogger; + CStatsContextLogger contextLogger; CStatsCtxLoggerDeltaUpdater statsUpdater; Owned joinFieldsAllocator; OwnedConstThorRow defaultRight; @@ -2938,8 +2938,7 @@ class CKeyedJoinSlave : public CSlaveActivity, implements IJoinProcessor, implem public: IMPLEMENT_IINTERFACE_USING(PARENT); - CKeyedJoinSlave(CGraphElementBase *_container) : PARENT(_container, keyedJoinActivityStatistics), - readAheadThread(*this), contextLogger(jhtreeCacheStatistics), statsUpdater(jhtreeCacheStatistics, *this, contextLogger) + CKeyedJoinSlave(CGraphElementBase *_container) : PARENT(_container, keyedJoinActivityStatistics), readAheadThread(*this), contextLogger(jhtreeCacheStatistics, thorJob), statsUpdater(jhtreeCacheStatistics, *this, contextLogger) { helper = static_cast (queryHelper()); reInit = 0 != (helper->getFetchFlags() & (FFvarfilename|FFdynamicfilename)) || (helper->getJoinFlags() & JFvarindexfilename); diff --git a/thorlcr/activities/soapcall/thsoapcallslave.cpp b/thorlcr/activities/soapcall/thsoapcallslave.cpp index afc9edaee41..cbb89484c42 100644 --- a/thorlcr/activities/soapcall/thsoapcallslave.cpp +++ b/thorlcr/activities/soapcall/thsoapcallslave.cpp @@ -39,13 +39,13 @@ class CWscRowCallSlaveActivity : public CSlaveActivity, implements IWSCRowProvid bool eof; Owned wscHelper; StringBuffer authToken; - CThorContextLogger contextLogger; + CStatsContextLogger contextLogger; CStatsCtxLoggerDeltaUpdater statsUpdater; public: IMPLEMENT_IINTERFACE_USING(CSlaveActivity); - CWscRowCallSlaveActivity(CGraphElementBase *_container) : CSlaveActivity(_container, soapcallActivityStatistics), contextLogger(soapcallStatistics), statsUpdater(soapcallStatistics, *this, contextLogger) + CWscRowCallSlaveActivity(CGraphElementBase *_container) : CSlaveActivity(_container, soapcallActivityStatistics), contextLogger(soapcallStatistics, thorJob), statsUpdater(soapcallStatistics, *this, contextLogger) { buildAuthToken(queryJob().queryUserDescriptor(), authToken); setRequireInitData(false); @@ -135,13 +135,13 @@ class SoapDatasetCallSlaveActivity : public CSlaveActivity, implements IWSCRowPr StringBuffer authToken; Owned wscHelper; CriticalSection crit; - CThorContextLogger contextLogger; + CStatsContextLogger contextLogger; CStatsCtxLoggerDeltaUpdater statsUpdater; public: IMPLEMENT_IINTERFACE_USING(CSlaveActivity); - SoapDatasetCallSlaveActivity(CGraphElementBase *_container) : CSlaveActivity(_container, soapcallActivityStatistics), contextLogger(soapcallStatistics), statsUpdater(soapcallStatistics, *this, contextLogger) + SoapDatasetCallSlaveActivity(CGraphElementBase *_container) : CSlaveActivity(_container, soapcallActivityStatistics), contextLogger(soapcallStatistics, thorJob), statsUpdater(soapcallStatistics, *this, contextLogger) { setRequireInitData(false); appendOutputLinked(this); @@ -229,13 +229,13 @@ class SoapRowActionSlaveActivity : public ProcessSlaveActivity, implements IWSCR typedef ProcessSlaveActivity PARENT; StringBuffer authToken; Owned wscHelper; - CThorContextLogger contextLogger; + CStatsContextLogger contextLogger; CStatsCtxLoggerDeltaUpdater statsUpdater; public: IMPLEMENT_IINTERFACE_USING(PARENT); - SoapRowActionSlaveActivity(CGraphElementBase *_container) : ProcessSlaveActivity(_container, soapcallActivityStatistics), contextLogger(soapcallStatistics), statsUpdater(soapcallStatistics, *this, contextLogger) + SoapRowActionSlaveActivity(CGraphElementBase *_container) : ProcessSlaveActivity(_container, soapcallActivityStatistics), contextLogger(soapcallStatistics, thorJob), statsUpdater(soapcallStatistics, *this, contextLogger) { setRequireInitData(false); } @@ -288,13 +288,13 @@ class SoapDatasetActionSlaveActivity : public ProcessSlaveActivity, implements I Owned wscHelper; StringBuffer authToken; CriticalSection crit; - CThorContextLogger contextLogger; + CStatsContextLogger contextLogger; CStatsCtxLoggerDeltaUpdater statsUpdater; public: IMPLEMENT_IINTERFACE_USING(PARENT); - SoapDatasetActionSlaveActivity(CGraphElementBase *_container) : ProcessSlaveActivity(_container, soapcallActivityStatistics), contextLogger(soapcallStatistics), statsUpdater(soapcallStatistics, *this, contextLogger) + SoapDatasetActionSlaveActivity(CGraphElementBase *_container) : ProcessSlaveActivity(_container, soapcallActivityStatistics), contextLogger(soapcallStatistics, thorJob), statsUpdater(soapcallStatistics, *this, contextLogger) { setRequireInitData(false); } diff --git a/thorlcr/graph/thgraph.cpp b/thorlcr/graph/thgraph.cpp index deb69708ab8..6ad59ac9ca6 100644 --- a/thorlcr/graph/thgraph.cpp +++ b/thorlcr/graph/thgraph.cpp @@ -2718,7 +2718,7 @@ void CJobBase::init() forceLogGraphIdMin = (graph_id)getWorkUnitValueInt("forceLogGraphIdMin", 0); forceLogGraphIdMax = (graph_id)getWorkUnitValueInt("forceLogGraphIdMax", 0); - logctx.setown(new CThorContextLogger(noStatistics)); + logctx.setown(new CStatsContextLogger(noStatistics)); // helpers to preserve legacy behaviour of a few 'expert' properties that could be set as attributes directly under ThorCluster auto getLegacyExpertSettingBool = [this](const char *property, bool dft) diff --git a/thorlcr/graph/thgraphslave.hpp b/thorlcr/graph/thgraphslave.hpp index b21a75dd96d..5540b72c032 100644 --- a/thorlcr/graph/thgraphslave.hpp +++ b/thorlcr/graph/thgraphslave.hpp @@ -334,10 +334,10 @@ class CStatsCtxLoggerDeltaUpdater : public CStatsDeltaUpdater { protected: CSlaveActivity &activity; - CThorContextLogger &ctxLogger; + CStatsContextLogger &ctxLogger; public: - inline CStatsCtxLoggerDeltaUpdater(const StatisticsMapping &mapping, CSlaveActivity &_activity, CThorContextLogger &_ctxLogger, unsigned timeThresholdSecs=0) + inline CStatsCtxLoggerDeltaUpdater(const StatisticsMapping &mapping, CSlaveActivity &_activity, CStatsContextLogger &_ctxLogger, unsigned timeThresholdSecs=0) : CStatsDeltaUpdater(mapping, timeThresholdSecs), activity(_activity), ctxLogger(_ctxLogger) { resetStart(); diff --git a/thorlcr/slave/slavmain.cpp b/thorlcr/slave/slavmain.cpp index 1514e084516..634964dc80a 100644 --- a/thorlcr/slave/slavmain.cpp +++ b/thorlcr/slave/slavmain.cpp @@ -115,7 +115,7 @@ class CKJService : public CSimpleInterfaceOf, implements IThreaded, unsigned maxCachedKJManagers = defaultMaxCachedKJManagers; unsigned maxCachedFetchContexts = defaultMaxCachedFetchContexts; unsigned keyLookupMaxProcessThreads = defaultKeyLookupMaxProcessThreads; - CThorContextLogger contextLogger; + CStatsContextLogger contextLogger; class CLookupKey { unsigned hashv = 0; @@ -1189,7 +1189,7 @@ class CKJService : public CSimpleInterfaceOf, implements IThreaded, public: IMPLEMENT_IINTERFACE_USING(CSimpleInterfaceOf); - CKJService(mptag_t _mpTag) : threaded("CKJService", this), keyLookupMpTag(_mpTag), contextLogger(jhtreeCacheStatistics) + CKJService(mptag_t _mpTag) : threaded("CKJService", this), keyLookupMpTag(_mpTag), contextLogger(jhtreeCacheStatistics, thorJob) { setupProcessorPool(); } diff --git a/thorlcr/thorutil/thormisc.cpp b/thorlcr/thorutil/thormisc.cpp index f2c6c2a2343..38bb5bc38ee 100644 --- a/thorlcr/thorutil/thormisc.cpp +++ b/thorlcr/thorutil/thormisc.cpp @@ -74,16 +74,7 @@ static Owned ClusterMPAllocator; // stat. mappings shared between master and slave activities const StatisticsMapping spillStatistics({StTimeSpillElapsed, StTimeSortElapsed, StNumSpills, StSizeSpillFile}); -const StatisticsMapping jhtreeCacheStatistics({ StNumIndexSeeks, StNumIndexScans, StNumPostFiltered, StNumIndexWildSeeks, - StNumNodeCacheAdds, StNumLeafCacheAdds, StNumBlobCacheAdds, StNumNodeCacheHits, StNumLeafCacheHits, StNumBlobCacheHits, - StNumNodeDiskFetches, StNumLeafDiskFetches, StNumBlobDiskFetches, - StTimeNodeRead, StCycleNodeReadCycles, StTimeLeafRead, StCycleLeafReadCycles, StTimeBlobRead, StCycleBlobReadCycles, - StTimeNodeFetch, StCycleNodeFetchCycles, StTimeLeafFetch, StCycleLeafFetchCycles, StTimeBlobFetch, StCycleBlobFetchCycles, - StTimeIndexCacheBlocked, StCycleIndexCacheBlockedCycles, StNumIndexMerges, StNumIndexMergeCompares, - StTimeBlobLoad, StCycleBlobLoadCycles, StTimeLeafLoad, StCycleLeafLoadCycles, StTimeNodeLoad, StCycleNodeLoadCycles, - StNumIndexSkips, StNumIndexNullSkips}); const StatisticsMapping soapcallStatistics({StTimeSoapcall}); - const StatisticsMapping basicActivityStatistics({StTimeTotalExecute, StTimeLocalExecute, StTimeBlocked}); const StatisticsMapping groupActivityStatistics({StNumGroups, StNumGroupMax}, basicActivityStatistics); const StatisticsMapping hashJoinActivityStatistics({StNumLeftRows, StNumRightRows}, basicActivityStatistics); diff --git a/thorlcr/thorutil/thormisc.hpp b/thorlcr/thorutil/thormisc.hpp index cf864b32ca3..1d99832cfa4 100644 --- a/thorlcr/thorutil/thormisc.hpp +++ b/thorlcr/thorutil/thormisc.hpp @@ -131,7 +131,6 @@ enum RegistryCode:unsigned { rc_register, rc_deregister }; #define destroyThorRow(ptr) free(ptr) #define reallocThorRow(ptr, size) realloc(ptr, size) - //statistics gathered by the different activities extern graph_decl const StatisticsMapping spillStatistics; extern graph_decl const StatisticsMapping jhtreeCacheStatistics; @@ -605,102 +604,6 @@ inline void readUnderlyingType(MemoryBuffer &mb, T &v) constexpr unsigned thorDetailedLogLevel = 200; constexpr LogMsgCategory MCthorDetailedDebugInfo(MCdebugInfo(thorDetailedLogLevel)); -//// -// IContextLogger -class CThorContextLogger : public CSimpleInterfaceOf -{ - unsigned traceLevel = 1; - Owned activeSpan; - mutable CRuntimeStatisticCollection stats; - -public: - CThorContextLogger(const StatisticsMapping & statsMapping) : stats(statsMapping) - { - } - virtual void CTXLOG(const char *format, ...) const override __attribute__((format(printf,2,3))) - { - va_list args; - va_start(args, format); - CTXLOGva(MCdebugProgress, thorJob, NoLogMsgCode, format, args); - va_end(args); - } - - virtual void CTXLOGva(const LogMsgCategory & cat, const LogMsgJobInfo & job, LogMsgCode code, const char *format, va_list args) const override __attribute__((format(printf,5,0))) - { - VALOG(cat, job, code, format, args); - } - virtual void logOperatorExceptionVA(IException *E, const char *file, unsigned line, const char *format, va_list args) const __attribute__((format(printf,5,0))) - { - StringBuffer ss; - ss.append("ERROR"); - if (E) - ss.append(": ").append(E->errorCode()); - if (file) - ss.appendf(": %s(%d) ", file, line); - if (E) - E->errorMessage(ss.append(": ")); - if (format) - ss.append(": ").valist_appendf(format, args); - LOG(MCoperatorProgress, thorJob, "%s", ss.str()); - } - virtual void noteStatistic(StatisticKind kind, unsigned __int64 value) const override - { - stats.addStatisticAtomic(kind, value); - } - virtual void setStatistic(StatisticKind kind, unsigned __int64 value) const override - { - stats.setStatistic(kind, value); - } - virtual void mergeStats(const CRuntimeStatisticCollection &from) const override - { - stats.merge(from); - } - virtual unsigned queryTraceLevel() const override - { - return traceLevel; - } - virtual void setActiveSpan(ISpan * span) override - { - activeSpan.set(span); - } - virtual IProperties * getClientHeaders() const override - { - if (!activeSpan) - return nullptr; - return ::getClientHeaders(activeSpan); - } - virtual const char *queryGlobalId() const override - { - if (!activeSpan) - return nullptr; - return activeSpan->queryGlobalId(); - } - virtual const char *queryLocalId() const override - { - if (!activeSpan) - return nullptr; - return activeSpan->queryLocalId(); - } - virtual const char *queryCallerId() const override - { - if (!activeSpan) - return nullptr; - return activeSpan->queryCallerId(); - } - virtual const CRuntimeStatisticCollection &queryStats() const override - { - return stats; - } - void updateStatsDeltaTo(CRuntimeStatisticCollection &to, CRuntimeStatisticCollection &previous) - { - previous.updateDelta(to, stats); - } - void reset() - { - stats.reset(); - } -}; - class graph_decl CThorPerfTracer : protected PerfTracer { PerfTracer perf;