Merge pull request #2472 from birarda/domain-json-stats

add minimal packet rate stats to all nodes, a little extra to avatar-mixer
This commit is contained in:
AndrewMeadows 2014-03-24 16:57:20 -07:00
commit 961815fe42
15 changed files with 198 additions and 75 deletions

View file

@ -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;

View file

@ -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,34 +359,28 @@ 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;
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;
}
ThreadedAssignment::addPacketStatsAndSendStatsPacket(statsObject);
_sumListeners = 0;
_sumMixes = 0;
_numStatFrames = 0;
NodeList::getInstance()->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, SIGNAL(timeout()), this, SLOT(sendStatsPacket()));
statsTimer->start(1000);
nodeList->addNodeTypeToInterestSet(NodeType::Agent);
@ -428,47 +422,39 @@ 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) {
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
_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;
}
}
if (!hasRatioChanged) {
++framesSinceCutoffEvent;
}
foreach (const SharedNodePointer& node, nodeList->getNodeHash()) {
if (node->getType() == NodeType::Agent && node->getActiveSocket() && node->getLinkedData()
&& ((AudioMixerClientData*) node->getLinkedData())->getAvatarAudioRingBuffer()) {

View file

@ -44,7 +44,7 @@ private:
float _trailingSleepRatio;
float _minAudibilityThreshold;
float _performanceThrottling;
float _performanceThrottlingRatio;
int _numStatFrames;
int _sumListeners;
int _sumMixes;

View file

@ -12,6 +12,7 @@
#include <QtCore/QCoreApplication>
#include <QtCore/QElapsedTimer>
#include <QtCore/QJsonObject>
#include <QtCore/QTimer>
#include <Logging.h>
@ -29,7 +30,11 @@ 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),
_trailingSleepRatio(1.0f),
_performanceThrottlingRatio(0.0f),
_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 +53,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 +62,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);
@ -78,7 +84,8 @@ void 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());
@ -241,11 +248,24 @@ void AvatarMixer::readPendingDatagrams() {
}
}
void AvatarMixer::sendStatsPacket() {
QJsonObject statsObject;
statsObject["average_listeners_last_second"] = (float) _sumListeners / (float) _numStatFrames;
statsObject["trailing_sleep_percentage"] = _trailingSleepRatio * 100;
statsObject["performance_throttling_ratio"] = _performanceThrottlingRatio;
ThreadedAssignment::addPacketStatsAndSendStatsPacket(statsObject);
_sumListeners = 0;
_numStatFrames = 0;
}
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);
@ -263,12 +283,57 @@ 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) {
QCoreApplication::processEvents();
++_numStatFrames;
if (_isFinished) {
break;
const float STRUGGLE_TRIGGER_SLEEP_PERCENTAGE_THRESHOLD = 0.10f;
const float BACK_OFF_TRIGGER_SLEEP_PERCENTAGE_THRESHOLD = 0.20f;
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 (_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;
}
}
broadcastAvatarData();
@ -286,7 +351,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);

View file

@ -24,6 +24,17 @@ public slots:
void nodeKilled(SharedNodePointer killedNode);
void readPendingDatagrams();
void sendStatsPacket();
private:
void broadcastAvatarData();
float _trailingSleepRatio;
float _performanceThrottlingRatio;
int _sumListeners;
int _numStatFrames;
};
#endif /* defined(__hifi__AvatarMixer__) */

View file

@ -35,7 +35,7 @@ public:
virtual void run();
virtual void readPendingDatagrams();
private slots:
void maybeAttachSession(const SharedNodePointer& node);

View file

@ -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) {

View file

@ -46,7 +46,6 @@ public:
virtual bool hasSpecialPacketToSend(const SharedNodePointer& node);
virtual int sendSpecialPacket(const SharedNodePointer& node);
private:
bool _sendEnvironments;
bool _sendMinimalEnvironment;

View file

@ -38,4 +38,8 @@
span.port {
color: #666666;
}
.stale {
color: red;
}

View file

@ -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 += "<tr>";
statsTableBody += "<td>" + key + "</td>";
statsTableBody += "<td>" + value + "</td>";
@ -21,7 +27,11 @@ $(document).ready(function(){
});
$('#stats-table tbody').html(statsTableBody);
});
}).fail(function(data) {
$('#stats-table td').each(function(){
$(this).addClass('stale');
});
});
}
// do the first GET on page load

View file

@ -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<DomainServerNodeData*>(matchingNode->getLinkedData())
->getStatsJSONObject());
QJsonObject statsObject =
reinterpret_cast<DomainServerNodeData*>(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));

View file

@ -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 = (float) _numCollectedPackets / ((float) _packetStatTimer.elapsed() / 1000.0f);
bytesPerSecond = (float) _numCollectedBytes / ((float) _packetStatTimer.elapsed() / 1000.0f);
}
void NodeList::resetPacketStats() {
_numCollectedPackets = 0;
_numCollectedBytes = 0;
_packetStatTimer.restart();
}
void NodeList::removeSilentNodes() {
_nodeHashMutex.lock();

View file

@ -21,6 +21,7 @@
#include <unistd.h> // not on windows, not needed for mac or windows
#endif
#include <QtCore/QElapsedTimer>
#include <QtCore/QMutex>
#include <QtCore/QSet>
#include <QtCore/QSettings>
@ -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__) */

View file

@ -7,6 +7,7 @@
//
#include <QtCore/QCoreApplication>
#include <QtCore/QJsonObject>
#include <QtCore/QTimer>
#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() {

View file

@ -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();