From 9a9eb56a3aff6bb338f02e6057f1d431dc99a230 Mon Sep 17 00:00:00 2001 From: Olivier Marty Date: Mon, 27 Apr 2020 16:08:20 +0200 Subject: [PATCH 1/3] clean rewrite of RsServer::threadTick --- libretroshare/src/rsserver/p3face-server.cc | 232 ++++++++------------ libretroshare/src/rsserver/p3face.h | 19 +- 2 files changed, 100 insertions(+), 151 deletions(-) diff --git a/libretroshare/src/rsserver/p3face-server.cc b/libretroshare/src/rsserver/p3face-server.cc index 54605333b..2abf16e98 100644 --- a/libretroshare/src/rsserver/p3face-server.cc +++ b/libretroshare/src/rsserver/p3face-server.cc @@ -73,14 +73,13 @@ static double getCurrentTS() // In some cases (VOIP) it's likely that we will need to set them temporarily to a very low // value, in order to favor a fast feedback -const double RsServer::minTimeDelta = 0.05; // 25; -const double RsServer::maxTimeDelta = 0.2; -const double RsServer::kickLimit = 0.15; +const double RsServer::minTickInterval = 0.05; +const double RsServer::maxTickInterval = 0.2; RsServer::RsServer() : - coreMutex("RsServer"), mShutdownCallback([](int){}), - coreReady(false) + coreMutex("RsServer"), mShutdownCallback([](int){}), + coreReady(false) { { RsEventsService* tmpRsEvtPtr = new RsEventsService(); @@ -108,21 +107,16 @@ RsServer::RsServer() : msgSrv = NULL; chatSrv = NULL; mStatusSrv = NULL; - mGxsTunnels = NULL; + mGxsTunnels = NULL; - mMin = 0; - mLoop = 0; + mLastts = getCurrentTS(); + mTickInterval = maxTickInterval ; + mAvgRunDuration = 0; + mLastRunDuration = 0; + /* caches (that need ticking) */ - mLastts = getCurrentTS(); - mLastSec = 0; /* for the slower ticked stuff */ - mTimeDelta = 0.25 ; - - mAvgTickRate = mTimeDelta; - - /* caches (that need ticking) */ - - /* Config */ + /* config */ mConfigMgr = NULL; mGeneralConfig = NULL; } @@ -132,143 +126,101 @@ RsServer::~RsServer() delete mGxsTrans; } - /* General Internal Helper Functions - ----> MUST BE LOCKED! - */ +// General Internal Helper Functions ----> MUST BE LOCKED! - - - /* Thread Fn: Run the Core */ void RsServer::threadTick() { - rstime::rs_usleep(mTimeDelta * 1000000); +RsDbg() << "DEBUG_TICK" << std::endl; +RsDbg() << "DEBUG_TICK ticking interval "<< mTickInterval << std::endl; - double ts = getCurrentTS(); - double delta = ts - mLastts; - - /* for the fast ticked stuff */ - if (delta > mTimeDelta) - { -#ifdef DEBUG_TICK - std::cerr << "Delta: " << delta << std::endl; - std::cerr << "Time Delta: " << mTimeDelta << std::endl; - std::cerr << "Avg Tick Rate: " << mAvgTickRate << std::endl; -#endif +// we try to tick at a regular interval which depends on the load +// if there is time left, we sleep + double timeToSleep = mTickInterval - mAvgRunDuration; - mLastts = ts; + if (timeToSleep > 0) + { +RsDbg() << "DEBUG_TICK will sleep " << timeToSleep << " ms" << std::endl; + rstime::rs_usleep(timeToSleep * 1000000); + } - /******************************** RUN SERVER *****************/ - lockRsCore(); + double ts = getCurrentTS(); + double delta = ts - mLastts; + mLastts = ts; - int moreToTick = pqih->tick(); +// stuff we do always +RsDbg() << "DEBUG_TICK ticking server" << std::endl; + lockRsCore(); + int moreToTick = pqih->tick(); + unlockRsCore(); -#ifdef DEBUG_TICK - std::cerr << "RsServer::run() ftserver->tick(): moreToTick: " << moreToTick << std::endl; -#endif - - unlockRsCore(); - - /* tick the Managers */ +// tick the managers +RsDbg() << "DEBUG_TICK ticking mPeerMgr" << std::endl; mPeerMgr->tick(); +RsDbg() << "DEBUG_TICK ticking mLinkMgr" << std::endl; mLinkMgr->tick(); +RsDbg() << "DEBUG_TICK ticking mNetMgr" << std::endl; mNetMgr->tick(); - /******************************** RUN SERVER *****************/ - /* adjust tick rate depending on whether there is more. - */ - mAvgTickRate = 0.2 * mTimeDelta + 0.8 * mAvgTickRate; - - if (1 == moreToTick) +// stuff we do every second + if (delta > 1) { - mTimeDelta = 0.9 * mAvgTickRate; - if (mTimeDelta > kickLimit) - { - /* force next tick in one sec - * if we are reading data. - */ - mTimeDelta = kickLimit; - mAvgTickRate = kickLimit; - } - } +RsDbg() << "DEBUG_TICK every second" << std::endl; + // slow services + if (rsPlugins) + rsPlugins->slowTickPlugins((rstime_t)ts); + // UDP keepalive + // tou_tick_stunkeepalive(); + // other stuff to tick + // update(); + } + +// stuff we do every five seconds + if (delta > 5) + { +RsDbg() << "DEBUG_TICK every 5 seconds" << std::endl; + // save stuff + mConfigMgr->tick(); + } + +// stuff we do every minute + if (delta > 60) + { +RsDbg() << "DEBUG_TICK 60 seconds" << std::endl; + // force saving FileTransferStatus TODO + // ftserver->saveFileTransferStatus(); + // see if we need to resave certs + // AuthSSL::getAuthSSL()->CheckSaveCertificates(); + } + +// stuff we do every hour + if (delta > 3600) + { +RsDbg() << "DEBUG_TICK every hour" << std::endl; + } + +// ticking is done, now compute new values of mLastRunDuration, mAvgRunDuration and mTickInterval + ts = getCurrentTS(); + mLastRunDuration = ts - mLastts; + mAvgRunDuration = 0.1 * mLastRunDuration + 0.9 * mAvgRunDuration; + +RsDbg() << "DEBUG_TICK new mLastRunDuration " << mLastRunDuration << " mAvgRunDuration " << mAvgRunDuration << std::endl; + if (mLastRunDuration > WARN_BIG_CYCLE_TIME) + RsDbg() << "DEBUG_TICK excessively long lycle time " << mLastRunDuration << std::endl; + +// if the core has returned that there is more to tick we decrease the ticking interval, else we increse it +RsDbg() << "DEBUG_TICK moreToTick " << moreToTick << std::endl; + if (moreToTick == 1) + mTickInterval = 0.9 * mTickInterval; else - { - mTimeDelta = 1.1 * mAvgTickRate; - } + mTickInterval = 1.1 * mTickInterval; +RsDbg() << "DEBUG_TICK new tick interval " << mTickInterval << std::endl; - /* limiter */ - if (mTimeDelta < minTimeDelta) - { - mTimeDelta = minTimeDelta; - } - else if (mTimeDelta > maxTimeDelta) - { - mTimeDelta = maxTimeDelta; - } - - /* Fast Updates */ - - - /* now we have the slow ticking stuff */ - /* stuff ticked once a second (but can be slowed down) */ - if ((int) ts > mLastSec) - { - mLastSec = (int) ts; - - // Every second! (UDP keepalive). - //tou_tick_stunkeepalive(); - - // every five loops (> 5 secs) - if (mLoop % 5 == 0) - { - // update_quick_stats(); - - // Update All Every 5 Seconds. - // These Update Functions do the locking themselves. -#ifdef DEBUG_TICK - std::cerr << "RsServer::run() Updates()" << std::endl; -#endif - - mConfigMgr->tick(); /* saves stuff */ - - } - - // every 60 loops (> 1 min) - if (++mLoop >= 60) - { - mLoop = 0; - - /* force saving FileTransferStatus TODO */ - //ftserver->saveFileTransferStatus(); - - /* see if we need to resave certs */ - //AuthSSL::getAuthSSL()->CheckSaveCertificates(); - - /* hour loop */ - if (++mMin >= 60) - { - mMin = 0; - } - } - - /* Tick slow services */ - if(rsPlugins) - rsPlugins->slowTickPlugins((rstime_t)ts); - - // slow update tick as well. - // update(); - } // end of slow tick. - - } // end of only once a second. - -#ifdef DEBUG_TICK - double endCycleTs = getCurrentTS(); - double cycleTime = endCycleTs - ts; - if (cycleTime > WARN_BIG_CYCLE_TIME) - { - std::string out; - rs_sprintf(out, "RsServer::run() WARNING Excessively Long Cycle Time: %g secs => Please DEBUG", cycleTime); - std::cerr << out << std::endl; - } -#endif +// keep the tick interval within allowed limits + if (mTickInterval < minTickInterval) + mTickInterval = minTickInterval; + else if (mTickInterval > maxTickInterval) + mTickInterval = maxTickInterval; +RsDbg() << "DEBUG_TICK new tick interval after limiter " << mTickInterval << std::endl; } + diff --git a/libretroshare/src/rsserver/p3face.h b/libretroshare/src/rsserver/p3face.h index 320c6f991..bb0b15353 100644 --- a/libretroshare/src/rsserver/p3face.h +++ b/libretroshare/src/rsserver/p3face.h @@ -172,8 +172,8 @@ public: // p3Posted *mPosted; // p3PhotoService *mPhoto; // p3GxsCircles *mGxsCircles; -// p3GxsNetService *mGxsNetService; -// p3IdService *mGxsIdService; +// p3GxsNetService *mGxsNetService; +// p3IdService *mGxsIdService; // p3GxsForums *mGxsForums; // p3GxsChannels *mGxsChannels; // p3Wire *mWire; @@ -188,16 +188,13 @@ public: // Worker Data..... - int mMin ; - int mLoop ; - int mLastts ; - long mLastSec ; - double mAvgTickRate ; - double mTimeDelta ; + double mLastts; + double mTickInterval; + double mLastRunDuration; + double mAvgRunDuration; - static const double minTimeDelta; // 25; - static const double maxTimeDelta; - static const double kickLimit; + static const double minTickInterval; + static const double maxTickInterval; /// @see RsControl::setShutdownCallback std::function mShutdownCallback; From b0613ef653fbee9bdc8c30d0bc72ff01e637055f Mon Sep 17 00:00:00 2001 From: Olivier Marty Date: Tue, 28 Apr 2020 09:48:12 +0200 Subject: [PATCH 2/3] Correct design flaw in slow process control, improve indentation, set up debug #ifdef --- libretroshare/src/rsserver/p3face-server.cc | 112 +++++++++++++------- libretroshare/src/rsserver/p3face.h | 5 +- 2 files changed, 76 insertions(+), 41 deletions(-) diff --git a/libretroshare/src/rsserver/p3face-server.cc b/libretroshare/src/rsserver/p3face-server.cc index 2abf16e98..65747739f 100644 --- a/libretroshare/src/rsserver/p3face-server.cc +++ b/libretroshare/src/rsserver/p3face-server.cc @@ -41,11 +41,10 @@ #include "services/rseventsservice.h" -/**** -#define DEBUG_TICK 1 -****/ +#define TICK_DEBUG 1 #define WARN_BIG_CYCLE_TIME (0.2) + #ifdef WINDOWS_SYS #include "util/rstime.h" #include @@ -113,6 +112,10 @@ RsServer::RsServer() : mTickInterval = maxTickInterval ; mAvgRunDuration = 0; mLastRunDuration = 0; + mCycle1 = 0; + mCycle2 = 0; + mCycle3 = 0; + mCycle4 = 0; /* caches (that need ticking) */ @@ -130,42 +133,54 @@ RsServer::~RsServer() void RsServer::threadTick() { -RsDbg() << "DEBUG_TICK" << std::endl; -RsDbg() << "DEBUG_TICK ticking interval "<< mTickInterval << std::endl; +#ifdef TICK_DEBUG + RsDbg() << "TICK_DEBUG ticking interval "<< mTickInterval << std::endl; +#endif // we try to tick at a regular interval which depends on the load // if there is time left, we sleep - double timeToSleep = mTickInterval - mAvgRunDuration; + double timeToSleep = mTickInterval - mAvgRunDuration; if (timeToSleep > 0) { -RsDbg() << "DEBUG_TICK will sleep " << timeToSleep << " ms" << std::endl; +#ifdef TICK_DEBUG + RsDbg() << "TICK_DEBUG will sleep " << timeToSleep << " ms" << std::endl; +#endif rstime::rs_usleep(timeToSleep * 1000000); } double ts = getCurrentTS(); - double delta = ts - mLastts; mLastts = ts; // stuff we do always -RsDbg() << "DEBUG_TICK ticking server" << std::endl; +// tick the core +#ifdef TICK_DEBUG + RsDbg() << "TICK_DEBUG ticking server" << std::endl; +#endif lockRsCore(); int moreToTick = pqih->tick(); unlockRsCore(); - // tick the managers -RsDbg() << "DEBUG_TICK ticking mPeerMgr" << std::endl; - mPeerMgr->tick(); -RsDbg() << "DEBUG_TICK ticking mLinkMgr" << std::endl; - mLinkMgr->tick(); -RsDbg() << "DEBUG_TICK ticking mNetMgr" << std::endl; - mNetMgr->tick(); +#ifdef TICK_DEBUG + RsDbg() << "TICK_DEBUG ticking mPeerMgr" << std::endl; +#endif + mPeerMgr->tick(); +#ifdef TICK_DEBUG + RsDbg() << "TICK_DEBUG ticking mLinkMgr" << std::endl; +#endif + mLinkMgr->tick(); +#ifdef TICK_DEBUG + RsDbg() << "TICK_DEBUG ticking mNetMgr" << std::endl; +#endif + mNetMgr->tick(); // stuff we do every second - if (delta > 1) - { -RsDbg() << "DEBUG_TICK every second" << std::endl; + if (ts - mCycle1 > 1) + { +#ifdef TICK_DEBUG + RsDbg() << "TICK_DEBUG every second" << std::endl; +#endif // slow services if (rsPlugins) rsPlugins->slowTickPlugins((rstime_t)ts); @@ -173,54 +188,73 @@ RsDbg() << "DEBUG_TICK every second" << std::endl; // tou_tick_stunkeepalive(); // other stuff to tick // update(); + mCycle1 = ts; } // stuff we do every five seconds - if (delta > 5) + if (ts - mCycle2 > 5) { -RsDbg() << "DEBUG_TICK every 5 seconds" << std::endl; +#ifdef TICK_DEBUG + RsDbg() << "TICK_DEBUG every 5 seconds" << std::endl; +#endif // save stuff mConfigMgr->tick(); + mCycle2 = ts; } // stuff we do every minute - if (delta > 60) + if (ts - mCycle3 > 60) { -RsDbg() << "DEBUG_TICK 60 seconds" << std::endl; +#ifdef TICK_DEBUG + RsDbg() << "TICK_DEBUG every 60 seconds" << std::endl; +#endif // force saving FileTransferStatus TODO - // ftserver->saveFileTransferStatus(); + // ftserver->saveFileTransferStatus(); // see if we need to resave certs - // AuthSSL::getAuthSSL()->CheckSaveCertificates(); + // AuthSSL::getAuthSSL()->CheckSaveCertificates(); + mCycle3 = ts; } // stuff we do every hour - if (delta > 3600) + if (ts - mCycle4 > 3600) { -RsDbg() << "DEBUG_TICK every hour" << std::endl; +#ifdef TICK_DEBUG + RsDbg() << "TICK_DEBUG every hour" << std::endl; +#endif + mCycle4 = ts; } // ticking is done, now compute new values of mLastRunDuration, mAvgRunDuration and mTickInterval - ts = getCurrentTS(); - mLastRunDuration = ts - mLastts; - mAvgRunDuration = 0.1 * mLastRunDuration + 0.9 * mAvgRunDuration; + ts = getCurrentTS(); + mLastRunDuration = ts - mLastts; + mAvgRunDuration = 0.1 * mLastRunDuration + 0.9 * mAvgRunDuration; -RsDbg() << "DEBUG_TICK new mLastRunDuration " << mLastRunDuration << " mAvgRunDuration " << mAvgRunDuration << std::endl; - if (mLastRunDuration > WARN_BIG_CYCLE_TIME) - RsDbg() << "DEBUG_TICK excessively long lycle time " << mLastRunDuration << std::endl; +#ifdef TICK_DEBUG + RsDbg() << "TICK_DEBUG new mLastRunDuration " << mLastRunDuration << " mAvgRunDuration " << mAvgRunDuration << std::endl; + if (mLastRunDuration > WARN_BIG_CYCLE_TIME) + RsDbg() << "TICK_DEBUG excessively long lycle time " << mLastRunDuration << std::endl; +#endif // if the core has returned that there is more to tick we decrease the ticking interval, else we increse it -RsDbg() << "DEBUG_TICK moreToTick " << moreToTick << std::endl; +// this should be studied closer as I dont think that the core ever returns 1 +#ifdef TICK_DEBUG + RsDbg() << "TICK_DEBUG moreToTick " << moreToTick << std::endl; +#endif if (moreToTick == 1) mTickInterval = 0.9 * mTickInterval; - else + else mTickInterval = 1.1 * mTickInterval; -RsDbg() << "DEBUG_TICK new tick interval " << mTickInterval << std::endl; +#ifdef TICK_DEBUG + RsDbg() << "TICK_DEBUG new tick interval " << mTickInterval << std::endl; +#endif // keep the tick interval within allowed limits - if (mTickInterval < minTickInterval) + if (mTickInterval < minTickInterval) mTickInterval = minTickInterval; - else if (mTickInterval > maxTickInterval) + else if (mTickInterval > maxTickInterval) mTickInterval = maxTickInterval; -RsDbg() << "DEBUG_TICK new tick interval after limiter " << mTickInterval << std::endl; +#ifdef TICK_DEBUG + RsDbg() << "TICK_DEBUG new tick interval after limiter " << mTickInterval << std::endl; +#endif } diff --git a/libretroshare/src/rsserver/p3face.h b/libretroshare/src/rsserver/p3face.h index bb0b15353..a2637ceaf 100644 --- a/libretroshare/src/rsserver/p3face.h +++ b/libretroshare/src/rsserver/p3face.h @@ -188,10 +188,11 @@ public: // Worker Data..... - double mLastts; - double mTickInterval; + double mLastts; + double mTickInterval; double mLastRunDuration; double mAvgRunDuration; + double mCycle1, mCycle2, mCycle3, mCycle4; static const double minTickInterval; static const double maxTickInterval; From 7db8cbca979774a21de8fbb0ead6c76c5d66f435 Mon Sep 17 00:00:00 2001 From: jolavillette Date: Sat, 2 May 2020 21:21:42 +0200 Subject: [PATCH 3/3] remove debug flag --- libretroshare/src/rsserver/p3face-server.cc | 2 ++ 1 file changed, 2 insertions(+) diff --git a/libretroshare/src/rsserver/p3face-server.cc b/libretroshare/src/rsserver/p3face-server.cc index 65747739f..0ed2f698c 100644 --- a/libretroshare/src/rsserver/p3face-server.cc +++ b/libretroshare/src/rsserver/p3face-server.cc @@ -41,7 +41,9 @@ #include "services/rseventsservice.h" +/******************* #define TICK_DEBUG 1 +*******************/ #define WARN_BIG_CYCLE_TIME (0.2)