clean up stats, add slave stats

This commit is contained in:
Brad Hefta-Gaub 2017-02-15 12:11:17 -08:00
parent 4f655bba3f
commit cddb72bbd7
6 changed files with 63 additions and 24 deletions

View file

@ -102,6 +102,7 @@ void AvatarMixer::start() {
//_slavePool.setNumThreads(1); // grins
while (!_isFinished) {
_numTightLoopFrames++;
_loopRate.increment();
// FIXME - we really should sleep for the remainder of what we haven't spent time processing
@ -754,24 +755,19 @@ void AvatarMixer::sendStatsPacket() {
statsObject["timing_average_b_ignoreCalculation"] = (float)_ignoreCalculationElapsedTime / (float)_numStatFrames;
statsObject["timing_average_c_avatarDataPacking"] = (float)_avatarDataPackingElapsedTime / (float)_numStatFrames;
statsObject["timing_average_d_packetSending"] = (float)_packetSendingElapsedTime / (float)_numStatFrames;
statsObject["timing_average_e_total_broadcastAvatarData"] = (float)_broadcastAvatarDataElapsedTime / (float)_numStatFrames;
statsObject["timing_average_y_processEvents"] = (float)_processEventsElapsedTime / (float)_numStatFrames;
statsObject["timing_average_y_queueIncomingPacket"] = (float)_queueIncomingPacketElapsedTime / (float)_numStatFrames;
statsObject["timing_average_z_handleAvatarDataPacket"] = (float)_handleAvatarDataPacketElapsedTime / (float)_numStatFrames;
statsObject["timing_average_z_handleAvatarIdentityPacket"] = (float)_handleAvatarIdentityPacketElapsedTime / (float)_numStatFrames;
statsObject["timing_average_z_handleKillAvatarPacket"] = (float)_handleKillAvatarPacketElapsedTime / (float)_numStatFrames;
statsObject["timing_average_z_handleNodeIgnoreRequestPacket"] = (float)_handleNodeIgnoreRequestPacketElapsedTime / (float)_numStatFrames;
statsObject["timing_average_z_handleRadiusIgnoreRequestPacket"] = (float)_handleRadiusIgnoreRequestPacketElapsedTime / (float)_numStatFrames;
statsObject["timing_average_z_handleRequestsDomainListDataPacket"] = (float)_handleRequestsDomainListDataPacketElapsedTime / (float)_numStatFrames;
statsObject["timing_average_z_handleViewFrustumPacket"] = (float)_handleViewFrustumPacketElapsedTime / (float)_numStatFrames;
statsObject["timing_average_z_processQueuedAvatarDataPackets"] = (float)_processQueuedAvatarDataPacketsElapsedTime / (float)_numStatFrames;
// this things all occur on the frequency of the tight loop
statsObject["timing_average_y_processEvents"] = (float)_processEventsElapsedTime / (float)_numTightLoopFrames;
statsObject["timing_average_y_queueIncomingPacket"] = (float)_queueIncomingPacketElapsedTime / (float)_numTightLoopFrames;
statsObject["timing_average_z_handleAvatarDataPacket"] = (float)_handleAvatarDataPacketElapsedTime / (float)_numTightLoopFrames;
statsObject["timing_average_z_handleAvatarIdentityPacket"] = (float)_handleAvatarIdentityPacketElapsedTime / (float)_numTightLoopFrames;
statsObject["timing_average_z_handleKillAvatarPacket"] = (float)_handleKillAvatarPacketElapsedTime / (float)_numTightLoopFrames;
statsObject["timing_average_z_handleNodeIgnoreRequestPacket"] = (float)_handleNodeIgnoreRequestPacketElapsedTime / (float)_numTightLoopFrames;
statsObject["timing_average_z_handleRadiusIgnoreRequestPacket"] = (float)_handleRadiusIgnoreRequestPacketElapsedTime / (float)_numTightLoopFrames;
statsObject["timing_average_z_handleRequestsDomainListDataPacket"] = (float)_handleRequestsDomainListDataPacketElapsedTime / (float)_numTightLoopFrames;
statsObject["timing_average_z_handleViewFrustumPacket"] = (float)_handleViewFrustumPacketElapsedTime / (float)_numTightLoopFrames;
statsObject["timing_average_z_processQueuedAvatarDataPackets"] = (float)_processQueuedAvatarDataPacketsElapsedTime / (float)_numTightLoopFrames;
statsObject["timing_sendStats"] = (float)_sendStatsElapsedTime;
@ -786,8 +782,24 @@ void AvatarMixer::sendStatsPacket() {
_queueIncomingPacketElapsedTime = 0;
_processQueuedAvatarDataPacketsElapsedTime = 0;
QJsonObject avatarsObject;
QJsonObject slavesObject;
// gather stats
int slaveNumber = 1;
_slavePool.each([&](AvatarMixerSlave& slave) {
QJsonObject slaveObject;
int nodesProcessed, packetsProcessed;
quint64 processIncomingPacketsElapsedTime;
slave.harvestStats(nodesProcessed, packetsProcessed, processIncomingPacketsElapsedTime);
slaveObject["nodesProcessed"] = nodesProcessed;
slaveObject["packetsProcessed"] = packetsProcessed;
slaveObject["timing_average_processIncomingPackets"] = (float)processIncomingPacketsElapsedTime / (float)_numTightLoopFrames;
slavesObject[QString::number(slaveNumber)] = slaveObject;
slaveNumber++;
});
statsObject["timing_slaves"] = slavesObject;
QJsonObject avatarsObject;
auto nodeList = DependencyManager::get<NodeList>();
// add stats for each listerner
nodeList->eachNode([&](const SharedNodePointer& node) {
@ -818,11 +830,13 @@ void AvatarMixer::sendStatsPacket() {
});
statsObject["z_avatars"] = avatarsObject;
ThreadedAssignment::addPacketStatsAndSendStatsPacket(statsObject);
_sumListeners = 0;
_sumIdentityPackets = 0;
_numStatFrames = 0;
_numTightLoopFrames = 0;
_broadcastAvatarDataElapsedTime = 0;
_displayNameManagementElapsedTime = 0;

View file

@ -69,6 +69,7 @@ private:
int _sumListeners { 0 };
int _numStatFrames { 0 };
std::atomic<int> _numTightLoopFrames;
int _sumIdentityPackets { 0 };
float _maxKbpsPerNode = 0.0f;

View file

@ -34,7 +34,8 @@ void AvatarMixerClientData::queuePacket(QSharedPointer<ReceivedMessage> message,
// packetReceiver.registerListener(PacketType::RadiusIgnoreRequest, this, "handleRadiusIgnoreRequestPacket");
// packetReceiver.registerListener(PacketType::RequestsDomainListData, this, "handleRequestsDomainListDataPacket");
void AvatarMixerClientData::processPackets() {
int AvatarMixerClientData::processPackets() {
int packetsProcessed = 0;
SharedNodePointer node = _packetQueue.node;
assert(_packetQueue.empty() || node);
_packetQueue.node.clear();
@ -42,6 +43,8 @@ void AvatarMixerClientData::processPackets() {
while (!_packetQueue.empty()) {
auto& packet = _packetQueue.back();
packetsProcessed++;
switch (packet->getType()) {
case PacketType::AvatarData:
parseData(*packet);
@ -52,6 +55,8 @@ void AvatarMixerClientData::processPackets() {
_packetQueue.pop();
}
assert(_packetQueue.empty());
return packetsProcessed;
}
int AvatarMixerClientData::parseData(ReceivedMessage& message) {

View file

@ -120,7 +120,7 @@ public:
}
void queuePacket(QSharedPointer<ReceivedMessage> message, SharedNodePointer node);
void processPackets();
int processPackets(); // returns number of packets processed
private:
struct PacketQueue : public std::queue<QSharedPointer<ReceivedMessage>> {

View file

@ -35,10 +35,23 @@ void AvatarMixerSlave::configure(ConstIter begin, ConstIter end) {
_end = end;
}
void AvatarMixerSlave::processIncomingPackets(const SharedNodePointer& node) {
auto nodeData = dynamic_cast<AvatarMixerClientData*>(node->getLinkedData());
if (nodeData) {
nodeData->processPackets();
}
void AvatarMixerSlave::harvestStats(int& nodesProcessed, int& packetsProcessed, quint64& processIncomingPacketsElapsedTime) {
nodesProcessed = _nodesProcessed;
packetsProcessed = _packetsProcessed;
processIncomingPacketsElapsedTime = _processIncomingPacketsElapsedTime;
_packetsProcessed = _nodesProcessed = 0;
_processIncomingPacketsElapsedTime = 0;
}
void AvatarMixerSlave::processIncomingPackets(const SharedNodePointer& node) {
auto start = usecTimestampNow();
auto nodeData = dynamic_cast<AvatarMixerClientData*>(node->getLinkedData());
if (nodeData) {
_nodesProcessed++;
_packetsProcessed += nodeData->processPackets();
}
auto end = usecTimestampNow();
_processIncomingPacketsElapsedTime += (end - start);
}

View file

@ -29,10 +29,16 @@ public:
void processIncomingPackets(const SharedNodePointer& node);
void harvestStats(int& nodesProcessed, int& packetsProcessed, quint64& processIncomingPacketsElapsedTime);
private:
// frame state
ConstIter _begin;
ConstIter _end;
int _nodesProcessed { 0 };
int _packetsProcessed { 0 };
quint64 _processIncomingPacketsElapsedTime { 0 };
};
#endif // hifi_AvatarMixerSlave_h