Separate merge from dump and call merge periodically
Every time merge is called by the thread loop,
the data is also processed and written to
PerformanceAnalysis. A call to dump retrieves
the FIFO of processed data in PerformanceAnalysis
instead of the unprocessed Reader FIFO, and prints
the result to the console.
Test: dumpsys media.log
Change-Id: Ic479f48e9e4fdf4523a8f15db514dbdd85b70434
diff --git a/include/media/nbaio/ReportPerformance.h b/include/media/nbaio/ReportPerformance.h
new file mode 120000
index 0000000..bd596e3
--- /dev/null
+++ b/include/media/nbaio/ReportPerformance.h
@@ -0,0 +1 @@
+../../../media/libnbaio/include/media/nbaio/ReportPerformance.h
\ No newline at end of file
diff --git a/media/libnbaio/NBLog.cpp b/media/libnbaio/NBLog.cpp
index 2f639d2..f00d86f 100644
--- a/media/libnbaio/NBLog.cpp
+++ b/media/libnbaio/NBLog.cpp
@@ -87,7 +87,6 @@
*/
#define LOG_TAG "NBLog"
-// #define LOG_NDEBUG 0
#include <algorithm>
#include <climits>
@@ -109,7 +108,7 @@
#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/CallStack.h>
#include <utils/Log.h>
#include <utils/String8.h>
@@ -766,8 +765,8 @@
NBLog::Event::EVENT_AUDIO_STATE};
NBLog::Reader::Reader(const void *shared, size_t size)
- : mShared((/*const*/ Shared *) shared), /*mIMemory*/
- mFd(-1), mIndent(0),
+ : mFd(-1), mIndent(0), mLost(0),
+ mShared((/*const*/ Shared *) shared), /*mIMemory*/
mFifo(mShared != NULL ?
new audio_utils_fifo(size, sizeof(uint8_t),
mShared->mBuffer, mShared->mRear, NULL /*throttlesFront*/) : NULL),
@@ -805,6 +804,9 @@
return nullptr; // no entry found
}
+// Copies content of a Reader FIFO into its Snapshot
+// The Snapshot has the same raw data, but represented as a sequence of entries
+// and an EntryIterator making it possible to process the data.
std::unique_ptr<NBLog::Reader::Snapshot> NBLog::Reader::getSnapshot()
{
if (mFifoReader == NULL) {
@@ -870,23 +872,19 @@
}
-// 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)
+// Takes raw content of the local merger FIFO, processes log entries, and
+// writes the data to a map of class PerformanceAnalysis, based on their thread ID.
+void NBLog::MergeReader::getAndProcessSnapshot(NBLog::Reader::Snapshot &snapshot)
{
- mFd = fd;
- mIndent = indent;
String8 timestamp, body;
+ // TODO: check: is the FIXME below still a problem?
// FIXME: this is not thread safe
- // TODO: need a separate instance of performanceAnalysis for each thread
- // used to store data and to call analysis functions
- static ReportPerformance::PerformanceAnalysis performanceAnalysis;
+ // TODO: add lost data information and notification to ReportPerformance
size_t lost = snapshot.lost() + (snapshot.begin() - EntryIterator(snapshot.data()));
if (lost > 0) {
- body.appendFormat("warning: lost %zu bytes worth of events", lost);
- // TODO timestamp empty here, only other choice to wait for the first timestamp event in the
- // log to push it out. Consider keeping the timestamp/body between calls to copyEntryDataAt().
- dumpLine(timestamp, body);
+ // TODO: ultimately, this will be += and reset to 0. TODO: check that this is
+ // obsolete now that Merger::merge is called periodically. No data should be lost
+ mLost = lost;
}
for (auto entry = snapshot.begin(); entry != snapshot.end();) {
@@ -902,12 +900,20 @@
memcpy(&hash, &(data->hash), sizeof(hash));
int64_t ts;
memcpy(&ts, &data->ts, sizeof(ts));
- performanceAnalysis.logTsEntry(ts);
+ mThreadPerformanceAnalysis[data->author].logTsEntry(ts);
++entry;
break;
}
case EVENT_AUDIO_STATE: {
- performanceAnalysis.handleStateChange();
+ HistTsEntryWithAuthor *data = (HistTsEntryWithAuthor *) (entry->data);
+ // TODO This memcpies are here to avoid unaligned memory access crash.
+ // There's probably a more efficient way to do it
+ // TODO: incorporate hash information in mThreadPerformanceAnalysis
+ // log_hash_t hash;
+ // memcpy(&hash, &(data->hash), sizeof(hash));
+ // int64_t ts;
+ // memcpy(&ts, &data->ts, sizeof(ts));
+ mThreadPerformanceAnalysis[data->author].handleStateChange();
++entry;
break;
}
@@ -922,19 +928,38 @@
break;
}
}
- performanceAnalysis.reportPerformance(&body);
+ // FIXME: decide whether to print the warnings here or elsewhere
if (!body.isEmpty()) {
dumpLine(timestamp, body);
}
}
-void NBLog::Reader::dump(int fd, size_t indent)
+void NBLog::MergeReader::getAndProcessSnapshot()
{
- // get a snapshot, dump it
+ // get a snapshot, process it
std::unique_ptr<Snapshot> snap = getSnapshot();
- dump(fd, indent, *snap);
+ getAndProcessSnapshot(*snap);
}
+// TODO: move this function to a different class than NBLog::Reader
+// writes summary of performance to the console
+void NBLog::MergeReader::dump(int fd, size_t indent)
+{
+ mFd = fd;
+ mIndent = indent;
+ String8 body, timestamp;
+ // TODO: check: is the FIXME below still a problem?
+ // FIXME: this is not thread safe
+ for (auto & threadReport : mThreadPerformanceAnalysis) {
+ threadReport.second.reportPerformance(&body);
+ }
+ if (!body.isEmpty()) {
+ ALOGD("body is not empty");
+ dumpLine(timestamp, body);
+ }
+}
+
+// Writes a string to the console
void NBLog::Reader::dumpLine(const String8 ×tamp, String8 &body)
{
if (mFd >= 0) {
@@ -1093,6 +1118,7 @@
{}
void NBLog::Merger::addReader(const NBLog::NamedReader &reader) {
+
// FIXME This is called by binder thread in MediaLogService::registerWriter
// but the access to shared variable mNamedReaders is not yet protected by a lock.
mNamedReaders.push_back(reader);
@@ -1116,7 +1142,7 @@
return i1.ts > i2.ts || (i1.ts == i2.ts && i1.index > i2.index);
}
-// Merge registered readers, sorted by timestamp
+// Merge registered readers, sorted by timestamp, and write data to a single FIFO in local memory
void NBLog::Merger::merge() {
// FIXME This is called by merge thread
// but the access to shared variable mNamedReaders is not yet protected by a lock.
@@ -1173,8 +1199,9 @@
// ---------------------------------------------------------------------------
-NBLog::MergeThread::MergeThread(NBLog::Merger &merger)
+NBLog::MergeThread::MergeThread(NBLog::Merger &merger, NBLog::MergeReader &mergeReader)
: mMerger(merger),
+ mMergeReader(mergeReader),
mTimeoutUs(0) {}
NBLog::MergeThread::~MergeThread() {
@@ -1196,7 +1223,12 @@
mTimeoutUs -= kThreadSleepPeriodUs;
}
if (doMerge) {
+ // Merge data from all the readers
mMerger.merge();
+ // Process the data collected by mMerger and write it to PerformanceAnalysis
+ // FIXME: decide whether to call getAndProcessSnapshot every time
+ // or whether to have a separate thread that calls it with a lower frequency
+ mMergeReader.getAndProcessSnapshot();
}
return true;
}
diff --git a/media/libnbaio/PerformanceAnalysis.cpp b/media/libnbaio/PerformanceAnalysis.cpp
index fb3bddc..d44dd45 100644
--- a/media/libnbaio/PerformanceAnalysis.cpp
+++ b/media/libnbaio/PerformanceAnalysis.cpp
@@ -271,7 +271,6 @@
ALOGD("reportPerformance: mRecentHists is empty");
return;
}
- ALOGD("reportPerformance: hists size %d", static_cast<int>(mRecentHists.size()));
// TODO: more elaborate data analysis
std::map<int, int> buckets;
for (const auto &shortHist: mRecentHists) {
@@ -306,6 +305,7 @@
scalingFactor = (height + maxHeight) / maxHeight;
height /= scalingFactor;
}
+ // TODO: print reader (author) ID
body->appendFormat("\n%*s", leftPadding + 11, "Occurrences");
// write histogram label line with bucket values
body->appendFormat("\n%s", " ");
diff --git a/media/libnbaio/ReportPerformance.cpp b/media/libnbaio/ReportPerformance.cpp
index dc50ada..7d3869c 100644
--- a/media/libnbaio/ReportPerformance.cpp
+++ b/media/libnbaio/ReportPerformance.cpp
@@ -38,8 +38,8 @@
// 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,
+void writeToFile(const std::deque<std::pair<outlierInterval, timestamp>> &outlierData,
+ const std::deque<std::pair<timestamp, Histogram>> &hists,
const char * kName,
bool append) {
ALOGD("writing performance data to file");
@@ -65,6 +65,7 @@
for (const auto &bucket : hist.second) {
ofs << bucket.first << ": " << bucket.second << "\n";
}
+ ofs << "\n"; // separate histograms with a newline
}
ofs.close();
}
diff --git a/media/libnbaio/include/media/nbaio/NBLog.h b/media/libnbaio/include/media/nbaio/NBLog.h
index 3189e4e..1504f81 100644
--- a/media/libnbaio/include/media/nbaio/NBLog.h
+++ b/media/libnbaio/include/media/nbaio/NBLog.h
@@ -19,16 +19,18 @@
#ifndef ANDROID_MEDIA_NBLOG_H
#define ANDROID_MEDIA_NBLOG_H
-#include <binder/IMemory.h>
-#include <audio_utils/fifo.h>
-#include <utils/Mutex.h>
-#include <utils/threads.h>
-
-#include <map>
#include <deque>
+#include <map>
#include <set>
#include <vector>
+#include <audio_utils/fifo.h>
+#include <binder/IMemory.h>
+#include <media/nbaio/PerformanceAnalysis.h>
+#include <media/nbaio/ReportPerformance.h>
+#include <utils/Mutex.h>
+#include <utils/threads.h>
+
namespace android {
class String8;
@@ -409,7 +411,6 @@
class Reader : public RefBase {
public:
-
// A snapshot of a readers buffer
// This is raw data. No analysis has been done on it
class Snapshot {
@@ -434,6 +435,7 @@
EntryIterator end() { return mEnd; }
private:
+ friend class MergeReader;
friend class Reader;
uint8_t *mData;
size_t mLost;
@@ -450,22 +452,26 @@
// get snapshot of readers fifo buffer, effectively consuming the buffer
std::unique_ptr<Snapshot> getSnapshot();
- // dump a particular snapshot of the reader
- // TODO: move dump to PerformanceAnalysis. Model/view/controller design
- void dump(int fd, size_t indent, Snapshot & snap);
- // dump the current content of the reader's buffer (call getSnapshot() and previous dump())
- void dump(int fd, size_t indent = 0);
+ // print a summary of the performance to the console
bool isIMemory(const sp<IMemory>& iMemory) const;
- private:
+ protected:
+ void dumpLine(const String8& timestamp, String8& body);
+ EntryIterator handleFormat(const FormatEntry &fmtEntry,
+ String8 *timestamp,
+ String8 *body);
+ int mFd; // file descriptor
+ int mIndent; // indentation level
+ int mLost; // bytes of data lost before buffer was read
+ private:
static const std::set<Event> startingTypes;
static const std::set<Event> endingTypes;
- /*const*/ Shared* const mShared; // raw pointer to shared memory, actually const but not
+
// declared as const because audio_utils_fifo() constructor
sp<IMemory> mIMemory; // ref-counted version, assigned only in constructor
- int mFd; // file descriptor
- int mIndent; // indentation level
+
+ /*const*/ Shared* const mShared; // raw pointer to shared memory, actually const but not
audio_utils_fifo * const mFifo; // FIFO itself,
// non-NULL unless constructor fails
audio_utils_fifo_reader * const mFifoReader; // used to read from FIFO,
@@ -476,20 +482,14 @@
// represented that location. And one_of its fields would be a vector of timestamps.
// That would allow us to record other information about the source location beyond
// timestamps.
- void dumpLine(const String8& timestamp, String8& body);
-
- EntryIterator handleFormat(const FormatEntry &fmtEntry,
- String8 *timestamp,
- String8 *body);
- // dummy method for handling absent author entry
- virtual void handleAuthor(const AbstractEntry& /*fmtEntry*/, String8* /*body*/) {}
// Searches for the last entry of type <type> in the range [front, back)
// back has to be entry-aligned. Returns nullptr if none enconuntered.
static const uint8_t *findLastEntryOfTypes(const uint8_t *front, const uint8_t *back,
const std::set<Event> &types);
- static const size_t kSquashTimestamp = 5; // squash this many or more adjacent timestamps
+ // dummy method for handling absent author entry
+ virtual void handleAuthor(const AbstractEntry& /*fmtEntry*/, String8* /*body*/) {}
};
// Wrapper for a reader with a name. Contains a pointer to the reader and a pointer to the name
@@ -511,6 +511,8 @@
// ---------------------------------------------------------------------------
+ // This class is used to read data from each thread's individual FIFO in shared memory
+ // and write it to a single FIFO in local memory.
class Merger : public RefBase {
public:
Merger(const void *shared, size_t size);
@@ -520,27 +522,43 @@
void addReader(const NamedReader &reader);
// TODO add removeReader
void merge();
+
// FIXME This is returning a reference to a shared variable that needs a lock
const std::vector<NamedReader>& getNamedReaders() const;
+
private:
// vector of the readers the merger is supposed to merge from.
// every reader reads from a writer's buffer
// FIXME Needs to be protected by a lock
std::vector<NamedReader> mNamedReaders;
- // TODO Need comments on all of these
- Shared * const mShared;
- std::unique_ptr<audio_utils_fifo> mFifo;
- std::unique_ptr<audio_utils_fifo_writer> mFifoWriter;
+ Shared * const mShared; // raw pointer to shared memory
+ std::unique_ptr<audio_utils_fifo> mFifo; // FIFO itself
+ std::unique_ptr<audio_utils_fifo_writer> mFifoWriter; // used to write to FIFO
};
+ // This class has a pointer to the FIFO in local memory which stores the merged
+ // data collected by NBLog::Merger from all NamedReaders. It is used to process
+ // this data and write the result to PerformanceAnalysis.
class MergeReader : public Reader {
public:
MergeReader(const void *shared, size_t size, Merger &merger);
+
+ // TODO: consider moving dump to ReportPerformance
+ void dump(int fd, size_t indent = 0);
+ // process a particular snapshot of the reader
+ void getAndProcessSnapshot(Snapshot & snap);
+ // call getSnapshot of the content of the reader's buffer and process the data
+ void getAndProcessSnapshot();
+
private:
// FIXME Needs to be protected by a lock,
// because even though our use of it is read-only there may be asynchronous updates
const std::vector<NamedReader>& mNamedReaders;
+
+ // analyzes, compresses and stores the merged data
+ std::map<int, ReportPerformance::PerformanceAnalysis> mThreadPerformanceAnalysis;
+
// handle author entry by looking up the author's name and appending it to the body
// returns number of bytes read from fmtEntry
void handleAuthor(const AbstractEntry &fmtEntry, String8 *body);
@@ -552,7 +570,7 @@
// The thread is triggered on AudioFlinger binder activity.
class MergeThread : public Thread {
public:
- MergeThread(Merger &merger);
+ MergeThread(Merger &merger, MergeReader &mergeReader);
virtual ~MergeThread() override;
// Reset timeout and activate thread to merge periodically if it's idle
@@ -567,6 +585,9 @@
// the merger who actually does the work of merging the logs
Merger& mMerger;
+ // the mergereader used to process data merged by mMerger
+ MergeReader& mMergeReader;
+
// mutex for the condition variable
Mutex mMutex;
diff --git a/media/libnbaio/include/media/nbaio/PerformanceAnalysis.h b/media/libnbaio/include/media/nbaio/PerformanceAnalysis.h
index b0dc148..d523aa9 100644
--- a/media/libnbaio/include/media/nbaio/PerformanceAnalysis.h
+++ b/media/libnbaio/include/media/nbaio/PerformanceAnalysis.h
@@ -19,11 +19,11 @@
#ifndef ANDROID_MEDIA_PERFORMANCEANALYSIS_H
#define ANDROID_MEDIA_PERFORMANCEANALYSIS_H
-#include <map>
#include <deque>
+#include <map>
#include <vector>
-#include "NBLog.h"
-#include "ReportPerformance.h"
+
+#include <media/nbaio/ReportPerformance.h>
namespace android {
diff --git a/media/libnbaio/include/media/nbaio/ReportPerformance.h b/media/libnbaio/include/media/nbaio/ReportPerformance.h
index 27d2810..e5b9840 100644
--- a/media/libnbaio/include/media/nbaio/ReportPerformance.h
+++ b/media/libnbaio/include/media/nbaio/ReportPerformance.h
@@ -24,7 +24,7 @@
namespace android {
// This class is used by reportPerformance function
-// TODO move reportPerformance function to ReportPerformance.cpp
+// TODO move PerformanceAnalysis::reportPerformance function to ReportPerformance.cpp
class String8;
namespace ReportPerformance {
@@ -52,10 +52,12 @@
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(std::deque<std::pair<outlierInterval, timestamp>> &outlierData,
- std::deque<std::pair<timestamp, Histogram>> &hists,
+void writeToFile(const std::deque<std::pair<outlierInterval, timestamp>> &outlierData,
+ const std::deque<std::pair<timestamp, Histogram>> &hists,
const char * kName,
bool append);
diff --git a/services/medialog/MediaLogService.cpp b/services/medialog/MediaLogService.cpp
index a5512e1..fe19b6b 100644
--- a/services/medialog/MediaLogService.cpp
+++ b/services/medialog/MediaLogService.cpp
@@ -26,13 +26,19 @@
namespace android {
- static const char kDeadlockedString[] = "MediaLogService may be deadlocked\n";
+static const char kDeadlockedString[] = "MediaLogService may be deadlocked\n";
+
+// mMerger, mMergeReader, and mMergeThread all point to the same location in memory
+// mMergerShared. This is the local memory FIFO containing data merged from all
+// individual thread FIFOs in shared memory. mMergeThread is used to periodically
+// call NBLog::Merger::merge() to collect the data and write it to the FIFO, and call
+// NBLog::MergeReader::getAndProcessSnapshot to process the merged data.
MediaLogService::MediaLogService() :
BnMediaLogService(),
mMergerShared((NBLog::Shared*) malloc(NBLog::Timeline::sharedSize(kMergeBufferSize))),
mMerger(mMergerShared, kMergeBufferSize),
mMergeReader(mMergerShared, kMergeBufferSize, mMerger),
- mMergeThread(new NBLog::MergeThread(mMerger))
+ mMergeThread(new NBLog::MergeThread(mMerger, mMergeReader))
{
mMergeThread->run("MergeThread");
}
@@ -123,15 +129,10 @@
} else {
ALOGI("%s:", namedReader.name());
}
- // TODO This code is for testing, remove it when done
- // namedReader.reader()->dump(fd, 0 /*indent*/);
}
-
mLock.unlock();
}
}
-
- // FIXME request merge to make sure log is up to date
mMergeReader.dump(fd);
return NO_ERROR;
}