Mirrors/overte
3
0
Fork 0
mirror of https://github.com/overte-org/overte.git synced 2025-08-07 13:50:35 +02:00
Code Issues Projects Releases Packages Wiki Activity Actions

Merge pull request #3274 from wangyix/leo_stats

Browse source 
Added domain setting to make AudioMixer print audiostream stats to stdout every second;  Added per-report prints to jittertester
This commit is contained in:
Leonardo Murillo 2014-08-13 10:43:20 -07:00
commit 08382327b4
8 changed files with 207 additions and 20 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

18
assignment-client/src/audio/AudioMixer.cpp
View file

@ -71,6 +71,8 @@ bool AudioMixer::_useDynamicJitterBuffers = false;
int AudioMixer::_staticDesiredJitterBufferFrames = 0;
int AudioMixer::_maxFramesOverDesired = 0;
bool AudioMixer::_printStreamStats = false;
AudioMixer::AudioMixer(const QByteArray& packet) :
ThreadedAssignment(packet),
_trailingSleepRatio(1.0f),
@ -448,7 +450,11 @@ void AudioMixer::run() {
}
qDebug() << "Max frames over desired:" << _maxFramesOverDesired;
const QString PRINT_STREAM_STATS_JSON_KEY = "H-print-stream-stats";
_printStreamStats = audioGroupObject[PRINT_STREAM_STATS_JSON_KEY].toBool();
if (_printStreamStats) {
qDebug() << "Stream stats will be printed to stdout";
}
const QString UNATTENUATED_ZONE_KEY = "D-unattenuated-zone";
@ -547,6 +553,7 @@ void AudioMixer::run() {
sendAudioStreamStats = true;
}
bool streamStatsPrinted = false;
foreach (const SharedNodePointer& node, nodeList->getNodeHash()) {
if (node->getLinkedData()) {
AudioMixerClientData* nodeData = (AudioMixerClientData*)node->getLinkedData();
@ -581,12 +588,21 @@ 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;
}
}
++_sumListeners;
}
}
}
if (streamStatsPrinted) {
printf("\n----------------------------------------------------------------\n");
}
++_numStatFrames;

2
assignment-client/src/audio/AudioMixer.h
View file

@ -66,6 +66,8 @@ private:
static int _staticDesiredJitterBufferFrames;
static int _maxFramesOverDesired;
static bool _printStreamStats;
quint64 _lastSendAudioStreamStatsTime;
};

45
assignment-client/src/audio/AudioMixerClientData.cpp
View file

@ -22,7 +22,8 @@
AudioMixerClientData::AudioMixerClientData() :
_audioStreams(),
_outgoingMixedAudioSequenceNumber(0)
_outgoingMixedAudioSequenceNumber(0),
_downstreamAudioStreamStats()
{
}
@ -263,3 +264,45 @@ QString AudioMixerClientData::getAudioStreamStatsString() const {
}
return result;
}
void AudioMixerClientData::printUpstreamDownstreamStats() const {
// print the upstream (mic stream) stats if the mic stream exists
if (_audioStreams.contains(QUuid())) {
printf("Upstream:\n");
printAudioStreamStats(_audioStreams.value(QUuid())->getAudioStreamStats());
}
// print the downstream stats if they contain valid info
if (_downstreamAudioStreamStats._packetStreamStats._received > 0) {
printf("Downstream:\n");
printAudioStreamStats(_downstreamAudioStreamStats);
}
}
void AudioMixerClientData::printAudioStreamStats(const AudioStreamStats& streamStats) const {
printf(" Packet loss | overall: %5.2f%% (%d lost), last_30s: %5.2f%% (%d lost)\n",
streamStats._packetStreamStats.getLostRate() * 100.0f,
streamStats._packetStreamStats._lost,
streamStats._packetStreamWindowStats.getLostRate() * 100.0f,
streamStats._packetStreamWindowStats._lost);
printf(" Ringbuffer frames | desired: %u, avg_available(10s): %u, available: %u\n",
streamStats._desiredJitterBufferFrames,
streamStats._framesAvailableAverage,
streamStats._framesAvailable);
printf(" Ringbuffer stats | starves: %u, prev_starve_lasted: %u, frames_dropped: %u, overflows: %u\n",
streamStats._starveCount,
streamStats._consecutiveNotMixedCount,
streamStats._framesDropped,
streamStats._overflowCount);
printf(" Inter-packet timegaps (overall) | min: %9s, max: %9s, avg: %9s\n",
formatUsecTime(streamStats._timeGapMin).toLatin1().data(),
formatUsecTime(streamStats._timeGapMax).toLatin1().data(),
formatUsecTime(streamStats._timeGapAverage).toLatin1().data());
printf(" Inter-packet timegaps (last 30s) | min: %9s, max: %9s, avg: %9s\n",
formatUsecTime(streamStats._timeGapWindowMin).toLatin1().data(),
formatUsecTime(streamStats._timeGapWindowMax).toLatin1().data(),
formatUsecTime(streamStats._timeGapWindowAverage).toLatin1().data());
}

