From ebafeda598060212b921b4fb8e86b8ca378d8feb Mon Sep 17 00:00:00 2001 From: Shamser Ahmed Date: Fri, 1 Nov 2024 15:56:41 +0000 Subject: [PATCH 1/2] HPCC-32931 Capture and report execute timings for splitters Signed-off-by: Shamser Ahmed --- thorlcr/activities/nsplitter/thnsplitterslave.cpp | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/thorlcr/activities/nsplitter/thnsplitterslave.cpp b/thorlcr/activities/nsplitter/thnsplitterslave.cpp index d1d8f2e2e8e..6e337a7a7a7 100644 --- a/thorlcr/activities/nsplitter/thnsplitterslave.cpp +++ b/thorlcr/activities/nsplitter/thnsplitterslave.cpp @@ -217,7 +217,10 @@ class NSplitterSlaveActivity : public CSlaveActivity, implements ISharedSmartBuf assertex(((unsigned)-1) != connectedOutputCount); activeOutputCount = connectedOutputCount; - PARENT::start(); + { + ActivityTimer t(slaveTimerStats, queryTimeActivities()); + PARENT::start(); + } initMetaInfo(cachedMetaInfo); cachedMetaInfo.suppressLookAhead = spill; // only suppress downstream lookaheads if this is a spilling splitter @@ -299,6 +302,7 @@ class NSplitterSlaveActivity : public CSlaveActivity, implements ISharedSmartBuf } inline const void *nextRow(unsigned outIdx, rowcount_t current) { + ActivityTimer t(slaveTimerStats, queryTimeActivities()); if (1 == activeOutputCount) // will be true, if only 1 input connected, or only 1 input was active (others stopped) when it started reading return inputStream->nextRow(); if (recsReady == current && writeAheadException.get()) From 2d4617cb5a9c9882f74cc35b53e1565d7af59625 Mon Sep 17 00:00:00 2001 From: Shamser Ahmed Date: Wed, 6 Nov 2024 15:51:30 +0000 Subject: [PATCH 2/2] HPCC-32931 Changes following review Signed-off-by: Shamser Ahmed --- .../activities/nsplitter/thnsplitterslave.cpp | 16 ++++++++++++---- 1 file changed, 12 insertions(+), 4 deletions(-) diff --git a/thorlcr/activities/nsplitter/thnsplitterslave.cpp b/thorlcr/activities/nsplitter/thnsplitterslave.cpp index 6e337a7a7a7..237e47eedae 100644 --- a/thorlcr/activities/nsplitter/thnsplitterslave.cpp +++ b/thorlcr/activities/nsplitter/thnsplitterslave.cpp @@ -58,6 +58,9 @@ class CSplitterOutput : public CSimpleInterfaceOf, pu virtual bool isInputOrdered(bool consumerOrdered) const override; virtual void setOutputStream(unsigned index, IEngineRowStream *stream) override; virtual IStrandJunction *getOutputStreams(CActivityBase &ctx, unsigned idx, PointerArrayOf &streams, const CThorStrandOptions * consumerOptions, bool consumerOrdered, IOrderedCallbackCollection * orderedCallbacks) override; + // queryTotalCycles is used by downstream activities for the purpose of calculating local execute time. + // queryTotalCycles should include all time taken in start() and nextRow() methods. + // n.b. This totalCycles are not actually reported - it is only used by downstream activities. virtual unsigned __int64 queryTotalCycles() const override { return COutputTiming::queryTotalCycles(); } virtual unsigned __int64 queryEndCycles() const override { return COutputTiming::queryEndCycles(); } virtual unsigned __int64 queryBlockedCycles() const { return COutputTiming::queryBlockedCycles(); } @@ -77,6 +80,13 @@ class CSplitterOutput : public CSimpleInterfaceOf, pu // // NSplitterSlaveActivity // +// Note regarding NSplitterSlaveActivity::COutputTiming methods: +// - queryTotalCycles in NSplitterSlaveActivity is not used by downstream +// activities (like they are in other activities). Downstream activities +// use CSplitterOutput::queryTotalCycles for the purposes of calculating +// local execute time +// - totalCycles in this class is reported as the activity's StTotalExecuteTime +// and it is used to calculate & report the StLocalExecuteTime. class NSplitterSlaveActivity : public CSlaveActivity, implements ISharedSmartBufferCallback { @@ -212,15 +222,13 @@ class NSplitterSlaveActivity : public CSlaveActivity, implements ISharedSmartBuf if (!inputPrepared) { inputPrepared = true; + ActivityTimer t(slaveTimerStats, queryTimeActivities()); try { assertex(((unsigned)-1) != connectedOutputCount); activeOutputCount = connectedOutputCount; - { - ActivityTimer t(slaveTimerStats, queryTimeActivities()); - PARENT::start(); - } + PARENT::start(); initMetaInfo(cachedMetaInfo); cachedMetaInfo.suppressLookAhead = spill; // only suppress downstream lookaheads if this is a spilling splitter