Write audio performance data to file
Created new file ReportPerformacne.cpp with file writing
functionality. When short-term histogram array is full,
its data is aggregated into a long-term histogram array.
Cleaned up documentation and comments.
Test: dumpsys media.log
Change-Id: I19f48ea27ffc8205e67ea4ded04615d33a422966
diff --git a/media/libnbaio/Android.bp b/media/libnbaio/Android.bp
index 02f7529..4220b77 100644
--- a/media/libnbaio/Android.bp
+++ b/media/libnbaio/Android.bp
@@ -45,6 +45,7 @@
"PerformanceAnalysis.cpp",
"Pipe.cpp",
"PipeReader.cpp",
+ "ReportPerformance.cpp",
"SourceAudioBufferProvider.cpp",
],
diff --git a/media/libnbaio/NBLog.cpp b/media/libnbaio/NBLog.cpp
index a352b15..2f639d2 100644
--- a/media/libnbaio/NBLog.cpp
+++ b/media/libnbaio/NBLog.cpp
@@ -108,6 +108,7 @@
#include <audio_utils/roundup.h>
#include <media/nbaio/NBLog.h>
#include <media/nbaio/PerformanceAnalysis.h>
+#include <media/nbaio/ReportPerformance.h>
// #include <utils/CallStack.h> // used to print callstack
#include <utils/Log.h>
#include <utils/String8.h>
@@ -869,42 +870,17 @@
}
-// writes sample deltas to file, either truncating or appending
-inline void writeHistToFile(const std::vector<int64_t> &samples, bool append) {
- // name of file on audioserver
- static const char* const kName = (char *)"/data/misc/audioserver/sample_results.txt";
- // stores deltas between the samples
- std::vector<int64_t> intervals;
- for (size_t i = 1; i < samples.size(); ++i) {
- intervals.push_back(deltaMs(samples[i - 1], samples[i]));
- }
- if (intervals.empty()) return;
- // Deletes maximum value in a histogram. Temp quick fix.
- // FIXME: need to find root cause of approx. 35th element from the end
- // consistently being an outlier in the first histogram of a flush
- // ALOGW("%" PRId64 "before", (int64_t) *(std::max_element(intervals.begin(), intervals.end())));
- intervals.erase(std::max_element(intervals.begin(), intervals.end()));
- // ALOGW("%" PRId64 "after", (int64_t) *(std::max_element(intervals.begin(), intervals.end())));
- std::ofstream ofs;
- ofs.open(kName, append ? std::ios::app : std::ios::trunc);
- if (!ofs) {
- ALOGW("couldn't open file %s", kName);
- return;
- }
- for (size_t i = 0; i < intervals.size(); ++i) {
- ofs << intervals[i] << "\n";
- }
- ofs.close();
-}
-
+// TODO: move this to PerformanceAnalysis
+// TODO: make call to dump periodic so that data in shared FIFO does not get overwritten
void NBLog::Reader::dump(int fd, size_t indent, NBLog::Reader::Snapshot &snapshot)
{
- // CallStack cs(LOG_TAG);
mFd = fd;
mIndent = indent;
String8 timestamp, body;
// FIXME: this is not thread safe
- static PerformanceAnalysis performanceAnalysis; // used to store data and to call analysis functions
+ // TODO: need a separate instance of performanceAnalysis for each thread
+ // used to store data and to call analysis functions
+ static ReportPerformance::PerformanceAnalysis performanceAnalysis;
size_t lost = snapshot.lost() + (snapshot.begin() - EntryIterator(snapshot.data()));
if (lost > 0) {
body.appendFormat("warning: lost %zu bytes worth of events", lost);
@@ -926,15 +902,12 @@
memcpy(&hash, &(data->hash), sizeof(hash));
int64_t ts;
memcpy(&ts, &data->ts, sizeof(ts));
- performanceAnalysis.logTsEntry(data->author, ts);
+ performanceAnalysis.logTsEntry(ts);
++entry;
break;
}
case EVENT_AUDIO_STATE: {
- StateTsEntryWithAuthor *data = (StateTsEntryWithAuthor *) (entry->data);
- // TODO This memcpies are here to avoid unaligned memory access crash.
- // There's probably a more efficient way to do it
- performanceAnalysis.handleStateChange(data->author);
+ performanceAnalysis.handleStateChange();
++entry;
break;
}
diff --git a/media/libnbaio/PerformanceAnalysis.cpp b/media/libnbaio/PerformanceAnalysis.cpp
index 7cba4c6..fb3bddc 100644
--- a/media/libnbaio/PerformanceAnalysis.cpp
+++ b/media/libnbaio/PerformanceAnalysis.cpp
@@ -21,7 +21,6 @@
#include <algorithm>
#include <climits>
#include <deque>
-#include <fstream>
#include <iostream>
#include <math.h>
#include <numeric>
@@ -36,6 +35,7 @@
#include <audio_utils/roundup.h>
#include <media/nbaio/NBLog.h>
#include <media/nbaio/PerformanceAnalysis.h>
+#include <media/nbaio/ReportPerformance.h>
// #include <utils/CallStack.h> // used to print callstack
#include <utils/Log.h>
#include <utils/String8.h>
@@ -45,6 +45,8 @@
namespace android {
+namespace ReportPerformance {
+
PerformanceAnalysis::PerformanceAnalysis() {
// These variables will be (FIXME) learned from the data
kPeriodMs = 4; // typical buffer period (mode)
@@ -76,53 +78,87 @@
// outliers, analyzes the outlier series for unexpectedly
// small or large values and stores these as peaks, and flushes
// the timestamp series from memory.
-void PerformanceAnalysis::processAndFlushTimeStampSeries(int author) {
+void PerformanceAnalysis::processAndFlushTimeStampSeries() {
// 1) analyze the series to store all outliers and their exact timestamps:
- storeOutlierData(mTimeStampSeries[author]);
+ storeOutlierData(mTimeStampSeries);
// 2) detect peaks in the outlier series
detectPeaks();
- // 3) compute its histogram, append this to mRecentHists and erase the time series
- // FIXME: need to store the timestamp of the beginning of each histogram
- // FIXME: Restore LOG_HIST_FLUSH to separate histograms at every end-of-stream event
- // A histogram should not span data between audio off/on timespans
- mRecentHists.emplace_back(author, buildBuckets(mTimeStampSeries[author]));
+ // 3) compute its histogram, append to mRecentHists and clear the time series
+ mRecentHists.emplace_back(static_cast<timestamp>(mTimeStampSeries[0]),
+ buildBuckets(mTimeStampSeries));
// do not let mRecentHists exceed capacity
// ALOGD("mRecentHists size: %d", static_cast<int>(mRecentHists.size()));
if (mRecentHists.size() >= kRecentHistsCapacity) {
// ALOGD("popped back mRecentHists");
mRecentHists.pop_front();
}
- mTimeStampSeries[author].clear();
+ mTimeStampSeries.clear();
}
// forces short-term histogram storage to avoid adding idle audio time interval
// to buffer period data
-void PerformanceAnalysis::handleStateChange(int author) {
+void PerformanceAnalysis::handleStateChange() {
ALOGD("handleStateChange");
- processAndFlushTimeStampSeries(author);
+ processAndFlushTimeStampSeries();
return;
}
-// Takes a single buffer period timestamp entry with author information and stores it
-// in a temporary series of timestamps. Once the series is full, the data is analyzed,
+// Takes a single buffer period timestamp entry information and stores it in a
+// temporary series of timestamps. Once the series is full, the data is analyzed,
// stored, and emptied.
-// TODO: decide whether author or file location information is more important to store
-// for now, only stores author (thread)
-void PerformanceAnalysis::logTsEntry(int author, int64_t ts) {
+void PerformanceAnalysis::logTsEntry(int64_t ts) {
// TODO might want to filter excessively high outliers, which are usually caused
// by the thread being inactive.
// Store time series data for each reader in order to bucket it once there
// is enough data. Then, write to recentHists as a histogram.
- mTimeStampSeries[author].push_back(ts);
+ mTimeStampSeries.push_back(ts);
// if length of the time series has reached kShortHistSize samples,
// analyze the data and flush the timestamp series from memory
- if (mTimeStampSeries[author].size() >= kShortHistSize) {
- processAndFlushTimeStampSeries(author);
+ if (mTimeStampSeries.size() >= kShortHistSize) {
+ processAndFlushTimeStampSeries();
}
}
+// When the short-term histogram array mRecentHists has reached capacity,
+// merge histograms for data compression and store them in mLongTermHists
+// clears mRecentHists
+// TODO: have logTsEntry write directly to mLongTermHists, discard mRecentHists,
+// start a new histogram when a peak occurs
+void PerformanceAnalysis::processAndFlushRecentHists() {
+
+ // Buckets is used to aggregate short-term histograms.
+ Histogram buckets;
+ timestamp startingTs = mRecentHists[0].first;
+
+ for (const auto &shortHist: mRecentHists) {
+ // If the time between starting and ending timestamps has reached the maximum,
+ // add the current histogram (buckets) to the long-term histogram buffer,
+ // clear buckets, and start a new long-term histogram aggregation process.
+ if (deltaMs(startingTs, shortHist.first) >= kMaxHistTimespanMs) {
+ mLongTermHists.emplace_back(startingTs, std::move(buckets));
+ buckets.clear();
+ startingTs = shortHist.first;
+ // When memory is full, delete oldest histogram
+ // TODO use a circular buffer
+ if (mLongTermHists.size() >= kLongTermHistsCapacity) {
+ mLongTermHists.pop_front();
+ }
+ }
+
+ // add current histogram to buckets
+ for (const auto &countPair : shortHist.second) {
+ buckets[countPair.first] += countPair.second;
+ }
+ }
+ mRecentHists.clear();
+ // TODO: decide when/where to call writeToFile
+ // TODO: add a thread-specific extension to the file name
+ static const char* const kName = (const char *) "/data/misc/audioserver/sample_results.txt";
+ writeToFile(mOutlierData, mLongTermHists, kName, false);
+}
+
// Given a series of outlier intervals (mOutlier data),
// looks for changes in distribution (peaks), which can be either positive or negative.
// The function sets the mean to the starting value and sigma to 0, and updates
@@ -131,7 +167,6 @@
// are set to the peak value and 0.
void PerformanceAnalysis::detectPeaks() {
if (mOutlierData.empty()) {
- ALOGD("peak detector called on empty array");
return;
}
@@ -166,14 +201,12 @@
mPeakDetectorSd = sqrt(std::accumulate(start, it + 1, 0.0,
[=](auto &a, auto &b){ return a + sqr(b.first - mPeakDetectorMean);})) /
((kN > 1)? kN - 1 : kN); // kN - 1: mean is correlated with variance
- // ALOGD("value, mean, sd: %f, %f, %f", static_cast<double>(it->first), mean, sd);
}
// surprising value: store peak timestamp and reset mean, sd, and start iterator
else {
mPeakTimestamps.emplace_back(it->second);
// TODO: remove pop_front once a circular buffer is in place
- if (mPeakTimestamps.size() >= kShortHistSize) {
- ALOGD("popped back mPeakTimestamps");
+ if (mPeakTimestamps.size() >= kPeakSeriesSize) {
mPeakTimestamps.pop_front();
}
mPeakDetectorMean = static_cast<double>(it->first);
@@ -181,9 +214,6 @@
start = it;
}
}
- //for (const auto &it : mPeakTimestamps) {
- // ALOGE("mPeakTimestamps %f", static_cast<double>(it));
- //}
return;
}
@@ -194,7 +224,6 @@
// This function is applied to the time series before it is converted into a histogram.
void PerformanceAnalysis::storeOutlierData(const std::vector<int64_t> ×tamps) {
if (timestamps.size() < 1) {
- ALOGE("storeOutlierData called on empty vector");
return;
}
// first pass: need to initialize
@@ -207,10 +236,9 @@
mOutlierData.emplace_back(mElapsed, static_cast<uint64_t>(mPrevNs));
// Remove oldest value if the vector is full
// TODO: remove pop_front once circular buffer is in place
- // FIXME: change kShortHistSize to some other constant. Make sure it is large
- // enough that data will never be lost before being written to a long-term FIFO
- if (mOutlierData.size() >= kShortHistSize) {
- ALOGD("popped back mOutlierData");
+ // FIXME: make sure kShortHistSize is large enough that that data will never be lost
+ // before being written to file or to a FIFO
+ if (mOutlierData.size() >= kOutlierSeriesSize) {
mOutlierData.pop_front();
}
mElapsed = 0;
@@ -236,9 +264,8 @@
}
// TODO Make it return a std::string instead of modifying body --> is this still relevant?
-// FIXME: as can be seen when printing the values, the outlier timestamps typically occur
-// in the first histogram 35 to 38 indices from the end (most often 35).
// TODO consider changing all ints to uint32_t or uint64_t
+// TODO: move this to ReportPerformance, probably make it a friend function of PerformanceAnalysis
void PerformanceAnalysis::reportPerformance(String8 *body, int maxHeight) {
if (mRecentHists.size() < 1) {
ALOGD("reportPerformance: mRecentHists is empty");
@@ -342,4 +369,6 @@
return;
}
+} // namespace ReportPerformance
+
} // namespace android
diff --git a/media/libnbaio/ReportPerformance.cpp b/media/libnbaio/ReportPerformance.cpp
new file mode 100644
index 0000000..dc50ada
--- /dev/null
+++ b/media/libnbaio/ReportPerformance.cpp
@@ -0,0 +1,74 @@
+/*
+ * Copyright (C) 2017 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#define LOG_TAG "ReportPerformance"
+
+#include <fstream>
+#include <iostream>
+#include <queue>
+#include <stdarg.h>
+#include <stdint.h>
+#include <stdio.h>
+#include <string.h>
+#include <sys/prctl.h>
+#include <utility>
+#include <media/nbaio/NBLog.h>
+#include <media/nbaio/PerformanceAnalysis.h>
+#include <media/nbaio/ReportPerformance.h>
+// #include <utils/CallStack.h> // used to print callstack
+#include <utils/Log.h>
+#include <utils/String8.h>
+
+namespace android {
+
+namespace ReportPerformance {
+
+// 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(std::deque<std::pair<outlierInterval, timestamp>> &outlierData,
+ std::deque<std::pair<timestamp, Histogram>> &hists,
+ const char * kName,
+ bool append) {
+ ALOGD("writing performance data to file");
+ if (outlierData.empty() || hists.empty()) {
+ return;
+ }
+
+ std::ofstream ofs;
+ ofs.open(kName, append ? std::ios::app : std::ios::trunc);
+ if (!ofs.is_open()) {
+ ALOGW("couldn't open file %s", kName);
+ return;
+ }
+ ofs << "Outlier data: interval and timestamp\n";
+ for (const auto &outlier : outlierData) {
+ ofs << outlier.first << ": " << outlier.second << "\n";
+ }
+ ofs << "Histogram data\n";
+ for (const auto &hist : hists) {
+ ofs << "\ttimestamp\n";
+ ofs << hist.first << "\n";
+ ofs << "\tbuckets and counts\n";
+ for (const auto &bucket : hist.second) {
+ ofs << bucket.first << ": " << bucket.second << "\n";
+ }
+ }
+ ofs.close();
+}
+
+} // namespace ReportPerformance
+
+} // namespace android
diff --git a/media/libnbaio/include/media/nbaio/PerformanceAnalysis.h b/media/libnbaio/include/media/nbaio/PerformanceAnalysis.h
index 4be567f..b0dc148 100644
--- a/media/libnbaio/include/media/nbaio/PerformanceAnalysis.h
+++ b/media/libnbaio/include/media/nbaio/PerformanceAnalysis.h
@@ -23,10 +23,11 @@
#include <deque>
#include <vector>
#include "NBLog.h"
+#include "ReportPerformance.h"
namespace android {
-class String8;
+namespace ReportPerformance {
class PerformanceAnalysis {
// This class stores and analyzes audio processing wakeup timestamps from NBLog
@@ -37,42 +38,25 @@
PerformanceAnalysis();
- // FIXME: decide whether to use 64 or 32 bits
- typedef uint64_t log_hash_t;
-
- // stores a short-term histogram of size determined by kShortHistSize
- // key: observed buffer period. value: count
- // TODO: unsigned, unsigned
- // TODO: change this name to histogram
- using short_histogram = std::map<int, int>;
-
- using outlierInterval = uint64_t;
- // int64_t timestamps are converted to uint64_t in PerformanceAnalysis::storeOutlierData,
- // and all further analysis functions use uint64_t.
- using timestamp = uint64_t;
- using timestamp_raw = int64_t;
-
// Given a series of audio processing wakeup timestamps,
// compresses and and analyzes the data, and flushes
// the timestamp series from memory.
- void processAndFlushTimeStampSeries(int author);
+ void processAndFlushTimeStampSeries();
- // Called when an audio on/off event is read from the buffer
+ // Called when an audio on/off event is read from the buffer,
+ // e.g. EVENT_AUDIO_STATE.
// calls flushTimeStampSeries on the data up to the event,
- // effectively skipping over the idle audio time interval
- // when writing buffer period data to memory.
- void handleStateChange(int author);
+ // effectively discarding the idle audio time interval
+ void handleStateChange();
+
+ // When the short-term histogram array mRecentHists has reached capacity,
+ // merges histograms for data compression and stores them in mLongTermHists
+ void processAndFlushRecentHists();
// Writes wakeup timestamp entry to log and runs analysis
- // author is the thread ID
- // TODO: check. if the thread has multiple histograms, is author info correct
- // FIXME: remove author from arglist. Want to call these function separately on
- // each thread’s data.
- // FIXME: decide whether to store the hash (source file location) instead
- // FIXME: If thread has multiple histograms, check that code works and correct
- // author is stored (test with multiple threads). Need to check that the current
- // code is not receiving data from multiple threads. This could cause odd values.
- void logTsEntry(int author, timestamp_raw ts);
+ // TODO: make this thread safe. Each thread should have its own instance
+ // of PerformanceAnalysis.
+ void logTsEntry(timestamp_raw ts);
// FIXME: make peakdetector and storeOutlierData a single function
// Input: mOutlierData. Looks at time elapsed between outliers
@@ -95,9 +79,7 @@
// This function used to detect glitches in a time series
// TODO incorporate this into the analysis (currently unused)
- void alertIfGlitch(const std::vector<timestamp_raw> &samples);
-
- ~PerformanceAnalysis() {}
+ void alertIfGlitch(const std::vector<timestamp_raw> &samples);
private:
@@ -108,23 +90,24 @@
// a peak is a moment at which the average outlier interval changed significantly
std::deque<timestamp> mPeakTimestamps;
+ // TODO: turn these into circular buffers for better data flow
// FIFO of small histograms
- // stores fixed-size short buffer period histograms with hash and thread data
- // TODO: Turn it into a circular buffer for better data flow
- std::deque<std::pair<int, short_histogram>> mRecentHists;
+ // stores fixed-size short buffer period histograms with timestamp of first sample
+ std::deque<std::pair<timestamp, Histogram>> mRecentHists;
- // map from author to vector of timestamps, collected from NBLog
- // when a vector reaches its maximum size, analysis is run and the data is deleted
- std::map<int, std::vector<timestamp_raw>> mTimeStampSeries;
+ // FIFO of small histograms
+ // stores fixed-size long-term buffer period histograms with timestamp of first sample
+ std::deque<std::pair<timestamp, Histogram>> mLongTermHists;
- // TODO: measure these from the data (e.g., mode) as they may change.
- // const int kGlitchThreshMs = 7;
- // const int kMsPerSec = 1000;
+ // vector of timestamps, collected from NBLog for a (TODO) specific thread
+ // when a vector reaches its maximum size, the data is processed and flushed
+ std::vector<timestamp_raw> mTimeStampSeries;
+
+ static const int kMsPerSec = 1000;
// Parameters used when detecting outliers
// TODO: learn some of these from the data, delete unused ones
// FIXME: decide whether to make kPeriodMs static.
- // The non-const values are (TODO: will be) learned from the data
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
@@ -135,8 +118,15 @@
// Peak detection: number of standard deviations from mean considered a significant change
static const int kStddevThreshold = 5;
+ // capacity allocated to data structures
+ // TODO: adjust all of these values
static const int kRecentHistsCapacity = 100; // number of short-term histograms stored in memory
static const int kShortHistSize = 50; // number of samples in a short-term histogram
+ static const int kOutlierSeriesSize = 100; // number of values stored in outlier array
+ static const int kPeakSeriesSize = 100; // number of values stored in peak array
+ static const int kLongTermHistsCapacity = 20; // number of long-term histogram stored in memory
+ // maximum elapsed time between first and last timestamp of a long-term histogram
+ static const int kMaxHistTimespanMs = 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.
@@ -149,14 +139,7 @@
};
-static inline int deltaMs(int64_t ns1, int64_t ns2) {
- return (ns2 - ns1) / (1000 * 1000);
-}
-
-static inline uint32_t log2(uint32_t x) {
- // This works for x > 0
- return 31 - __builtin_clz(x);
-}
+} // namespace ReportPerformance
} // namespace android
diff --git a/media/libnbaio/include/media/nbaio/ReportPerformance.h b/media/libnbaio/include/media/nbaio/ReportPerformance.h
new file mode 100644
index 0000000..27d2810
--- /dev/null
+++ b/media/libnbaio/include/media/nbaio/ReportPerformance.h
@@ -0,0 +1,66 @@
+/*
+ * Copyright (C) 2017 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#ifndef ANDROID_MEDIA_REPORTPERFORMANCE_H
+#define ANDROID_MEDIA_REPORTPERFORMANCE_H
+
+#include <deque>
+#include <map>
+#include <vector>
+
+namespace android {
+
+// This class is used by reportPerformance function
+// TODO move reportPerformance function to ReportPerformance.cpp
+class String8;
+
+namespace ReportPerformance {
+
+// stores a histogram: key: observed buffer period. 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;
+
+// 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;
+
+static inline int deltaMs(int64_t ns1, int64_t ns2) {
+ return (ns2 - ns1) / (1000 * 1000);
+}
+
+static inline uint32_t log2(uint32_t x) {
+ // This works for x > 0
+ return 31 - __builtin_clz(x);
+}
+
+// Writes outlier intervals, timestamps, and histograms spanning long time
+// intervals to a file.
+void writeToFile(std::deque<std::pair<outlierInterval, timestamp>> &outlierData,
+ std::deque<std::pair<timestamp, Histogram>> &hists,
+ const char * kName,
+ bool append);
+
+} // namespace ReportPerformance
+
+} // namespace android
+
+#endif // ANDROID_MEDIA_REPORTPERFORMANCE_H