5
assignment-client/src/audio/AudioMixerClientData.h
View file

@ -38,6 +38,11 @@ public:
void incrementOutgoingMixedAudioSequenceNumber() { _outgoingMixedAudioSequenceNumber++; }
quint16 getOutgoingSequenceNumber() const { return _outgoingMixedAudioSequenceNumber; }
void printUpstreamDownstreamStats() const;
private:
void printAudioStreamStats(const AudioStreamStats& streamStats) const;
private:
QHash<QUuid, PositionalAudioStream*> _audioStreams; // mic stream stored under key of null UUID

6
domain-server/resources/web/settings/describe.json
View file

@ -20,6 +20,12 @@
"help": "The highest number of frames an AudioMixer's ringbuffer can exceed the desired jitter buffer frames by",
"placeholder": "10",
"default": "10"
},
"H-print-stream-stats": {
"type": "checkbox",
"label": "Print Stream Stats:",
"help": "If enabled, audio upstream and downstream stats of each agent will be printed each second to stdout",
"default": false
},
"D-unattenuated-zone": {
"label": "Unattenuated Zone",

25
libraries/networking/src/SequenceNumberStats.cpp
View file

@ -253,14 +253,19 @@ PacketStreamStats SequenceNumberStats::getStatsForHistoryWindow() const {
}
// calculate difference between newest stats and oldest stats to get window stats
PacketStreamStats windowStats;
windowStats._received = newestStats->_received - oldestStats->_received;
windowStats._unreasonable = newestStats->_unreasonable - oldestStats->_unreasonable;
windowStats._early = newestStats->_early - oldestStats->_early;
windowStats._late = newestStats->_late - oldestStats->_late;
windowStats._lost = newestStats->_lost - oldestStats->_lost;
windowStats._recovered = newestStats->_recovered - oldestStats->_recovered;
windowStats._expectedReceived = newestStats->_expectedReceived - oldestStats->_expectedReceived;
return windowStats;
return *newestStats - *oldestStats;
}
PacketStreamStats SequenceNumberStats::getStatsForLastHistoryInterval() const {
const PacketStreamStats* newestStats = _statsHistory.getNewestEntry();
const PacketStreamStats* secondNewestStats = _statsHistory.get(1);
// this catches cases where history is length 1 or 0 (both are NULL in case of 0)
if (newestStats == NULL || secondNewestStats == NULL) {
return PacketStreamStats();
}
return *newestStats - *secondNewestStats;
}

13
libraries/networking/src/SequenceNumberStats.h
View file

@ -31,6 +31,18 @@ public:
_expectedReceived(0)
{}
PacketStreamStats operator-(const PacketStreamStats& rhs) const {
PacketStreamStats diff;
diff._received = _received - rhs._received;
diff._unreasonable = _unreasonable - rhs._unreasonable;
diff._early = _early - rhs._early;
diff._late = _late - rhs._late;
diff._lost = _lost - rhs._lost;
diff._recovered = _recovered - rhs._recovered;
diff._expectedReceived = _expectedReceived - rhs._expectedReceived;
return diff;
}
float getLostRate() const { return (float)_lost / _expectedReceived; }
quint32 _received;
@ -76,6 +88,7 @@ public:
const PacketStreamStats& getStats() const { return _stats; }
PacketStreamStats getStatsForHistoryWindow() const;
PacketStreamStats getStatsForLastHistoryInterval() const;
const QSet<quint16>& getMissingSet() const { return _missingSet; }
private:

