Merge pull request #15551 from roxanneskelly/queueDepthDebug

Queue depth debugging code

assignment-client/src/audio/AudioMixer.cpp

@@ -17,6 +17,7 @@
 #include <QtCore/QJsonDocument>
 #include <QtCore/QJsonObject>
 #include <QtCore/QJsonValue>
+#include <shared/QtHelpers.h>
 
 #include <LogHandler.h>
 #include <NetworkAccessManager.h>
@@ -269,6 +270,13 @@ void AudioMixer::sendStatsPacket() {
         return;
     }
 
+#ifdef DEBUG_EVENT_QUEUE
+    QJsonObject qtStats;
+
+    _slavePool.queueStats(qtStats);
+    statsObject["audio_thread_event_queue"] = qtStats;
+#endif
+
     // general stats
     statsObject["useDynamicJitterBuffers"] = _numStaticJitterFrames == DISABLE_STATIC_JITTER_FRAMES;
 

assignment-client/src/audio/AudioMixerSlavePool.cpp

@@ -113,6 +113,19 @@ void AudioMixerSlavePool::each(std::function<void(AudioMixerSlave& slave)> funct
     }
 }
 
+#ifdef DEBUG_EVENT_QUEUE
+void AudioMixerSlavePool::queueStats(QJsonObject& stats) {
+    unsigned i = 0;
+    for (auto& slave : _slaves) {
+        int queueSize = ::hifi::qt::getEventQueueSize(slave.get());
+        QString queueName = QString("audio_thread_event_queue_%1").arg(i);
+        stats[queueName] = queueSize;
+
+        i++;
+    }
+}
+#endif // DEBUG_EVENT_QUEUE
+
 void AudioMixerSlavePool::setNumThreads(int numThreads) {
     // clamp to allowed size
     {

assignment-client/src/audio/AudioMixerSlavePool.h

@@ -17,7 +17,7 @@
 #include <vector>
 
 #include <QThread>
-
+#include <shared/QtHelpers.h>
 #include <TBBHelpers.h>
 
 #include "AudioMixerSlave.h"
@@ -72,6 +72,10 @@ public:
     // iterate over all slaves
     void each(std::function<void(AudioMixerSlave& slave)> functor);
 
+#ifdef DEBUG_EVENT_QUEUE
+    void queueStats(QJsonObject& stats);
+#endif
+
     void setNumThreads(int numThreads);
     int numThreads() { return _numThreads; }
 

assignment-client/src/avatars/AvatarMixer.cpp

@@ -24,6 +24,7 @@
 #include <QtCore/QTimer>
 #include <QtCore/QThread>
 #include <QtCore/QJsonDocument>
+#include <shared/QtHelpers.h>
 
 #include <AABox.h>
 #include <AvatarLogging.h>
@@ -753,6 +754,13 @@ void AvatarMixer::sendStatsPacket() {
     statsObject["trailing_mix_ratio"] = _trailingMixRatio;
     statsObject["throttling_ratio"] = _throttlingRatio;
 
+#ifdef DEBUG_EVENT_QUEUE
+    QJsonObject qtStats;
+
+    _slavePool.queueStats(qtStats);
+    statsObject["avatar_thread_event_queue"] = qtStats;
+#endif
+
     // this things all occur on the frequency of the tight loop
     int tightLoopFrames = _numTightLoopFrames;
     int tenTimesPerFrame = tightLoopFrames * 10;

assignment-client/src/avatars/AvatarMixerSlavePool.cpp

@@ -117,6 +117,19 @@ void AvatarMixerSlavePool::each(std::function<void(AvatarMixerSlave& slave)> fun
     }
 }
 
+#ifdef DEBUG_EVENT_QUEUE
+void AvatarMixerSlavePool::queueStats(QJsonObject& stats) {
+    unsigned i = 0;
+    for (auto& slave : _slaves) {
+        int queueSize = ::hifi::qt::getEventQueueSize(slave.get());
+        QString queueName = QString("avatar_thread_event_queue_%1").arg(i);
+        stats[queueName] = queueSize;
+
+        i++;
+    }
+}
+#endif // DEBUG_EVENT_QUEUE
+
 void AvatarMixerSlavePool::setNumThreads(int numThreads) {
     // clamp to allowed size
     {

assignment-client/src/avatars/AvatarMixerSlavePool.h

@@ -20,9 +20,11 @@
 
 #include <TBBHelpers.h>
 #include <NodeList.h>
+#include <shared/QtHelpers.h>
 
 #include "AvatarMixerSlave.h"
 
+
 class AvatarMixerSlavePool;
 
 class AvatarMixerSlaveThread : public QThread, public AvatarMixerSlave {
@@ -72,6 +74,10 @@ public:
     // iterate over all slaves
     void each(std::function<void(AvatarMixerSlave& slave)> functor);
 
+#ifdef DEBUG_EVENT_QUEUE
+    void AvatarMixerSlavePool::queueStats(QJsonObject& stats);
+#endif
+
     void setNumThreads(int numThreads);
     int numThreads() const { return _numThreads; }
 

cmake/macros/SetupQt.cmake

@@ -7,7 +7,8 @@
 #
 
 # Construct a default QT location from a root path, a version and an architecture
-function(calculate_default_qt_dir _RESULT_NAME)
+
+function(calculate_default_qt_dir _QT_VERSION _RESULT_NAME)
     if (ANDROID)
         set(QT_DEFAULT_ARCH "android_armv7")
     elseif(UWP)
@@ -27,22 +28,22 @@ function(calculate_default_qt_dir _RESULT_NAME)
     endif()
 
     set_from_env(QT_ROOT QT_ROOT ${QT_DEFAULT_ROOT})
-    set_from_env(QT_VERSION QT_VERSION "5.10.1")
     set_from_env(QT_ARCH QT_ARCH ${QT_DEFAULT_ARCH})
 
-    set(${_RESULT_NAME} "${QT_ROOT}/${QT_VERSION}/${QT_ARCH}" PARENT_SCOPE)
+    set(${_RESULT_NAME} "${QT_ROOT}/${_QT_VERSION}/${QT_ARCH}" PARENT_SCOPE)
 endfunction()
 
 # Sets the QT_CMAKE_PREFIX_PATH and QT_DIR variables
 # Also enables CMAKE_AUTOMOC and CMAKE_AUTORCC
 macro(setup_qt)
+    set_from_env(QT_VERSION QT_VERSION "5.10.1")
     # if QT_CMAKE_PREFIX_PATH was not specified before hand,
     # try to use the environment variable
     if (NOT QT_CMAKE_PREFIX_PATH)
         set(QT_CMAKE_PREFIX_PATH "$ENV{QT_CMAKE_PREFIX_PATH}")
     endif()
     if (("QT_CMAKE_PREFIX_PATH" STREQUAL "") OR (NOT EXISTS "${QT_CMAKE_PREFIX_PATH}"))
-        calculate_default_qt_dir(QT_DIR)
+        calculate_default_qt_dir(${QT_VERSION} QT_DIR)
         set(QT_CMAKE_PREFIX_PATH "${QT_DIR}/lib/cmake")
     else()
         # figure out where the qt dir is

interface/resources/qml/Stats.qml

@@ -147,6 +147,17 @@ Item {
                                     "Parabolas:\t" + root.parabolaPicksUpdated.x + "/" + root.parabolaPicksUpdated.y + "/" + root.parabolaPicksUpdated.z + "\n    " +
                                     "Colliders:\t" + root.collisionPicksUpdated.x + "/" + root.collisionPicksUpdated.y + "/" + root.collisionPicksUpdated.z
                     }
+                    StatText {
+                        visible: { root.eventQueueDebuggingOn && root.expanded }
+                        text: { if (root.eventQueueDebuggingOn) {
+                                    return "Event Queue Depth\n    " +
+                                        "Main:\t" + root.mainThreadQueueDepth + "\n" +
+                                        "NodeList:\t" + root.nodeListThreadQueueDepth;
+                                } else {
+                                    return "";
+                                }
+                            }
+                    }
                 }
             }
 

interface/src/Application.cpp

@@ -250,17 +250,6 @@
 #if defined(Q_OS_WIN)
 #include <VersionHelpers.h>
 
-#ifdef DEBUG_EVENT_QUEUE
-// This is a HACK that uses private headers included with the qt source distrubution.
-// To use this feature you need to add these directores to your include path:
-// E:/Qt/5.10.1/Src/qtbase/include/QtCore/5.10.1/QtCore
-// E:/Qt/5.10.1/Src/qtbase/include/QtCore/5.10.1
-#define QT_BOOTSTRAPPED
-#include <private/qthread_p.h>
-#include <private/qobject_p.h>
-#undef QT_BOOTSTRAPPED
-#endif
-
 // On Windows PC, NVidia Optimus laptop, we want to enable NVIDIA GPU
 // FIXME seems to be broken.
 extern "C" {
@@ -4029,24 +4018,6 @@ bool Application::handleFileOpenEvent(QFileOpenEvent* fileEvent) {
     return false;
 }
 
-#ifdef DEBUG_EVENT_QUEUE
-static int getEventQueueSize(QThread* thread) {
-    auto threadData = QThreadData::get2(thread);
-    QMutexLocker locker(&threadData->postEventList.mutex);
-    return threadData->postEventList.size();
-}
-
-static void dumpEventQueue(QThread* thread) {
-    auto threadData = QThreadData::get2(thread);
-    QMutexLocker locker(&threadData->postEventList.mutex);
-    qDebug() << "Event list, size =" << threadData->postEventList.size();
-    for (auto& postEvent : threadData->postEventList) {
-        QEvent::Type type = (postEvent.event ? postEvent.event->type() : QEvent::None);
-        qDebug() << "    " << type;
-    }
-}
-#endif // DEBUG_EVENT_QUEUE
-
 bool Application::notify(QObject * object, QEvent * event) {
     if (thread() == QThread::currentThread()) {
         PROFILE_RANGE_IF_LONGER(app, "notify", 2)
@@ -4082,14 +4053,16 @@ bool Application::event(QEvent* event) {
         case ApplicationEvent::Idle:
             idle();
 
-#ifdef DEBUG_EVENT_QUEUE
+#ifdef DEBUG_EVENT_QUEUE_DEPTH
+            // The event queue may very well grow beyond 400, so 
+            // this code should only be enabled on local builds
             {
-                int count = getEventQueueSize(QThread::currentThread());
+                int count = ::hifi::qt::getEventQueueSize(QThread::currentThread());
                 if (count > 400) {
-                    dumpEventQueue(QThread::currentThread());
+                    ::hifi::qt::dumpEventQueue(QThread::currentThread());
                 }
             }
-#endif // DEBUG_EVENT_QUEUE
+#endif // DEBUG_EVENT_QUEUE_DEPTH
 
             _pendingIdleEvent.store(false);
 

interface/src/ui/Stats.cpp

@@ -180,6 +180,11 @@ void Stats::updateStats(bool force) {
     STAT_UPDATE_FLOAT(mbpsIn, nodeList->getInboundKbps() / 1000.0f, 0.01f);
     STAT_UPDATE_FLOAT(mbpsOut, nodeList->getOutboundKbps() / 1000.0f, 0.01f);
 
+#ifdef DEBUG_EVENT_QUEUE
+    STAT_UPDATE(mainThreadQueueDepth, ::hifi::qt::getEventQueueSize(QThread::currentThread()));
+    STAT_UPDATE(nodeListThreadQueueDepth, ::hifi::qt::getEventQueueSize(nodeList->thread()));
+#endif
+
     SharedNodePointer audioMixerNode = nodeList->soloNodeOfType(NodeType::AudioMixer);
     SharedNodePointer avatarMixerNode = nodeList->soloNodeOfType(NodeType::AvatarMixer);
     SharedNodePointer assetServerNode = nodeList->soloNodeOfType(NodeType::AssetServer);

interface/src/ui/Stats.h

@@ -14,6 +14,7 @@
 #include <OffscreenQmlElement.h>
 #include <AudioIOStats.h>
 #include <render/Args.h>
+#include <shared/QtHelpers.h>
 
 #define STATS_PROPERTY(type, name, initialValue) \
     Q_PROPERTY(type name READ name NOTIFY name##Changed) \
@@ -179,6 +180,7 @@ private: \
  * @property {Vec3} rayPicksUpdated - <em>Read-only.</em>
  * @property {Vec3} parabolaPicksUpdated - <em>Read-only.</em>
  * @property {Vec3} collisionPicksUpdated - <em>Read-only.</em>
+ * @property {bool} eventQueueDebuggingOn - <em>Read-only.</em>
  */
 // Properties from x onwards are QQuickItem properties.
 
@@ -312,6 +314,14 @@ class Stats : public QQuickItem {
     STATS_PROPERTY(QVector3D, parabolaPicksUpdated, QVector3D(0, 0, 0))
     STATS_PROPERTY(QVector3D, collisionPicksUpdated, QVector3D(0, 0, 0))
 
+#ifdef DEBUG_EVENT_QUEUE
+    STATS_PROPERTY(bool, eventQueueDebuggingOn, true)
+    STATS_PROPERTY(int, mainThreadQueueDepth, -1);
+    STATS_PROPERTY(int, nodeListThreadQueueDepth, -1);
+#else
+    STATS_PROPERTY(bool, eventQueueDebuggingOn, false)
+#endif // DEBUG_EVENT_QUEUE
+
 public:
     static Stats* getInstance();
 
@@ -1357,6 +1367,27 @@ signals:
      */
     void collisionPicksUpdatedChanged();
 
+    /**jsdoc
+     * Triggered when the value of the <code>eventQueueDebuggingOn</code> property changes.
+     * @function Stats.eventQueueDebuggingOn
+     * @returns {Signal}
+     */
+    void eventQueueDebuggingOnChanged();
+
+    /**jsdoc
+     * Triggered when the value of the <code>nodeListThreadQueueDepth</code> property changes.
+     * @function Stats.nodeListThreadQueueDepth
+     * @returns {Signal}
+     */
+    void nodeListThreadQueueDepthChanged();
+
+    /**jsdoc
+     * Triggered when the value of the <code>nodeListThreadQueueDepth</code> property changes.
+     * @function Stats.nodeListThreadQueueDepth
+     * @returns {Signal}
+     */
+    void mainThreadQueueDepthChanged();
+
 private:
     int _recentMaxPackets{ 0 } ; // recent max incoming voxel packets to process
     bool _resetRecentMaxPacketsSoon{ true };

libraries/networking/src/DomainHandler.cpp

@@ -567,9 +567,19 @@ bool DomainHandler::checkInPacketTimeout() {
     }
 
     if (_checkInPacketsSinceLastReply > MAX_SILENT_DOMAIN_SERVER_CHECK_INS) {
+
+        auto nodeList = DependencyManager::get<NodeList>();
+
         // we haven't heard back from DS in MAX_SILENT_DOMAIN_SERVER_CHECK_INS
         // so emit our signal that says that
-        qCDebug(networking_ice) << "Limit of silent domain checkins reached";
+
+#ifdef DEBUG_EVENT_QUEUE
+        int nodeListQueueSize = ::hifi::qt::getEventQueueSize(nodeList->thread());
+        qCDebug(networking) << "Limit of silent domain checkins reached (network qt queue: " << nodeListQueueSize << ")";
+#else  // DEBUG_EVENT_QUEUE
+        qCDebug(networking) << "Limit of silent domain checkins reached";
+#endif // DEBUG_EVENT_QUEUE
+
         emit limitOfSilentDomainCheckInsReached();
         return true;
     } else {

libraries/networking/src/ThreadedAssignment.cpp

@@ -18,6 +18,7 @@
 #include <QtCore/QTimer>
 
 #include <LogHandler.h>
+#include <shared/QtHelpers.h>
 
 #include "NetworkLogging.h"
 
@@ -94,6 +95,10 @@ void ThreadedAssignment::commonInit(const QString& targetName, NodeType_t nodeTy
 void ThreadedAssignment::addPacketStatsAndSendStatsPacket(QJsonObject statsObject) {
     auto nodeList = DependencyManager::get<NodeList>();
 
+#ifdef DEBUG_EVENT_QUEUE
+    statsObject["nodelist_event_queue_size"] = ::hifi::qt::getEventQueueSize(nodeList->thread());
+#endif
+
     QJsonObject ioStats;
     ioStats["inbound_kbps"] = nodeList->getInboundKbps();
     ioStats["inbound_pps"] = nodeList->getInboundPPS();

libraries/shared/CMakeLists.txt

@@ -1,5 +1,7 @@
 set(TARGET_NAME shared)
 
+include_directories("${QT_DIR}/include/QtCore/${QT_VERSION}/QtCore" "${QT_DIR}/include/QtCore/${QT_VERSION}")
+
 # TODO: there isn't really a good reason to have Script linked here - let's get what is requiring it out (RegisteredMetaTypes.cpp)
 setup_hifi_library(Gui Network Script)
 

libraries/shared/src/shared/QtHelpers.cpp

@@ -13,6 +13,17 @@
 #include <QtCore/QLoggingCategory>
 #include <QtCore/QReadWriteLock>
 
+// Inspecting of the qt event queue depth
+// requres access to private Qt datastructures
+// defined in private Qt headers
+#ifdef DEBUG_EVENT_QUEUE
+#include "../TryLocker.h"
+#define QT_BOOTSTRAPPED
+#include <private/qthread_p.h>
+#include <private/qobject_p.h>
+#undef QT_BOOTSTRAPPED
+#endif // DEBUG_EVENT_QUEUE
+
 #include "../Profile.h"
 Q_LOGGING_CATEGORY(thread_safety, "hifi.thread_safety")
 
@@ -80,6 +91,35 @@ bool blockingInvokeMethod(
     return blockingInvokeMethod(function, obj, member, QGenericReturnArgument(), val0, val1, val2, val3, val4, val5, val6, val7, val8, val9);
 }
 
+// Inspecting of the qt event queue
+// requres access to private Qt datastructures
+// Querying the event queue should be done with
+// care as it could lock the threadData->postEventList.mutex
+// The code uses a tryLock to avoid the possability of a
+// deadlock during a call to this code, although that is unlikely
+//
+#ifdef DEBUG_EVENT_QUEUE
+int getEventQueueSize(QThread* thread) {
+    auto threadData = QThreadData::get2(thread);
+    {
+        MutexTryLocker locker(threadData->postEventList.mutex);
+        if (locker.isLocked()) {
+            return threadData->postEventList.size();
+        }
+    }
+    return -1;
+}
 
+void dumpEventQueue(QThread* thread) {
+    auto threadData = QThreadData::get2(thread);
+    QMutexLocker locker(&threadData->postEventList.mutex);
+    qDebug() << "Event list, size =" << threadData->postEventList.size();
+    for (auto& postEvent : threadData->postEventList) {
+        QEvent::Type type = (postEvent.event ? postEvent.event->type() : QEvent::None);
+        qDebug() << "    " << type;
+    }
+}
+
+#endif // DEBUG_EVENT_QUEUE
 
 } }

libraries/shared/src/shared/QtHelpers.h

@@ -12,6 +12,10 @@
 
 #include <QtCore/QObject>
 
+#ifdef WIN32
+// Enable event queue debugging
+#define DEBUG_EVENT_QUEUE
+#endif // WIN32
 
 namespace hifi { namespace qt {
 void addBlockingForbiddenThread(const QString& name, QThread* thread = nullptr);
@@ -45,6 +49,18 @@ bool blockingInvokeMethod(
     QGenericArgument val8 = QGenericArgument(),
     QGenericArgument val9 = QGenericArgument());
 
+// Inspecting of the qt event queue
+// requres access to private Qt datastructures
+// Querying the event queue should be done with
+// care as it could lock the threadData->postEventList.mutex
+// The code uses a tryLock to avoid the possability of a
+// deadlock during a call to this code, although that is unlikely
+// When getEventQueueSize fails to get the lock, it returns -1
+#ifdef DEBUG_EVENT_QUEUE
+    int getEventQueueSize(QThread* thread);
+    void dumpEventQueue(QThread* thread);
+#endif // DEBUG_EVENT_QUEUE
+
 } }
 
 #define BLOCKING_INVOKE_METHOD(obj, member, ...) \