From b0d5b3c6d13398fb0dfccac98191c6aba037abf3 Mon Sep 17 00:00:00 2001 From: Klaus Basan Date: Sat, 29 Feb 2020 19:18:39 +0100 Subject: [PATCH] [Worker] Log. how long it takes to quitAndWait a worker * sometimes the shutdown sequence of swift takes extremly long, this is to identify which workers are affected * reduced "wait time" * function so each worker can have its own "wait" time * for a worker there are 2 "waits", the quitAndWait of the worker and the wait of CRegularThread (dtor) Originally Ref T145, T647 --- .../simulation/backgroundvalidation.cpp | 5 +++ .../simulation/backgroundvalidation.h | 4 +++ src/blackmisc/worker.cpp | 35 +++++++++++++------ src/blackmisc/worker.h | 7 ++++ 4 files changed, 41 insertions(+), 10 deletions(-) diff --git a/src/blackmisc/simulation/backgroundvalidation.cpp b/src/blackmisc/simulation/backgroundvalidation.cpp index bdeb42a1d..da47e7e2f 100644 --- a/src/blackmisc/simulation/backgroundvalidation.cpp +++ b/src/blackmisc/simulation/backgroundvalidation.cpp @@ -104,6 +104,11 @@ namespace BlackMisc return true; } + unsigned long CBackgroundValidation::waitTimeoutMs() const + { + return 0; + } + void CBackgroundValidation::doWork() { if (m_inWork) { return; } diff --git a/src/blackmisc/simulation/backgroundvalidation.h b/src/blackmisc/simulation/backgroundvalidation.h index ae8600998..e62410838 100644 --- a/src/blackmisc/simulation/backgroundvalidation.h +++ b/src/blackmisc/simulation/backgroundvalidation.h @@ -75,6 +75,10 @@ namespace BlackMisc //! Validated for simulator void validated(const CSimulatorInfo &simulator, const CAircraftModelList &validModels, const CAircraftModelList &invalidModels, bool stopped, const CStatusMessageList &msgs); + protected: + //! \copydoc CContinuousWorker::waitTimeoutMs + virtual unsigned long waitTimeoutMs() const override; + private: mutable QReadWriteLock m_lock; //!< lock snapshot std::atomic_bool m_inWork { false }; //!< indicates a running update diff --git a/src/blackmisc/worker.cpp b/src/blackmisc/worker.cpp index 2a03223a9..9753080fe 100644 --- a/src/blackmisc/worker.cpp +++ b/src/blackmisc/worker.cpp @@ -9,6 +9,7 @@ #include "blackmisc/threadutils.h" #include "blackmisc/worker.h" #include "blackmisc/verify.h" +#include "blackmisc/logmessage.h" #include #include @@ -34,6 +35,8 @@ namespace BlackMisc CRegularThread::~CRegularThread() { + const QString name = this->objectName(); + #ifdef Q_OS_WIN32 auto handle = m_handle.load(); if (handle) @@ -44,8 +47,8 @@ namespace BlackMisc switch (status) { default: - case WAIT_FAILED: qWarning() << "Thread" << objectName() << "unspecified error"; break; - case WAIT_OBJECT_0: qWarning() << "Thread" << objectName() << "unsafely terminated by program shutdown"; break; + case WAIT_FAILED: qWarning() << "Thread" << name << "unspecified error"; break; + case WAIT_OBJECT_0: qWarning() << "Thread" << name << "unsafely terminated by program shutdown"; break; case WAIT_TIMEOUT: break; } } @@ -53,9 +56,13 @@ namespace BlackMisc #endif quit(); - bool ok = wait(30 * 1000); //! \todo KB 2017-10 temp workaround: in T145 this will be fixed, sometimes (very rarely) hanging here during shutdown - Q_ASSERT_X(ok, Q_FUNC_INFO, "Wait timeout"); // MS 2018-09 assert because we want a stack trace of all threads, via breakpad - Q_UNUSED(ok); + // the wait avoids: QThread: Destroyed while thread is still running + const unsigned long timeoutMs = 5 * 1000; + const bool ok = wait(timeoutMs); //! \todo KB 2017-10 temp workaround: in T145 this will be fixed, sometimes (very rarely) hanging here during shutdown + const QString as = QStringLiteral("Wait timeout after %1ms for '%2'").arg(timeoutMs).arg(name); + const QByteArray asBA = as.toLatin1(); + BLACK_AUDIT_X(ok, Q_FUNC_INFO, asBA); // MS 2018-09 assert because we want a stack trace of all threads, via breakpad + Q_UNUSED(ok) } CWorker *CWorker::fromTaskImpl(QObject *owner, const QString &name, int typeId, const std::function &task) @@ -74,7 +81,7 @@ namespace BlackMisc worker->moveToThread(thread); const bool s = QMetaObject::invokeMethod(worker, &CWorker::ps_runTask); Q_ASSERT_X(s, Q_FUNC_INFO, "cannot invoke"); - Q_UNUSED(s); + Q_UNUSED(s) thread->start(); return worker; } @@ -157,7 +164,7 @@ namespace BlackMisc } moveToThread(thread); - connect(thread, &QThread::started, this, &CContinuousWorker::initialize); + connect(thread, &QThread::started, this, &CContinuousWorker::initialize); connect(thread, &QThread::finished, &m_updateTimer, &QTimer::stop); connect(thread, &QThread::finished, this, &CContinuousWorker::cleanup); connect(thread, &QThread::finished, this, &CContinuousWorker::finish); @@ -172,6 +179,7 @@ namespace BlackMisc if (this->thread() == m_owner->thread()) { return; } // remark: cannot stop timer here, as I am normally not in the correct thread + this->beforeQuit(); thread()->quit(); } @@ -189,9 +197,16 @@ namespace BlackMisc this->quit(); // T647, discussed here: https://discordapp.com/channels/539048679160676382/539925070550794240/573260844004016148 - const bool ok = workerThread->wait(30 * 1000); //! \todo KB 2017-10 temp workaround: in T145 this will be fixed, sometimes (very rarely) hanging here during shutdown - BLACK_AUDIT_X(ok, Q_FUNC_INFO, "Wait timeout"); // MS 2019-05 VERIFY because we want a stack trace of all threads, via breakpad - Q_UNUSED(ok); + const unsigned long waitTimeoutMs = this->waitTimeoutMs(); + const QString name(this->getName()); + qint64 waitTime = QDateTime::currentMSecsSinceEpoch(); + const bool ok = workerThread->wait(waitTimeoutMs); //! \todo KB 2017-10 temp workaround: in T145 this will be fixed, sometimes (very rarely) hanging here during shutdown + waitTime = QDateTime::currentMSecsSinceEpoch() - waitTime; + const QString msg = QStringLiteral("Waiting for quitAndWait of '%1' for %2ms").arg(name).arg(waitTime); + const QByteArray msgBA = msg.toLatin1(); + BLACK_AUDIT_X(ok, Q_FUNC_INFO, msgBA); // MS 2019-05 AUDIT because we want a stack trace of all threads, via breakpad + CLogMessage(this).info(msg); + Q_UNUSED(ok) } void CContinuousWorker::startUpdating(int updateTimeSecs) diff --git a/src/blackmisc/worker.h b/src/blackmisc/worker.h index 7b6315706..69f463afb 100644 --- a/src/blackmisc/worker.h +++ b/src/blackmisc/worker.h @@ -327,6 +327,13 @@ namespace BlackMisc //! Called when the thread is finished. virtual void cleanup() {} + //! Called before quit is called + //! \remark can be used to "clean things up" or request work functions to stop + virtual void beforeQuit() noexcept {} + + //! Wait time for quitAndWait, 0 means not waiting + virtual unsigned long waitTimeoutMs() const { return 15 * 1000; } + QTimer m_updateTimer { this }; //!< timer which can be used by implementing classes private: