diff options
author | Tor Arne Vestbø <tor.arne.vestbo@qt.io> | 2023-12-12 13:52:41 +0100 |
---|---|---|
committer | Tor Arne Vestbø <tor.arne.vestbo@qt.io> | 2023-12-21 02:04:12 +0100 |
commit | c3a2b9f35a9a12ff3c6f5f0d11844de161b47c2a (patch) | |
tree | 8c35621da19aa81145f32c703d268159f7b63b50 | |
parent | fd38df3ec34238d9886be754ae1b5c9e8b10cc4b (diff) |
Add categorized logging of delete later machinery
A QT_MESSAGE_PATTERN including %{backtrace depth=4} should give
the call site of the QScopedScopeLevelCounter.
Task-number: QTBUG-120124
Change-Id: Ie477994882bde9168c931479102017ad5fde426a
Reviewed-by: Fabian Kosmale <fabian.kosmale@qt.io>
-rw-r--r-- | src/corelib/kernel/qcoreapplication.cpp | 45 | ||||
-rw-r--r-- | src/corelib/kernel/qcoreapplication_p.h | 5 | ||||
-rw-r--r-- | src/corelib/kernel/qeventloop.cpp | 9 | ||||
-rw-r--r-- | src/corelib/kernel/qobject.cpp | 13 | ||||
-rw-r--r-- | src/corelib/thread/qthread.cpp | 15 | ||||
-rw-r--r-- | src/corelib/thread/qthread_p.h | 7 | ||||
-rw-r--r-- | src/corelib/thread/qthread_unix.cpp | 1 | ||||
-rw-r--r-- | src/corelib/thread/qthread_win.cpp | 1 |
8 files changed, 81 insertions, 15 deletions
diff --git a/src/corelib/kernel/qcoreapplication.cpp b/src/corelib/kernel/qcoreapplication.cpp index 3acf9419df..9360df7e69 100644 --- a/src/corelib/kernel/qcoreapplication.cpp +++ b/src/corelib/kernel/qcoreapplication.cpp @@ -111,6 +111,10 @@ QT_BEGIN_NAMESPACE +#ifndef QT_NO_QOBJECT +Q_LOGGING_CATEGORY(lcDeleteLater, "qt.core.qobject.deletelater") +#endif + using namespace Qt::StringLiterals; Q_TRACE_PREFIX(qtcore, @@ -1494,6 +1498,8 @@ void QCoreApplicationPrivate::execCleanup() { threadData.loadRelaxed()->quitNow = false; in_exec = false; + + qCDebug(lcDeleteLater) << "Sending deferred delete events as part of exec cleanup"; QCoreApplication::sendPostedEvents(nullptr, QEvent::DeferredDelete); } @@ -1856,16 +1862,37 @@ void QCoreApplicationPrivate::sendPostedEvents(QObject *receiver, int event_type // events posted by the current event loop; or // 3) if the event was posted before the outermost event loop. - const int eventLoopLevel = static_cast<QDeferredDeleteEvent *>(pe.event)->loopLevel(); - const int eventScopeLevel = static_cast<QDeferredDeleteEvent *>(pe.event)->scopeLevel(); + const auto *event = static_cast<QDeferredDeleteEvent *>(pe.event); + qCDebug(lcDeleteLater) << "Processing deferred delete event for" << pe.receiver + << "with loop level" << event->loopLevel() << "and scope level" << event->scopeLevel(); + + qCDebug(lcDeleteLater) << "Checking" << data->thread << "with loop level" + << data->loopLevel << "and scope level" << data->scopeLevel; + + bool allowDeferredDelete = false; + if (event->loopLevel() == 0 && data->loopLevel > 0) { + qCDebug(lcDeleteLater) << "Event was posted outside outermost event loop" + << "and current thread has an event loop running."; + allowDeferredDelete = true; + } else { + const int totalEventLevel = event->loopLevel() + event->scopeLevel(); + const int totalThreadLevel = data->loopLevel + data->scopeLevel; + + if (totalEventLevel > totalThreadLevel) { + qCDebug(lcDeleteLater) << "Combined levels of event" << totalEventLevel + << "is higher than thread" << totalThreadLevel; + allowDeferredDelete = true; + } else if (event_type == QEvent::DeferredDelete && totalEventLevel == totalThreadLevel) { + qCDebug(lcDeleteLater) << "Explicit send of DeferredDelete and" + << "levels of event" << totalEventLevel + << "is same as thread" << totalThreadLevel; + allowDeferredDelete = true; + } + } - const bool postedBeforeOutermostLoop = eventLoopLevel == 0; - const bool allowDeferredDelete = - (eventLoopLevel + eventScopeLevel > data->loopLevel + data->scopeLevel - || (postedBeforeOutermostLoop && data->loopLevel > 0) - || (event_type == QEvent::DeferredDelete - && eventLoopLevel + eventScopeLevel == data->loopLevel + data->scopeLevel)); if (!allowDeferredDelete) { + qCDebug(lcDeleteLater) << "Failed conditions for deferred delete. Deferring again"; + // cannot send deferred delete if (!event_type && !receiver) { // we must copy it first; we want to re-post the event @@ -1882,6 +1909,8 @@ void QCoreApplicationPrivate::sendPostedEvents(QObject *receiver, int event_type data->postEventList.addEvent(pe_copy); } continue; + } else { + qCDebug(lcDeleteLater) << "Sending deferred delete to" << pe.receiver; } } diff --git a/src/corelib/kernel/qcoreapplication_p.h b/src/corelib/kernel/qcoreapplication_p.h index 56d726cff5..1c1577c9ff 100644 --- a/src/corelib/kernel/qcoreapplication_p.h +++ b/src/corelib/kernel/qcoreapplication_p.h @@ -25,6 +25,7 @@ #include "QtCore/qsettings.h" #endif #ifndef QT_NO_QOBJECT +#include <qloggingcategory.h> #include "private/qobject_p.h" #include "private/qlocking_p.h" #endif @@ -35,6 +36,10 @@ QT_BEGIN_NAMESPACE +#ifndef QT_NO_QOBJECT +Q_DECLARE_LOGGING_CATEGORY(lcDeleteLater) +#endif + typedef QList<QTranslator*> QTranslatorList; class QAbstractEventDispatcher; diff --git a/src/corelib/kernel/qeventloop.cpp b/src/corelib/kernel/qeventloop.cpp index dcd5f6d5c0..a921f54fac 100644 --- a/src/corelib/kernel/qeventloop.cpp +++ b/src/corelib/kernel/qeventloop.cpp @@ -151,6 +151,9 @@ int QEventLoop::exec(ProcessEventsFlags flags) auto threadData = d->threadData.loadRelaxed(); ++threadData->loopLevel; threadData->eventLoops.push(d->q_func()); + qCDebug(lcDeleteLater) << "Increased" << threadData->thread + << "loop level to" << threadData->loopLevel + << "with leaf loop now" << threadData->eventLoops.last(); locker.unlock(); } @@ -169,6 +172,12 @@ int QEventLoop::exec(ProcessEventsFlags flags) Q_UNUSED(eventLoop); // --release warning d->inExec = false; --threadData->loopLevel; + + qCDebug(lcDeleteLater) << "Decreased" << threadData->thread + << "loop level to" << threadData->loopLevel + << "with leaf loop now" << (threadData->eventLoops.isEmpty() + ? nullptr : threadData->eventLoops.last()); + } }; LoopReference ref(d, locker); diff --git a/src/corelib/kernel/qobject.cpp b/src/corelib/kernel/qobject.cpp index ef02b87a71..293f133eff 100644 --- a/src/corelib/kernel/qobject.cpp +++ b/src/corelib/kernel/qobject.cpp @@ -1430,6 +1430,7 @@ bool QObject::event(QEvent *e) break; case QEvent::DeferredDelete: + qCDebug(lcDeleteLater) << "Deferred deleting" << this; delete this; break; @@ -2450,8 +2451,10 @@ void QObject::deleteLater() // as long as we're not guarding every access to the bit field. Q_D(QObject); - if (d->deleteLaterCalled) + if (d->deleteLaterCalled) { + qCDebug(lcDeleteLater) << "Skipping deleteLater for already deferred object" << this; return; + } d->deleteLaterCalled = true; @@ -2477,10 +2480,16 @@ void QObject::deleteLater() // non-conformant code path, and our best guess is that the scope level // should be 1. (Loop level 0 is special: it means that no event loops // are running.) - if (scopeLevel == 0 && loopLevel != 0) + if (scopeLevel == 0 && loopLevel != 0) { + qCDebug(lcDeleteLater) << "Delete later called with scope level 0" + << "but loop level is > 0. Assuming scope is 1"; scopeLevel = 1; + } } + qCDebug(lcDeleteLater) << "Posting deferred delete for" << this + << "with loop level" << loopLevel << "and scope level" << scopeLevel; + eventListLocker.unlock(); QCoreApplication::postEvent(this, new QDeferredDeleteEvent(loopLevel, scopeLevel)); diff --git a/src/corelib/thread/qthread.cpp b/src/corelib/thread/qthread.cpp index a1c2c26e37..b45ff17373 100644 --- a/src/corelib/thread/qthread.cpp +++ b/src/corelib/thread/qthread.cpp @@ -147,6 +147,21 @@ void QAdoptedThread::run() qFatal("QAdoptedThread::run(): Internal error, this implementation should never be called."); } +QScopedScopeLevelCounter::QScopedScopeLevelCounter(QThreadData *threadData) + : threadData(threadData) +{ + ++threadData->scopeLevel; + qCDebug(lcDeleteLater) << "Increased" << threadData->thread + << "scope level to" << threadData->scopeLevel; +} + +QScopedScopeLevelCounter::~QScopedScopeLevelCounter() +{ + --threadData->scopeLevel; + qCDebug(lcDeleteLater) << "Decreased" << threadData->thread + << "scope level to" << threadData->scopeLevel; +} + /* QThreadPrivate */ diff --git a/src/corelib/thread/qthread_p.h b/src/corelib/thread/qthread_p.h index 7e32bcf7cd..2335ba398d 100644 --- a/src/corelib/thread/qthread_p.h +++ b/src/corelib/thread/qthread_p.h @@ -334,11 +334,8 @@ class QScopedScopeLevelCounter { QThreadData *threadData; public: - inline QScopedScopeLevelCounter(QThreadData *threadData) - : threadData(threadData) - { ++threadData->scopeLevel; } - inline ~QScopedScopeLevelCounter() - { --threadData->scopeLevel; } + QScopedScopeLevelCounter(QThreadData *threadData); + ~QScopedScopeLevelCounter(); }; // thread wrapper for the main() thread diff --git a/src/corelib/thread/qthread_unix.cpp b/src/corelib/thread/qthread_unix.cpp index d5d61aed66..4b165eef9c 100644 --- a/src/corelib/thread/qthread_unix.cpp +++ b/src/corelib/thread/qthread_unix.cpp @@ -347,6 +347,7 @@ void QThreadPrivate::finish(void *arg) void *data = &d->data->tls; locker.unlock(); emit thr->finished(QThread::QPrivateSignal()); + qCDebug(lcDeleteLater) << "Sending deferred delete events as part of finishing thread" << thr; QCoreApplication::sendPostedEvents(nullptr, QEvent::DeferredDelete); QThreadStorageData::finish((void **)data); locker.relock(); diff --git a/src/corelib/thread/qthread_win.cpp b/src/corelib/thread/qthread_win.cpp index b4a10d2426..07bdd5df80 100644 --- a/src/corelib/thread/qthread_win.cpp +++ b/src/corelib/thread/qthread_win.cpp @@ -316,6 +316,7 @@ void QThreadPrivate::finish(void *arg, bool lockAnyway) noexcept if (lockAnyway) locker.unlock(); emit thr->finished(QThread::QPrivateSignal()); + qCDebug(lcDeleteLater) << "Sending deferred delete events as part of finishing thread" << thr; QCoreApplicationPrivate::sendPostedEvents(nullptr, QEvent::DeferredDelete, d->data); QThreadStorageData::finish(tls_data); if (lockAnyway) |