Merge "NBLog: Make separate readers for dumping logs and histograms"
diff --git a/media/libnblog/NBLog.cpp b/media/libnblog/NBLog.cpp
index f5d2d6d..d659445 100644
--- a/media/libnblog/NBLog.cpp
+++ b/media/libnblog/NBLog.cpp
@@ -20,11 +20,7 @@
#include <algorithm>
#include <climits>
-#include <deque>
-#include <fstream>
-#include <iostream>
#include <math.h>
-#include <numeric>
#include <unordered_set>
#include <vector>
#include <stdarg.h>
@@ -727,7 +723,7 @@
};
NBLog::Reader::Reader(const void *shared, size_t size, const std::string &name)
- : mFd(-1), mIndent(0), mLost(0), mName(name),
+ : mName(name),
mShared((/*const*/ Shared *) shared), /*mIMemory*/
mFifo(mShared != NULL ?
new audio_utils_fifo(size, sizeof(uint8_t),
@@ -769,10 +765,10 @@
// 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()
+std::unique_ptr<NBLog::Snapshot> NBLog::Reader::getSnapshot()
{
if (mFifoReader == NULL) {
- return std::unique_ptr<NBLog::Reader::Snapshot>(new Snapshot());
+ return std::make_unique<Snapshot>();
}
// This emulates the behaviour of audio_utils_fifo_reader::read, but without incrementing the
@@ -802,7 +798,7 @@
if (availToRead <= 0) {
ALOGW_IF(availToRead < 0, "NBLog Reader %s failed to catch up with Writer", mName.c_str());
- return std::make_unique<NBLog::Reader::Snapshot>();
+ return std::make_unique<Snapshot>();
}
std::unique_ptr<Snapshot> snapshot(new Snapshot(availToRead));
@@ -853,17 +849,12 @@
// 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)
+void NBLog::MergeReader::getAndProcessSnapshot(NBLog::Snapshot &snapshot, int author)
{
- String8 timestamp, body;
-
- for (auto entry = snapshot.begin(); entry != snapshot.end();) {
- switch (entry->type) {
- case EVENT_START_FMT:
- entry = handleFormat(FormatEntry(entry), ×tamp, &body);
- break;
+ for (const entry &etr : snapshot) {
+ switch (etr.type) {
case EVENT_HISTOGRAM_ENTRY_TS: {
- HistTsEntryWithAuthor *data = (HistTsEntryWithAuthor *) (entry->data);
+ HistTsEntry *data = (HistTsEntry *) (etr.data);
// TODO This memcpies are here to avoid unaligned memory access crash.
// There's probably a more efficient way to do it
log_hash_t hash;
@@ -872,45 +863,41 @@
memcpy(&ts, &data->ts, sizeof(ts));
// TODO: hash for histogram ts and audio state need to match
// and correspond to audio production source file location
- mThreadPerformanceAnalysis[data->author][0 /*hash*/].logTsEntry(ts);
- ++entry;
- break;
- }
+ mThreadPerformanceAnalysis[author][0 /*hash*/].logTsEntry(ts);
+ } break;
case EVENT_AUDIO_STATE: {
- HistTsEntryWithAuthor *data = (HistTsEntryWithAuthor *) (entry->data);
+ HistTsEntry *data = (HistTsEntry *) (etr.data);
// TODO This memcpies are here to avoid unaligned memory access crash.
// There's probably a more efficient way to do it
log_hash_t hash;
memcpy(&hash, &(data->hash), sizeof(hash));
- // TODO: remove ts if unused
- int64_t ts;
- memcpy(&ts, &data->ts, sizeof(ts));
- mThreadPerformanceAnalysis[data->author][0 /*hash*/].handleStateChange();
- ++entry;
- break;
- }
+ mThreadPerformanceAnalysis[author][0 /*hash*/].handleStateChange();
+ } break;
case EVENT_END_FMT:
- body.appendFormat("warning: got to end format event");
- ++entry;
- break;
case EVENT_RESERVED:
+ case EVENT_UPPER_BOUND:
+ ALOGW("warning: unexpected event %d", etr.type);
default:
- body.appendFormat("warning: unexpected event %d", entry->type);
- ++entry;
break;
}
}
- // FIXME: decide whether to print the warnings here or elsewhere
- if (!body.isEmpty()) {
- dumpLine(×tamp, &body);
- }
}
void NBLog::MergeReader::getAndProcessSnapshot()
{
- // get a snapshot, process it
- std::unique_ptr<Snapshot> snap = getSnapshot();
- getAndProcessSnapshot(*snap);
+ // get a snapshot of each reader and process them
+ // TODO insert lock here
+ const size_t nLogs = mReaders.size();
+ std::vector<std::unique_ptr<Snapshot>> snapshots(nLogs);
+ for (size_t i = 0; i < nLogs; i++) {
+ snapshots[i] = mReaders[i]->getSnapshot();
+ }
+ // TODO unlock lock here
+ for (size_t i = 0; i < nLogs; i++) {
+ if (snapshots[i] != nullptr) {
+ getAndProcessSnapshot(*(snapshots[i]), i);
+ }
+ }
}
void NBLog::MergeReader::dump(int fd, int indent)
@@ -919,66 +906,41 @@
ReportPerformance::dump(fd, indent, mThreadPerformanceAnalysis);
}
-void NBLog::Reader::dump(int fd, size_t indent, NBLog::Reader::Snapshot &snapshot)
+// TODO for future compatibility, would prefer to have a dump() go to string, and then go
+// to fd only when invoked through binder.
+void NBLog::DumpReader::dump(int fd, size_t indent)
{
- mFd = fd;
- mIndent = indent;
- String8 timestamp, body;
-
- // Range-based for loop isn't used here because handleFormat() returns an EntryIterator
- // that points to the next entry (it handles all of the necessary operator++() calls).
- for (auto entry = snapshot.begin(); entry != snapshot.end();) {
- switch (entry->type) {
- case EVENT_START_FMT:
- entry = handleFormat(FormatEntry(entry), ×tamp, &body);
- break;
- case EVENT_HISTOGRAM_ENTRY_TS:
- ++entry;
- break;
- case EVENT_AUDIO_STATE:
- ++entry;
- break;
- case EVENT_END_FMT:
- body.appendFormat("warning: got to end format event");
- ++entry;
- break;
- case EVENT_MONOTONIC_CYCLE_TIME: {
- uint32_t monotonicNs = *(uint32_t *) (entry->data);
- body.appendFormat("Thread cycle took %u ns", monotonicNs);
- ++entry;
- } break;
- case EVENT_RESERVED:
- default:
- body.appendFormat("warning: unexpected event %d", entry->type);
- ++entry;
- break;
- }
- // FIXME: decide whether to print the warnings here or elsewhere
- if (!body.isEmpty()) {
- dumpLine(×tamp, &body);
- }
- }
-}
-
-void NBLog::Reader::dump(int fd, size_t indent)
-{
- // get a snapshot, dump it
- std::unique_ptr<Snapshot> snap = getSnapshot();
- dump(fd, indent, *snap);
-}
-
-// Writes a string to the console
-void NBLog::Reader::dumpLine(const String8 *timestamp, String8 *body)
-{
- if (timestamp == nullptr || body == nullptr) {
+ if (fd < 0) return;
+ std::unique_ptr<Snapshot> snapshot = getSnapshot();
+ if (snapshot == nullptr) {
return;
}
- if (mFd >= 0) {
- dprintf(mFd, "%.*s%s %s\n", mIndent, "", timestamp->string(), body->string());
- } else {
- ALOGI("%.*s%s %s", mIndent, "", timestamp->string(), body->string());
+ String8 timestamp, body;
+
+ // TODO all logged types should have a printable format.
+ for (auto it = snapshot->begin(); it != snapshot->end(); ++it) {
+ switch (it->type) {
+ case EVENT_START_FMT:
+ it = handleFormat(FormatEntry(it), ×tamp, &body);
+ break;
+ case EVENT_MONOTONIC_CYCLE_TIME: {
+ uint32_t monotonicNs;
+ memcpy(&monotonicNs, it->data, sizeof(monotonicNs));
+ body.appendFormat("Thread cycle took %u ns", monotonicNs);
+ } break;
+ case EVENT_END_FMT:
+ case EVENT_RESERVED:
+ case EVENT_UPPER_BOUND:
+ body.appendFormat("warning: unexpected event %d", it->type);
+ default:
+ break;
+ }
+ if (!body.isEmpty()) {
+ dprintf(fd, "%.*s%s %s\n", (int)indent, "", timestamp.string(), body.string());
+ body.clear();
+ }
+ timestamp.clear();
}
- body->clear();
}
bool NBLog::Reader::isIMemory(const sp<IMemory>& iMemory) const
@@ -986,9 +948,7 @@
return iMemory != 0 && mIMemory != 0 && iMemory->pointer() == mIMemory->pointer();
}
-// ---------------------------------------------------------------------------
-
-void NBLog::appendTimestamp(String8 *body, const void *data)
+void NBLog::DumpReader::appendTimestamp(String8 *body, const void *data)
{
if (body == nullptr || data == nullptr) {
return;
@@ -999,7 +959,7 @@
(int) ((ts / (1000 * 1000)) % 1000));
}
-void NBLog::appendInt(String8 *body, const void *data)
+void NBLog::DumpReader::appendInt(String8 *body, const void *data)
{
if (body == nullptr || data == nullptr) {
return;
@@ -1008,7 +968,7 @@
body->appendFormat("<%d>", x);
}
-void NBLog::appendFloat(String8 *body, const void *data)
+void NBLog::DumpReader::appendFloat(String8 *body, const void *data)
{
if (body == nullptr || data == nullptr) {
return;
@@ -1018,7 +978,7 @@
body->appendFormat("<%f>", f);
}
-void NBLog::appendPID(String8 *body, const void* data, size_t length)
+void NBLog::DumpReader::appendPID(String8 *body, const void* data, size_t length)
{
if (body == nullptr || data == nullptr) {
return;
@@ -1028,7 +988,7 @@
body->appendFormat("<PID: %d, name: %.*s>", id, (int) (length - sizeof(pid_t)), name);
}
-String8 NBLog::bufferDump(const uint8_t *buffer, size_t size)
+String8 NBLog::DumpReader::bufferDump(const uint8_t *buffer, size_t size)
{
String8 str;
if (buffer == nullptr) {
@@ -1042,14 +1002,14 @@
return str;
}
-String8 NBLog::bufferDump(const EntryIterator &it)
+String8 NBLog::DumpReader::bufferDump(const EntryIterator &it)
{
return bufferDump(it, it->length + Entry::kOverhead);
}
-NBLog::EntryIterator NBLog::Reader::handleFormat(const FormatEntry &fmtEntry,
- String8 *timestamp,
- String8 *body)
+NBLog::EntryIterator NBLog::DumpReader::handleFormat(const FormatEntry &fmtEntry,
+ String8 *timestamp,
+ String8 *body)
{
// log timestamp
int64_t ts = fmtEntry.timestamp();
@@ -1135,7 +1095,6 @@
++arg;
}
ALOGW_IF(arg->type != EVENT_END_FMT, "Expected end of format, got %d", arg->type);
- ++arg;
return arg;
}
@@ -1172,10 +1131,10 @@
// 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.
+ if (true) return; // Merging is not necessary at the moment, so this is to disable it
+ // and bypass compiler warnings about member variables not being used.
const int nLogs = mReaders.size();
- std::vector<std::unique_ptr<NBLog::Reader::Snapshot>> snapshots(nLogs);
+ std::vector<std::unique_ptr<Snapshot>> snapshots(nLogs);
std::vector<EntryIterator> offsets;
offsets.reserve(nLogs);
for (int i = 0; i < nLogs; ++i) {
@@ -1258,13 +1217,12 @@
{
AutoMutex _l(mMutex);
// If mTimeoutUs is negative, wait on the condition variable until it's positive.
- // If it's positive, wait kThreadSleepPeriodUs and then merge
- nsecs_t waitTime = mTimeoutUs > 0 ? kThreadSleepPeriodUs * 1000 : LLONG_MAX;
- mCond.waitRelative(mMutex, waitTime);
+ // If it's positive, merge. The minimum period between waking the condition variable
+ // is handled in AudioFlinger::MediaLogNotifier::threadLoop().
+ mCond.wait(mMutex);
doMerge = mTimeoutUs > 0;
mTimeoutUs -= kThreadSleepPeriodUs;
}
- doMerge = false; // Disable merging for now.
if (doMerge) {
// Merge data from all the readers
mMerger.merge();
diff --git a/media/libnblog/include/media/nblog/NBLog.h b/media/libnblog/include/media/nblog/NBLog.h
index 71941a4..c9bfaae 100644
--- a/media/libnblog/include/media/nblog/NBLog.h
+++ b/media/libnblog/include/media/nblog/NBLog.h
@@ -19,7 +19,6 @@
#ifndef ANDROID_MEDIA_NBLOG_H
#define ANDROID_MEDIA_NBLOG_H
-#include <deque>
#include <map>
#include <unordered_set>
#include <vector>
@@ -76,17 +75,6 @@
private:
// ---------------------------------------------------------------------------
- // API for handling format entry operations
-
- // a formatted entry has the following structure:
- // * START_FMT entry, containing the format string
- // * TIMESTAMP entry
- // * HASH entry
- // * author entry of the thread that generated it (optional, present in merged log)
- // * format arg1
- // * format arg2
- // * ...
- // * END_FMT entry
// entry representation in memory
struct entry {
@@ -144,6 +132,9 @@
const uint8_t *mPtr; // Should not be nullptr except for dummy initialization
};
+ // ---------------------------------------------------------------------------
+ // The following classes are used for merging into the Merger's buffer.
+
class AbstractEntry {
public:
virtual ~AbstractEntry() {}
@@ -175,6 +166,17 @@
const uint8_t *mEntry;
};
+ // API for handling format entry operations
+
+ // a formatted entry has the following structure:
+ // * START_FMT entry, containing the format string
+ // * TIMESTAMP entry
+ // * HASH entry
+ // * author entry of the thread that generated it (optional, present in merged log)
+ // * format arg1
+ // * format arg2
+ // * ...
+ // * END_FMT entry
class FormatEntry : public AbstractEntry {
public:
// explicit FormatEntry(const EntryIterator &it);
@@ -226,7 +228,16 @@
// ---------------------------------------------------------------------------
- // representation of a single log entry in private memory
+ // representation of a single log entry in shared memory
+ // byte[0] mEvent
+ // byte[1] mLength
+ // byte[2] mData[0]
+ // ...
+ // byte[2+i] mData[i]
+ // ...
+ // byte[2+mLength-1] mData[mLength-1]
+ // byte[2+mLength] duplicate copy of mLength to permit reverse scan
+ // byte[3+mLength] start of next log entry
class Entry {
public:
Entry(Event event, const void *data, size_t length)
@@ -267,24 +278,6 @@
int value;
}; //TODO __attribute__((packed));
- // representation of a single log entry in shared memory
- // byte[0] mEvent
- // byte[1] mLength
- // byte[2] mData[0]
- // ...
- // byte[2+i] mData[i]
- // ...
- // byte[2+mLength-1] mData[mLength-1]
- // byte[2+mLength] duplicate copy of mLength to permit reverse scan
- // byte[3+mLength] start of next log entry
-
- static void appendInt(String8 *body, const void *data);
- static void appendFloat(String8 *body, const void *data);
- static void appendPID(String8 *body, const void *data, size_t length);
- static void appendTimestamp(String8 *body, const void *data);
- static size_t fmtEntryLength(const uint8_t *data);
- static String8 bufferDump(const uint8_t *buffer, size_t size);
- static String8 bufferDump(const EntryIterator &it);
public:
// Located in shared memory, must be POD.
@@ -420,89 +413,86 @@
// ---------------------------------------------------------------------------
+ // A snapshot of a readers buffer
+ // This is raw data. No analysis has been done on it
+ class Snapshot {
+ public:
+ Snapshot() = default;
+
+ explicit Snapshot(size_t bufferSize) : mData(new uint8_t[bufferSize]) {}
+
+ ~Snapshot() { delete[] mData; }
+
+ // amount of data lost (given by audio_utils_fifo_reader)
+ size_t lost() const { return mLost; }
+
+ // iterator to beginning of readable segment of snapshot
+ // data between begin and end has valid entries
+ EntryIterator begin() const { return mBegin; }
+
+ // iterator to end of readable segment of snapshot
+ EntryIterator end() const { return mEnd; }
+
+ private:
+ friend class Reader;
+ uint8_t * const mData{};
+ size_t mLost{0};
+ EntryIterator mBegin;
+ EntryIterator mEnd;
+ };
+
class Reader : public RefBase {
public:
- // A snapshot of a readers buffer
- // This is raw data. No analysis has been done on it
- class Snapshot {
- public:
- Snapshot() : mData(NULL), mLost(0) {}
-
- Snapshot(size_t bufferSize) : mData(new uint8_t[bufferSize]) {}
-
- ~Snapshot() { delete[] mData; }
-
- // copy of the buffer
- uint8_t *data() const { return mData; }
-
- // amount of data lost (given by audio_utils_fifo_reader)
- size_t lost() const { return mLost; }
-
- // iterator to beginning of readable segment of snapshot
- // data between begin and end has valid entries
- EntryIterator begin() { return mBegin; }
-
- // iterator to end of readable segment of snapshot
- EntryIterator end() { return mEnd; }
-
- private:
- friend class Reader;
- uint8_t *mData;
- size_t mLost;
- EntryIterator mBegin;
- EntryIterator mEnd;
- };
-
// Input parameter 'size' is the desired size of the timeline in byte units.
// The size of the shared memory must be at least Timeline::sharedSize(size).
Reader(const void *shared, size_t size, const std::string &name);
Reader(const sp<IMemory>& iMemory, size_t size, const std::string &name);
-
virtual ~Reader();
// get snapshot of readers fifo buffer, effectively consuming the buffer
std::unique_ptr<Snapshot> getSnapshot();
- // dump a particular snapshot of the reader
- 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);
-
bool isIMemory(const sp<IMemory>& iMemory) const;
-
const std::string &name() const { return mName; }
- protected:
- // print a summary of the performance to the console
- 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
- const std::string mName; // name of reader (actually name of writer)
- static constexpr int kMaxObtainTries = 3;
-
private:
+ static constexpr int kMaxObtainTries = 3;
+ // startingTypes and endingTypes are used to check for log corruption.
static const std::unordered_set<Event> startingTypes;
static const std::unordered_set<Event> endingTypes;
-
// declared as const because audio_utils_fifo() constructor
sp<IMemory> mIMemory; // ref-counted version, assigned only in constructor
+ const std::string mName; // name of reader (actually name of writer)
/*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
+ // non-NULL unless constructor fails
audio_utils_fifo_reader * const mFifoReader; // used to read from FIFO,
- // non-NULL unless constructor fails
+ // non-NULL unless constructor fails
// 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::unordered_set<Event> &types);
+ };
- // dummy method for handling absent author entry
- virtual void handleAuthor(const AbstractEntry& /*fmtEntry*/, String8* /*body*/) {}
+ class DumpReader : public Reader {
+ public:
+ DumpReader(const void *shared, size_t size, const std::string &name)
+ : Reader(shared, size, name) {}
+ DumpReader(const sp<IMemory>& iMemory, size_t size, const std::string &name)
+ : Reader(iMemory, size, name) {}
+ void dump(int fd, size_t indent = 0);
+ private:
+ void handleAuthor(const AbstractEntry& fmtEntry __unused, String8* body __unused) {}
+ EntryIterator handleFormat(const FormatEntry &fmtEntry, String8 *timestamp, String8 *body);
+
+ static void appendInt(String8 *body, const void *data);
+ static void appendFloat(String8 *body, const void *data);
+ static void appendPID(String8 *body, const void *data, size_t length);
+ static void appendTimestamp(String8 *body, const void *data);
+ //static size_t fmtEntryLength(const uint8_t *data); // TODO Eric remove if not used
+ static String8 bufferDump(const uint8_t *buffer, size_t size);
+ static String8 bufferDump(const EntryIterator &it);
};
// ---------------------------------------------------------------------------
@@ -542,7 +532,7 @@
void dump(int fd, int indent = 0);
// process a particular snapshot of the reader
- void getAndProcessSnapshot(Snapshot & snap);
+ void getAndProcessSnapshot(Snapshot &snap, int author);
// call getSnapshot of the content of the reader's buffer and process the data
void getAndProcessSnapshot();
diff --git a/services/medialog/MediaLogService.cpp b/services/medialog/MediaLogService.cpp
index 095dd5c..b23832e 100644
--- a/services/medialog/MediaLogService.cpp
+++ b/services/medialog/MediaLogService.cpp
@@ -58,9 +58,10 @@
shared->size() < NBLog::Timeline::sharedSize(size)) {
return;
}
- sp<NBLog::Reader> reader(new NBLog::Reader(shared, size, name));
+ sp<NBLog::Reader> reader(new NBLog::Reader(shared, size, name)); // Reader handled by merger
+ sp<NBLog::DumpReader> dumpReader(new NBLog::DumpReader(shared, size, name)); // for dumpsys
Mutex::Autolock _l(mLock);
- mReaders.add(reader);
+ mDumpReaders.add(dumpReader);
mMerger.addReader(reader);
}
@@ -70,9 +71,10 @@
return;
}
Mutex::Autolock _l(mLock);
- for (size_t i = 0; i < mReaders.size(); ) {
- if (mReaders[i]->isIMemory(shared)) {
- mReaders.removeAt(i);
+ for (size_t i = 0; i < mDumpReaders.size(); ) {
+ if (mDumpReaders[i]->isIMemory(shared)) {
+ mDumpReaders.removeAt(i);
+ // TODO mMerger.removeReaders(shared)
} else {
i++;
}
@@ -120,18 +122,18 @@
return NO_ERROR;
}
- for (auto reader : mReaders) {
+ for (const auto &dumpReader : mDumpReaders) {
if (fd >= 0) {
- dprintf(fd, "\n%s:\n", reader->name().c_str());
- reader->dump(fd, 0 /*indent*/);
+ dprintf(fd, "\n%s:\n", dumpReader->name().c_str());
+ dumpReader->dump(fd, 0 /*indent*/);
} else {
- ALOGI("%s:", reader->name().c_str());
+ ALOGI("%s:", dumpReader->name().c_str());
}
}
mLock.unlock();
}
}
- //mMergeReader.dump(fd);
+ mMergeReader.dump(fd);
return NO_ERROR;
}
diff --git a/services/medialog/MediaLogService.h b/services/medialog/MediaLogService.h
index 3763484..a1572f9 100644
--- a/services/medialog/MediaLogService.h
+++ b/services/medialog/MediaLogService.h
@@ -55,7 +55,7 @@
Mutex mLock;
- Vector<sp<NBLog::Reader>> mReaders; // protected by mLock
+ Vector<sp<NBLog::DumpReader>> mDumpReaders; // protected by mLock
// FIXME Need comments on all of these, especially about locking
NBLog::Shared *mMergerShared;