113
tests/jitter/src/main.cpp
View file

@ -16,6 +16,8 @@
#include <stdio.h>
#include <MovingMinMaxAvg.h> // for MovingMinMaxAvg
#include <SequenceNumberStats.h>
#include <StdDev.h>
#include <SharedUtil.h> // for usecTimestampNow
const quint64 MSEC_TO_USEC = 1000;
@ -62,6 +64,8 @@ void runSend(const char* addressOption, int port, int gap, int size, int report)
char* outputBuffer = new char[size];
memset(outputBuffer, 0, size);
quint16 outgoingSequenceNumber = 0;
sockfd=socket(AF_INET,SOCK_DGRAM,0);
memset(&servaddr, 0, sizeof(servaddr));
@ -75,6 +79,16 @@ void runSend(const char* addressOption, int port, int gap, int size, int report)
MovingMinMaxAvg<int> timeGaps(1, SAMPLES_FOR_30_SECONDS); // stats
const int SAMPLES_PER_REPORT = report * MSEC_TO_USEC / gap;
std::cout << "SAMPLES_PER_REPORT:" << SAMPLES_PER_REPORT << "\n";
MovingMinMaxAvg<int> timeGapsPerReport(1, SAMPLES_PER_REPORT);
StDev stDevReportInterval;
StDev stDev30s;
StDev stDev;
quint64 last = usecTimestampNow();
quint64 lastReport = 0;
@ -85,21 +99,47 @@ void runSend(const char* addressOption, int port, int gap, int size, int report)
if (actualGap >= gap) {
// pack seq num
memcpy(outputBuffer, &outgoingSequenceNumber, sizeof(quint16));
sendto(sockfd, outputBuffer, size, 0, (struct sockaddr *)&servaddr, sizeof(servaddr));
outgoingSequenceNumber++;
int gapDifferece = actualGap - gap;
timeGaps.update(gapDifferece);
timeGapsPerReport.update(gapDifferece);
stDev.addValue(gapDifferece);
stDev30s.addValue(gapDifferece);
stDevReportInterval.addValue(gapDifferece);
last = now;
if (now - lastReport >= (report * MSEC_TO_USEC)) {
std::cout << "SEND gap Difference From Expected "
std::cout << "\n"
<< "SEND gap Difference From Expected\n"
<< "Overall:\n"
<< "min: " << timeGaps.getMin() << " usecs, "
<< "max: " << timeGaps.getMax() << " usecs, "
<< "avg: " << timeGaps.getAverage() << " usecs, "
<< "min last 30: " << timeGaps.getWindowMin() << " usecs, "
<< "max last 30: " << timeGaps.getWindowMax() << " usecs, "
<< "avg last 30: " << timeGaps.getWindowAverage() << " usecs "
<< "stdev: " << stDev.getStDev() << " usecs\n"
<< "Last 30s:\n"
<< "min: " << timeGaps.getWindowMin() << " usecs, "
<< "max: " << timeGaps.getWindowMax() << " usecs, "
<< "avg: " << timeGaps.getWindowAverage() << " usecs, "
<< "stdev: " << stDev30s.getStDev() << " usecs\n"
<< "Last report interval:\n"
<< "min: " << timeGapsPerReport.getWindowMin() << " usecs, "
<< "max: " << timeGapsPerReport.getWindowMax() << " usecs, "
<< "avg: " << timeGapsPerReport.getWindowAverage() << " usecs, "
<< "stdev: " << stDevReportInterval.getStDev() << " usecs\n"
<< "\n";
stDevReportInterval.reset();
if (stDev30s.getSamples() > SAMPLES_FOR_30_SECONDS) {
stDev30s.reset();
}
lastReport = now;
}
}
@ -129,6 +169,22 @@ void runReceive(const char* addressOption, int port, int gap, int size, int repo
MovingMinMaxAvg<int> timeGaps(1, SAMPLES_FOR_30_SECONDS); // stats
const int SAMPLES_PER_REPORT = report * MSEC_TO_USEC / gap;
std::cout << "SAMPLES_PER_REPORT:" << SAMPLES_PER_REPORT << "\n";
MovingMinMaxAvg<int> timeGapsPerReport(1, SAMPLES_PER_REPORT);
const int REPORTS_FOR_30_SECONDS = 30 * MSECS_PER_SECOND / report;
std::cout << "REPORTS_FOR_30_SECONDS:" << REPORTS_FOR_30_SECONDS << "\n";
SequenceNumberStats seqStats(REPORTS_FOR_30_SECONDS);
StDev stDevReportInterval;
StDev stDev30s;
StDev stDev;
if (bind(sockfd, (struct sockaddr *)&myaddr, sizeof(myaddr)) < 0) {
std::cout << "bind failed\n";
return;
@ -140,6 +196,10 @@ 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
// parse seq num
quint16 incomingSequenceNumber = *(reinterpret_cast<quint16*>(inputBuffer));
seqStats.sequenceNumberReceived(incomingSequenceNumber);
if (last == 0) {
last = usecTimestampNow();
std::cout << "first packet received\n";
@ -148,17 +208,54 @@ void runReceive(const char* addressOption, int port, int gap, int size, int repo
int actualGap = now - last;
int gapDifferece = actualGap - gap;
timeGaps.update(gapDifferece);
timeGapsPerReport.update(gapDifferece);
stDev.addValue(gapDifferece);
stDev30s.addValue(gapDifferece);
stDevReportInterval.addValue(gapDifferece);
last = now;
if (now - lastReport >= (report * MSEC_TO_USEC)) {
std::cout << "RECEIVE gap Difference From Expected "
seqStats.pushStatsToHistory();
std::cout << "RECEIVE gap Difference From Expected\n"
<< "Overall:\n"
<< "min: " << timeGaps.getMin() << " usecs, "
<< "max: " << timeGaps.getMax() << " usecs, "
<< "avg: " << timeGaps.getAverage() << " usecs, "
<< "min last 30: " << timeGaps.getWindowMin() << " usecs, "
<< "max last 30: " << timeGaps.getWindowMax() << " usecs, "
<< "avg last 30: " << timeGaps.getWindowAverage() << " usecs "
<< "stdev: " << stDev.getStDev() << " usecs\n"
<< "Last 30s:\n"
<< "min: " << timeGaps.getWindowMin() << " usecs, "
<< "max: " << timeGaps.getWindowMax() << " usecs, "
<< "avg: " << timeGaps.getWindowAverage() << " usecs, "
<< "stdev: " << stDev30s.getStDev() << " usecs\n"
<< "Last report interval:\n"
<< "min: " << timeGapsPerReport.getWindowMin() << " usecs, "
<< "max: " << timeGapsPerReport.getWindowMax() << " usecs, "
<< "avg: " << timeGapsPerReport.getWindowAverage() << " usecs, "
<< "stdev: " << stDevReportInterval.getStDev() << " usecs\n"
<< "\n";
stDevReportInterval.reset();
if (stDev30s.getSamples() > SAMPLES_FOR_30_SECONDS) {
stDev30s.reset();
}
PacketStreamStats packetStatsLast30s = seqStats.getStatsForHistoryWindow();
PacketStreamStats packetStatsLastReportInterval = seqStats.getStatsForLastHistoryInterval();
std::cout << "RECEIVE Packet Stats\n"
<< "Overall:\n"
<< "lost: " << seqStats.getLost() << ", "
<< "lost %: " << seqStats.getStats().getLostRate() * 100.0f << "%\n"
<< "Last 30s:\n"
<< "lost: " << packetStatsLast30s._lost << ", "
<< "lost %: " << packetStatsLast30s.getLostRate() * 100.0f << "%\n"
<< "Last report interval:\n"
<< "lost: " << packetStatsLastReportInterval._lost << ", "
<< "lost %: " << packetStatsLastReportInterval.getLostRate() * 100.0f << "%\n"
<< "\n\n";
lastReport = now;
}
}