Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

HPCC-31545 Thread pool wait time reporting #18475

Merged
merged 1 commit into from
Apr 5, 2024
Merged

HPCC-31545 Thread pool wait time reporting #18475

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
40 changes: 23 additions & 17 deletions system/jlib/jthread.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1006,36 +1006,42 @@ class CThreadPool: public CThreadPoolBase, implements IThreadPool, public CInter
PooledThreadHandle _start(void *param,const char *name, bool noBlock, unsigned timeout=0)
{
CCycleTimer startTimer;
bool timedout = defaultmax && !availsem.wait(noBlock ? 0 : (timeout>0?timeout:delay));
bool waited = false;
bool timedout = false;
if (defaultmax)
{
waited = !availsem.wait(0);
if (noBlock)
timedout = waited;
else if (waited)
timedout = !availsem.wait(timeout>0?timeout:delay);
}
PooledThreadHandle ret;
{
CriticalBlock block(crit);
if (timedout)
{
if (!availsem.wait(0)) { // make sure take allocated sem if has become available
if (!availsem.wait(0)) // make sure take allocated sem if has become available
{
if (noBlock || timeout > 0)
throw MakeStringException(0, "No threads available in pool %s", poolname.get());
IWARNLOG("Pool limit exceeded for %s", poolname.get());
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This code continues on with a new thread even when it timed out waiting for a free slot (when timeout == 0)
Is that what we want ? Should it instead wait 'forever' for a free slot when timeout == 0 ?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

if parameter 'timeout' is 0 (and noBlock=false), then it will have waited for 'delay' ms.
I think it's correct/by design, to have waited for 'delay' ms, then continue in that case.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

trivial/formatting/not new: line 1024 is only line formatted without brace on newline, would be good to change so consistent with rest of function

}
else
timedout = false;
}
if (traceStartDelayPeriod)
{
++startsInPeriod;
if (timedout)
{
if (waited)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Don't think it really matters, but if there's an accumulate delay, but as it crosses the 1 minute mark (the 'traceStartDelayPeriod' period), 'waited' isn't true, then it won't report until the next delayed thread.

Perhaps change to:

            if (traceStartDelayPeriod)
            {
                ++startsInPeriod;
                if (waited)
                    startDelayInPeriod += startTimer.elapsedCycles();
                if (startDelayInPeriod && (overAllTimer.elapsedCycles() >= queryOneSecCycles()*traceStartDelayPeriod)) // check avg. delay per minute
                {
....
                }
            }

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I agree, good find. I would even say tho I want to know how many threads started even if there is no accumulated delay, so I don't think we need the extra check of if(startDelayInPeriod) to log the info. See commit 2.

startDelayInPeriod += startTimer.elapsedCycles();
if (overAllTimer.elapsedCycles() >= queryOneSecCycles()*traceStartDelayPeriod) // check avg. delay per minute
{
double totalDelayMs = (static_cast<double>(cycle_to_nanosec(startDelayInPeriod)))/1000000;
double avgDelayMs = (static_cast<double>(cycle_to_nanosec(startDelayInPeriod/startsInPeriod)))/1000000;
unsigned totalElapsedSecs = overAllTimer.elapsedMs()/1000;
PROGLOG("%s: %u threads started in last %u seconds, total delay = %0.2f milliseconds, average delay = %0.2f milliseconds, currently running = %u", poolname.get(), startsInPeriod, totalElapsedSecs, totalDelayMs, avgDelayMs, runningCount());
startsInPeriod = 0;
startDelayInPeriod = 0;
overAllTimer.reset();
}
if (overAllTimer.elapsedCycles() >= queryOneSecCycles()*traceStartDelayPeriod) // check avg. delay per minute
{
double totalDelayMs = (static_cast<double>(cycle_to_nanosec(startDelayInPeriod)))/1000000;
double avgDelayMs = (static_cast<double>(cycle_to_nanosec(startDelayInPeriod/startsInPeriod)))/1000000;
unsigned totalElapsedSecs = overAllTimer.elapsedMs()/1000;
PROGLOG("%s: %u threads started in last %u seconds, total delay = %0.2f milliseconds, average delay = %0.2f milliseconds, currently running = %u", poolname.get(), startsInPeriod, totalElapsedSecs, totalDelayMs, avgDelayMs, runningCount());
startsInPeriod = 0;
startDelayInPeriod = 0;
overAllTimer.reset();
}
}
CPooledThreadWrapper &t = allocThread();
Expand Down Expand Up @@ -2683,4 +2689,4 @@ void PerfTracer::dostop()
#else
UNIMPLEMENTED;
#endif
}
}
2 changes: 1 addition & 1 deletion thorlcr/slave/slavmain.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1185,7 +1185,7 @@ class CKJService : public CSimpleInterfaceOf<IKJService>, implements IThreaded,
{
Owned<CProcessorFactory> factory = new CProcessorFactory(*this);
processorPool.setown(createThreadPool("KJService processor pool", factory, this, keyLookupMaxProcessThreads, 10000));
processorPool->setStartDelayTracing(60000);
processorPool->setStartDelayTracing(60);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

whoops, good change!
Perhaps we should just default it to 60seconds in CThreadPool ?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sure if you want I can change default.

}
public:
IMPLEMENT_IINTERFACE_USING(CSimpleInterfaceOf<IKJService>);
Expand Down
Loading