add stats for processing time per packet

interface/src/ui/OctreeStatsDialog.cpp

@@ -55,6 +55,8 @@ OctreeStatsDialog::OctreeStatsDialog(QWidget* parent, NodeToOctreeSceneStats* mo
 
     _processedPacketsElements = AddStatItem("Processed Packets Elements");
     _processedPacketsEntities = AddStatItem("Processed Packets Entities");
+    _processedPacketsTiming = AddStatItem("Processed Packets Timing");
+
     _entityUpdateTime = AddStatItem("Entity Update Time");
     _entityUpdates = AddStatItem("Entity Updates");
     
@@ -220,11 +222,19 @@ void OctreeStatsDialog::paintEvent(QPaintEvent* event) {
     auto averageElementsPerSecond = entities->getAverageElementsPerSecond();
     auto averageEntitiesPerSecond = entities->getAverageEntitiesPerSecond();
 
+    auto averageWaitLockPerPacket = entities->getAverageWaitLockPerPacket();
+    auto averageUncompressPerPacket = entities->getAverageUncompressPerPacket();
+    auto averageReadBitstreamPerPacket = entities->getAverageReadBitstreamPerPacket();
+
     QString averageElementsPerPacketString = locale.toString(averageElementsPerPacket);
     QString averageEntitiesPerPacketString = locale.toString(averageEntitiesPerPacket);
     QString averageElementsPerSecondString = locale.toString(averageElementsPerSecond);
     QString averageEntitiesPerSecondString = locale.toString(averageEntitiesPerSecond);
 
+    QString averageWaitLockPerPacketString = locale.toString(averageWaitLockPerPacket);
+    QString averageUncompressPerPacketString = locale.toString(averageUncompressPerPacket);
+    QString averageReadBitstreamPerPacketString = locale.toString(averageReadBitstreamPerPacket);
+
     label = _labels[_processedPacketsElements];
     statsValue.str("");
     statsValue << 
@@ -241,6 +251,15 @@ void OctreeStatsDialog::paintEvent(QPaintEvent* event) {
         
     label->setText(statsValue.str().c_str());
 
+    label = _labels[_processedPacketsTiming];
+    statsValue.str("");
+    statsValue << 
+        "Lock Wait:" << qPrintable(averageWaitLockPerPacketString) << " (usecs) / " <<
+        "Uncompress:" << qPrintable(averageUncompressPerPacketString) << " (usecs) / " <<
+        "Process:" << qPrintable(averageReadBitstreamPerPacketString) << " (usecs)";
+        
+    label->setText(statsValue.str().c_str());
+
     // Entity Edits update time
     label = _labels[_entityUpdateTime];
     auto averageEditDelta = entitiesTree->getAverageEditDeltas();

interface/src/ui/OctreeStatsDialog.h

@@ -68,6 +68,7 @@ private:
     int _entityUpdates;
     int _processedPacketsElements;
     int _processedPacketsEntities;
+    int _processedPacketsTiming;
     
     const int SAMPLES_PER_SECOND = 10;
     SimpleMovingAverage _averageUpdatesPerSecond;

libraries/octree/src/OctreeRenderer.cpp

@@ -104,6 +104,10 @@ void OctreeRenderer::processDatagram(const QByteArray& dataByteArray, const Shar
         int elementsPerPacket = 0;
         int entitiesPerPacket = 0;
         
+        quint64 totalWaitingForLock = 0;
+        quint64 totalUncompress = 0;
+        quint64 totalReadBitsteam = 0;
+        
         int subsection = 1;
         while (dataBytes > 0) {
             if (packetIsCompressed) {
@@ -123,7 +127,9 @@ void OctreeRenderer::processDatagram(const QByteArray& dataByteArray, const Shar
                 // ask the VoxelTree to read the bitstream into the tree
                 ReadBitstreamToTreeParams args(packetIsColored ? WANT_COLOR : NO_COLOR, WANT_EXISTS_BITS, NULL, 
                                                 sourceUUID, sourceNode, false, packetVersion);
+                quint64 startLock = usecTimestampNow();
                 _tree->lockForWrite();
+                quint64 startUncompress = usecTimestampNow();
                 OctreePacketData packetData(packetIsCompressed);
                 packetData.loadFinalizedContent(dataAt, sectionLength);
                 if (extraDebugging) {
@@ -137,7 +143,9 @@ void OctreeRenderer::processDatagram(const QByteArray& dataByteArray, const Shar
                 if (extraDebugging) {
                     qCDebug(octree) << "OctreeRenderer::processDatagram() ******* START _tree->readBitstreamToTree()...";
                 }
+                quint64 startReadBitsteam = usecTimestampNow();
                 _tree->readBitstreamToTree(packetData.getUncompressedData(), packetData.getUncompressedSize(), args);
+                quint64 endReadBitsteam = usecTimestampNow();
                 if (extraDebugging) {
                     qCDebug(octree) << "OctreeRenderer::processDatagram() ******* END _tree->readBitstreamToTree()...";
                 }
@@ -152,11 +160,19 @@ void OctreeRenderer::processDatagram(const QByteArray& dataByteArray, const Shar
                 _elementsInLastWindow += args.elementsPerPacket;
                 _entitiesInLastWindow += args.entitiesPerPacket;
 
+                totalWaitingForLock += (startUncompress - startLock);
+                totalUncompress += (startReadBitsteam - startUncompress);
+                totalReadBitsteam += (endReadBitsteam - startReadBitsteam);
+
             }
             subsection++;
         }
         _elementsPerPacket.updateAverage(elementsPerPacket);
         _entitiesPerPacket.updateAverage(entitiesPerPacket);
+
+        _waitLockPerPacket.updateAverage(totalWaitingForLock);
+        _uncompressPerPacket.updateAverage(totalUncompress);
+        _readBitstreamPerPacket.updateAverage(totalReadBitsteam);
         
         quint64 now = usecTimestampNow();
         if (_lastWindowAt == 0) {

libraries/octree/src/OctreeRenderer.h

@@ -66,6 +66,10 @@ public:
 
     float getAverageElementsPerSecond() const { return _elementsPerSecond.getAverage(); }
     float getAverageEntitiesPerSecond() const { return _entitiesPerSecond.getAverage(); }
+
+    float getAverageWaitLockPerPacket() const { return _waitLockPerPacket.getAverage(); }
+    float getAverageUncompressPerPacket() const { return _uncompressPerPacket.getAverage(); }
+    float getAverageReadBitstreamPerPacket() const { return _readBitstreamPerPacket.getAverage(); }
     
 protected:
     virtual Octree* createTree() = 0;
@@ -79,6 +83,10 @@ protected:
     SimpleMovingAverage _elementsPerSecond;
     SimpleMovingAverage _entitiesPerSecond;
 
+    SimpleMovingAverage _waitLockPerPacket;
+    SimpleMovingAverage _uncompressPerPacket;
+    SimpleMovingAverage _readBitstreamPerPacket;
+
     quint64 _lastWindowAt = 0;
     int _elementsInLastWindow = 0;
     int _entitiesInLastWindow = 0;