Mirrors/overte-HifiExperiments
3
0
Fork 0
mirror of https://github.com/HifiExperiments/overte.git synced 2025-04-07 23:24:10 +02:00
Code Issues Projects Releases Packages Wiki Activity Actions

Merge pull request #6090 from ZappoMan/fixStat

Browse source 
Add some additional stats for debugging edit lags
This commit is contained in:
Stephen Birarda 2015-10-15 16:00:29 -07:00
commit e5825daa57
4 changed files with 70 additions and 9 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

39
assignment-client/src/octree/OctreeServer.cpp
View file

@ -625,6 +625,8 @@ bool OctreeServer::handleHTTPRequest(HTTPConnection* connection, const QUrl& url
statsString += QString().sprintf("<b>%s Edit Statistics... <a href='/resetStats'>[RESET]</a></b>\r\n",
getMyServerName());
quint64 currentPacketsInQueue = _octreeInboundPacketProcessor->packetsToProcessCount();
float incomingPPS = _octreeInboundPacketProcessor->getIncomingPPS();
float processedPPS = _octreeInboundPacketProcessor->getProcessedPPS();
quint64 averageTransitTimePerPacket = _octreeInboundPacketProcessor->getAverageTransitTimePerPacket();
quint64 averageProcessTimePerPacket = _octreeInboundPacketProcessor->getAverageProcessTimePerPacket();
quint64 averageLockWaitTimePerPacket = _octreeInboundPacketProcessor->getAverageLockWaitTimePerPacket();
@ -639,11 +641,16 @@ bool OctreeServer::handleHTTPRequest(HTTPConnection* connection, const QUrl& url
quint64 averageCreateTime = _tree->getAverageCreateTime();
quint64 averageLoggingTime = _tree->getAverageLoggingTime();
int FLOAT_PRECISION = 3;
float averageElementsPerPacket = totalPacketsProcessed == 0 ? 0 : (float)totalElementsProcessed / totalPacketsProcessed;
statsString += QString(" Current Inbound Packets Queue: %1 packets\r\n")
statsString += QString(" Current Inbound Packets Queue: %1 packets \r\n")
.arg(locale.toString((uint)currentPacketsInQueue).rightJustified(COLUMN_WIDTH, ' '));
statsString += QString(" Packets Queue Network IN: %1 PPS \r\n")
.arg(locale.toString(incomingPPS, 'f', FLOAT_PRECISION).rightJustified(COLUMN_WIDTH, ' '));
statsString += QString(" Packets Queue Processing OUT: %1 PPS \r\n")
.arg(locale.toString(processedPPS, 'f', FLOAT_PRECISION).rightJustified(COLUMN_WIDTH, ' '));
statsString += QString(" Total Inbound Packets: %1 packets\r\n")
.arg(locale.toString((uint)totalPacketsProcessed).rightJustified(COLUMN_WIDTH, ' '));
@ -692,6 +699,16 @@ bool OctreeServer::handleHTTPRequest(HTTPConnection* connection, const QUrl& url
totalElementsProcessed = senderStats.getTotalElementsProcessed();
totalPacketsProcessed = senderStats.getTotalPacketsProcessed();
auto received = senderStats._incomingEditSequenceNumberStats.getReceived();
auto expected = senderStats._incomingEditSequenceNumberStats.getExpectedReceived();
auto unreasonable = senderStats._incomingEditSequenceNumberStats.getUnreasonable();
auto outOfOrder = senderStats._incomingEditSequenceNumberStats.getOutOfOrder();
auto early = senderStats._incomingEditSequenceNumberStats.getEarly();
auto late = senderStats._incomingEditSequenceNumberStats.getLate();
auto lost = senderStats._incomingEditSequenceNumberStats.getLost();
auto recovered = senderStats._incomingEditSequenceNumberStats.getRecovered();
averageElementsPerPacket = totalPacketsProcessed == 0 ? 0 : (float)totalElementsProcessed / totalPacketsProcessed;
statsString += QString(" Total Inbound Packets: %1 packets\r\n")
@ -702,7 +719,7 @@ bool OctreeServer::handleHTTPRequest(HTTPConnection* connection, const QUrl& url
(double)averageElementsPerPacket);
statsString += QString(" Average Transit Time/Packet: %1 usecs\r\n")
.arg(locale.toString((uint)averageTransitTimePerPacket).rightJustified(COLUMN_WIDTH, ' '));
statsString += QString(" Average Process Time/Packet: %1 usecs\r\n")
statsString += QString(" Average Process Time/Packet: %1 usecs\r\n")
.arg(locale.toString((uint)averageProcessTimePerPacket).rightJustified(COLUMN_WIDTH, ' '));
statsString += QString(" Average Wait Lock Time/Packet: %1 usecs\r\n")
.arg(locale.toString((uint)averageLockWaitTimePerPacket).rightJustified(COLUMN_WIDTH, ' '));
@ -711,6 +728,24 @@ bool OctreeServer::handleHTTPRequest(HTTPConnection* connection, const QUrl& url
statsString += QString(" Average Wait Lock Time/Element: %1 usecs\r\n")
.arg(locale.toString((uint)averageLockWaitTimePerElement).rightJustified(COLUMN_WIDTH, ' '));
statsString += QString("\r\n Inbound Edit Packets --------------------------------\r\n");
statsString += QString(" Received: %1\r\n")
.arg(locale.toString(received).rightJustified(COLUMN_WIDTH, ' '));
statsString += QString(" Expected: %1\r\n")
.arg(locale.toString(expected).rightJustified(COLUMN_WIDTH, ' '));
statsString += QString(" Unreasonable: %1\r\n")
.arg(locale.toString(unreasonable).rightJustified(COLUMN_WIDTH, ' '));
statsString += QString(" Out of Order: %1\r\n")
.arg(locale.toString(outOfOrder).rightJustified(COLUMN_WIDTH, ' '));
statsString += QString(" Early: %1\r\n")
.arg(locale.toString(early).rightJustified(COLUMN_WIDTH, ' '));
statsString += QString(" Late: %1\r\n")
.arg(locale.toString(late).rightJustified(COLUMN_WIDTH, ' '));
statsString += QString(" Lost: %1\r\n")
.arg(locale.toString(lost).rightJustified(COLUMN_WIDTH, ' '));
statsString += QString(" Recovered: %1\r\n")
.arg(locale.toString(recovered).rightJustified(COLUMN_WIDTH, ' '));
}
statsString += "\r\n\r\n";

31
interface/src/ui/OctreeStatsDialog.cpp
View file

@ -54,11 +54,13 @@ OctreeStatsDialog::OctreeStatsDialog(QWidget* parent, NodeToOctreeSceneStats* mo
_localElementsMemory = AddStatItem("Elements Memory");
_sendingMode = AddStatItem("Sending Mode");
_processedPackets = AddStatItem("Entity Packets");
_processedPackets = AddStatItem("Incoming Entity Packets");
_processedPacketsElements = AddStatItem("Processed Packets Elements");
_processedPacketsEntities = AddStatItem("Processed Packets Entities");
_processedPacketsTiming = AddStatItem("Processed Packets Timing");
_outboundEditPackets = AddStatItem("Outbound Entity Packets");
_entityUpdateTime = AddStatItem("Entity Update Time");
_entityUpdates = AddStatItem("Entity Updates");
@ -266,6 +268,7 @@ void OctreeStatsDialog::paintEvent(QPaintEvent* event) {
label = _labels[_processedPackets];
const OctreePacketProcessor& entitiesPacketProcessor = qApp->getOctreePacketProcessor();
auto incomingPacketsDepth = entitiesPacketProcessor.packetsToProcessCount();
auto incomingPPS = entitiesPacketProcessor.getIncomingPPS();
auto processedPPS = entitiesPacketProcessor.getProcessedPPS();
auto treeProcessedPPS = entities->getAveragePacketsPerSecond();
@ -276,6 +279,7 @@ void OctreeStatsDialog::paintEvent(QPaintEvent* event) {
statsValue.str("");
statsValue <<
"Queue Size: " << incomingPacketsDepth << " Packets / " <<
"Network IN: " << qPrintable(incomingPPSString) << " PPS / " <<
"Queue OUT: " << qPrintable(processedPPSString) << " PPS / " <<
"Tree IN: " << qPrintable(treeProcessedPPSString) << " PPS";
@ -301,12 +305,31 @@ void OctreeStatsDialog::paintEvent(QPaintEvent* event) {
label = _labels[_processedPacketsTiming];
statsValue.str("");
statsValue <<
"Lock Wait:" << qPrintable(averageWaitLockPerPacketString) << " (usecs) / " <<
"Uncompress:" << qPrintable(averageUncompressPerPacketString) << " (usecs) / " <<
"Process:" << qPrintable(averageReadBitstreamPerPacketString) << " (usecs)";
"Lock Wait: " << qPrintable(averageWaitLockPerPacketString) << " (usecs) / " <<
"Uncompress: " << qPrintable(averageUncompressPerPacketString) << " (usecs) / " <<
"Process: " << qPrintable(averageReadBitstreamPerPacketString) << " (usecs)";
label->setText(statsValue.str().c_str());
auto entitiesEditPacketSender = qApp->getEntityEditPacketSender();
auto outboundPacketsDepth = entitiesEditPacketSender->packetsToSendCount();
auto outboundQueuedPPS = entitiesEditPacketSender->getLifetimePPSQueued();
auto outboundSentPPS = entitiesEditPacketSender->getLifetimePPS();
QString outboundQueuedPPSString = locale.toString(outboundQueuedPPS, 'f', FLOATING_POINT_PRECISION);
QString outboundSentPPSString = locale.toString(outboundSentPPS, 'f', FLOATING_POINT_PRECISION);
label = _labels[_outboundEditPackets];
statsValue.str("");
statsValue <<
"Queue Size: " << outboundPacketsDepth << " packets / " <<
"Queued IN: " << qPrintable(outboundQueuedPPSString) << " PPS / " <<
"Sent OUT: " << qPrintable(outboundSentPPSString) << " PPS";
label->setText(statsValue.str().c_str());
// Entity Edits update time
label = _labels[_entityUpdateTime];
auto averageEditDelta = entitiesTree->getAverageEditDeltas();

3
interface/src/ui/OctreeStatsDialog.h
View file

@ -70,10 +70,11 @@ private:
int _processedPacketsElements;
int _processedPacketsEntities;
int _processedPacketsTiming;
int _outboundEditPackets;
const int SAMPLES_PER_SECOND = 10;
SimpleMovingAverage _averageUpdatesPerSecond;
quint64 _lastWindowAt = 0;
quint64 _lastWindowAt = usecTimestampNow();
quint64 _lastKnownTrackedEdits = 0;
quint64 _lastRefresh = 0;

6
libraries/entities/src/EntityTree.cpp
View file

@ -653,8 +653,10 @@ int EntityTree::processEditPacketData(NLPacket& packet, const unsigned char* edi
}
} else {
static QString repeatedMessage =
LogHandler::getInstance().addRepeatedMessageRegex("^Add or Edit failed.*");
qCDebug(entities) << "Add or Edit failed." << packet.getType() << existingEntity.get();
LogHandler::getInstance().addRepeatedMessageRegex("^Edit failed.*");
qCDebug(entities) << "Edit failed. [" << packet.getType() <<"] " <<
"entity id:" << entityItemID <<
"existingEntity pointer:" << existingEntity.get();
}
}