Reports buffer period glitch timestamps and intervals
Test: dumpsys media.log
Change-Id: I3f386fdfc997f14cc825aa7f39e86488ccf0fcd2
diff --git a/media/libnbaio/NBLog.cpp b/media/libnbaio/NBLog.cpp
index 73adff6..8bbb686 100644
--- a/media/libnbaio/NBLog.cpp
+++ b/media/libnbaio/NBLog.cpp
@@ -941,6 +941,7 @@
mFd = fd;
mIndent = indent;
String8 timestamp, body;
+ PerformanceAnalysis performanceAnalyzer; // used to call analysis functions
size_t lost = snapshot.lost() + (snapshot.begin() - EntryIterator(snapshot.data()));
if (lost > 0) {
body.appendFormat("warning: lost %zu bytes worth of events", lost);
@@ -969,9 +970,11 @@
// store time series data for each reader in order to bucket it once there
// is enough data. Then, it is written to recentHists as a histogram.
mTimeStampSeries[data->author].push_back(ts);
- // if length of the time series has reached kShortHistSize samples,
- // compute its histogram, append this to mRecentHists and erase the time series
+ // if length of the time series has reached kShortHistSize samples, do 1) and 2):
if (mTimeStampSeries[data->author].size() >= kShortHistSize) {
+ // 1) analyze the series to store all outliers and their exact timestamps:
+ performanceAnalyzer.storeOutlierData(data->author, mTimeStampSeries[data->author]);
+ // 2) compute its histogram, append this to mRecentHists and erase the time series
mRecentHists.emplace_front(data->author,
buildBuckets(mTimeStampSeries[data->author]));
// do not let mRecentHists exceed capacity
@@ -1001,11 +1004,12 @@
break;
}
}
- PerformanceAnalysis performanceAnalyzer;
performanceAnalyzer.reportPerformance(&body, mRecentHists);
if (!body.isEmpty()) {
dumpLine(timestamp, body);
}
+ // comment in for tests
+ // performanceAnalyzer.testFunction();
}
void NBLog::Reader::dump(int fd, size_t indent)
diff --git a/media/libnbaio/PerformanceAnalysis.cpp b/media/libnbaio/PerformanceAnalysis.cpp
index b3d5f1f..84b7635 100644
--- a/media/libnbaio/PerformanceAnalysis.cpp
+++ b/media/libnbaio/PerformanceAnalysis.cpp
@@ -22,7 +22,6 @@
#include <climits>
#include <deque>
#include <fstream>
-// #include <inttypes.h>
#include <iostream>
#include <math.h>
#include <numeric>
@@ -47,8 +46,7 @@
namespace android {
PerformanceAnalysis::PerformanceAnalysis() : findGlitch(false) {
- ALOGE("this value should be 4: %d", kPeriodMs);
- kPeriodMsCPU = static_cast<int>(PerformanceAnalysis::kPeriodMs * kRatio);
+ kPeriodMsCPU = static_cast<int>(PerformanceAnalysis::kPeriodMs * kRatio);
}
static int widthOf(int x) {
@@ -60,55 +58,57 @@
return width;
}
-// WIP: uploading this half-written function to get code review on
-// cleanup and new file creation.
-/*
-static std::vector<std::pair<int, int>> outlierIntervals(
- const std::deque<std::pair<int, short_histogram>> &shortHists) {
- // TODO: need the timestamps
- if (shortHists.size() < 1) {
+// FIXME: delete this temporary test code, recycled for various new functions
+void PerformanceAnalysis::testFunction() {
+ // produces values (4: 5000000), (13: 18000000)
+ // ns timestamps of buffer periods
+ const std::vector<int64_t>kTempTestData = {1000000, 4000000, 5000000,
+ 16000000, 18000000, 28000000};
+ const int kTestAuthor = 1;
+ PerformanceAnalysis::storeOutlierData(kTestAuthor, kTempTestData);
+ for (const auto &outlier: mOutlierData) {
+ ALOGE("PerformanceAnalysis test %lld: %lld",
+ static_cast<long long>(outlier.first), static_cast<long long>(outlier.second));
+ }
+}
+
+// Each pair consists of: <outlier timestamp, time elapsed since previous outlier>.
+// The timestamp of the beginning of the outlier is recorded.
+// The elapsed time is from the timestamp of the previous outlier
+// e.g. timestamps (ms) 1, 4, 5, 16, 18, 28 will produce pairs (4, 5), (13, 18).
+// This function is applied to the time series before it is converted into a histogram.
+void PerformanceAnalysis::storeOutlierData(
+ int author, const std::vector<int64_t> ×tamps) {
+ if (timestamps.size() < 1) {
+ ALOGE("storeOutlierData called on empty vector");
return;
}
- // count number of outliers in histogram
- // TODO: need the alertIfGlitch analysis on the time series in NBLog::reader
- // to find all the glitches
- const std::vector<int> glitchCount = std::vector<int>(shortHists.size());
- // Total ms elapsed in each shortHist
- const std::vector<int> timeElapsedMs = std::vector<int>(shortHists.size());
- int i = 0;
- for (const auto &shortHist: shortHists) {
- for (const auto &bin: shortHist) {
- timeElapsedMs.at(i) += bin->first * bin->second;
- if (bin->first >= kGlitchThreshMs) {
- glitchCount.at(i) += bin->second;
- }
+ author++; // temp to avoid unused error until this value is
+ // either TODO: used or discarded from the arglist
+ author--;
+ uint64_t elapsed = 0;
+ int64_t prev = timestamps.at(0);
+ for (const auto &ts: timestamps) {
+ const uint64_t diff = static_cast<uint64_t>(deltaMs(prev, ts));
+ if (diff >= static_cast<uint64_t>(kOutlierMs)) {
+ mOutlierData.emplace_back(elapsed, static_cast<uint64_t>(prev));
+ elapsed = 0;
}
- i++;
+ elapsed += diff;
+ prev = ts;
}
- // seconds between glitches and corresponding timestamp
- const std::vector<std::pair<double, int>> glitchFreeIntervalsSec;
- // Sec since last glitch. nonzero if the duration spans many shortHists
- double glitchFreeSec = 0;
- for (int i = 0; i < kGlitchCount.size(); i++) {
- if (kGlitchCount.at(i) == 0) {
- glitchFreeSec += static_cast<double>timeElapsedMs.at(i) / kMsPerSec;
- }
- else {
- // average time between glitches in this interval
- const double kInterval = static_cast<double>(timeElapsedMs.at(i)) / kGlitchCount.at(i);
- for (int j = 0; j < kGlitchCount.at(i); j++) {
- kIntervals.emplace_front(kInterval);
- }
- }
- }
- return;
-}*/
+ // ALOGE("storeOutlierData: result length %zu", outlierData.size());
+ // for (const auto &outlier: OutlierData) {
+ // ALOGE("PerformanceAnalysis test %lld: %lld",
+ // static_cast<long long>(outlier.first), static_cast<long long>(outlier.second));
+ //}
+}
// TODO: implement peak detector
/*
-static void peakDetector() {
- return;
-} */
+ static void peakDetector() {
+ return;
+ } */
// TODO put this function in separate file. Make it return a std::string instead of modifying body
// TODO create a subclass of Reader for this and related work
@@ -117,9 +117,9 @@
// TODO: build histogram buckets earlier and discard timestamps to save memory
// TODO consider changing all ints to uint32_t or uint64_t
void PerformanceAnalysis::reportPerformance(String8 *body,
- const std::deque<std::pair
- <int, short_histogram>> &shortHists,
- int maxHeight) {
+ const std::deque<std::pair
+ <int, short_histogram>> &shortHists,
+ int maxHeight) {
if (shortHists.size() < 1) {
return;
}
@@ -189,6 +189,13 @@
}
body->appendFormat("%.*s%s", colWidth, spaces.c_str(), "ms\n");
+ // Now report glitches
+ body->appendFormat("\ntime elapsed between glitches and glitch timestamps\n");
+ for (const auto &outlier: mOutlierData) {
+ body->appendFormat("%lld: %lld\n", static_cast<long long>(outlier.first),
+ static_cast<long long>(outlier.second));
+ }
+
}
@@ -224,7 +231,5 @@
{
findGlitch = s;
}
-//TODO: ask Andy where to keep '= 4'
-const int PerformanceAnalysis::kPeriodMs; // = 4;
} // namespace android
diff --git a/media/libnbaio/include/PerformanceAnalysis.h b/media/libnbaio/include/PerformanceAnalysis.h
index fb82099..32ae38b 100644
--- a/media/libnbaio/include/PerformanceAnalysis.h
+++ b/media/libnbaio/include/PerformanceAnalysis.h
@@ -39,12 +39,14 @@
// both in this header file and in NBLog.h?
using short_histogram = std::map<int, int>;
-// returns a 2d array where the first values are ms time intervals between
-// outliers and the second values are the timestamps at which the outliers
-// occurred. The first values do not keep track of time spent *on* the outlier.
+// returns a vector of pairs <outlier timestamp, time elapsed since previous outlier
+// called by NBLog::Reader::dump before data is converted into histogram
+// TODO: currently, the elapsed time
// The resolution is only as good as the ms duration of one shortHist
-// static void outlierIntervals(const std::deque<std::pair
-// <int, short_histogram>> &shortHists);
+void storeOutlierData(int author, const std::vector<int64_t> ×tamps);
+
+// TODO: delete this. temp for testing
+void testFunction();
// Given a series, looks for changes in distribution (peaks)
// Returns a 'signal' array of the same length as the series, where each
@@ -60,10 +62,10 @@
// data to the console
// TODO: change this so that it writes the analysis to the long-term
// circular buffer and prints an analyses both for the short and long-term
-static void reportPerformance(String8 *body,
- const std::deque<std::pair
- <int, short_histogram>> &shortHists,
- int maxHeight = 10);
+void reportPerformance(String8 *body,
+ const std::deque<std::pair
+ <int, short_histogram>> &shortHists,
+ int maxHeight = 10);
// if findGlitch is true, log warning when buffer periods caused glitch
// TODO adapt this to the analysis in reportPerformance instead of logging
@@ -75,6 +77,9 @@
private:
+// stores outlier analysis
+std::vector<std::pair<uint64_t, uint64_t>> mOutlierData;
+
// stores long-term audio performance data
// TODO: Turn it into a circular buffer
std::deque<std::pair<int, int>> mPerformanceAnalysis;
@@ -82,10 +87,11 @@
// alert if a local buffer period sequence caused an audio glitch
bool findGlitch;
//TODO: measure these from the data (e.g., mode) as they may change.
-static const int kGlitchThreshMs = 7;
-static const int kMsPerSec = 1000;
-static const int kNumBuff = 3; // number of buffers considered in local history
-static const int kPeriodMs = 4; // current period length is ideally 4 ms
+//const int kGlitchThreshMs = 7;
+// const int kMsPerSec = 1000;
+const int kNumBuff = 3; // number of buffers considered in local history
+const int kPeriodMs = 4; // current period length is ideally 4 ms
+const int kOutlierMs = 7; // values greater or equal to this cause glitches every time
// DAC processing time for 4 ms buffer
static constexpr double kRatio = 0.75; // estimate of CPU time as ratio of period length
int kPeriodMsCPU; //compute based on kPeriodLen and kRatio