From 81fa5ed41fd090864732516aab6d9e7239271866 Mon Sep 17 00:00:00 2001 From: wangyix Date: Wed, 13 Aug 2014 16:48:06 -0700 Subject: [PATCH] readPendingDatagrams stats printed and sent to domain page jittertester now prints out send or receive error msgs --- assignment-client/src/audio/AudioMixer.cpp | 95 ++++++++++++++++++---- assignment-client/src/audio/AudioMixer.h | 1 + libraries/shared/src/MovingMinMaxAvg.h | 20 ++++- tests/jitter/src/main.cpp | 11 ++- 4 files changed, 108 insertions(+), 19 deletions(-) diff --git a/assignment-client/src/audio/AudioMixer.cpp b/assignment-client/src/audio/AudioMixer.cpp index 3fe872d57c..d32f14ac0f 100644 --- a/assignment-client/src/audio/AudioMixer.cpp +++ b/assignment-client/src/audio/AudioMixer.cpp @@ -404,9 +404,24 @@ void AudioMixer::sendStatsPacket() { int sizeOfStats = 0; int TOO_BIG_FOR_MTU = 1200; // some extra space for JSONification + QString property = "readPendingDatagramsStats"; + QString value = getReadPendingDatagramsStatsString(); + statsObject2[qPrintable(property)] = value; + somethingToSend = true; + sizeOfStats += property.size() + value.size(); + NodeList* nodeList = NodeList::getInstance(); int clientNumber = 0; foreach (const SharedNodePointer& node, nodeList->getNodeHash()) { + + // if we're too large, send the packet + if (sizeOfStats > TOO_BIG_FOR_MTU) { + nodeList->sendStatsToDomainServer(statsObject2); + sizeOfStats = 0; + statsObject2 = QJsonObject(); // clear it + somethingToSend = false; + } + clientNumber++; AudioMixerClientData* clientData = static_cast(node->getLinkedData()); if (clientData) { @@ -416,14 +431,6 @@ void AudioMixer::sendStatsPacket() { somethingToSend = true; sizeOfStats += property.size() + value.size(); } - - // if we're too large, send the packet - if (sizeOfStats > TOO_BIG_FOR_MTU) { - nodeList->sendStatsToDomainServer(statsObject2); - sizeOfStats = 0; - statsObject2 = QJsonObject(); // clear it - somethingToSend = false; - } } if (somethingToSend) { @@ -682,11 +689,6 @@ void AudioMixer::run() { // send an audio stream stats packet if it's time if (_sendAudioStreamStats) { nodeData->sendAudioStreamStatsPackets(node); - if (_printStreamStats) { - printf("\nStats for agent %s:\n", node->getUUID().toString().toLatin1().data()); - nodeData->printUpstreamDownstreamStats(); - streamStatsPrinted = true; - } _sendAudioStreamStats = false; } @@ -694,9 +696,6 @@ void AudioMixer::run() { } } } - if (streamStatsPrinted) { - printf("\n----------------------------------------------------------------\n"); - } ++_numStatFrames; @@ -720,7 +719,71 @@ void AudioMixer::perSecondActions() { int callsLastSecond = _datagramsReadPerCallStats.getCurrentIntervalSamples(); _readPendingCallsPerSecondStats.update(callsLastSecond); + if (_printStreamStats) { + + printf("\n================================================================================\n\n"); + + printf(" readPendingDatagram() calls per second | avg: %.2f, avg_30s: %.2f, last_second: %d\n", + _readPendingCallsPerSecondStats.getAverage(), + _readPendingCallsPerSecondStats.getWindowAverage(), + callsLastSecond); + + printf(" Datagrams read per call | avg: %.2f, avg_30s: %.2f, last_second: %.2f\n", + _datagramsReadPerCallStats.getAverage(), + _datagramsReadPerCallStats.getWindowAverage(), + _datagramsReadPerCallStats.getCurrentIntervalAverage()); + + printf(" Usecs spent per readPendingDatagram() call | avg: %.2f, avg_30s: %.2f, last_second: %.2f\n", + _timeSpentPerCallStats.getAverage(), + _timeSpentPerCallStats.getWindowAverage(), + _timeSpentPerCallStats.getCurrentIntervalAverage()); + + printf(" Usecs spent per packetVersionAndHashMatch() call | avg: %.2f, avg_30s: %.2f, last_second: %.2f\n", + _timeSpentPerHashMatchCallStats.getAverage(), + _timeSpentPerHashMatchCallStats.getWindowAverage(), + _timeSpentPerHashMatchCallStats.getCurrentIntervalAverage()); + + double WINDOW_LENGTH_USECS = READ_DATAGRAMS_STATS_WINDOW_SECONDS * USECS_PER_SECOND; + + printf(" %% time spent in readPendingDatagram() calls | avg_30s: %.6f%%, last_second: %.6f%%\n", + _timeSpentPerCallStats.getWindowSum() / WINDOW_LENGTH_USECS * 100.0, + _timeSpentPerCallStats.getCurrentIntervalSum() / USECS_PER_SECOND * 100.0); + + printf("%% time spent in packetVersionAndHashMatch() calls: | avg_30s: %.6f%%, last_second: %.6f%%\n", + _timeSpentPerHashMatchCallStats.getWindowSum() / WINDOW_LENGTH_USECS * 100.0, + _timeSpentPerHashMatchCallStats.getCurrentIntervalSum() / USECS_PER_SECOND * 100.0); + + foreach(const SharedNodePointer& node, NodeList::getInstance()->getNodeHash()) { + if (node->getLinkedData()) { + AudioMixerClientData* nodeData = (AudioMixerClientData*)node->getLinkedData(); + + if (node->getType() == NodeType::Agent && node->getActiveSocket()) { + printf("\nStats for agent %s --------------------------------\n", + node->getUUID().toString().toLatin1().data()); + nodeData->printUpstreamDownstreamStats(); + } + } + } + } + _datagramsReadPerCallStats.currentIntervalComplete(); _timeSpentPerCallStats.currentIntervalComplete(); _timeSpentPerHashMatchCallStats.currentIntervalComplete(); } + +QString AudioMixer::getReadPendingDatagramsStatsString() const { + QString result + = "calls_per_sec_avg_30s: " + QString::number(_readPendingCallsPerSecondStats.getWindowAverage(), 'f', 2) + + " calls_last_sec: " + QString::number(_readPendingCallsPerSecondStats.getLastCompleteIntervalStats().getSum() + 0.5, 'f', 0) + + " pkts_per_call_avg_30s: " + QString::number(_datagramsReadPerCallStats.getWindowAverage(), 'f', 2) + + " pkts_per_call_avg_1s: " + QString::number(_datagramsReadPerCallStats.getLastCompleteIntervalStats().getAverage(), 'f', 2) + + " usecs_per_call_avg_30s: " + QString::number(_timeSpentPerCallStats.getWindowAverage(), 'f', 2) + + " usecs_per_call_avg_1s: " + QString::number(_timeSpentPerCallStats.getLastCompleteIntervalStats().getAverage(), 'f', 2) + + " usecs_per_hashmatch_avg_30s: " + QString::number(_timeSpentPerHashMatchCallStats.getWindowAverage(), 'f', 2) + + " usecs_per_hashmatch_avg_1s: " + QString::number(_timeSpentPerHashMatchCallStats.getLastCompleteIntervalStats().getAverage(), 'f', 2) + + " prct_time_in_call_30s: " + QString::number(_timeSpentPerCallStats.getWindowSum() / (READ_DATAGRAMS_STATS_WINDOW_SECONDS*USECS_PER_SECOND) * 100.0, 'f', 6) + "%" + + " prct_time_in_call_1s: " + QString::number(_timeSpentPerCallStats.getLastCompleteIntervalStats().getSum() / USECS_PER_SECOND * 100.0, 'f', 6) + "%" + + " prct_time_in_hashmatch_30s: " + QString::number(_timeSpentPerHashMatchCallStats.getWindowSum() / (READ_DATAGRAMS_STATS_WINDOW_SECONDS*USECS_PER_SECOND) * 100.0, 'f', 6) + "%" + + " prct_time_in_hashmatch_1s: " + QString::number(_timeSpentPerHashMatchCallStats.getLastCompleteIntervalStats().getSum() / USECS_PER_SECOND * 100.0, 'f', 6) + "%"; + return result; +} \ No newline at end of file diff --git a/assignment-client/src/audio/AudioMixer.h b/assignment-client/src/audio/AudioMixer.h index e47c5f3811..0c1378d54f 100644 --- a/assignment-client/src/audio/AudioMixer.h +++ b/assignment-client/src/audio/AudioMixer.h @@ -54,6 +54,7 @@ private: void perSecondActions(); + QString getReadPendingDatagramsStatsString() const; float _trailingSleepRatio; float _minAudibilityThreshold; diff --git a/libraries/shared/src/MovingMinMaxAvg.h b/libraries/shared/src/MovingMinMaxAvg.h index 16fcb94dcf..4a044392c1 100644 --- a/libraries/shared/src/MovingMinMaxAvg.h +++ b/libraries/shared/src/MovingMinMaxAvg.h @@ -64,6 +64,7 @@ public: T getMax() const { return _max; } double getAverage() const { return _average; } int getSamples() const { return _samples; } + double getSum() const { return _samples * _average; } private: T _min; @@ -152,14 +153,29 @@ public: T getMin() const { return _overallStats.getMin(); } T getMax() const { return _overallStats.getMax(); } double getAverage() const { return _overallStats.getAverage(); } + int getSamples() const { return _overallStats.getSamples(); } + double getSum() const { return _overallStats.getSum(); } + T getWindowMin() const { return _windowStats.getMin(); } T getWindowMax() const { return _windowStats.getMax(); } double getWindowAverage() const { return _windowStats.getAverage(); } + int getWindowSamples() const { return _windowStats.getSamples(); } + double getWindowSum() const { return _windowStats.getSum(); } - int getCurrentIntervalSamples() const { return _windowStats._samples; } - + T getCurrentIntervalMin() const { return _currentIntervalStats.getMin(); } + T getCurrentIntervalMax() const { return _currentIntervalStats.getMax(); } + double getCurrentIntervalAverage() const { return _currentIntervalStats.getAverage(); } + int getCurrentIntervalSamples() const { return _currentIntervalStats.getSamples(); } + double getCurrentIntervalSum() const { return _currentIntervalStats.getSum(); } + const MinMaxAvg& getOverallStats() const{ return _overallStats; } const MinMaxAvg& getWindowStats() const{ return _windowStats; } + const MinMaxAvg& getCurrentIntervalStats() const { return _currentIntervalStats; } + + MinMaxAvg getLastCompleteIntervalStats() const { + const MinMaxAvg* stats = _intervalStats.getNewestEntry(); + return stats == NULL ? MinMaxAvg() : *stats; + } bool isWindowFilled() const { return _intervalStats.isFilled(); } diff --git a/tests/jitter/src/main.cpp b/tests/jitter/src/main.cpp index a33347f9ef..07dc7062a8 100644 --- a/tests/jitter/src/main.cpp +++ b/tests/jitter/src/main.cpp @@ -13,6 +13,7 @@ #include #include #endif +#include #include #include // for MovingMinMaxAvg @@ -103,7 +104,10 @@ void runSend(const char* addressOption, int port, int gap, int size, int report) // pack seq num memcpy(outputBuffer, &outgoingSequenceNumber, sizeof(quint16)); - sendto(sockfd, outputBuffer, size, 0, (struct sockaddr *)&servaddr, sizeof(servaddr)); + int n = sendto(sockfd, outputBuffer, size, 0, (struct sockaddr *)&servaddr, sizeof(servaddr)); + if (n < 0) { + std::cout << "Send error: " << strerror(errno) << "\n"; + } outgoingSequenceNumber++; int gapDifferece = actualGap - gap; @@ -144,6 +148,7 @@ void runSend(const char* addressOption, int port, int gap, int size, int report) } } } + delete[] outputBuffer; } void runReceive(const char* addressOption, int port, int gap, int size, int report) { @@ -195,6 +200,9 @@ void runReceive(const char* addressOption, int port, int gap, int size, int repo while (true) { n = recvfrom(sockfd, inputBuffer, size, 0, NULL, NULL); // we don't care about where it came from + if (n < 0) { + std::cout << "Receive error: " << strerror(errno) << "\n"; + } // parse seq num quint16 incomingSequenceNumber = *(reinterpret_cast(inputBuffer)); @@ -260,5 +268,6 @@ void runReceive(const char* addressOption, int port, int gap, int size, int repo } } } + delete[] inputBuffer; }