From 8dbe4dfddef3fe714a2844574f756a595a271df3 Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Mon, 24 Mar 2014 15:06:53 -0700 Subject: [PATCH 01/10] collect packet rate stats in NodeList --- assignment-client/src/audio/AudioMixer.cpp | 10 ++++++++- libraries/shared/src/NodeList.cpp | 24 ++++++++++++++++++++-- libraries/shared/src/NodeList.h | 12 ++++++++--- 3 files changed, 40 insertions(+), 6 deletions(-) diff --git a/assignment-client/src/audio/AudioMixer.cpp b/assignment-client/src/audio/AudioMixer.cpp index 9e7cf53e2f..c4e09bfe47 100644 --- a/assignment-client/src/audio/AudioMixer.cpp +++ b/assignment-client/src/audio/AudioMixer.cpp @@ -369,12 +369,20 @@ void AudioMixer::sendStatsPacket() { statsObject["average_mixes_per_listener"] = 0.0; } + NodeList* nodeList = NodeList::getInstance(); + + float packetsPerSecond, bytesPerSecond; + nodeList->getPacketStats(packetsPerSecond, bytesPerSecond); + nodeList->resetPacketStats(); + + statsObject["packets_per_second"] = packetsPerSecond; + statsObject["bytes_per_second"] = bytesPerSecond; _sumListeners = 0; _sumMixes = 0; _numStatFrames = 0; - NodeList::getInstance()->sendStatsToDomainServer(statsObject); + nodeList->sendStatsToDomainServer(statsObject); } void AudioMixer::run() { diff --git a/libraries/shared/src/NodeList.cpp b/libraries/shared/src/NodeList.cpp index fe1466d5d1..d4babd4557 100644 --- a/libraries/shared/src/NodeList.cpp +++ b/libraries/shared/src/NodeList.cpp @@ -69,7 +69,10 @@ NodeList::NodeList(char newOwnerType, unsigned short int newSocketListenPort) : _assignmentServerSocket(), _publicSockAddr(), _hasCompletedInitialSTUNFailure(false), - _stunRequestsSinceSuccess(0) + _stunRequestsSinceSuccess(0), + _numCollectedPackets(0), + _numCollectedBytes(0), + _packetStatTimer() { _nodeSocket.bind(QHostAddress::AnyIPv4, newSocketListenPort); qDebug() << "NodeList socket is listening on" << _nodeSocket.localPort(); @@ -79,6 +82,8 @@ NodeList::NodeList(char newOwnerType, unsigned short int newSocketListenPort) : // clear our NodeList when logout is requested connect(&AccountManager::getInstance(), &AccountManager::logoutComplete , this, &NodeList::reset); + + _packetStatTimer.start(); } bool NodeList::packetVersionAndHashMatch(const QByteArray& packet) { @@ -161,7 +166,11 @@ qint64 NodeList::writeDatagram(const QByteArray& datagram, const HifiSockAddr& d // setup the MD5 hash for source verification in the header replaceHashInPacketGivenConnectionUUID(datagramCopy, connectionSecret); - + + // stat collection for packets + ++_numCollectedPackets; + _numCollectedBytes += datagram.size(); + return _nodeSocket.writeDatagram(datagramCopy, destinationSockAddr.getAddress(), destinationSockAddr.getPort()); } @@ -854,6 +863,17 @@ SharedNodePointer NodeList::soloNodeOfType(char nodeType) { return SharedNodePointer(); } +void NodeList::getPacketStats(float& packetsPerSecond, float& bytesPerSecond) { + packetsPerSecond = _numCollectedPackets / (float) (_packetStatTimer.elapsed() / 1000.0f); + bytesPerSecond = _numCollectedBytes / (float) (_packetStatTimer.elapsed() / 1000.0f); +} + +void NodeList::resetPacketStats() { + _numCollectedPackets = 0; + _numCollectedBytes = 0; + _packetStatTimer.restart(); +} + void NodeList::removeSilentNodes() { _nodeHashMutex.lock(); diff --git a/libraries/shared/src/NodeList.h b/libraries/shared/src/NodeList.h index 379db70412..d892223f75 100644 --- a/libraries/shared/src/NodeList.h +++ b/libraries/shared/src/NodeList.h @@ -21,6 +21,7 @@ #include // not on windows, not needed for mac or windows #endif +#include #include #include #include @@ -120,6 +121,9 @@ public: unsigned broadcastToNodes(const QByteArray& packet, const NodeSet& destinationNodeTypes); SharedNodePointer soloNodeOfType(char nodeType); + void getPacketStats(float &packetsPerSecond, float &bytesPerSecond); + void resetPacketStats(); + void loadData(QSettings* settings); void saveData(QSettings* settings); public slots: @@ -155,6 +159,8 @@ private: void processDomainServerAuthRequest(const QByteArray& packet); void requestAuthForDomainServer(); + void activateSocketFromNodeCommunication(const QByteArray& packet, const SharedNodePointer& sendingNode); + void timePingReply(const QByteArray& packet, const SharedNodePointer& sendingNode); NodeHash _nodeHash; QMutex _nodeHashMutex; @@ -168,9 +174,9 @@ private: HifiSockAddr _publicSockAddr; bool _hasCompletedInitialSTUNFailure; unsigned int _stunRequestsSinceSuccess; - - void activateSocketFromNodeCommunication(const QByteArray& packet, const SharedNodePointer& sendingNode); - void timePingReply(const QByteArray& packet, const SharedNodePointer& sendingNode); + int _numCollectedPackets; + int _numCollectedBytes; + QElapsedTimer _packetStatTimer; }; #endif /* defined(__hifi__NodeList__) */ From 638e9eae48cf5ce0b1690f6acfaee2d84c732550 Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Mon, 24 Mar 2014 15:38:01 -0700 Subject: [PATCH 02/10] add some basic stat collection to avatar-mixer --- assignment-client/src/audio/AudioMixer.cpp | 2 +- assignment-client/src/avatars/AvatarMixer.cpp | 34 +++++++++++++++++-- assignment-client/src/avatars/AvatarMixer.h | 8 +++++ 3 files changed, 41 insertions(+), 3 deletions(-) diff --git a/assignment-client/src/audio/AudioMixer.cpp b/assignment-client/src/audio/AudioMixer.cpp index c4e09bfe47..608362e0d4 100644 --- a/assignment-client/src/audio/AudioMixer.cpp +++ b/assignment-client/src/audio/AudioMixer.cpp @@ -393,7 +393,7 @@ void AudioMixer::run() { // send a stats packet every 1 second QTimer* statsTimer = new QTimer(this); - connect(statsTimer, SIGNAL(timeout()), this, SLOT(sendStatsPacket())); + connect(statsTimer, &QTimer::timeout, this, &AudioMixer::sendStatsPacket); statsTimer->start(1000); nodeList->addNodeTypeToInterestSet(NodeType::Agent); diff --git a/assignment-client/src/avatars/AvatarMixer.cpp b/assignment-client/src/avatars/AvatarMixer.cpp index 47f7084f64..d243894ea1 100644 --- a/assignment-client/src/avatars/AvatarMixer.cpp +++ b/assignment-client/src/avatars/AvatarMixer.cpp @@ -12,6 +12,7 @@ #include #include +#include #include #include @@ -29,7 +30,9 @@ const QString AVATAR_MIXER_LOGGING_NAME = "avatar-mixer"; const unsigned int AVATAR_DATA_SEND_INTERVAL_USECS = (1 / 60.0) * 1000 * 1000; AvatarMixer::AvatarMixer(const QByteArray& packet) : - ThreadedAssignment(packet) + ThreadedAssignment(packet), + _sumListeners(0), + _numStatFrames(0) { // make sure we hear about node kills so we can tell the other nodes connect(NodeList::getInstance(), &NodeList::nodeKilled, this, &AvatarMixer::nodeKilled); @@ -48,7 +51,7 @@ void attachAvatarDataToNode(Node* newNode) { // 3) if we need to rate limit the amount of data we send, we can use a distance weighted "semi-random" function to // determine which avatars are included in the packet stream // 4) we should optimize the avatar data format to be more compact (100 bytes is pretty wasteful). -void broadcastAvatarData() { +void AvatarMixer::broadcastAvatarData() { static QByteArray mixedAvatarByteArray; int numPacketHeaderBytes = populatePacketHeader(mixedAvatarByteArray, PacketTypeBulkAvatarData); @@ -57,6 +60,7 @@ void broadcastAvatarData() { foreach (const SharedNodePointer& node, nodeList->getNodeHash()) { if (node->getLinkedData() && node->getType() == NodeType::Agent && node->getActiveSocket()) { + ++_sumListeners; // reset packet pointers for this node mixedAvatarByteArray.resize(numPacketHeaderBytes); @@ -241,6 +245,25 @@ void AvatarMixer::readPendingDatagrams() { } } +void AvatarMixer::sendStatsPacket() { + QJsonObject statsObject; + statsObject["average_listeners_last_second"] = _sumListeners / (float) _numStatFrames; + + NodeList* nodeList = NodeList::getInstance(); + + float packetsPerSecond, bytesPerSecond; + nodeList->getPacketStats(packetsPerSecond, bytesPerSecond); + nodeList->resetPacketStats(); + + statsObject["packets_per_second"] = packetsPerSecond; + statsObject["bytes_per_second"] = bytesPerSecond; + + nodeList->sendStatsToDomainServer(statsObject); + + _sumListeners = 0; + _numStatFrames = 0; +} + const qint64 AVATAR_IDENTITY_KEYFRAME_MSECS = 5000; const qint64 AVATAR_BILLBOARD_KEYFRAME_MSECS = 5000; @@ -250,6 +273,11 @@ void AvatarMixer::run() { NodeList* nodeList = NodeList::getInstance(); nodeList->addNodeTypeToInterestSet(NodeType::Agent); + // send a stats packet every 1 second + QTimer* statsTimer = new QTimer(this); + connect(statsTimer, &QTimer::timeout, this, &AvatarMixer::sendStatsPacket); + statsTimer->start(1000); + nodeList->linkedDataCreateCallback = attachAvatarDataToNode; int nextFrame = 0; @@ -265,6 +293,8 @@ void AvatarMixer::run() { while (!_isFinished) { + ++_numStatFrames; + QCoreApplication::processEvents(); if (_isFinished) { diff --git a/assignment-client/src/avatars/AvatarMixer.h b/assignment-client/src/avatars/AvatarMixer.h index acc5a178aa..8e9364ddf9 100644 --- a/assignment-client/src/avatars/AvatarMixer.h +++ b/assignment-client/src/avatars/AvatarMixer.h @@ -24,6 +24,14 @@ public slots: void nodeKilled(SharedNodePointer killedNode); void readPendingDatagrams(); + + void sendStatsPacket(); + +private: + void broadcastAvatarData(); + + int _sumListeners; + int _numStatFrames; }; #endif /* defined(__hifi__AvatarMixer__) */ From e7f9acd945a45f8e98996087b514cb4f69a125c2 Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Mon, 24 Mar 2014 15:42:57 -0700 Subject: [PATCH 03/10] add trailing sleep and performance throttling logic to AvatarMixer --- assignment-client/src/audio/AudioMixer.cpp | 22 +++--- assignment-client/src/audio/AudioMixer.h | 2 +- assignment-client/src/avatars/AvatarMixer.cpp | 70 +++++++++++++++++-- assignment-client/src/avatars/AvatarMixer.h | 3 + 4 files changed, 81 insertions(+), 16 deletions(-) diff --git a/assignment-client/src/audio/AudioMixer.cpp b/assignment-client/src/audio/AudioMixer.cpp index 608362e0d4..f7092cd4ae 100644 --- a/assignment-client/src/audio/AudioMixer.cpp +++ b/assignment-client/src/audio/AudioMixer.cpp @@ -68,7 +68,7 @@ AudioMixer::AudioMixer(const QByteArray& packet) : ThreadedAssignment(packet), _trailingSleepRatio(1.0f), _minAudibilityThreshold(LOUDNESS_TO_DISTANCE_RATIO / 2.0f), - _performanceThrottling(0.0f), + _performanceThrottlingRatio(0.0f), _numStatFrames(0), _sumListeners(0), _sumMixes(0) @@ -359,7 +359,7 @@ void AudioMixer::readPendingDatagrams() { void AudioMixer::sendStatsPacket() { static QJsonObject statsObject; statsObject["trailing_sleep_percentage"] = _trailingSleepRatio * 100.0f; - statsObject["performance_throttling"] = _performanceThrottling; + statsObject["performance_throttling_ratio"] = _performanceThrottlingRatio; statsObject["average_listeners_per_frame"] = _sumListeners / (float) _numStatFrames; @@ -436,7 +436,7 @@ void AudioMixer::run() { _trailingSleepRatio = (PREVIOUS_FRAMES_RATIO * _trailingSleepRatio) + (usecToSleep * CURRENT_FRAME_RATIO / (float) BUFFER_SEND_INTERVAL_USECS); - float lastCutoffRatio = _performanceThrottling; + float lastCutoffRatio = _performanceThrottlingRatio; bool hasRatioChanged = false; if (framesSinceCutoffEvent >= TRAILING_AVERAGE_FRAMES) { @@ -446,27 +446,27 @@ void AudioMixer::run() { if (_trailingSleepRatio <= STRUGGLE_TRIGGER_SLEEP_PERCENTAGE_THRESHOLD) { // we're struggling - change our min required loudness to reduce some load - _performanceThrottling = _performanceThrottling + (0.5f * (1.0f - _performanceThrottling)); + _performanceThrottlingRatio = _performanceThrottlingRatio + (0.5f * (1.0f - _performanceThrottlingRatio)); qDebug() << "Mixer is struggling, sleeping" << _trailingSleepRatio * 100 << "% of frame time. Old cutoff was" - << lastCutoffRatio << "and is now" << _performanceThrottling; + << lastCutoffRatio << "and is now" << _performanceThrottlingRatio; hasRatioChanged = true; - } else if (_trailingSleepRatio >= BACK_OFF_TRIGGER_SLEEP_PERCENTAGE_THRESHOLD && _performanceThrottling != 0) { + } else if (_trailingSleepRatio >= BACK_OFF_TRIGGER_SLEEP_PERCENTAGE_THRESHOLD && _performanceThrottlingRatio != 0) { // we've recovered and can back off the required loudness - _performanceThrottling = _performanceThrottling - RATIO_BACK_OFF; + _performanceThrottlingRatio = _performanceThrottlingRatio - RATIO_BACK_OFF; - if (_performanceThrottling < 0) { - _performanceThrottling = 0; + if (_performanceThrottlingRatio < 0) { + _performanceThrottlingRatio = 0; } qDebug() << "Mixer is recovering, sleeping" << _trailingSleepRatio * 100 << "% of frame time. Old cutoff was" - << lastCutoffRatio << "and is now" << _performanceThrottling; + << lastCutoffRatio << "and is now" << _performanceThrottlingRatio; hasRatioChanged = true; } if (hasRatioChanged) { // set out min audability threshold from the new ratio - _minAudibilityThreshold = LOUDNESS_TO_DISTANCE_RATIO / (2.0f * (1.0f - _performanceThrottling)); + _minAudibilityThreshold = LOUDNESS_TO_DISTANCE_RATIO / (2.0f * (1.0f - _performanceThrottlingRatio)); qDebug() << "Minimum audability required to be mixed is now" << _minAudibilityThreshold; framesSinceCutoffEvent = 0; diff --git a/assignment-client/src/audio/AudioMixer.h b/assignment-client/src/audio/AudioMixer.h index 0b1de6f069..0ca241c5ed 100644 --- a/assignment-client/src/audio/AudioMixer.h +++ b/assignment-client/src/audio/AudioMixer.h @@ -44,7 +44,7 @@ private: float _trailingSleepRatio; float _minAudibilityThreshold; - float _performanceThrottling; + float _performanceThrottlingRatio; int _numStatFrames; int _sumListeners; int _sumMixes; diff --git a/assignment-client/src/avatars/AvatarMixer.cpp b/assignment-client/src/avatars/AvatarMixer.cpp index d243894ea1..09f6923f40 100644 --- a/assignment-client/src/avatars/AvatarMixer.cpp +++ b/assignment-client/src/avatars/AvatarMixer.cpp @@ -31,6 +31,8 @@ const unsigned int AVATAR_DATA_SEND_INTERVAL_USECS = (1 / 60.0) * 1000 * 1000; AvatarMixer::AvatarMixer(const QByteArray& packet) : ThreadedAssignment(packet), + _trailingSleepRatio(0.0f), + _performanceThrottlingRatio(0.0f), _sumListeners(0), _numStatFrames(0) { @@ -258,6 +260,9 @@ void AvatarMixer::sendStatsPacket() { statsObject["packets_per_second"] = packetsPerSecond; statsObject["bytes_per_second"] = bytesPerSecond; + statsObject["trailing_sleep_percentage"] = _trailingSleepRatio * 100; + statsObject["performance_throttling_ratio"] = _performanceThrottlingRatio; + nodeList->sendStatsToDomainServer(statsObject); _sumListeners = 0; @@ -291,14 +296,65 @@ void AvatarMixer::run() { QElapsedTimer billboardTimer; billboardTimer.start(); + int usecToSleep = AVATAR_DATA_SEND_INTERVAL_USECS; + + const int TRAILING_AVERAGE_FRAMES = 100; + int framesSinceCutoffEvent = TRAILING_AVERAGE_FRAMES; + while (!_isFinished) { ++_numStatFrames; - QCoreApplication::processEvents(); + const float STRUGGLE_TRIGGER_SLEEP_PERCENTAGE_THRESHOLD = 0.10f; + const float BACK_OFF_TRIGGER_SLEEP_PERCENTAGE_THRESHOLD = 0.20f; - if (_isFinished) { - break; + const float RATIO_BACK_OFF = 0.02f; + + const float CURRENT_FRAME_RATIO = 1.0f / TRAILING_AVERAGE_FRAMES; + const float PREVIOUS_FRAMES_RATIO = 1.0f - CURRENT_FRAME_RATIO; + + if (usecToSleep < 0) { + usecToSleep = 0; + } + + _trailingSleepRatio = (PREVIOUS_FRAMES_RATIO * _trailingSleepRatio) + + (usecToSleep * CURRENT_FRAME_RATIO / (float) AVATAR_DATA_SEND_INTERVAL_USECS); + + float lastCutoffRatio = _performanceThrottlingRatio; + bool hasRatioChanged = false; + + if (framesSinceCutoffEvent >= TRAILING_AVERAGE_FRAMES) { + if (framesSinceCutoffEvent % TRAILING_AVERAGE_FRAMES == 0) { + qDebug() << "Current trailing sleep ratio:" << _trailingSleepRatio; + } + + if (_trailingSleepRatio <= STRUGGLE_TRIGGER_SLEEP_PERCENTAGE_THRESHOLD) { + // we're struggling - change our min required loudness to reduce some load + _performanceThrottlingRatio = _performanceThrottlingRatio + (0.5f * (1.0f - _performanceThrottlingRatio)); + + qDebug() << "Mixer is struggling, sleeping" << _trailingSleepRatio * 100 << "% of frame time. Old cutoff was" + << lastCutoffRatio << "and is now" << _performanceThrottlingRatio; + hasRatioChanged = true; + } else if (_trailingSleepRatio >= BACK_OFF_TRIGGER_SLEEP_PERCENTAGE_THRESHOLD && _performanceThrottlingRatio != 0) { + // we've recovered and can back off the required loudness + _performanceThrottlingRatio = _performanceThrottlingRatio - RATIO_BACK_OFF; + + if (_performanceThrottlingRatio < 0) { + _performanceThrottlingRatio = 0; + } + + qDebug() << "Mixer is recovering, sleeping" << _trailingSleepRatio * 100 << "% of frame time. Old cutoff was" + << lastCutoffRatio << "and is now" << _performanceThrottlingRatio; + hasRatioChanged = true; + } + + if (hasRatioChanged) { + framesSinceCutoffEvent = 0; + } + } + + if (!hasRatioChanged) { + ++framesSinceCutoffEvent; } broadcastAvatarData(); @@ -316,7 +372,13 @@ void AvatarMixer::run() { billboardTimer.restart(); } - int usecToSleep = usecTimestamp(&startTime) + (++nextFrame * AVATAR_DATA_SEND_INTERVAL_USECS) - usecTimestampNow(); + QCoreApplication::processEvents(); + + if (_isFinished) { + break; + } + + usecToSleep = usecTimestamp(&startTime) + (++nextFrame * AVATAR_DATA_SEND_INTERVAL_USECS) - usecTimestampNow(); if (usecToSleep > 0) { usleep(usecToSleep); diff --git a/assignment-client/src/avatars/AvatarMixer.h b/assignment-client/src/avatars/AvatarMixer.h index 8e9364ddf9..4d54b715f8 100644 --- a/assignment-client/src/avatars/AvatarMixer.h +++ b/assignment-client/src/avatars/AvatarMixer.h @@ -30,6 +30,9 @@ public slots: private: void broadcastAvatarData(); + float _trailingSleepRatio; + float _performanceThrottlingRatio; + int _sumListeners; int _numStatFrames; }; From 3db8386743f6792bfeb2850425d38601b709623d Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Mon, 24 Mar 2014 15:46:02 -0700 Subject: [PATCH 04/10] suppress trailing sleep ratio debug --- assignment-client/src/audio/AudioMixer.cpp | 8 -------- assignment-client/src/avatars/AvatarMixer.cpp | 10 +--------- 2 files changed, 1 insertion(+), 17 deletions(-) diff --git a/assignment-client/src/audio/AudioMixer.cpp b/assignment-client/src/audio/AudioMixer.cpp index f7092cd4ae..5aeedd24f3 100644 --- a/assignment-client/src/audio/AudioMixer.cpp +++ b/assignment-client/src/audio/AudioMixer.cpp @@ -440,10 +440,6 @@ void AudioMixer::run() { bool hasRatioChanged = false; if (framesSinceCutoffEvent >= TRAILING_AVERAGE_FRAMES) { - if (framesSinceCutoffEvent % TRAILING_AVERAGE_FRAMES == 0) { - qDebug() << "Current trailing sleep ratio:" << _trailingSleepRatio; - } - if (_trailingSleepRatio <= STRUGGLE_TRIGGER_SLEEP_PERCENTAGE_THRESHOLD) { // we're struggling - change our min required loudness to reduce some load _performanceThrottlingRatio = _performanceThrottlingRatio + (0.5f * (1.0f - _performanceThrottlingRatio)); @@ -473,10 +469,6 @@ void AudioMixer::run() { } } - if (!hasRatioChanged) { - ++framesSinceCutoffEvent; - } - foreach (const SharedNodePointer& node, nodeList->getNodeHash()) { if (node->getType() == NodeType::Agent && node->getActiveSocket() && node->getLinkedData() && ((AudioMixerClientData*) node->getLinkedData())->getAvatarAudioRingBuffer()) { diff --git a/assignment-client/src/avatars/AvatarMixer.cpp b/assignment-client/src/avatars/AvatarMixer.cpp index 09f6923f40..b302c9bdf0 100644 --- a/assignment-client/src/avatars/AvatarMixer.cpp +++ b/assignment-client/src/avatars/AvatarMixer.cpp @@ -31,7 +31,7 @@ const unsigned int AVATAR_DATA_SEND_INTERVAL_USECS = (1 / 60.0) * 1000 * 1000; AvatarMixer::AvatarMixer(const QByteArray& packet) : ThreadedAssignment(packet), - _trailingSleepRatio(0.0f), + _trailingSleepRatio(1.0f), _performanceThrottlingRatio(0.0f), _sumListeners(0), _numStatFrames(0) @@ -324,10 +324,6 @@ void AvatarMixer::run() { bool hasRatioChanged = false; if (framesSinceCutoffEvent >= TRAILING_AVERAGE_FRAMES) { - if (framesSinceCutoffEvent % TRAILING_AVERAGE_FRAMES == 0) { - qDebug() << "Current trailing sleep ratio:" << _trailingSleepRatio; - } - if (_trailingSleepRatio <= STRUGGLE_TRIGGER_SLEEP_PERCENTAGE_THRESHOLD) { // we're struggling - change our min required loudness to reduce some load _performanceThrottlingRatio = _performanceThrottlingRatio + (0.5f * (1.0f - _performanceThrottlingRatio)); @@ -353,10 +349,6 @@ void AvatarMixer::run() { } } - if (!hasRatioChanged) { - ++framesSinceCutoffEvent; - } - broadcastAvatarData(); if (identityTimer.elapsed() >= AVATAR_IDENTITY_KEYFRAME_MSECS) { From ba338cb7bc93ad75e065c3fae368f3fe685dc656 Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Mon, 24 Mar 2014 16:06:25 -0700 Subject: [PATCH 05/10] at minimum send packet rate stats for ThreadedAssignment subclasses --- assignment-client/src/Agent.cpp | 17 +++-------- assignment-client/src/audio/AudioMixer.cpp | 18 ++---------- assignment-client/src/avatars/AvatarMixer.cpp | 18 ++---------- .../src/metavoxels/MetavoxelServer.h | 2 +- assignment-client/src/octree/OctreeServer.cpp | 14 ++-------- assignment-client/src/voxels/VoxelServer.h | 1 - libraries/shared/src/ThreadedAssignment.cpp | 28 ++++++++++++++++++- libraries/shared/src/ThreadedAssignment.h | 4 ++- 8 files changed, 42 insertions(+), 60 deletions(-) diff --git a/assignment-client/src/Agent.cpp b/assignment-client/src/Agent.cpp index d32d6a3fd7..b23f9d210a 100644 --- a/assignment-client/src/Agent.cpp +++ b/assignment-client/src/Agent.cpp @@ -120,10 +120,12 @@ void Agent::readPendingDatagrams() { } } +const QString AGENT_LOGGING_NAME = "agent"; + void Agent::run() { - NodeList* nodeList = NodeList::getInstance(); - nodeList->setOwnerType(NodeType::Agent); + ThreadedAssignment::commonInit(AGENT_LOGGING_NAME, NodeType::Agent); + NodeList* nodeList = NodeList::getInstance(); nodeList->addSetOfNodeTypesToNodeInterestSet(NodeSet() << NodeType::AudioMixer << NodeType::AvatarMixer); // figure out the URL for the script for this agent assignment @@ -148,17 +150,6 @@ void Agent::run() { qDebug() << "Downloaded script:" << scriptContents; - timeval startTime; - gettimeofday(&startTime, NULL); - - QTimer* domainServerTimer = new QTimer(this); - connect(domainServerTimer, SIGNAL(timeout()), this, SLOT(checkInWithDomainServerOrExit())); - domainServerTimer->start(DOMAIN_SERVER_CHECK_IN_USECS / 1000); - - QTimer* silentNodeTimer = new QTimer(this); - connect(silentNodeTimer, SIGNAL(timeout()), nodeList, SLOT(removeSilentNodes())); - silentNodeTimer->start(NODE_SILENCE_THRESHOLD_USECS / 1000); - // setup an Avatar for the script to use AvatarData scriptedAvatar; diff --git a/assignment-client/src/audio/AudioMixer.cpp b/assignment-client/src/audio/AudioMixer.cpp index 5aeedd24f3..2ef1142b70 100644 --- a/assignment-client/src/audio/AudioMixer.cpp +++ b/assignment-client/src/audio/AudioMixer.cpp @@ -369,32 +369,18 @@ void AudioMixer::sendStatsPacket() { statsObject["average_mixes_per_listener"] = 0.0; } - NodeList* nodeList = NodeList::getInstance(); - - float packetsPerSecond, bytesPerSecond; - nodeList->getPacketStats(packetsPerSecond, bytesPerSecond); - nodeList->resetPacketStats(); - - statsObject["packets_per_second"] = packetsPerSecond; - statsObject["bytes_per_second"] = bytesPerSecond; + ThreadedAssignment::addPacketStatsAndSendStatsPacket(statsObject); _sumListeners = 0; _sumMixes = 0; _numStatFrames = 0; - - nodeList->sendStatsToDomainServer(statsObject); } void AudioMixer::run() { - commonInit(AUDIO_MIXER_LOGGING_TARGET_NAME, NodeType::AudioMixer); + ThreadedAssignment::commonInit(AUDIO_MIXER_LOGGING_TARGET_NAME, NodeType::AudioMixer); NodeList* nodeList = NodeList::getInstance(); - - // send a stats packet every 1 second - QTimer* statsTimer = new QTimer(this); - connect(statsTimer, &QTimer::timeout, this, &AudioMixer::sendStatsPacket); - statsTimer->start(1000); nodeList->addNodeTypeToInterestSet(NodeType::Agent); diff --git a/assignment-client/src/avatars/AvatarMixer.cpp b/assignment-client/src/avatars/AvatarMixer.cpp index b302c9bdf0..2400abbde1 100644 --- a/assignment-client/src/avatars/AvatarMixer.cpp +++ b/assignment-client/src/avatars/AvatarMixer.cpp @@ -251,19 +251,10 @@ void AvatarMixer::sendStatsPacket() { QJsonObject statsObject; statsObject["average_listeners_last_second"] = _sumListeners / (float) _numStatFrames; - NodeList* nodeList = NodeList::getInstance(); - - float packetsPerSecond, bytesPerSecond; - nodeList->getPacketStats(packetsPerSecond, bytesPerSecond); - nodeList->resetPacketStats(); - - statsObject["packets_per_second"] = packetsPerSecond; - statsObject["bytes_per_second"] = bytesPerSecond; - statsObject["trailing_sleep_percentage"] = _trailingSleepRatio * 100; statsObject["performance_throttling_ratio"] = _performanceThrottlingRatio; - nodeList->sendStatsToDomainServer(statsObject); + ThreadedAssignment::addPacketStatsAndSendStatsPacket(statsObject); _sumListeners = 0; _numStatFrames = 0; @@ -273,16 +264,11 @@ const qint64 AVATAR_IDENTITY_KEYFRAME_MSECS = 5000; const qint64 AVATAR_BILLBOARD_KEYFRAME_MSECS = 5000; void AvatarMixer::run() { - commonInit(AVATAR_MIXER_LOGGING_NAME, NodeType::AvatarMixer); + ThreadedAssignment::commonInit(AVATAR_MIXER_LOGGING_NAME, NodeType::AvatarMixer); NodeList* nodeList = NodeList::getInstance(); nodeList->addNodeTypeToInterestSet(NodeType::Agent); - // send a stats packet every 1 second - QTimer* statsTimer = new QTimer(this); - connect(statsTimer, &QTimer::timeout, this, &AvatarMixer::sendStatsPacket); - statsTimer->start(1000); - nodeList->linkedDataCreateCallback = attachAvatarDataToNode; int nextFrame = 0; diff --git a/assignment-client/src/metavoxels/MetavoxelServer.h b/assignment-client/src/metavoxels/MetavoxelServer.h index bd7a280c43..d178127ac7 100644 --- a/assignment-client/src/metavoxels/MetavoxelServer.h +++ b/assignment-client/src/metavoxels/MetavoxelServer.h @@ -35,7 +35,7 @@ public: virtual void run(); virtual void readPendingDatagrams(); - + private slots: void maybeAttachSession(const SharedNodePointer& node); diff --git a/assignment-client/src/octree/OctreeServer.cpp b/assignment-client/src/octree/OctreeServer.cpp index 4990de2b55..6f604c5fd5 100644 --- a/assignment-client/src/octree/OctreeServer.cpp +++ b/assignment-client/src/octree/OctreeServer.cpp @@ -823,9 +823,9 @@ void OctreeServer::run() { _safeServerName = getMyServerName(); // Before we do anything else, create our tree... _tree = createTree(); - - // change the logging target name while this is running - Logging::setTargetName(getMyLoggingServerTargetName()); + + // use common init to setup common timers and logging + commonInit(getMyLoggingServerTargetName(), getMyNodeType()); // Now would be a good time to parse our arguments, if we got them as assignment if (getPayload().size() > 0) { @@ -988,14 +988,6 @@ void OctreeServer::run() { strftime(utcBuffer, MAX_TIME_LENGTH, " [%m/%d/%Y %X UTC]", gmtm); } qDebug() << "Now running... started at: " << localBuffer << utcBuffer; - - QTimer* domainServerTimer = new QTimer(this); - connect(domainServerTimer, SIGNAL(timeout()), this, SLOT(checkInWithDomainServerOrExit())); - domainServerTimer->start(DOMAIN_SERVER_CHECK_IN_USECS / 1000); - - QTimer* silentNodeTimer = new QTimer(this); - connect(silentNodeTimer, SIGNAL(timeout()), nodeList, SLOT(removeSilentNodes())); - silentNodeTimer->start(NODE_SILENCE_THRESHOLD_USECS / 1000); } void OctreeServer::nodeAdded(SharedNodePointer node) { diff --git a/assignment-client/src/voxels/VoxelServer.h b/assignment-client/src/voxels/VoxelServer.h index 509d838fff..2e97736963 100644 --- a/assignment-client/src/voxels/VoxelServer.h +++ b/assignment-client/src/voxels/VoxelServer.h @@ -46,7 +46,6 @@ public: virtual bool hasSpecialPacketToSend(const SharedNodePointer& node); virtual int sendSpecialPacket(const SharedNodePointer& node); - private: bool _sendEnvironments; bool _sendMinimalEnvironment; diff --git a/libraries/shared/src/ThreadedAssignment.cpp b/libraries/shared/src/ThreadedAssignment.cpp index b3a54b1488..f4ea383399 100644 --- a/libraries/shared/src/ThreadedAssignment.cpp +++ b/libraries/shared/src/ThreadedAssignment.cpp @@ -7,6 +7,7 @@ // #include +#include #include #include "Logging.h" @@ -34,7 +35,7 @@ void ThreadedAssignment::setFinished(bool isFinished) { } } -void ThreadedAssignment::commonInit(const QString& targetName, NodeType_t nodeType) { +void ThreadedAssignment::commonInit(const QString& targetName, NodeType_t nodeType, bool shouldSendStats) { // change the logging target name while the assignment is running Logging::setTargetName(targetName); @@ -52,6 +53,31 @@ void ThreadedAssignment::commonInit(const QString& targetName, NodeType_t nodeTy QTimer* silentNodeRemovalTimer = new QTimer(this); connect(silentNodeRemovalTimer, SIGNAL(timeout()), nodeList, SLOT(removeSilentNodes())); silentNodeRemovalTimer->start(NODE_SILENCE_THRESHOLD_USECS / 1000); + + if (shouldSendStats) { + // send a stats packet every 1 second + QTimer* statsTimer = new QTimer(this); + connect(statsTimer, &QTimer::timeout, this, &ThreadedAssignment::sendStatsPacket); + statsTimer->start(1000); + } +} + +void ThreadedAssignment::addPacketStatsAndSendStatsPacket(QJsonObject &statsObject) { + NodeList* nodeList = NodeList::getInstance(); + + float packetsPerSecond, bytesPerSecond; + nodeList->getPacketStats(packetsPerSecond, bytesPerSecond); + nodeList->resetPacketStats(); + + statsObject["packets_per_second"] = packetsPerSecond; + statsObject["bytes_per_second"] = bytesPerSecond; + + nodeList->sendStatsToDomainServer(statsObject); +} + +void ThreadedAssignment::sendStatsPacket() { + QJsonObject statsObject; + addPacketStatsAndSendStatsPacket(statsObject); } void ThreadedAssignment::checkInWithDomainServerOrExit() { diff --git a/libraries/shared/src/ThreadedAssignment.h b/libraries/shared/src/ThreadedAssignment.h index d3502e9c4d..5b78eed56d 100644 --- a/libraries/shared/src/ThreadedAssignment.h +++ b/libraries/shared/src/ThreadedAssignment.h @@ -17,16 +17,18 @@ public: ThreadedAssignment(const QByteArray& packet); void setFinished(bool isFinished); virtual void aboutToFinish() { }; + void addPacketStatsAndSendStatsPacket(QJsonObject& statsObject); public slots: /// threaded run of assignment virtual void run() = 0; virtual void deleteLater(); virtual void readPendingDatagrams() = 0; + virtual void sendStatsPacket(); protected: bool readAvailableDatagram(QByteArray& destinationByteArray, HifiSockAddr& senderSockAddr); - void commonInit(const QString& targetName, NodeType_t nodeType); + void commonInit(const QString& targetName, NodeType_t nodeType, bool shouldSendStats = true); bool _isFinished; private slots: void checkInWithDomainServerOrExit(); From 364df16a9f7d901058474e0cfd31ebe6cebde36f Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Mon, 24 Mar 2014 16:34:00 -0700 Subject: [PATCH 06/10] pretty up the stats table --- domain-server/resources/web/stats/js/stats.js | 10 ++++++++-- domain-server/src/DomainServer.cpp | 9 +++++++-- 2 files changed, 15 insertions(+), 4 deletions(-) diff --git a/domain-server/resources/web/stats/js/stats.js b/domain-server/resources/web/stats/js/stats.js index e82668ea9e..bebd16b883 100644 --- a/domain-server/resources/web/stats/js/stats.js +++ b/domain-server/resources/web/stats/js/stats.js @@ -13,7 +13,13 @@ $(document).ready(function(){ var statsTableBody = ""; $.getJSON("/nodes/" + uuid + ".json", function(json){ - $.each(json, function (key, value) { + + // update the table header with the right node type + $('#stats-lead h3').html(json.node_type + " stats (" + uuid +); + + delete json.node_type; + + $.each(json, function(key, value) { statsTableBody += ""; statsTableBody += "" + key + ""; statsTableBody += "" + value + ""; @@ -21,7 +27,7 @@ $(document).ready(function(){ }); $('#stats-table tbody').html(statsTableBody); - }); + }); } // do the first GET on page load diff --git a/domain-server/src/DomainServer.cpp b/domain-server/src/DomainServer.cpp index 0a8b70a673..913ca44e12 100644 --- a/domain-server/src/DomainServer.cpp +++ b/domain-server/src/DomainServer.cpp @@ -737,8 +737,13 @@ bool DomainServer::handleHTTPRequest(HTTPConnection* connection, const QUrl& url SharedNodePointer matchingNode = NodeList::getInstance()->nodeWithUUID(matchingUUID); if (matchingNode) { // create a QJsonDocument with the stats QJsonObject - QJsonDocument statsDocument(reinterpret_cast(matchingNode->getLinkedData()) - ->getStatsJSONObject()); + QJsonObject statsObject = + reinterpret_cast(matchingNode->getLinkedData())->getStatsJSONObject(); + + // add the node type to the JSON data for output purposes + statsObject["node_type"] = NodeType::getNodeTypeName(matchingNode->getType()).toLower().replace(' ', '-'); + + QJsonDocument statsDocument(statsObject); // send the response connection->respond(HTTPConnection::StatusCode200, statsDocument.toJson(), qPrintable(JSON_MIME_TYPE)); From b01b2a3311127a711324d92151e16cc972d8b7e8 Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Mon, 24 Mar 2014 16:35:36 -0700 Subject: [PATCH 07/10] use explicit float casts where appropriate --- assignment-client/src/audio/AudioMixer.cpp | 4 ++-- assignment-client/src/avatars/AvatarMixer.cpp | 2 +- libraries/shared/src/NodeList.cpp | 4 ++-- 3 files changed, 5 insertions(+), 5 deletions(-) diff --git a/assignment-client/src/audio/AudioMixer.cpp b/assignment-client/src/audio/AudioMixer.cpp index 2ef1142b70..450b6e0ad9 100644 --- a/assignment-client/src/audio/AudioMixer.cpp +++ b/assignment-client/src/audio/AudioMixer.cpp @@ -361,10 +361,10 @@ void AudioMixer::sendStatsPacket() { statsObject["trailing_sleep_percentage"] = _trailingSleepRatio * 100.0f; statsObject["performance_throttling_ratio"] = _performanceThrottlingRatio; - statsObject["average_listeners_per_frame"] = _sumListeners / (float) _numStatFrames; + statsObject["average_listeners_per_frame"] = (float) _sumListeners / (float) _numStatFrames; if (_sumListeners > 0) { - statsObject["average_mixes_per_listener"] = _sumMixes / (float) _sumListeners; + statsObject["average_mixes_per_listener"] = (float) _sumMixes / (float) _sumListeners; } else { statsObject["average_mixes_per_listener"] = 0.0; } diff --git a/assignment-client/src/avatars/AvatarMixer.cpp b/assignment-client/src/avatars/AvatarMixer.cpp index 2400abbde1..8964c8f771 100644 --- a/assignment-client/src/avatars/AvatarMixer.cpp +++ b/assignment-client/src/avatars/AvatarMixer.cpp @@ -249,7 +249,7 @@ void AvatarMixer::readPendingDatagrams() { void AvatarMixer::sendStatsPacket() { QJsonObject statsObject; - statsObject["average_listeners_last_second"] = _sumListeners / (float) _numStatFrames; + statsObject["average_listeners_last_second"] = (float) _sumListeners / (float) _numStatFrames; statsObject["trailing_sleep_percentage"] = _trailingSleepRatio * 100; statsObject["performance_throttling_ratio"] = _performanceThrottlingRatio; diff --git a/libraries/shared/src/NodeList.cpp b/libraries/shared/src/NodeList.cpp index d4babd4557..89e915a722 100644 --- a/libraries/shared/src/NodeList.cpp +++ b/libraries/shared/src/NodeList.cpp @@ -864,8 +864,8 @@ SharedNodePointer NodeList::soloNodeOfType(char nodeType) { } void NodeList::getPacketStats(float& packetsPerSecond, float& bytesPerSecond) { - packetsPerSecond = _numCollectedPackets / (float) (_packetStatTimer.elapsed() / 1000.0f); - bytesPerSecond = _numCollectedBytes / (float) (_packetStatTimer.elapsed() / 1000.0f); + packetsPerSecond = (float) _numCollectedPackets / (float) (_packetStatTimer.elapsed() / 1000.0f); + bytesPerSecond = (float) _numCollectedBytes / (float) (_packetStatTimer.elapsed() / 1000.0f); } void NodeList::resetPacketStats() { From 4f7a8473fde27c66a5d59dfb7d49d7f727fce125 Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Mon, 24 Mar 2014 16:40:14 -0700 Subject: [PATCH 08/10] make stats red when they become stale --- domain-server/resources/web/css/style.css | 4 ++++ domain-server/resources/web/stats/js/stats.js | 6 +++++- 2 files changed, 9 insertions(+), 1 deletion(-) diff --git a/domain-server/resources/web/css/style.css b/domain-server/resources/web/css/style.css index d641aa5f71..fb295cffc3 100644 --- a/domain-server/resources/web/css/style.css +++ b/domain-server/resources/web/css/style.css @@ -38,4 +38,8 @@ span.port { color: #666666; +} + +.stale { + color: red; } \ No newline at end of file diff --git a/domain-server/resources/web/stats/js/stats.js b/domain-server/resources/web/stats/js/stats.js index bebd16b883..a7b0aecfcf 100644 --- a/domain-server/resources/web/stats/js/stats.js +++ b/domain-server/resources/web/stats/js/stats.js @@ -15,7 +15,7 @@ $(document).ready(function(){ $.getJSON("/nodes/" + uuid + ".json", function(json){ // update the table header with the right node type - $('#stats-lead h3').html(json.node_type + " stats (" + uuid +); + $('#stats-lead h3').html(json.node_type + " stats (" + uuid + ")"); delete json.node_type; @@ -27,6 +27,10 @@ $(document).ready(function(){ }); $('#stats-table tbody').html(statsTableBody); + }).fail(function(data) { + $('#stats-table td').each(function(){ + $(this).addClass('stale'); + }); }); } From ce214bc43998cf277f83f1962ff565e372fbc067 Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Mon, 24 Mar 2014 16:48:23 -0700 Subject: [PATCH 09/10] use the performance tuning ratio in avatar mixer to send less --- assignment-client/src/avatars/AvatarMixer.cpp | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/assignment-client/src/avatars/AvatarMixer.cpp b/assignment-client/src/avatars/AvatarMixer.cpp index 8964c8f771..0ec7c3e15e 100644 --- a/assignment-client/src/avatars/AvatarMixer.cpp +++ b/assignment-client/src/avatars/AvatarMixer.cpp @@ -84,7 +84,8 @@ void AvatarMixer::broadcastAvatarData() { // at a distance of twice the full rate distance, there will be a 50% chance of sending this avatar's update const float FULL_RATE_DISTANCE = 2.f; // Decide whether to send this avatar's data based on it's distance from us - if ((distanceToAvatar == 0.f) || (randFloat() < FULL_RATE_DISTANCE / distanceToAvatar)) { + if ((distanceToAvatar == 0.f) || (randFloat() < FULL_RATE_DISTANCE / distanceToAvatar) + * (1 - _performanceThrottlingRatio)) { QByteArray avatarByteArray; avatarByteArray.append(otherNode->getUUID().toRfc4122()); avatarByteArray.append(otherAvatar.toByteArray()); From a90cd7ed312f50cc66a601637f19dcf50e565804 Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Mon, 24 Mar 2014 16:54:14 -0700 Subject: [PATCH 10/10] cast numerator to float before divide --- libraries/shared/src/NodeList.cpp | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/libraries/shared/src/NodeList.cpp b/libraries/shared/src/NodeList.cpp index 89e915a722..95417f4f71 100644 --- a/libraries/shared/src/NodeList.cpp +++ b/libraries/shared/src/NodeList.cpp @@ -864,8 +864,8 @@ SharedNodePointer NodeList::soloNodeOfType(char nodeType) { } void NodeList::getPacketStats(float& packetsPerSecond, float& bytesPerSecond) { - packetsPerSecond = (float) _numCollectedPackets / (float) (_packetStatTimer.elapsed() / 1000.0f); - bytesPerSecond = (float) _numCollectedBytes / (float) (_packetStatTimer.elapsed() / 1000.0f); + packetsPerSecond = (float) _numCollectedPackets / ((float) _packetStatTimer.elapsed() / 1000.0f); + bytesPerSecond = (float) _numCollectedBytes / ((float) _packetStatTimer.elapsed() / 1000.0f); } void NodeList::resetPacketStats() {