From c3aab7337f5b7e2f9e8dace5bbea4af860c289c7 Mon Sep 17 00:00:00 2001 From: ZappoMan Date: Wed, 26 Mar 2014 11:36:35 -0700 Subject: [PATCH] added more performance stats tracking to octree server --- .../src/octree/OctreeSendThread.cpp | 15 + assignment-client/src/octree/OctreeServer.cpp | 409 ++++++++++++++---- assignment-client/src/octree/OctreeServer.h | 35 ++ 3 files changed, 374 insertions(+), 85 deletions(-) diff --git a/assignment-client/src/octree/OctreeSendThread.cpp b/assignment-client/src/octree/OctreeSendThread.cpp index a215d9b3c3..40c045a4c1 100644 --- a/assignment-client/src/octree/OctreeSendThread.cpp +++ b/assignment-client/src/octree/OctreeSendThread.cpp @@ -45,6 +45,7 @@ OctreeSendThread::~OctreeSendThread() { qDebug() << qPrintable(safeServerName) << "server [" << _myServer << "]: client disconnected " "- ending sending thread [" << this << "]"; OctreeServer::clientDisconnected(); + OctreeServer::stopTrackingThread(this); } void OctreeSendThread::setIsShuttingDown() { @@ -54,7 +55,14 @@ void OctreeSendThread::setIsShuttingDown() { bool OctreeSendThread::process() { + OctreeServer::didProcess(this); + + float lockWaitElapsedUsec = OctreeServer::SKIP_TIME; + quint64 lockWaitStart = usecTimestampNow(); QMutexLocker locker(&_processLock); + quint64 lockWaitEnd = usecTimestampNow(); + lockWaitElapsedUsec = (float)(lockWaitEnd - lockWaitStart); + OctreeServer::trackProcessWaitTime(lockWaitElapsedUsec); if (_isShuttingDown) { return false; // exit early if we're shutting down @@ -119,6 +127,8 @@ quint64 OctreeSendThread::_totalPackets = 0; int OctreeSendThread::handlePacketSend(const SharedNodePointer& node, OctreeQueryNode* nodeData, int& trueBytesSent, int& truePacketsSent) { + + OctreeServer::didHandlePacketSend(this); // if we're shutting down, then exit early if (nodeData->isShuttingDown()) { @@ -175,10 +185,12 @@ int OctreeSendThread::handlePacketSend(const SharedNodePointer& node, } // actually send it + OctreeServer::didCallWriteDatagram(this); NodeList::getInstance()->writeDatagram((char*) statsMessage, statsMessageLength, SharedNodePointer(node)); packetSent = true; } else { // not enough room in the packet, send two packets + OctreeServer::didCallWriteDatagram(this); NodeList::getInstance()->writeDatagram((char*) statsMessage, statsMessageLength, SharedNodePointer(node)); // since a stats message is only included on end of scene, don't consider any of these bytes "wasted", since @@ -197,6 +209,7 @@ int OctreeSendThread::handlePacketSend(const SharedNodePointer& node, truePacketsSent++; packetsSent++; + OctreeServer::didCallWriteDatagram(this); NodeList::getInstance()->writeDatagram((char*) nodeData->getPacket(), nodeData->getPacketLength(), SharedNodePointer(node)); @@ -217,6 +230,7 @@ int OctreeSendThread::handlePacketSend(const SharedNodePointer& node, // If there's actually a packet waiting, then send it. if (nodeData->isPacketWaiting() && !nodeData->isShuttingDown()) { // just send the voxel packet + OctreeServer::didCallWriteDatagram(this); NodeList::getInstance()->writeDatagram((char*) nodeData->getPacket(), nodeData->getPacketLength(), SharedNodePointer(node)); packetSent = true; @@ -246,6 +260,7 @@ int OctreeSendThread::handlePacketSend(const SharedNodePointer& node, /// Version of voxel distributor that sends the deepest LOD level at once int OctreeSendThread::packetDistributor(const SharedNodePointer& node, OctreeQueryNode* nodeData, bool viewFrustumChanged) { + OctreeServer::didPacketDistributor(this); // if shutting down, exit early if (nodeData->isShuttingDown()) { diff --git a/assignment-client/src/octree/OctreeServer.cpp b/assignment-client/src/octree/OctreeServer.cpp index 6f604c5fd5..6c17c80e5f 100644 --- a/assignment-client/src/octree/OctreeServer.cpp +++ b/assignment-client/src/octree/OctreeServer.cpp @@ -6,9 +6,10 @@ // Copyright (c) 2013 HighFidelity, Inc. All rights reserved. // -#include -#include -#include +#include +#include +#include +#include #include #include @@ -59,6 +60,15 @@ int OctreeServer::_noCompress = 0; SimpleMovingAverage OctreeServer::_averagePacketSendingTime(MOVING_AVERAGE_SAMPLE_COUNTS); int OctreeServer::_noSend = 0; +SimpleMovingAverage OctreeServer::_averageProcessWaitTime(MOVING_AVERAGE_SAMPLE_COUNTS); +SimpleMovingAverage OctreeServer::_averageProcessShortWaitTime(MOVING_AVERAGE_SAMPLE_COUNTS); +SimpleMovingAverage OctreeServer::_averageProcessLongWaitTime(MOVING_AVERAGE_SAMPLE_COUNTS); +SimpleMovingAverage OctreeServer::_averageProcessExtraLongWaitTime(MOVING_AVERAGE_SAMPLE_COUNTS); +int OctreeServer::_extraLongProcessWait = 0; +int OctreeServer::_longProcessWait = 0; +int OctreeServer::_shortProcessWait = 0; +int OctreeServer::_noProcessWait = 0; + void OctreeServer::resetSendingStats() { _averageLoopTime.reset(); @@ -95,6 +105,15 @@ void OctreeServer::resetSendingStats() { _averagePacketSendingTime.reset(); _noSend = 0; + + _averageProcessWaitTime.reset(); + _averageProcessShortWaitTime.reset(); + _averageProcessLongWaitTime.reset(); + _averageProcessExtraLongWaitTime.reset(); + _extraLongProcessWait = 0; + _longProcessWait = 0; + _shortProcessWait = 0; + _noProcessWait = 0; } void OctreeServer::trackEncodeTime(float time) { @@ -164,6 +183,24 @@ void OctreeServer::trackPacketSendingTime(float time) { } +void OctreeServer::trackProcessWaitTime(float time) { + const float MAX_SHORT_TIME = 10.0f; + const float MAX_LONG_TIME = 100.0f; + if (time == SKIP_TIME) { + _noProcessWait++; + time = 0.0f; + } else if (time <= MAX_SHORT_TIME) { + _shortProcessWait++; + _averageProcessShortWaitTime.updateAverage(time); + } else if (time <= MAX_LONG_TIME) { + _longProcessWait++; + _averageProcessLongWaitTime.updateAverage(time); + } else { + _extraLongProcessWait++; + _averageProcessExtraLongWaitTime.updateAverage(time); + } + _averageProcessWaitTime.updateAverage(time); +} void OctreeServer::attachQueryNodeToNode(Node* newNode) { if (!newNode->getLinkedData()) { @@ -289,41 +326,7 @@ bool OctreeServer::handleHTTPRequest(HTTPConnection* connection, const QUrl& url statsString += "\r\n"; - quint64 now = usecTimestampNow(); - const int USECS_PER_MSEC = 1000; - quint64 msecsElapsed = (now - _startedUSecs) / USECS_PER_MSEC; - const int MSECS_PER_SEC = 1000; - const int SECS_PER_MIN = 60; - const int MIN_PER_HOUR = 60; - const int MSECS_PER_MIN = MSECS_PER_SEC * SECS_PER_MIN; - - float seconds = (msecsElapsed % MSECS_PER_MIN)/(float)MSECS_PER_SEC; - int minutes = (msecsElapsed/(MSECS_PER_MIN)) % MIN_PER_HOUR; - int hours = (msecsElapsed/(MSECS_PER_MIN * MIN_PER_HOUR)); - - statsString += "Uptime: "; - - if (hours > 0) { - statsString += QString("%1 hour").arg(hours); - if (hours > 1) { - statsString += QString("s"); - } - } - if (minutes > 0) { - if (hours > 0) { - statsString += QString(" "); - } - statsString += QString("%1 minute").arg(minutes); - if (minutes > 1) { - statsString += QString("s"); - } - } - if (seconds > 0) { - if (hours > 0 || minutes > 0) { - statsString += QString(" "); - } - statsString += QString().sprintf("%.3f seconds", seconds); - } + statsString += "Uptime: " + getUptime(); statsString += "\r\n\r\n"; // display voxel file load time @@ -336,33 +339,8 @@ bool OctreeServer::handleHTTPRequest(HTTPConnection* connection, const QUrl& url statsString += "\r\n"; - quint64 msecsElapsed = getLoadElapsedTime() / USECS_PER_MSEC;; - float seconds = (msecsElapsed % MSECS_PER_MIN)/(float)MSECS_PER_SEC; - int minutes = (msecsElapsed/(MSECS_PER_MIN)) % MIN_PER_HOUR; - int hours = (msecsElapsed/(MSECS_PER_MIN * MIN_PER_HOUR)); - statsString += QString("%1 File Load Took ").arg(getMyServerName()); - if (hours > 0) { - statsString += QString("%1 hour").arg(hours); - if (hours > 1) { - statsString += QString("s"); - } - } - if (minutes > 0) { - if (hours > 0) { - statsString += QString(" "); - } - statsString += QString("%1 minute").arg(minutes); - if (minutes > 1) { - statsString += QString("s"); - } - } - if (seconds >= 0) { - if (hours > 0 || minutes > 0) { - statsString += QString(" "); - } - statsString += QString().sprintf("%.3f seconds", seconds); - } + statsString += getFileLoadTime(); statsString += "\r\n"; } else { @@ -371,27 +349,31 @@ bool OctreeServer::handleHTTPRequest(HTTPConnection* connection, const QUrl& url statsString += "\r\n\r\n"; statsString += "Configuration:\r\n"; + statsString += getConfiguration() + "\r\n"; //one to end the config line + statsString += "\r\n"; + + const int COLUMN_WIDTH = 19; + QLocale locale(QLocale::English); + const float AS_PERCENT = 100.0; + + statsString += QString(" Configured Max PPS/Client: %1 pps/client\r\n") + .arg(locale.toString((uint)getPacketsPerClientPerSecond()).rightJustified(COLUMN_WIDTH, ' ')); + statsString += QString(" Configured Max PPS/Server: %1 pps/server\r\n\r\n") + .arg(locale.toString((uint)getPacketsTotalPerSecond()).rightJustified(COLUMN_WIDTH, ' ')); - for (int i = 1; i < _argc; i++) { - statsString += _argv[i]; - } - statsString += "\r\n"; //one to end the config line - statsString += "\r\n\r\n"; // two more for spacing // display scene stats unsigned long nodeCount = OctreeElement::getNodeCount(); unsigned long internalNodeCount = OctreeElement::getInternalNodeCount(); unsigned long leafNodeCount = OctreeElement::getLeafNodeCount(); - QLocale locale(QLocale::English); - const float AS_PERCENT = 100.0; - statsString += "Current Nodes in scene:\r\n"; - statsString += QString(" Total Nodes: %1 nodes\r\n").arg(locale.toString((uint)nodeCount).rightJustified(16, ' ')); - statsString += QString().sprintf(" Internal Nodes: %s nodes (%5.2f%%)\r\n", + statsString += "Current Elements in scene:\r\n"; + statsString += QString(" Total Elements: %1 nodes\r\n").arg(locale.toString((uint)nodeCount).rightJustified(16, ' ')); + statsString += QString().sprintf(" Internal Elements: %s nodes (%5.2f%%)\r\n", locale.toString((uint)internalNodeCount).rightJustified(16, ' ').toLocal8Bit().constData(), ((float)internalNodeCount / (float)nodeCount) * AS_PERCENT); - statsString += QString().sprintf(" Leaf Nodes: %s nodes (%5.2f%%)\r\n", + statsString += QString().sprintf(" Leaf Elements: %s nodes (%5.2f%%)\r\n", locale.toString((uint)leafNodeCount).rightJustified(16, ' ').toLocal8Bit().constData(), ((float)leafNodeCount / (float)nodeCount) * AS_PERCENT); statsString += "\r\n"; @@ -408,20 +390,65 @@ bool OctreeServer::handleHTTPRequest(HTTPConnection* connection, const QUrl& url quint64 totalBytesOfBitMasks = OctreePacketData::getTotalBytesOfBitMasks(); quint64 totalBytesOfColor = OctreePacketData::getTotalBytesOfColor(); - const int COLUMN_WIDTH = 19; - statsString += QString(" Configured Max PPS/Client: %1 pps/client\r\n") - .arg(locale.toString((uint)getPacketsPerClientPerSecond()).rightJustified(COLUMN_WIDTH, ' ')); - statsString += QString(" Configured Max PPS/Server: %1 pps/server\r\n\r\n") - .arg(locale.toString((uint)getPacketsTotalPerSecond()).rightJustified(COLUMN_WIDTH, ' ')); - statsString += QString(" Total Clients Connected: %1 clients\r\n\r\n") + statsString += QString(" Total Clients Connected: %1 clients\r\n") .arg(locale.toString((uint)getCurrentClientCount()).rightJustified(COLUMN_WIDTH, ' ')); + quint64 oneSecondAgo = usecTimestampNow() - USECS_PER_SECOND; + + statsString += QString(" process() last second: %1 clients\r\n") + .arg(locale.toString((uint)howManyThreadsDidProcess(oneSecondAgo)).rightJustified(COLUMN_WIDTH, ' ')); + statsString += QString(" packetDistributor() last second: %1 clients\r\n") + .arg(locale.toString((uint)howManyThreadsDidPacketDistributor(oneSecondAgo)).rightJustified(COLUMN_WIDTH, ' ')); + statsString += QString(" handlePacketSend() last second: %1 clients\r\n") + .arg(locale.toString((uint)howManyThreadsDidHandlePacketSend(oneSecondAgo)).rightJustified(COLUMN_WIDTH, ' ')); + statsString += QString(" writeDatagram() last second: %1 clients\r\n\r\n") + .arg(locale.toString((uint)howManyThreadsDidCallWriteDatagram(oneSecondAgo)).rightJustified(COLUMN_WIDTH, ' ')); + float averageLoopTime = getAverageLoopTime(); - statsString += QString().sprintf(" Average packetLoop() time: %7.2f msecs\r\n", averageLoopTime); + statsString += QString().sprintf(" Average packetLoop() time: %7.2f msecs" + " samples: %12d \r\n", + averageLoopTime, _averageLoopTime.getSampleCount()); float averageInsideTime = getAverageInsideTime(); - statsString += QString().sprintf(" Average 'inside' time: %9.2f usecs\r\n\r\n", averageInsideTime); + statsString += QString().sprintf(" Average 'inside' time: %9.2f usecs" + " samples: %12d \r\n\r\n", + averageInsideTime, _averageInsideTime.getSampleCount()); + + // Process Wait + { + int allWaitTimes = _extraLongProcessWait +_longProcessWait + _shortProcessWait + _noProcessWait; + + float averageProcessWaitTime = getAverageProcessWaitTime(); + statsString += QString().sprintf(" Average process lock wait time:" + " %9.2f usecs samples: %12d \r\n", + averageProcessWaitTime, allWaitTimes); + + float zeroVsTotal = (allWaitTimes > 0) ? ((float)_noProcessWait / (float)allWaitTimes) : 0.0f; + statsString += QString().sprintf(" No Lock Wait:" + " (%6.2f%%) samples: %12d \r\n", + zeroVsTotal * AS_PERCENT, _noProcessWait); + + float shortVsTotal = (allWaitTimes > 0) ? ((float)_shortProcessWait / (float)allWaitTimes) : 0.0f; + statsString += QString().sprintf(" Avg process lock short wait time:" + " %9.2f usecs (%6.2f%%) samples: %12d \r\n", + _averageProcessShortWaitTime.getAverage(), + shortVsTotal * AS_PERCENT, _shortProcessWait); + + float longVsTotal = (allWaitTimes > 0) ? ((float)_longProcessWait / (float)allWaitTimes) : 0.0f; + statsString += QString().sprintf(" Avg process lock long wait time:" + " %9.2f usecs (%6.2f%%) samples: %12d \r\n", + _averageProcessLongWaitTime.getAverage(), + longVsTotal * AS_PERCENT, _longProcessWait); + + float extraLongVsTotal = (allWaitTimes > 0) ? ((float)_extraLongProcessWait / (float)allWaitTimes) : 0.0f; + statsString += QString().sprintf("Avg process lock extralong wait time:" + " %9.2f usecs (%6.2f%%) samples: %12d \r\n\r\n", + _averageProcessExtraLongWaitTime.getAverage(), + extraLongVsTotal * AS_PERCENT, _extraLongProcessWait); + } + + // Tree Wait int allWaitTimes = _extraLongTreeWait +_longTreeWait + _shortTreeWait + _noTreeWait; float averageTreeWaitTime = getAverageTreeWaitTime(); @@ -452,6 +479,7 @@ bool OctreeServer::handleHTTPRequest(HTTPConnection* connection, const QUrl& url _averageTreeExtraLongWaitTime.getAverage(), extraLongVsTotal * AS_PERCENT, _extraLongTreeWait); + // encode float averageEncodeTime = getAverageEncodeTime(); statsString += QString().sprintf(" Average encode time: %9.2f usecs\r\n", averageEncodeTime); @@ -839,8 +867,8 @@ void OctreeServer::run() { const char* STATUS_PORT = "--statusPort"; const char* statusPort = getCmdOption(_argc, _argv, STATUS_PORT); if (statusPort) { - int statusPortNumber = atoi(statusPort); - initHTTPManager(statusPortNumber); + _statusPortNumber = atoi(statusPort); + initHTTPManager(_statusPortNumber); } @@ -1017,3 +1045,214 @@ void OctreeServer::aboutToFinish() { qDebug() << qPrintable(_safeServerName) << "server ENDING about to finish..."; } +QString OctreeServer::getUptime() { + QString formattedUptime; + quint64 now = usecTimestampNow(); + const int USECS_PER_MSEC = 1000; + quint64 msecsElapsed = (now - _startedUSecs) / USECS_PER_MSEC; + const int MSECS_PER_SEC = 1000; + const int SECS_PER_MIN = 60; + const int MIN_PER_HOUR = 60; + const int MSECS_PER_MIN = MSECS_PER_SEC * SECS_PER_MIN; + + float seconds = (msecsElapsed % MSECS_PER_MIN)/(float)MSECS_PER_SEC; + int minutes = (msecsElapsed/(MSECS_PER_MIN)) % MIN_PER_HOUR; + int hours = (msecsElapsed/(MSECS_PER_MIN * MIN_PER_HOUR)); + + if (hours > 0) { + formattedUptime += QString("%1 hour").arg(hours); + if (hours > 1) { + formattedUptime += QString("s"); + } + } + if (minutes > 0) { + if (hours > 0) { + formattedUptime += QString(" "); + } + formattedUptime += QString("%1 minute").arg(minutes); + if (minutes > 1) { + formattedUptime += QString("s"); + } + } + if (seconds > 0) { + if (hours > 0 || minutes > 0) { + formattedUptime += QString(" "); + } + formattedUptime += QString().sprintf("%.3f seconds", seconds); + } + return formattedUptime; +} + +QString OctreeServer::getFileLoadTime() { + QString result; + if (isInitialLoadComplete()) { + + const int USECS_PER_MSEC = 1000; + const int MSECS_PER_SEC = 1000; + const int SECS_PER_MIN = 60; + const int MIN_PER_HOUR = 60; + const int MSECS_PER_MIN = MSECS_PER_SEC * SECS_PER_MIN; + + quint64 msecsElapsed = getLoadElapsedTime() / USECS_PER_MSEC;; + float seconds = (msecsElapsed % MSECS_PER_MIN)/(float)MSECS_PER_SEC; + int minutes = (msecsElapsed/(MSECS_PER_MIN)) % MIN_PER_HOUR; + int hours = (msecsElapsed/(MSECS_PER_MIN * MIN_PER_HOUR)); + + if (hours > 0) { + result += QString("%1 hour").arg(hours); + if (hours > 1) { + result += QString("s"); + } + } + if (minutes > 0) { + if (hours > 0) { + result += QString(" "); + } + result += QString("%1 minute").arg(minutes); + if (minutes > 1) { + result += QString("s"); + } + } + if (seconds >= 0) { + if (hours > 0 || minutes > 0) { + result += QString(" "); + } + result += QString().sprintf("%.3f seconds", seconds); + } + } else { + result = "Not yet loaded..."; + } + return result; +} + +QString OctreeServer::getConfiguration() { + QString result; + for (int i = 1; i < _argc; i++) { + result += _argv[i] + QString(" "); + } + return result; +} + +void OctreeServer::sendStatsPacket() { + + // TODO: we have too many stats to fit in a single MTU... so for now, we break it into multiple JSON objects and + // send them separately. What we really should do is change the NodeList::sendStatsToDomainServer() to handle the + // the following features: + // 1) remember last state sent + // 2) only send new data + // 3) automatically break up into multiple packets + static QJsonObject statsObject1; + + QString baseName = getMyServerName() + QString("Server"); + + statsObject1[baseName + QString(".0.1.configuration")] = getConfiguration(); + + QString detailedStats= QString("http://") + QHostAddress(getHostOrderLocalAddress()).toString() + + QString(":%1").arg(_statusPortNumber); + + detailedStats = ""+detailedStats+""; + statsObject1[baseName + QString(".0.2.detailed_stats_url")] = detailedStats; + + statsObject1[baseName + QString(".0.3.uptime")] = getUptime(); + statsObject1[baseName + QString(".0.4.persistFileLoadTime")] = getFileLoadTime(); + statsObject1[baseName + QString(".0.5.clients")] = getCurrentClientCount(); + + statsObject1[baseName + QString(".1.1.octree.elementCount")] = (double)OctreeElement::getNodeCount(); + statsObject1[baseName + QString(".1.2.octree.internalElementCount")] = (double)OctreeElement::getInternalNodeCount(); + statsObject1[baseName + QString(".1.3.octree.leafElementCount")] = (double)OctreeElement::getLeafNodeCount(); + + ThreadedAssignment::addPacketStatsAndSendStatsPacket(statsObject1); + + static QJsonObject statsObject2; + + statsObject2[baseName + QString(".2.outbound.data.totalPackets")] = (double)OctreeSendThread::_totalPackets; + statsObject2[baseName + QString(".2.outbound.data.totalBytes")] = (double)OctreeSendThread::_totalBytes; + statsObject2[baseName + QString(".2.outbound.data.totalBytesWasted")] = (double)OctreeSendThread::_totalWastedBytes; + statsObject2[baseName + QString(".2.outbound.data.totalBytesOctalCodes")] = (double)OctreePacketData::getTotalBytesOfOctalCodes(); + statsObject2[baseName + QString(".2.outbound.data.totalBytesBitMasks")] = (double)OctreePacketData::getTotalBytesOfBitMasks(); + statsObject2[baseName + QString(".2.outbound.data.totalBytesBitMasks")] = (double)OctreePacketData::getTotalBytesOfColor(); + + statsObject2[baseName + QString(".2.outbound.timing.1.avgLoopTime")] = getAverageLoopTime(); + statsObject2[baseName + QString(".2.outbound.timing.2.avgInsideTime")] = getAverageInsideTime(); + statsObject2[baseName + QString(".2.outbound.timing.3.avgTreeLockTime")] = getAverageTreeWaitTime(); + statsObject2[baseName + QString(".2.outbound.timing.4.avgEncodeTime")] = getAverageEncodeTime(); + statsObject2[baseName + QString(".2.outbound.timing.5.avgCompressAndWriteTime")] = getAverageCompressAndWriteTime(); + statsObject2[baseName + QString(".2.outbound.timing.5.avgSendTime")] = getAveragePacketSendingTime(); + statsObject2[baseName + QString(".2.outbound.timing.5.nodeWaitTime")] = getAverageNodeWaitTime(); + + NodeList::getInstance()->sendStatsToDomainServer(statsObject2); + + static QJsonObject statsObject3; + + statsObject3[baseName + QString(".3.inbound.data.1.totalPackets")] = (double)_octreeInboundPacketProcessor->getTotalPacketsProcessed(); + statsObject3[baseName + QString(".3.inbound.data.2.totalElements")] = (double)_octreeInboundPacketProcessor->getTotalElementsProcessed(); + statsObject3[baseName + QString(".3.inbound.timing.1.avgTransitTimePerPacket")] = (double)_octreeInboundPacketProcessor->getAverageTransitTimePerPacket(); + statsObject3[baseName + QString(".3.inbound.timing.2.avgProcessTimePerPacket")] = (double)_octreeInboundPacketProcessor->getAverageProcessTimePerPacket(); + statsObject3[baseName + QString(".3.inbound.timing.3.avgLockWaitTimePerPacket")] = (double)_octreeInboundPacketProcessor->getAverageLockWaitTimePerPacket(); + statsObject3[baseName + QString(".3.inbound.timing.4.avgProcessTimePerElement")] = (double)_octreeInboundPacketProcessor->getAverageProcessTimePerElement(); + statsObject3[baseName + QString(".3.inbound.timing.5.avgLockWaitTimePerElement")] = (double)_octreeInboundPacketProcessor->getAverageLockWaitTimePerElement(); + + NodeList::getInstance()->sendStatsToDomainServer(statsObject3); +} + +QMap OctreeServer::_threadsDidProcess; +QMap OctreeServer::_threadsDidPacketDistributor; +QMap OctreeServer::_threadsDidHandlePacketSend; +QMap OctreeServer::_threadsDidCallWriteDatagram; + + +void OctreeServer::didProcess(OctreeSendThread* thread) { + _threadsDidProcess[thread] = usecTimestampNow(); +} + +void OctreeServer::didPacketDistributor(OctreeSendThread* thread) { + _threadsDidPacketDistributor[thread] = usecTimestampNow(); +} + +void OctreeServer::didHandlePacketSend(OctreeSendThread* thread) { + _threadsDidHandlePacketSend[thread] = usecTimestampNow(); +} + +void OctreeServer::didCallWriteDatagram(OctreeSendThread* thread) { + _threadsDidCallWriteDatagram[thread] = usecTimestampNow(); +} + + +void OctreeServer::stopTrackingThread(OctreeSendThread* thread) { + _threadsDidProcess.remove(thread); + _threadsDidPacketDistributor.remove(thread); + _threadsDidHandlePacketSend.remove(thread); +} + +int howManyThreadsDidSomething(QMap& something, quint64 since) { + if (since == 0) { + return something.size(); + } + int count = 0; + QMap::const_iterator i = something.constBegin(); + while (i != something.constEnd()) { + if (i.value() > since) { + count++; + } + ++i; + } + return count; +} + + +int OctreeServer::howManyThreadsDidProcess(quint64 since) { + return howManyThreadsDidSomething(_threadsDidProcess, since); +} + +int OctreeServer::howManyThreadsDidPacketDistributor(quint64 since) { + return howManyThreadsDidSomething(_threadsDidPacketDistributor, since); +} + +int OctreeServer::howManyThreadsDidHandlePacketSend(quint64 since) { + return howManyThreadsDidSomething(_threadsDidHandlePacketSend, since); +} + +int OctreeServer::howManyThreadsDidCallWriteDatagram(quint64 since) { + return howManyThreadsDidSomething(_threadsDidCallWriteDatagram, since); +} + diff --git a/assignment-client/src/octree/OctreeServer.h b/assignment-client/src/octree/OctreeServer.h index 2664499b6a..1e90239852 100644 --- a/assignment-client/src/octree/OctreeServer.h +++ b/assignment-client/src/octree/OctreeServer.h @@ -97,6 +97,21 @@ public: static void trackPacketSendingTime(float time); static float getAveragePacketSendingTime() { return _averagePacketSendingTime.getAverage(); } + static void trackProcessWaitTime(float time); + static float getAverageProcessWaitTime() { return _averageProcessWaitTime.getAverage(); } + + // these methods allow us to track which threads got to various states + static void didProcess(OctreeSendThread* thread); + static void didPacketDistributor(OctreeSendThread* thread); + static void didHandlePacketSend(OctreeSendThread* thread); + static void didCallWriteDatagram(OctreeSendThread* thread); + static void stopTrackingThread(OctreeSendThread* thread); + + static int howManyThreadsDidProcess(quint64 since = 0); + static int howManyThreadsDidPacketDistributor(quint64 since = 0); + static int howManyThreadsDidHandlePacketSend(quint64 since = 0); + static int howManyThreadsDidCallWriteDatagram(quint64 since = 0); + bool handleHTTPRequest(HTTPConnection* connection, const QUrl& url); virtual void aboutToFinish(); @@ -107,17 +122,22 @@ public slots: void readPendingDatagrams(); void nodeAdded(SharedNodePointer node); void nodeKilled(SharedNodePointer node); + void sendStatsPacket(); protected: void parsePayload(); void initHTTPManager(int port); void resetSendingStats(); + QString getUptime(); + QString getFileLoadTime(); + QString getConfiguration(); int _argc; const char** _argv; char** _parsedArgV; HTTPManager* _httpManager; + int _statusPortNumber; char _persistFilename[MAX_FILENAME_LENGTH]; int _packetsPerClientPerInterval; @@ -151,6 +171,7 @@ protected: static int _noEncode; static SimpleMovingAverage _averageInsideTime; + static SimpleMovingAverage _averageTreeWaitTime; static SimpleMovingAverage _averageTreeShortWaitTime; static SimpleMovingAverage _averageTreeLongWaitTime; @@ -174,6 +195,20 @@ protected: static SimpleMovingAverage _averagePacketSendingTime; static int _noSend; + static SimpleMovingAverage _averageProcessWaitTime; + static SimpleMovingAverage _averageProcessShortWaitTime; + static SimpleMovingAverage _averageProcessLongWaitTime; + static SimpleMovingAverage _averageProcessExtraLongWaitTime; + static int _extraLongProcessWait; + static int _longProcessWait; + static int _shortProcessWait; + static int _noProcessWait; + + static QMap _threadsDidProcess; + static QMap _threadsDidPacketDistributor; + static QMap _threadsDidHandlePacketSend; + static QMap _threadsDidCallWriteDatagram; + }; #endif // __octree_server__OctreeServer__