Variable time resolution in histogram (Jiffy)
Changed variable types to make them more consistent,
e.g., always use int64_t. Made histogram take up less
space by adjusting the column with for each value.
Example of results (only the fastmixer histogram's
left half is shown, not the slowmixer's).
Occurrences
2 2 2 7 21 44 122 416 394 123
| |
| |
| | | |
| | | | |
| | | | | |
| | | | | |
| | | | | | |
| | | | | | | | | |
| | | | | | | | | |
________________________________________________
3.2 3.3 3.4 3.5 3.6 3.7 3.8 3.9 4.0 ms
Test: dumpsys media.log
Change-Id: I007a6104c3f62ab04ee386a1de196b267adddecc
diff --git a/media/libnbaio/PerformanceAnalysis.cpp b/media/libnbaio/PerformanceAnalysis.cpp
index c9ca99d..8c2104c 100644
--- a/media/libnbaio/PerformanceAnalysis.cpp
+++ b/media/libnbaio/PerformanceAnalysis.cpp
@@ -46,13 +46,6 @@
namespace ReportPerformance {
-PerformanceAnalysis::PerformanceAnalysis() {
- // These variables will be (FIXME) learned from the data
- kPeriodMs = 4; // typical buffer period (mode)
- // average number of Ms spent processing buffer
- kPeriodMsCPU = static_cast<int>(kPeriodMs * kRatio);
-}
-
static int widthOf(int x) {
int width = 0;
while (x > 0) {
@@ -68,17 +61,39 @@
// buckets the time interval into a histogram, searches for
// outliers, analyzes the outlier series for unexpectedly
// small or large values and stores these as peaks
-void PerformanceAnalysis::logTsEntry(int64_t ts) {
+void PerformanceAnalysis::logTsEntry(timestamp ts) {
// after a state change, start a new series and do not
// record time intervals in-between
- if (mOutlierDistribution.mPrevTs == 0) {
- mOutlierDistribution.mPrevTs = ts;
+ if (mBufferPeriod.mPrevTs == 0) {
+ mBufferPeriod.mPrevTs = ts;
return;
}
+ // calculate time interval between current and previous timestamp
+ const msInterval diffMs = static_cast<msInterval>(
+ deltaMs(mBufferPeriod.mPrevTs, ts));
+
+ const int diffJiffy = deltaJiffy(mBufferPeriod.mPrevTs, ts);
+
+
+ // update buffer period distribution
+ // old versus new weight ratio when updating the buffer period mean
+ static constexpr double exponentialWeight = 0.999;
+ // update buffer period mean with exponential weighting
+ mBufferPeriod.mMean = (mBufferPeriod.mMean < 0) ? diffMs :
+ exponentialWeight * mBufferPeriod.mMean + (1.0 - exponentialWeight) * diffMs;
+ // set mOutlierFactor to a smaller value for the fastmixer thread
+ const int kFastMixerMax = 10;
+ // NormalMixer times vary much more than FastMixer times.
+ // TODO: mOutlierFactor values are set empirically based on what appears to be
+ // an outlier. Learn these values from the data.
+ mBufferPeriod.mOutlierFactor = mBufferPeriod.mMean < kFastMixerMax ? 1.8 : 2.5;
+ // set outlier threshold
+ mBufferPeriod.mOutlier = mBufferPeriod.mMean * mBufferPeriod.mOutlierFactor;
+
// Check whether the time interval between the current timestamp
// and the previous one is long enough to count as an outlier
- const bool isOutlier = detectAndStoreOutlier(ts);
+ const bool isOutlier = detectAndStoreOutlier(diffMs);
// If an outlier was found, check whether it was a peak
if (isOutlier) {
/*bool isPeak =*/ detectAndStorePeak(
@@ -93,7 +108,7 @@
// if the current histogram has spanned its maximum time interval.
if (mHists.empty() ||
deltaMs(mHists[0].first, ts) >= kMaxLength.HistTimespanMs) {
- mHists.emplace_front(static_cast<uint64_t>(ts), std::map<int, int>());
+ mHists.emplace_front(ts, std::map<int, int>());
// When memory is full, delete oldest histogram
// TODO: use a circular buffer
if (mHists.size() >= kMaxLength.Hists) {
@@ -101,16 +116,16 @@
}
}
// add current time intervals to histogram
- ++mHists[0].second[deltaMs(mOutlierDistribution.mPrevTs, ts)];
+ ++mHists[0].second[diffJiffy];
// update previous timestamp
- mOutlierDistribution.mPrevTs = ts;
+ mBufferPeriod.mPrevTs = ts;
}
// forces short-term histogram storage to avoid adding idle audio time interval
// to buffer period data
void PerformanceAnalysis::handleStateChange() {
- mOutlierDistribution.mPrevTs = 0;
+ mBufferPeriod.mPrevTs = 0;
return;
}
@@ -122,7 +137,7 @@
// them as long as no peak is detected. When a value is more than 'threshold'
// standard deviations from the mean, a peak is detected and the mean and sigma
// are set to the peak value and 0.
-bool PerformanceAnalysis::detectAndStorePeak(outlierInterval diff, timestamp ts) {
+bool PerformanceAnalysis::detectAndStorePeak(msInterval diff, timestamp ts) {
bool isPeak = false;
if (mOutlierData.empty()) {
return false;
@@ -135,15 +150,15 @@
// Initialize short-term mean at start of program
if (mOutlierDistribution.mMean == 0) {
- mOutlierDistribution.mMean = static_cast<double>(diff);
+ mOutlierDistribution.mMean = diff;
}
// Update length of current sequence of outliers
mOutlierDistribution.mN++;
- // If statement checks whether a large deviation from the mean occurred.
+ // Check whether a large deviation from the mean occurred.
// If the standard deviation has been reset to zero, the comparison is
// instead to the mean of the full mOutlierInterval sequence.
- if ((fabs(static_cast<double>(diff) - mOutlierDistribution.mMean) <
+ if ((fabs(diff - mOutlierDistribution.mMean) <
mOutlierDistribution.kMaxDeviation * mOutlierDistribution.mSd) ||
(mOutlierDistribution.mSd == 0 &&
fabs(diff - mOutlierDistribution.mMean) <
@@ -176,7 +191,6 @@
mOutlierDistribution.mN = 0;
mOutlierDistribution.mM2 = 0;
}
- ALOGD("outlier distr %f %f", mOutlierDistribution.mMean, mOutlierDistribution.mSd);
return isPeak;
}
@@ -186,13 +200,12 @@
// and writes to mOutlierdata in the following format:
// Time elapsed since previous outlier: Timestamp of start of outlier
// e.g. timestamps (ms) 1, 4, 5, 16, 18, 28 will produce pairs (4, 5), (13, 18).
-bool PerformanceAnalysis::detectAndStoreOutlier(const int64_t ts) {
+bool PerformanceAnalysis::detectAndStoreOutlier(const msInterval diffMs) {
bool isOutlier = false;
- const int64_t diffMs = static_cast<int64_t>(deltaMs(mOutlierDistribution.mPrevTs, ts));
- if (diffMs >= static_cast<int64_t>(kOutlierMs)) {
+ if (diffMs >= mBufferPeriod.mOutlier) {
isOutlier = true;
- mOutlierData.emplace_front(mOutlierDistribution.mElapsed,
- static_cast<uint64_t>(mOutlierDistribution.mPrevTs));
+ mOutlierData.emplace_front(
+ mOutlierDistribution.mElapsed, mBufferPeriod.mPrevTs);
// Remove oldest value if the vector is full
// TODO: turn this into a circular buffer
// TODO: make sure kShortHistSize is large enough that that data will never be lost
@@ -206,13 +219,15 @@
return isOutlier;
}
+// computes the column width required for a specific histogram value
+inline int numberWidth(int number, int leftPadding) {
+ return std::max(std::max(widthOf(number) + 4, 3), leftPadding + 2);
+}
-// TODO Make it return a std::string instead of modifying body --> is this still relevant?
-// TODO consider changing all ints to uint32_t or uint64_t
+// TODO Make it return a std::string instead of modifying body
// TODO: move this to ReportPerformance, probably make it a friend function of PerformanceAnalysis
void PerformanceAnalysis::reportPerformance(String8 *body, int maxHeight) {
if (mHists.empty()) {
- ALOGD("reportPerformance: mHists is empty");
return;
}
@@ -224,7 +239,7 @@
}
// underscores and spaces length corresponds to maximum width of histogram
- static const int kLen = 40;
+ static const int kLen = 100;
std::string underscores(kLen, '_');
std::string spaces(kLen, ' ');
@@ -242,7 +257,7 @@
}
int height = log2(maxCount) + 1; // maxCount > 0, safe to call log2
const int leftPadding = widthOf(1 << height);
- const int colWidth = std::max(std::max(widthOf(maxDelta) + 1, 3), leftPadding + 2);
+ const int bucketWidth = numberWidth(maxDelta, leftPadding);
int scalingFactor = 1;
// scale data if it exceeds maximum height
if (height > maxHeight) {
@@ -255,6 +270,7 @@
body->appendFormat("\n%s", " ");
body->appendFormat("%*s", leftPadding, " ");
for (auto const &x : buckets) {
+ const int colWidth = numberWidth(x.first / kJiffyPerMs, leftPadding);
body->appendFormat("%*d", colWidth, x.second);
}
// write histogram ascii art
@@ -263,23 +279,26 @@
const int value = 1 << row;
body->appendFormat("%.*s", leftPadding, spaces.c_str());
for (auto const &x : buckets) {
- body->appendFormat("%.*s%s", colWidth - 1,
- spaces.c_str(), x.second < value ? " " : "|");
+ const int colWidth = numberWidth(x.first / kJiffyPerMs, leftPadding);
+ body->appendFormat("%.*s%s", colWidth - 1,
+ spaces.c_str(), x.second < value ? " " : "|");
}
body->appendFormat("\n%s", " ");
}
// print x-axis
const int columns = static_cast<int>(buckets.size());
body->appendFormat("%*c", leftPadding, ' ');
- body->appendFormat("%.*s", (columns + 1) * colWidth, underscores.c_str());
+ body->appendFormat("%.*s", (columns + 1) * bucketWidth, underscores.c_str());
body->appendFormat("\n%s", " ");
// write footer with bucket labels
body->appendFormat("%*s", leftPadding, " ");
for (auto const &x : buckets) {
- body->appendFormat("%*d", colWidth, x.first);
+ const int colWidth = numberWidth(x.first / kJiffyPerMs, leftPadding);
+ body->appendFormat("%*.*f", colWidth, 1,
+ static_cast<double>(x.first) / kJiffyPerMs);
}
- body->appendFormat("%.*s%s", colWidth, spaces.c_str(), "ms\n");
+ body->appendFormat("%.*s%s", bucketWidth, spaces.c_str(), "ms\n");
// Now report glitches
body->appendFormat("\ntime elapsed between glitches and glitch timestamps\n");
@@ -289,29 +308,28 @@
}
}
-
-// TODO: decide whether to use this or whether it is overkill, and it is enough
-// to only treat as glitches single wakeup call intervals which are too long.
-// Ultimately, glitch detection will be directly on the audio signal.
+// TODO: learn what timestamp sequences correlate with glitches instead of
+// manually designing a heuristic. Ultimately, detect glitches directly from audio.
// Produces a log warning if the timing of recent buffer periods caused a glitch
// Computes sum of running window of three buffer periods
// Checks whether the buffer periods leave enough CPU time for the next one
// e.g. if a buffer period is expected to be 4 ms and a buffer requires 3 ms of CPU time,
// here are some glitch cases:
// 4 + 4 + 6 ; 5 + 4 + 5; 2 + 2 + 10
-void PerformanceAnalysis::alertIfGlitch(const std::vector<int64_t> &samples) {
- std::deque<int> periods(kNumBuff, kPeriodMs);
- for (size_t i = 2; i < samples.size(); ++i) { // skip first time entry
- periods.push_front(deltaMs(samples[i - 1], samples[i]));
- periods.pop_back();
- // TODO: check that all glitch cases are covered
- if (std::accumulate(periods.begin(), periods.end(), 0) > kNumBuff * kPeriodMs +
- kPeriodMs - kPeriodMsCPU) {
- periods.assign(kNumBuff, kPeriodMs);
- }
- }
- return;
-}
+
+// void PerformanceAnalysis::alertIfGlitch(const std::vector<int64_t> &samples) {
+// std::deque<int> periods(kNumBuff, kPeriodMs);
+// for (size_t i = 2; i < samples.size(); ++i) { // skip first time entry
+// periods.push_front(deltaMs(samples[i - 1], samples[i]));
+// periods.pop_back();
+// // TODO: check that all glitch cases are covered
+// if (std::accumulate(periods.begin(), periods.end(), 0) > kNumBuff * kPeriodMs +
+// kPeriodMs - kPeriodMsCPU) {
+// periods.assign(kNumBuff, kPeriodMs);
+// }
+// }
+// return;
+//}
//------------------------------------------------------------------------------
diff --git a/media/libnbaio/ReportPerformance.cpp b/media/libnbaio/ReportPerformance.cpp
index fa2b9a0..813df94 100644
--- a/media/libnbaio/ReportPerformance.cpp
+++ b/media/libnbaio/ReportPerformance.cpp
@@ -39,7 +39,7 @@
// Writes outlier intervals, timestamps, and histograms spanning long time intervals to a file.
// TODO: format the data efficiently and write different types of data to different files
void writeToFile(const std::deque<std::pair<timestamp, Histogram>> &hists,
- const std::deque<std::pair<outlierInterval, timestamp>> &outlierData,
+ const std::deque<std::pair<msInterval, timestamp>> &outlierData,
const std::deque<timestamp> &peakTimestamps,
const char * directory, bool append, int author, log_hash_t hash) {
if (outlierData.empty() || hists.empty()) {
@@ -65,9 +65,10 @@
for (const auto &hist : hists) {
hfs << "\ttimestamp\n";
hfs << hist.first << "\n";
- hfs << "\tbuckets and counts\n";
+ hfs << "\tbuckets (in ms) and counts\n";
for (const auto &bucket : hist.second) {
- hfs << bucket.first << ": " << bucket.second << "\n";
+ hfs << bucket.first / static_cast<double>(kJiffyPerMs)
+ << ": " << bucket.second << "\n";
}
hfs << "\n"; // separate histograms with a newline
}
diff --git a/media/libnbaio/include/media/nbaio/NBLog.h b/media/libnbaio/include/media/nbaio/NBLog.h
index 059d3f6..5549728 100644
--- a/media/libnbaio/include/media/nbaio/NBLog.h
+++ b/media/libnbaio/include/media/nbaio/NBLog.h
@@ -39,7 +39,7 @@
public:
- typedef uint64_t log_hash_t;
+ using log_hash_t = ReportPerformance::log_hash_t;
// FIXME Everything needed for client (writer API and registration) should be isolated
// from the rest of the implementation.
@@ -142,7 +142,6 @@
static std::unique_ptr<AbstractEntry> buildEntry(const uint8_t *ptr);
// get format entry timestamp
- // TODO consider changing to uint64_t
virtual int64_t timestamp() const = 0;
// get format entry's unique id
diff --git a/media/libnbaio/include/media/nbaio/PerformanceAnalysis.h b/media/libnbaio/include/media/nbaio/PerformanceAnalysis.h
index 3f03d4b..97b2c92 100644
--- a/media/libnbaio/include/media/nbaio/PerformanceAnalysis.h
+++ b/media/libnbaio/include/media/nbaio/PerformanceAnalysis.h
@@ -14,7 +14,8 @@
* limitations under the License.
*/
-// Non-blocking event logger intended for safe communication between processes via shared memory
+// Non-blocking event logger intended for safe communication between
+// processes via shared memory
#ifndef ANDROID_MEDIA_PERFORMANCEANALYSIS_H
#define ANDROID_MEDIA_PERFORMANCEANALYSIS_H
@@ -42,7 +43,7 @@
// the fifo writer utilities.
public:
- PerformanceAnalysis();
+ PerformanceAnalysis() {};
friend void dump(int fd, int indent,
PerformanceAnalysisMap &threadPerformanceAnalysis);
@@ -61,29 +62,28 @@
// Writes wakeup timestamp entry to log and runs analysis
// TODO: make this thread safe. Each thread should have its own instance
// of PerformanceAnalysis.
- void logTsEntry(timestamp_raw ts);
+ void logTsEntry(timestamp ts);
// FIXME: make peakdetector and storeOutlierData a single function
// Input: mOutlierData. Looks at time elapsed between outliers
// finds significant changes in the distribution
// writes timestamps of significant changes to mPeakTimestamps
- bool detectAndStorePeak(outlierInterval delta, timestamp ts);
+ bool detectAndStorePeak(msInterval delta, timestamp ts);
// runs analysis on timestamp series before it is converted to a histogram
// finds outliers
// writes to mOutlierData <time elapsed since previous outlier, outlier timestamp>
- bool detectAndStoreOutlier(const timestamp_raw timestamp);
+ bool detectAndStoreOutlier(const msInterval diffMs);
- // input: series of short histograms. Generates a string of analysis of the buffer periods
+ // Generates a string of analysis of the buffer periods and prints to console
// TODO: WIP write more detailed analysis
// FIXME: move this data visualization to a separate class. Model/view/controller
void reportPerformance(String8 *body, int maxHeight = 10);
// This function detects glitches in a time series.
- // TODO: decide whether to use this or whether it is overkill, and it is enough
- // to only treat as glitches single wakeup call intervals which are too long.
- // Ultimately, glitch detection will be directly on the audio signal.
- void alertIfGlitch(const std::vector<timestamp_raw> &samples);
+ // TODO: learn what timestamp sequences correlate with glitches instead of
+ // manually designing a heuristic. Ultimately, detect glitches directly from audio.
+ // void alertIfGlitch(const std::vector<timestamp_raw> &samples);
private:
@@ -91,7 +91,7 @@
// stores outlier analysis:
// <elapsed time between outliers in ms, outlier beginning timestamp>
- std::deque<std::pair<outlierInterval, timestamp>> mOutlierData;
+ std::deque<std::pair<msInterval, timestamp>> mOutlierData;
// stores each timestamp at which a peak was detected
// a peak is a moment at which the average outlier interval changed significantly
@@ -101,43 +101,45 @@
std::deque<std::pair<timestamp, Histogram>> mHists;
// Parameters used when detecting outliers
- // TODO: learn some of these from the data, delete unused ones
- // TODO: put used variables in a struct
+ struct BufferPeriod {
+ double mMean = -1; // average time between audio processing wakeups
+ double mOutlierFactor = -1; // values > mMean * mOutlierFactor are outliers
+ double mOutlier = -1; // this is set to mMean * mOutlierFactor
+ timestamp mPrevTs = -1; // previous timestamp
+ } mBufferPeriod;
+
+ // TODO: delete values below if unused or add them to the BufferPeriod struct
// FIXME: decide whether to make kPeriodMs static.
- static const int kNumBuff = 3; // number of buffers considered in local history
- int kPeriodMs; // current period length is ideally 4 ms
- static const int kOutlierMs = 7; // values greater or equal to this cause glitches
+ // static const int kNumBuff = 3; // number of buffers considered in local history
+ // int kPeriodMs; // current period length is ideally 4 ms
+ // static const int kOutlierMs = 7; // values greater or equal to this cause glitches
// 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
+ // static constexpr double kRatio = 0.75; // estimate CPU time as ratio of period
+ // int kPeriodMsCPU; // compute based on kPeriodLen and kRatio
// capacity allocated to data structures
// TODO: make these values longer when testing is finished
struct MaxLength {
size_t Hists; // number of histograms stored in memory
- size_t TimeStamps; // histogram size, e.g. maximum length of timestamp series
+ size_t TimeStamps; // histogram size
size_t Outliers; // number of values stored in outlier array
size_t Peaks; // number of values stored in peak array
- // maximum elapsed time between first and last timestamp of a long-term histogram
- int HistTimespanMs;
+ int HistTimespanMs; // maximum histogram timespan
};
static constexpr MaxLength kMaxLength = {.Hists = 20, .TimeStamps = 1000,
.Outliers = 100, .Peaks = 100, .HistTimespanMs = 5 * kMsPerSec };
- // these variables are stored in-class to ensure continuity while analyzing the timestamp
- // series one short sequence at a time: the variables are not re-initialized every time.
- // TODO: use m prefix
+ // these variables ensure continuity while analyzing the timestamp
+ // series one sample at a time.
// TODO: change this to a running variance/mean class
struct OutlierDistribution {
- double mMean = 0; // sample mean since previous peak
- double mSd = 0; // sample sd since previous peak
- outlierInterval mElapsed = 0; // time since previous detected outlier
- int64_t mPrevTs = -1; // previous timestamp
- // number of standard deviations from mean considered a significant change
- const int kMaxDeviation = 5;
- double mTypicalDiff = 0; // global mean of outliers
- double mN = 0; // length of sequence since the last peak
- double mM2 = 0;
+ msInterval mMean = 0; // sample mean since previous peak
+ msInterval mSd = 0; // sample sd since previous peak
+ msInterval mElapsed = 0; // time since previous detected outlier
+ const int kMaxDeviation = 5; // standard deviations from the mean threshold
+ msInterval mTypicalDiff = 0; // global mean of outliers
+ double mN = 0; // length of sequence since the last peak
+ double mM2 = 0; // used to calculate sd
} mOutlierDistribution;
};
diff --git a/media/libnbaio/include/media/nbaio/ReportPerformance.h b/media/libnbaio/include/media/nbaio/ReportPerformance.h
index ed97a23..0d4a7b9 100644
--- a/media/libnbaio/include/media/nbaio/ReportPerformance.h
+++ b/media/libnbaio/include/media/nbaio/ReportPerformance.h
@@ -29,37 +29,39 @@
namespace ReportPerformance {
-const int kMsPerSec = 1000;
+constexpr int kMsPerSec = 1000;
-// stores a histogram: key: observed buffer period. value: count
+constexpr int kJiffyPerMs = 10; // time unit for histogram as a multiple of milliseconds
+
+// stores a histogram: key: observed buffer period (multiple of jiffy). value: count
// TODO: unsigned, unsigned
using Histogram = std::map<int, int>;
-using outlierInterval = uint64_t;
-// int64_t timestamps are converted to uint64_t in PerformanceAnalysis::storeOutlierData,
-// and all analysis functions use uint64_t.
-using timestamp = uint64_t;
-using timestamp_raw = int64_t;
+using msInterval = double;
+using jiffyInterval = double;
-// FIXME: decide whether to use 64 or 32 bits
-// TODO: the code has a mix of typedef and using. Standardize to one or the other.
-typedef uint64_t log_hash_t;
+using timestamp = int64_t;
+using log_hash_t = uint64_t;
+
+// TODO: should this return an int64_t?
static inline int deltaMs(int64_t ns1, int64_t ns2) {
return (ns2 - ns1) / (1000 * 1000);
}
+static inline int deltaJiffy(int64_t ns1, int64_t ns2) {
+ return (kJiffyPerMs * (ns2 - ns1)) / (1000 * 1000);
+}
+
static inline uint32_t log2(uint32_t x) {
// This works for x > 0
return 31 - __builtin_clz(x);
}
-// TODO: delete dump in NBLog::Reader and add it here
-
// Writes outlier intervals, timestamps, and histograms spanning long time
// intervals to a file.
void writeToFile(const std::deque<std::pair<timestamp, Histogram>> &hists,
- const std::deque<std::pair<outlierInterval, timestamp>> &outlierData,
+ const std::deque<std::pair<msInterval, timestamp>> &outlierData,
const std::deque<timestamp> &peakTimestamps,
const char * kDirectory, bool append, int author, log_hash_t hash);