Restored audio onStateChange log
Calls flushTsSeries when a state change was detected
to avoid logging idle audio time as a buffer period.
Test: dumpsys media.log
Change-Id: Ia33bec8829dcd5d2de5c40f904e5ea19c5a2b453
diff --git a/media/libnbaio/NBLog.cpp b/media/libnbaio/NBLog.cpp
index 2b5b4ff..f90d7fc 100644
--- a/media/libnbaio/NBLog.cpp
+++ b/media/libnbaio/NBLog.cpp
@@ -24,8 +24,8 @@
* Calls LOG_HIST_TS
* LOG_HIST_TS
* Hashes file name and line number, and writes single timestamp to buffer
-* calls NBLOG::Writer::logHistTS once
-* NBLOG::Writer::logHistTS
+* calls NBLOG::Writer::logEventHistTS once
+* NBLOG::Writer::logEventHistTS
* calls NBLOG::Writer::log on hash and current timestamp
* time is in CLOCK_MONOTONIC converted to ns
* NBLOG::Writer::log(Event, const void*, size_t)
@@ -44,6 +44,8 @@
* ssize_t audio_utils_fifo_reader::obtain
* Determines readable buffer section via pointer arithmetic on reader
* and writer pointers
+* Similarly, LOG_AUDIO_STATE() is called by onStateChange whenever audio is
+* turned on or off, and writes this notification to the FIFO.
*
* 2) reading the data from shared memory
* Thread::threadloop()
@@ -138,6 +140,7 @@
switch (type) {
case EVENT_START_FMT:
return std::make_unique<FormatEntry>(FormatEntry(ptr));
+ case EVENT_AUDIO_STATE:
case EVENT_HISTOGRAM_ENTRY_TS:
return std::make_unique<HistogramEntry>(HistogramEntry(ptr));
default:
@@ -516,7 +519,7 @@
log(EVENT_HASH, &hash, sizeof(hash));
}
-void NBLog::Writer::logHistTS(log_hash_t hash)
+void NBLog::Writer::logEventHistTs(Event event, log_hash_t hash)
{
if (!mEnabled) {
return;
@@ -525,7 +528,7 @@
data.hash = hash;
data.ts = get_monotonic_ns();
if (data.ts > 0) {
- log(EVENT_HISTOGRAM_ENTRY_TS, &data, sizeof(data));
+ log(event, &data, sizeof(data));
} else {
ALOGE("Failed to get timestamp");
}
@@ -758,7 +761,9 @@
const std::set<NBLog::Event> NBLog::Reader::startingTypes {NBLog::Event::EVENT_START_FMT,
NBLog::Event::EVENT_HISTOGRAM_ENTRY_TS};
const std::set<NBLog::Event> NBLog::Reader::endingTypes {NBLog::Event::EVENT_END_FMT,
- NBLog::Event::EVENT_HISTOGRAM_ENTRY_TS};
+ NBLog::Event::EVENT_HISTOGRAM_ENTRY_TS,
+ NBLog::Event::EVENT_AUDIO_STATE};
+
NBLog::Reader::Reader(const void *shared, size_t size)
: mShared((/*const*/ Shared *) shared), /*mIMemory*/
mFd(-1), mIndent(0),
@@ -925,6 +930,14 @@
++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);
+ ++entry;
+ break;
+ }
case EVENT_END_FMT:
body.appendFormat("warning: got to end format event");
++entry;
diff --git a/media/libnbaio/PerformanceAnalysis.cpp b/media/libnbaio/PerformanceAnalysis.cpp
index fa8f47e..7cba4c6 100644
--- a/media/libnbaio/PerformanceAnalysis.cpp
+++ b/media/libnbaio/PerformanceAnalysis.cpp
@@ -71,6 +71,40 @@
return width;
}
+// Given a series of audio processing wakeup timestamps,
+// buckets the time intervals into a histogram, searches for
+// 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) {
+ // 1) analyze the series to store all outliers and their exact timestamps:
+ storeOutlierData(mTimeStampSeries[author]);
+
+ // 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]));
+ // 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();
+}
+
+// forces short-term histogram storage to avoid adding idle audio time interval
+// to buffer period data
+void PerformanceAnalysis::handleStateChange(int author) {
+ ALOGD("handleStateChange");
+ processAndFlushTimeStampSeries(author);
+ 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,
// stored, and emptied.
@@ -82,25 +116,10 @@
// 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);
- // if length of the time series has reached kShortHistSize samples, do 1) and 2):
+ // 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) {
- // 1) analyze the series to store all outliers and their exact timestamps:
- storeOutlierData(mTimeStampSeries[author]);
- // 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]));
- // 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();
+ processAndFlushTimeStampSeries(author);
}
}
diff --git a/media/libnbaio/include/media/nbaio/NBLog.h b/media/libnbaio/include/media/nbaio/NBLog.h
index 0b5e24d..3e48ee1 100644
--- a/media/libnbaio/include/media/nbaio/NBLog.h
+++ b/media/libnbaio/include/media/nbaio/NBLog.h
@@ -44,8 +44,6 @@
class Writer;
class Reader;
-private:
-
enum Event : uint8_t {
EVENT_RESERVED,
EVENT_STRING, // ASCII string, not NUL-terminated
@@ -60,11 +58,13 @@
EVENT_HASH, // unique HASH of log origin, originates from hash of file name
// and line number
EVENT_HISTOGRAM_ENTRY_TS, // single datum for timestamp histogram
+ EVENT_AUDIO_STATE, // audio on/off event: logged upon FastMixer::onStateChange() call
EVENT_END_FMT, // end of logFormat argument list
EVENT_UPPER_BOUND, // to check for invalid events
};
+private:
// ---------------------------------------------------------------------------
// API for handling format entry operations
@@ -248,6 +248,8 @@
int author;
}; //TODO __attribute__((packed));
+using StateTsEntryWithAuthor = HistTsEntryWithAuthor;
+
struct HistIntEntry {
log_hash_t hash;
int value;
@@ -341,7 +343,7 @@
virtual void logStart(const char *fmt);
virtual void logEnd();
virtual void logHash(log_hash_t hash);
- virtual void logHistTS(log_hash_t hash);
+ virtual void logEventHistTs(Event event, log_hash_t hash);
virtual bool isEnabled() const;
diff --git a/media/libnbaio/include/media/nbaio/PerformanceAnalysis.h b/media/libnbaio/include/media/nbaio/PerformanceAnalysis.h
index 89699bf..4be567f 100644
--- a/media/libnbaio/include/media/nbaio/PerformanceAnalysis.h
+++ b/media/libnbaio/include/media/nbaio/PerformanceAnalysis.h
@@ -52,6 +52,17 @@
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);
+
+ // Called when an audio on/off event is read from the buffer
+ // 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);
+
// 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
diff --git a/services/audioflinger/FastMixer.cpp b/services/audioflinger/FastMixer.cpp
index c4a0c0d..c10fa05 100644
--- a/services/audioflinger/FastMixer.cpp
+++ b/services/audioflinger/FastMixer.cpp
@@ -138,6 +138,8 @@
void FastMixer::onStateChange()
{
+ // log that audio was turned on/off
+ LOG_AUDIO_STATE();
const FastMixerState * const current = (const FastMixerState *) mCurrent;
const FastMixerState * const previous = (const FastMixerState *) mPrevious;
FastMixerDumpState * const dumpState = (FastMixerDumpState *) mDumpState;
diff --git a/services/audioflinger/TypedLogger.h b/services/audioflinger/TypedLogger.h
index 83aa6a1..909af09 100644
--- a/services/audioflinger/TypedLogger.h
+++ b/services/audioflinger/TypedLogger.h
@@ -88,7 +88,11 @@
// Write histogram timestamp entry
#define LOG_HIST_TS() do { NBLog::Writer *x = tlNBLogWriter; if (x != nullptr) \
- x->logHistTS(hash(__FILE__, __LINE__)); } while(0)
+ x->logEventHistTs(NBLog::EVENT_HISTOGRAM_ENTRY_TS, hash(__FILE__, __LINE__)); } while(0)
+
+// Record that audio was turned on/off
+#define LOG_AUDIO_STATE() do { NBLog::Writer *x = tlNBLogWriter; if (x != nullptr) \
+ x->logEventHistTs(NBLog::EVENT_AUDIO_STATE, hash(__FILE__, __LINE__)); } while(0)
namespace android {
extern "C" {