Merge "nblog: split NBLog.cpp into multiple files"

gugelfrei
Glenn Kasten 6 years ago committed by Android (Google) Code Review
commit d975119d1a

@ -18,6 +18,7 @@ LOCAL_SHARED_LIBRARIES := \
libmedia \
libmedialogservice \
libnbaio \
libnblog \
libsoundtriggerservice \
libutils

@ -40,16 +40,17 @@ cc_library_shared {
"TrackPlayerBase.cpp",
],
shared_libs: [
"liblog",
"libcutils",
"libutils",
"libbinder",
"libdl",
"libaudioutils",
"libaudiomanager",
"libbinder",
"libcutils",
"libdl",
"liblog",
"libmedia_helper",
"libmediametrics",
"libmediautils",
"libnblog",
"libutils",
],
export_shared_lib_headers: ["libbinder"],

@ -18,17 +18,18 @@
#ifndef ANDROID_AUDIO_MIXER_H
#define ANDROID_AUDIO_MIXER_H
#include <map>
#include <pthread.h>
#include <sstream>
#include <stdint.h>
#include <sys/types.h>
#include <unordered_map>
#include <vector>
#include <media/AudioBufferProvider.h>
#include <media/AudioResampler.h>
#include <media/AudioResamplerPublic.h>
#include <media/BufferProviders.h>
#include <media/nblog/NBLog.h>
#include <system/audio.h>
#include <utils/Compat.h>
#include <utils/threads.h>
@ -41,6 +42,10 @@
namespace android {
namespace NBLog {
class Writer;
} // namespace NBLog
// ----------------------------------------------------------------------------
class AudioMixer

@ -3,9 +3,13 @@ cc_library_shared {
name: "libnblog",
srcs: [
"NBLog.cpp",
"Entry.cpp",
"Merger.cpp",
"PerformanceAnalysis.cpp",
"Reader.cpp",
"ReportPerformance.cpp",
"Timeline.cpp",
"Writer.cpp",
],
shared_libs: [

@ -0,0 +1,262 @@
/*
* Copyright (C) 2018 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 "NBLog"
//#define LOG_NDEBUG 0
#include <memory>
#include <stddef.h>
#include <stdint.h>
#include <audio_utils/fifo.h>
#include <media/nblog/Entry.h>
#include <media/nblog/Events.h>
#include <utils/Log.h>
namespace android {
namespace NBLog {
int Entry::copyEntryDataAt(size_t offset) const
{
// FIXME This is too slow
if (offset == 0) {
return mEvent;
} else if (offset == 1) {
return mLength;
} else if (offset < (size_t) (mLength + 2)) {
return (int) ((char *) mData)[offset - 2];
} else if (offset == (size_t) (mLength + 2)) {
return mLength;
} else {
return 0; // FIXME is this an error?
}
}
EntryIterator::EntryIterator() // Dummy initialization.
: mPtr(nullptr)
{
}
EntryIterator::EntryIterator(const uint8_t *entry)
: mPtr(entry)
{
}
EntryIterator::EntryIterator(const EntryIterator &other)
: mPtr(other.mPtr)
{
}
const entry& EntryIterator::operator*() const
{
return *(entry*) mPtr;
}
const entry* EntryIterator::operator->() const
{
return (entry*) mPtr;
}
EntryIterator& EntryIterator::operator++()
{
mPtr += mPtr[offsetof(entry, length)] + Entry::kOverhead;
return *this;
}
EntryIterator& EntryIterator::operator--()
{
mPtr -= mPtr[Entry::kPreviousLengthOffset] + Entry::kOverhead;
return *this;
}
EntryIterator EntryIterator::next() const
{
EntryIterator aux(*this);
return ++aux;
}
EntryIterator EntryIterator::prev() const
{
EntryIterator aux(*this);
return --aux;
}
bool EntryIterator::operator!=(const EntryIterator &other) const
{
return mPtr != other.mPtr;
}
int EntryIterator::operator-(const EntryIterator &other) const
{
return mPtr - other.mPtr;
}
bool EntryIterator::hasConsistentLength() const
{
return mPtr[offsetof(entry, length)] == mPtr[mPtr[offsetof(entry, length)] +
Entry::kOverhead + Entry::kPreviousLengthOffset];
}
void EntryIterator::copyTo(std::unique_ptr<audio_utils_fifo_writer> &dst) const
{
size_t length = mPtr[offsetof(entry, length)] + Entry::kOverhead;
dst->write(mPtr, length);
}
void EntryIterator::copyData(uint8_t *dst) const
{
memcpy((void*) dst, mPtr + offsetof(entry, data), mPtr[offsetof(entry, length)]);
}
// ---------------------------------------------------------------------------
std::unique_ptr<AbstractEntry> AbstractEntry::buildEntry(const uint8_t *ptr)
{
if (ptr == nullptr) {
return nullptr;
}
const uint8_t type = EntryIterator(ptr)->type;
switch (type) {
case EVENT_FMT_START:
return std::make_unique<FormatEntry>(FormatEntry(ptr));
case EVENT_AUDIO_STATE:
case EVENT_HISTOGRAM_ENTRY_TS:
return std::make_unique<HistogramEntry>(HistogramEntry(ptr));
default:
ALOGW("Tried to create AbstractEntry of type %d", type);
return nullptr;
}
}
EntryIterator FormatEntry::begin() const
{
return EntryIterator(mEntry);
}
const char *FormatEntry::formatString() const
{
return (const char*) mEntry + offsetof(entry, data);
}
size_t FormatEntry::formatStringLength() const
{
return mEntry[offsetof(entry, length)];
}
EntryIterator FormatEntry::args() const
{
auto it = begin();
++it; // skip start fmt
++it; // skip timestamp
++it; // skip hash
// Skip author if present
if (it->type == EVENT_FMT_AUTHOR) {
++it;
}
return it;
}
int64_t FormatEntry::timestamp() const
{
auto it = begin();
++it; // skip start fmt
return it.payload<int64_t>();
}
log_hash_t FormatEntry::hash() const
{
auto it = begin();
++it; // skip start fmt
++it; // skip timestamp
// unaligned 64-bit read not supported
log_hash_t hash;
memcpy(&hash, it->data, sizeof(hash));
return hash;
}
int FormatEntry::author() const
{
auto it = begin();
++it; // skip start fmt
++it; // skip timestamp
++it; // skip hash
// if there is an author entry, return it, return -1 otherwise
return it->type == EVENT_FMT_AUTHOR ? it.payload<int>() : -1;
}
EntryIterator FormatEntry::copyWithAuthor(
std::unique_ptr<audio_utils_fifo_writer> &dst, int author) const
{
auto it = begin();
it.copyTo(dst); // copy fmt start entry
(++it).copyTo(dst); // copy timestamp
(++it).copyTo(dst); // copy hash
// insert author entry
size_t authorEntrySize = Entry::kOverhead + sizeof(author);
uint8_t authorEntry[authorEntrySize];
authorEntry[offsetof(entry, type)] = EVENT_FMT_AUTHOR;
authorEntry[offsetof(entry, length)] =
authorEntry[authorEntrySize + Entry::kPreviousLengthOffset] =
sizeof(author);
*(int*) (&authorEntry[offsetof(entry, data)]) = author;
dst->write(authorEntry, authorEntrySize);
// copy rest of entries
while ((++it)->type != EVENT_FMT_END) {
it.copyTo(dst);
}
it.copyTo(dst);
++it;
return it;
}
int64_t HistogramEntry::timestamp() const
{
return EntryIterator(mEntry).payload<HistTsEntry>().ts;
}
log_hash_t HistogramEntry::hash() const
{
return EntryIterator(mEntry).payload<HistTsEntry>().hash;
}
int HistogramEntry::author() const
{
EntryIterator it(mEntry);
return it->length == sizeof(HistTsEntryWithAuthor)
? it.payload<HistTsEntryWithAuthor>().author : -1;
}
EntryIterator HistogramEntry::copyWithAuthor(
std::unique_ptr<audio_utils_fifo_writer> &dst, int author) const
{
// Current histogram entry has {type, length, struct HistTsEntry, length}.
// We now want {type, length, struct HistTsEntryWithAuthor, length}
uint8_t buffer[Entry::kOverhead + sizeof(HistTsEntryWithAuthor)];
// Copy content until the point we want to add the author
memcpy(buffer, mEntry, sizeof(entry) + sizeof(HistTsEntry));
// Copy the author
*(int*) (buffer + sizeof(entry) + sizeof(HistTsEntry)) = author;
// Update lengths
buffer[offsetof(entry, length)] = sizeof(HistTsEntryWithAuthor);
buffer[offsetof(entry, data) + sizeof(HistTsEntryWithAuthor) + offsetof(ending, length)]
= sizeof(HistTsEntryWithAuthor);
// Write new buffer into FIFO
dst->write(buffer, sizeof(buffer));
return EntryIterator(mEntry).next();
}
} // namespace NBLog
} // namespace android

@ -0,0 +1,297 @@
/*
* Copyright (C) 2018 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 "NBLog"
//#define LOG_NDEBUG 0
#include <memory>
#include <queue>
#include <stddef.h>
#include <stdint.h>
#include <vector>
#include <audio_utils/fifo.h>
#include <json/json.h>
#include <media/nblog/Merger.h>
#include <media/nblog/PerformanceAnalysis.h>
#include <media/nblog/ReportPerformance.h>
#include <media/nblog/Reader.h>
#include <media/nblog/Timeline.h>
#include <utils/Condition.h>
#include <utils/Log.h>
#include <utils/Mutex.h>
#include <utils/RefBase.h>
#include <utils/String8.h>
#include <utils/Timers.h>
#include <utils/Thread.h>
namespace android {
namespace NBLog {
Merger::Merger(const void *shared, size_t size):
mShared((Shared *) shared),
mFifo(mShared != NULL ?
new audio_utils_fifo(size, sizeof(uint8_t),
mShared->mBuffer, mShared->mRear, NULL /*throttlesFront*/) : NULL),
mFifoWriter(mFifo != NULL ? new audio_utils_fifo_writer(*mFifo) : NULL)
{
}
void Merger::addReader(const sp<Reader> &reader)
{
// FIXME This is called by binder thread in MediaLogService::registerWriter
// but the access to shared variable mReaders is not yet protected by a lock.
mReaders.push_back(reader);
}
// items placed in priority queue during merge
// composed by a timestamp and the index of the snapshot where the timestamp came from
struct MergeItem
{
int64_t ts;
int index;
MergeItem(int64_t ts, int index): ts(ts), index(index) {}
};
bool operator>(const struct MergeItem &i1, const struct MergeItem &i2)
{
return i1.ts > i2.ts || (i1.ts == i2.ts && i1.index > i2.index);
}
// Merge registered readers, sorted by timestamp, and write data to a single FIFO in local memory
void Merger::merge()
{
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<Snapshot>> snapshots(nLogs);
std::vector<EntryIterator> offsets;
offsets.reserve(nLogs);
for (int i = 0; i < nLogs; ++i) {
snapshots[i] = mReaders[i]->getSnapshot();
offsets.push_back(snapshots[i]->begin());
}
// initialize offsets
// TODO custom heap implementation could allow to update top, improving performance
// for bursty buffers
std::priority_queue<MergeItem, std::vector<MergeItem>, std::greater<MergeItem>> timestamps;
for (int i = 0; i < nLogs; ++i)
{
if (offsets[i] != snapshots[i]->end()) {
std::unique_ptr<AbstractEntry> abstractEntry = AbstractEntry::buildEntry(offsets[i]);
if (abstractEntry == nullptr) {
continue;
}
timestamps.emplace(abstractEntry->timestamp(), i);
}
}
while (!timestamps.empty()) {
int index = timestamps.top().index; // find minimum timestamp
// copy it to the log, increasing offset
offsets[index] = AbstractEntry::buildEntry(offsets[index])->
copyWithAuthor(mFifoWriter, index);
// update data structures
timestamps.pop();
if (offsets[index] != snapshots[index]->end()) {
int64_t ts = AbstractEntry::buildEntry(offsets[index])->timestamp();
timestamps.emplace(ts, index);
}
}
}
const std::vector<sp<Reader>>& Merger::getReaders() const
{
//AutoMutex _l(mLock);
return mReaders;
}
// ---------------------------------------------------------------------------
MergeReader::MergeReader(const void *shared, size_t size, Merger &merger)
: Reader(shared, size, "MergeReader"), mReaders(merger.getReaders())
{
}
// 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 MergeReader::processSnapshot(Snapshot &snapshot, int author)
{
ReportPerformance::PerformanceData& data = mThreadPerformanceData[author];
// We don't do "auto it" because it reduces readability in this case.
for (EntryIterator it = snapshot.begin(); it != snapshot.end(); ++it) {
switch (it->type) {
case EVENT_HISTOGRAM_ENTRY_TS: {
const HistTsEntry payload = it.payload<HistTsEntry>();
// TODO: hash for histogram ts and audio state need to match
// and correspond to audio production source file location
mThreadPerformanceAnalysis[author][0 /*hash*/].logTsEntry(payload.ts);
} break;
case EVENT_AUDIO_STATE: {
mThreadPerformanceAnalysis[author][0 /*hash*/].handleStateChange();
} break;
case EVENT_THREAD_INFO: {
const thread_info_t info = it.payload<thread_info_t>();
// TODO make PerformanceData hold a type of thread_info_t.
// Currently, thread_info_t is defined in NBLog.h, which includes
// PerformanceAnalysis.h. PerformanceData is defined in PerformanceAnalysis.h,
// where including NBLog.h would result in circular includes. The organization
// of files will need to change to avoid this problem.
data.threadInfo = info;
} break;
case EVENT_LATENCY: {
const double latencyMs = it.payload<double>();
data.latencyHist.add(latencyMs);
} break;
case EVENT_WORK_TIME: {
const int64_t monotonicNs = it.payload<int64_t>();
const double monotonicMs = monotonicNs * 1e-6;
data.workHist.add(monotonicMs);
data.active += monotonicNs;
} break;
case EVENT_WARMUP_TIME: {
const double timeMs = it.payload<double>();
data.warmupHist.add(timeMs);
} break;
case EVENT_UNDERRUN:
data.underruns++;
break;
case EVENT_OVERRUN:
data.overruns++;
break;
case EVENT_RESERVED:
case EVENT_UPPER_BOUND:
ALOGW("warning: unexpected event %d", it->type);
default:
break;
}
}
}
void MergeReader::getAndProcessSnapshot()
{
// 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) {
processSnapshot(*(snapshots[i]), i);
}
}
checkPushToMediaMetrics();
}
void MergeReader::checkPushToMediaMetrics()
{
const nsecs_t now = systemTime();
for (auto& item : mThreadPerformanceData) {
ReportPerformance::PerformanceData& data = item.second;
if (now - data.start >= kPeriodicMediaMetricsPush) {
(void)ReportPerformance::sendToMediaMetrics(data);
data.reset(); // data is persistent per thread
}
}
}
void MergeReader::dump(int fd, int indent)
{
// TODO: add a mutex around media.log dump
ReportPerformance::dump(fd, indent, mThreadPerformanceAnalysis);
Json::Value root(Json::arrayValue);
for (const auto& item : mThreadPerformanceData) {
const ReportPerformance::PerformanceData& data = item.second;
std::unique_ptr<Json::Value> threadData = ReportPerformance::dumpToJson(data);
if (threadData == nullptr) {
continue;
}
(*threadData)["threadNum"] = item.first;
root.append(*threadData);
}
Json::StyledWriter writer;
std::string rootStr = writer.write(root);
write(fd, rootStr.c_str(), rootStr.size());
}
void MergeReader::handleAuthor(const AbstractEntry &entry, String8 *body)
{
int author = entry.author();
if (author == -1) {
return;
}
// FIXME Needs a lock
const char* name = mReaders[author]->name().c_str();
body->appendFormat("%s: ", name);
}
// ---------------------------------------------------------------------------
MergeThread::MergeThread(Merger &merger, MergeReader &mergeReader)
: mMerger(merger),
mMergeReader(mergeReader),
mTimeoutUs(0)
{
}
MergeThread::~MergeThread()
{
// set exit flag, set timeout to 0 to force threadLoop to exit and wait for the thread to join
requestExit();
setTimeoutUs(0);
join();
}
bool MergeThread::threadLoop()
{
bool doMerge;
{
AutoMutex _l(mMutex);
// If mTimeoutUs is negative, wait on the condition variable until it's positive.
// 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;
}
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;
}
void MergeThread::wakeup()
{
setTimeoutUs(kThreadWakeupPeriodUs);
}
void MergeThread::setTimeoutUs(int time)
{
AutoMutex _l(mMutex);
mTimeoutUs = time;
mCond.signal();
}
} // namespace NBLog
} // namespace android

File diff suppressed because it is too large Load Diff

@ -47,7 +47,6 @@
#include <utility>
namespace android {
namespace ReportPerformance {
void Histogram::add(double value)
@ -367,5 +366,4 @@ void dumpLine(int fd, int indent, const String8 &body) {
}
} // namespace ReportPerformance
} // namespace android

@ -0,0 +1,421 @@
/*
* Copyright (C) 2018 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 "NBLog"
//#define LOG_NDEBUG 0
#include <memory>
#include <stddef.h>
#include <string>
#include <unordered_set>
#include <audio_utils/fifo.h>
#include <binder/IMemory.h>
#include <media/nblog/Entry.h>
#include <media/nblog/Events.h>
#include <media/nblog/Reader.h>
#include <media/nblog/Timeline.h>
#include <utils/Log.h>
#include <utils/String8.h>
namespace android {
namespace NBLog {
Reader::Reader(const void *shared, size_t size, const std::string &name)
: mName(name),
mShared((/*const*/ Shared *) shared), /*mIMemory*/
mFifo(mShared != NULL ?
new audio_utils_fifo(size, sizeof(uint8_t),
mShared->mBuffer, mShared->mRear, NULL /*throttlesFront*/) : NULL),
mFifoReader(mFifo != NULL ? new audio_utils_fifo_reader(*mFifo) : NULL)
{
}
Reader::Reader(const sp<IMemory>& iMemory, size_t size, const std::string &name)
: Reader(iMemory != 0 ? (Shared *) iMemory->pointer() : NULL, size, name)
{
mIMemory = iMemory;
}
Reader::~Reader()
{
delete mFifoReader;
delete mFifo;
}
// 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<Snapshot> Reader::getSnapshot()
{
if (mFifoReader == NULL) {
return std::unique_ptr<Snapshot>(new Snapshot());
}
// This emulates the behaviour of audio_utils_fifo_reader::read, but without incrementing the
// reader index. The index is incremented after handling corruption, to after the last complete
// entry of the buffer
size_t lost = 0;
audio_utils_iovec iovec[2];
const size_t capacity = mFifo->capacity();
ssize_t availToRead;
// A call to audio_utils_fifo_reader::obtain() places the read pointer one buffer length
// before the writer's pointer (since mFifoReader was constructed with flush=false). The
// do while loop is an attempt to read all of the FIFO's contents regardless of how behind
// the reader is with respect to the writer. However, the following scheduling sequence is
// possible and can lead to a starvation situation:
// - Writer T1 writes, overrun with respect to Reader T2
// - T2 calls obtain() and gets EOVERFLOW, T2 ptr placed one buffer size behind T1 ptr
// - T1 write, overrun
// - T2 obtain(), EOVERFLOW (and so on...)
// To address this issue, we limit the number of tries for the reader to catch up with
// the writer.
int tries = 0;
size_t lostTemp;
do {
availToRead = mFifoReader->obtain(iovec, capacity, NULL /*timeout*/, &lostTemp);
lost += lostTemp;
} while (availToRead < 0 || ++tries <= kMaxObtainTries);
if (availToRead <= 0) {
ALOGW_IF(availToRead < 0, "NBLog Reader %s failed to catch up with Writer", mName.c_str());
return std::unique_ptr<Snapshot>(new Snapshot());
}
// Change to #if 1 for debugging. This statement is useful for checking buffer fullness levels
// (as seen by reader) and how much data was lost. If you find that the fullness level is
// getting close to full, or that data loss is happening to often, then you should
// probably try some of the following:
// - log less data
// - log less often
// - increase the initial shared memory allocation for the buffer
#if 0
ALOGD("getSnapshot name=%s, availToRead=%zd, capacity=%zu, fullness=%.3f, lost=%zu",
name().c_str(), availToRead, capacity, (double)availToRead / (double)capacity, lost);
#endif
std::unique_ptr<Snapshot> snapshot(new Snapshot(availToRead));
memcpy(snapshot->mData, (const char *) mFifo->buffer() + iovec[0].mOffset, iovec[0].mLength);
if (iovec[1].mLength > 0) {
memcpy(snapshot->mData + (iovec[0].mLength),
(const char *) mFifo->buffer() + iovec[1].mOffset, iovec[1].mLength);
}
// Handle corrupted buffer
// Potentially, a buffer has corrupted data on both beginning (due to overflow) and end
// (due to incomplete format entry). But even if the end format entry is incomplete,
// it ends in a complete entry (which is not an FMT_END). So is safe to traverse backwards.
// TODO: handle client corruption (in the middle of a buffer)
const uint8_t *back = snapshot->mData + availToRead;
const uint8_t *front = snapshot->mData;
// Find last FMT_END. <back> is sitting on an entry which might be the middle of a FormatEntry.
// We go backwards until we find an EVENT_FMT_END.
const uint8_t *lastEnd = findLastValidEntry(front, back, invalidEndTypes);
if (lastEnd == nullptr) {
snapshot->mEnd = snapshot->mBegin = EntryIterator(front);
} else {
// end of snapshot points to after last FMT_END entry
snapshot->mEnd = EntryIterator(lastEnd).next();
// find first FMT_START
const uint8_t *firstStart = nullptr;
const uint8_t *firstStartTmp = snapshot->mEnd;
while ((firstStartTmp = findLastValidEntry(front, firstStartTmp, invalidBeginTypes))
!= nullptr) {
firstStart = firstStartTmp;
}
// firstStart is null if no FMT_START entry was found before lastEnd
if (firstStart == nullptr) {
snapshot->mBegin = snapshot->mEnd;
} else {
snapshot->mBegin = EntryIterator(firstStart);
}
}
// advance fifo reader index to after last entry read.
mFifoReader->release(snapshot->mEnd - front);
snapshot->mLost = lost;
return snapshot;
}
bool Reader::isIMemory(const sp<IMemory>& iMemory) const
{
return iMemory != 0 && mIMemory != 0 && iMemory->pointer() == mIMemory->pointer();
}
// We make a set of the invalid types rather than the valid types when aligning
// Snapshot EntryIterators to valid entries during log corruption checking.
// This is done in order to avoid the maintenance overhead of adding a new Event
// type to the two sets below whenever a new Event type is created, as it is
// very likely that new types added will be valid types.
// Currently, invalidBeginTypes and invalidEndTypes are used to handle the special
// case of a Format Entry, which consists of a variable number of simple log entries.
// If a new Event is added that consists of a variable number of simple log entries,
// then these sets need to be updated.
// We want the beginning of a Snapshot to point to an entry that is not in
// the middle of a formatted entry and not an FMT_END.
const std::unordered_set<Event> Reader::invalidBeginTypes {
EVENT_FMT_AUTHOR,
EVENT_FMT_END,
EVENT_FMT_FLOAT,
EVENT_FMT_HASH,
EVENT_FMT_INTEGER,
EVENT_FMT_PID,
EVENT_FMT_STRING,
EVENT_FMT_TIMESTAMP,
};
// We want the end of a Snapshot to point to an entry that is not in
// the middle of a formatted entry and not a FMT_START.
const std::unordered_set<Event> Reader::invalidEndTypes {
EVENT_FMT_AUTHOR,
EVENT_FMT_FLOAT,
EVENT_FMT_HASH,
EVENT_FMT_INTEGER,
EVENT_FMT_PID,
EVENT_FMT_START,
EVENT_FMT_STRING,
EVENT_FMT_TIMESTAMP,
};
const uint8_t *Reader::findLastValidEntry(const uint8_t *front, const uint8_t *back,
const std::unordered_set<Event> &invalidTypes) {
if (front == nullptr || back == nullptr) {
return nullptr;
}
while (back + Entry::kPreviousLengthOffset >= front) {
const uint8_t *prev = back - back[Entry::kPreviousLengthOffset] - Entry::kOverhead;
const Event type = (const Event)prev[offsetof(entry, type)];
if (prev < front
|| prev + prev[offsetof(entry, length)] + Entry::kOverhead != back
|| type <= EVENT_RESERVED || type >= EVENT_UPPER_BOUND) {
// prev points to an out of limits or inconsistent entry
return nullptr;
}
// if invalidTypes does not contain the type, then the type is valid.
if (invalidTypes.find(type) == invalidTypes.end()) {
return prev;
}
back = prev;
}
return nullptr; // no entry found
}
// TODO for future compatibility, would prefer to have a dump() go to string, and then go
// to fd only when invoked through binder.
void DumpReader::dump(int fd, size_t indent)
{
if (fd < 0) return;
std::unique_ptr<Snapshot> snapshot = getSnapshot();
if (snapshot == nullptr) {
return;
}
String8 timestamp, body;
// TODO all logged types should have a printable format.
for (EntryIterator it = snapshot->begin(); it != snapshot->end(); ++it) {
switch (it->type) {
case EVENT_FMT_START:
it = handleFormat(FormatEntry(it), &timestamp, &body);
break;
case EVENT_WORK_TIME: {
const int64_t monotonicNs = it.payload<int64_t>();
body.appendFormat("Thread cycle: %ld ns", (long)monotonicNs);
} break;
case EVENT_LATENCY: {
const double latencyMs = it.payload<double>();
body.appendFormat("latency: %.3f ms", latencyMs);
} break;
case EVENT_WARMUP_TIME: {
const double timeMs = it.payload<double>();
body.appendFormat("warmup time: %.3f ms", timeMs);
} break;
case EVENT_UNDERRUN:
body.appendFormat("underrun");
break;
case EVENT_OVERRUN:
body.appendFormat("overrun");
break;
case EVENT_FMT_END:
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();
}
}
EntryIterator DumpReader::handleFormat(const FormatEntry &fmtEntry,
String8 *timestamp, String8 *body)
{
// log timestamp
const int64_t ts = fmtEntry.timestamp();
timestamp->clear();
timestamp->appendFormat("[%d.%03d]", (int) (ts / (1000 * 1000 * 1000)),
(int) ((ts / (1000 * 1000)) % 1000));
// log unique hash
log_hash_t hash = fmtEntry.hash();
// print only lower 16bit of hash as hex and line as int to reduce spam in the log
body->appendFormat("%.4X-%d ", (int)(hash >> 16) & 0xFFFF, (int) hash & 0xFFFF);
// log author (if present)
handleAuthor(fmtEntry, body);
// log string
EntryIterator arg = fmtEntry.args();
const char* fmt = fmtEntry.formatString();
size_t fmt_length = fmtEntry.formatStringLength();
for (size_t fmt_offset = 0; fmt_offset < fmt_length; ++fmt_offset) {
if (fmt[fmt_offset] != '%') {
body->append(&fmt[fmt_offset], 1); // TODO optimize to write consecutive strings at once
continue;
}
// case "%%""
if (fmt[++fmt_offset] == '%') {
body->append("%");
continue;
}
// case "%\0"
if (fmt_offset == fmt_length) {
continue;
}
Event event = (Event) arg->type;
size_t length = arg->length;
// TODO check length for event type is correct
if (event == EVENT_FMT_END) {
break;
}
// TODO: implement more complex formatting such as %.3f
const uint8_t *datum = arg->data; // pointer to the current event args
switch(fmt[fmt_offset])
{
case 's': // string
ALOGW_IF(event != EVENT_FMT_STRING,
"NBLog Reader incompatible event for string specifier: %d", event);
body->append((const char*) datum, length);
break;
case 't': // timestamp
ALOGW_IF(event != EVENT_FMT_TIMESTAMP,
"NBLog Reader incompatible event for timestamp specifier: %d", event);
appendTimestamp(body, datum);
break;
case 'd': // integer
ALOGW_IF(event != EVENT_FMT_INTEGER,
"NBLog Reader incompatible event for integer specifier: %d", event);
appendInt(body, datum);
break;
case 'f': // float
ALOGW_IF(event != EVENT_FMT_FLOAT,
"NBLog Reader incompatible event for float specifier: %d", event);
appendFloat(body, datum);
break;
case 'p': // pid
ALOGW_IF(event != EVENT_FMT_PID,
"NBLog Reader incompatible event for pid specifier: %d", event);
appendPID(body, datum, length);
break;
default:
ALOGW("NBLog Reader encountered unknown character %c", fmt[fmt_offset]);
}
++arg;
}
ALOGW_IF(arg->type != EVENT_FMT_END, "Expected end of format, got %d", arg->type);
return arg;
}
void DumpReader::appendInt(String8 *body, const void *data)
{
if (body == nullptr || data == nullptr) {
return;
}
//int x = *((int*) data);
int x;
memcpy(&x, data, sizeof(x));
body->appendFormat("<%d>", x);
}
void DumpReader::appendFloat(String8 *body, const void *data)
{
if (body == nullptr || data == nullptr) {
return;
}
float f;
memcpy(&f, data, sizeof(f));
body->appendFormat("<%f>", f);
}
void DumpReader::appendPID(String8 *body, const void* data, size_t length)
{
if (body == nullptr || data == nullptr) {
return;
}
pid_t id = *((pid_t*) data);
char * name = &((char*) data)[sizeof(pid_t)];
body->appendFormat("<PID: %d, name: %.*s>", id, (int) (length - sizeof(pid_t)), name);
}
void DumpReader::appendTimestamp(String8 *body, const void *data)
{
if (body == nullptr || data == nullptr) {
return;
}
int64_t ts;
memcpy(&ts, data, sizeof(ts));
body->appendFormat("[%d.%03d]", (int) (ts / (1000 * 1000 * 1000)),
(int) ((ts / (1000 * 1000)) % 1000));
}
String8 DumpReader::bufferDump(const uint8_t *buffer, size_t size)
{
String8 str;
if (buffer == nullptr) {
return str;
}
str.append("[ ");
for(size_t i = 0; i < size; i++) {
str.appendFormat("%d ", buffer[i]);
}
str.append("]");
return str;
}
String8 DumpReader::bufferDump(const EntryIterator &it)
{
return bufferDump(it, it->length + Entry::kOverhead);
}
} // namespace NBLog
} // namespace android

@ -15,6 +15,7 @@
*/
#define LOG_TAG "ReportPerformance"
//#define LOG_NDEBUG 0
#include <fstream>
#include <iostream>
@ -30,23 +31,22 @@
#include <utility>
#include <json/json.h>
#include <media/MediaAnalyticsItem.h>
#include <media/nblog/NBLog.h>
#include <media/nblog/Events.h>
#include <media/nblog/PerformanceAnalysis.h>
#include <media/nblog/ReportPerformance.h>
#include <utils/Log.h>
#include <utils/String8.h>
namespace android {
namespace ReportPerformance {
std::unique_ptr<Json::Value> dumpToJson(const PerformanceData& data)
{
std::unique_ptr<Json::Value> rootPtr = std::make_unique<Json::Value>(Json::objectValue);
Json::Value& root = *rootPtr;
root["type"] = data.type;
root["frameCount"] = (Json::Value::Int)data.frameCount;
root["sampleRate"] = (Json::Value::Int)data.sampleRate;
root["type"] = (Json::Value::Int)data.threadInfo.type;
root["frameCount"] = (Json::Value::Int)data.threadInfo.frameCount;
root["sampleRate"] = (Json::Value::Int)data.threadInfo.sampleRate;
root["workMsHist"] = data.workHist.toString();
root["latencyMsHist"] = data.latencyHist.toString();
root["warmupMsHist"] = data.warmupHist.toString();
@ -102,15 +102,10 @@ bool sendToMediaMetrics(const PerformanceData& data)
// we want to send them only if there are performance metrics to send.
if (item->count() > 0) {
// Add thread info fields.
const int type = data.type;
// TODO have a int-to-string mapping defined somewhere else for other thread types.
if (type == 2) {
item->setCString(kThreadType, "FASTMIXER");
} else {
item->setCString(kThreadType, "UNKNOWN");
}
item->setInt32(kThreadFrameCount, data.frameCount);
item->setInt32(kThreadSampleRate, data.sampleRate);
const char * const typeString = NBLog::threadTypeToString(data.threadInfo.type);
item->setCString(kThreadType, typeString);
item->setInt32(kThreadFrameCount, data.threadInfo.frameCount);
item->setInt32(kThreadSampleRate, data.threadInfo.sampleRate);
// Add time info fields.
item->setInt64(kThreadActive, data.active / 1000000);
item->setInt64(kThreadDuration, (systemTime() - data.start) / 1000000);
@ -211,6 +206,5 @@ void writeToFile(const std::deque<std::pair<timestamp, Hist>> &hists,
pfs.close();
}
} // namespace ReportPerformance
} // namespace ReportPerformance
} // namespace android

@ -0,0 +1,50 @@
/*
* Copyright (C) 2018 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.
*/
#include <stddef.h>
#include <audio_utils/roundup.h>
#include <media/nblog/Timeline.h>
namespace android {
namespace NBLog {
#if 0 // FIXME see note in Timeline.h
NBLog::Timeline::Timeline(size_t size, void *shared)
: mSize(roundup(size)), mOwn(shared == NULL),
mShared((Shared *) (mOwn ? new char[sharedSize(size)] : shared))
{
new (mShared) Shared;
}
NBLog::Timeline::~Timeline()
{
mShared->~Shared();
if (mOwn) {
delete[] (char *) mShared;
}
}
#endif
/*static*/
size_t Timeline::sharedSize(size_t size)
{
// TODO fifo now supports non-power-of-2 buffer sizes, so could remove the roundup
return sizeof(Shared) + roundup(size);
}
} // namespace NBLog
} // namespace android

@ -0,0 +1,320 @@
/*
* Copyright (C) 2018 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 "NBLog"
//#define LOG_NDEBUG 0
#include <stdarg.h>
#include <stddef.h>
#include <sys/prctl.h>
#include <audio_utils/fifo.h>
#include <binder/IMemory.h>
#include <media/nblog/Entry.h>
#include <media/nblog/Events.h>
#include <media/nblog/Timeline.h>
#include <media/nblog/Writer.h>
#include <utils/Log.h>
#include <utils/Mutex.h>
namespace android {
namespace NBLog {
Writer::Writer(void *shared, size_t size)
: mShared((Shared *) shared),
mFifo(mShared != NULL ?
new audio_utils_fifo(size, sizeof(uint8_t),
mShared->mBuffer, mShared->mRear, NULL /*throttlesFront*/) : NULL),
mFifoWriter(mFifo != NULL ? new audio_utils_fifo_writer(*mFifo) : NULL),
mEnabled(mFifoWriter != NULL)
{
// caching pid and process name
pid_t id = ::getpid();
char procName[16];
int status = prctl(PR_GET_NAME, procName);
if (status) { // error getting process name
procName[0] = '\0';
}
size_t length = strlen(procName);
mPidTagSize = length + sizeof(pid_t);
mPidTag = new char[mPidTagSize];
memcpy(mPidTag, &id, sizeof(pid_t));
memcpy(mPidTag + sizeof(pid_t), procName, length);
}
Writer::Writer(const sp<IMemory>& iMemory, size_t size)
: Writer(iMemory != 0 ? (Shared *) iMemory->pointer() : NULL, size)
{
mIMemory = iMemory;
}
Writer::~Writer()
{
delete mFifoWriter;
delete mFifo;
delete[] mPidTag;
}
void Writer::log(const char *string)
{
if (!mEnabled) {
return;
}
LOG_ALWAYS_FATAL_IF(string == NULL, "Attempted to log NULL string");
size_t length = strlen(string);
if (length > Entry::kMaxLength) {
length = Entry::kMaxLength;
}
log(EVENT_STRING, string, length);
}
void Writer::logf(const char *fmt, ...)
{
if (!mEnabled) {
return;
}
va_list ap;
va_start(ap, fmt);
Writer::logvf(fmt, ap); // the Writer:: is needed to avoid virtual dispatch for LockedWriter
va_end(ap);
}
void Writer::logTimestamp()
{
if (!mEnabled) {
return;
}
struct timespec ts;
if (!clock_gettime(CLOCK_MONOTONIC, &ts)) {
log(EVENT_TIMESTAMP, &ts, sizeof(ts));
}
}
void Writer::logFormat(const char *fmt, log_hash_t hash, ...)
{
if (!mEnabled) {
return;
}
va_list ap;
va_start(ap, hash);
Writer::logVFormat(fmt, hash, ap);
va_end(ap);
}
void Writer::logEventHistTs(Event event, log_hash_t hash)
{
if (!mEnabled) {
return;
}
HistTsEntry data;
data.hash = hash;
data.ts = systemTime();
if (data.ts > 0) {
log(event, &data, sizeof(data));
} else {
ALOGE("Failed to get timestamp");
}
}
bool Writer::isEnabled() const
{
return mEnabled;
}
bool Writer::setEnabled(bool enabled)
{
bool old = mEnabled;
mEnabled = enabled && mShared != NULL;
return old;
}
void Writer::log(const Entry &etr, bool trusted)
{
if (!mEnabled) {
return;
}
if (!trusted) {
log(etr.mEvent, etr.mData, etr.mLength);
return;
}
const size_t need = etr.mLength + Entry::kOverhead; // mEvent, mLength, data[mLength], mLength
// need = number of bytes written to FIFO
// FIXME optimize this using memcpy for the data part of the Entry.
// The Entry could have a method copyTo(ptr, offset, size) to optimize the copy.
// checks size of a single log Entry: type, length, data pointer and ending
uint8_t temp[Entry::kMaxLength + Entry::kOverhead];
// write this data to temp array
for (size_t i = 0; i < need; i++) {
temp[i] = etr.copyEntryDataAt(i);
}
// write to circular buffer
mFifoWriter->write(temp, need);
}
void Writer::log(Event event, const void *data, size_t length)
{
if (!mEnabled) {
return;
}
if (data == NULL || length > Entry::kMaxLength) {
// TODO Perhaps it makes sense to display truncated data or at least a
// message that the data is too long? The current behavior can create
// a confusion for a programmer debugging their code.
return;
}
// Ignore if invalid event
if (event == EVENT_RESERVED || event >= EVENT_UPPER_BOUND) {
return;
}
Entry etr(event, data, length);
log(etr, true /*trusted*/);
}
void Writer::logvf(const char *fmt, va_list ap)
{
if (!mEnabled) {
return;
}
char buffer[Entry::kMaxLength + 1 /*NUL*/];
int length = vsnprintf(buffer, sizeof(buffer), fmt, ap);
if (length >= (int) sizeof(buffer)) {
length = sizeof(buffer) - 1;
// NUL termination is not required
// buffer[length] = '\0';
}
if (length >= 0) {
log(EVENT_STRING, buffer, length);
}
}
void Writer::logStart(const char *fmt)
{
if (!mEnabled) {
return;
}
size_t length = strlen(fmt);
if (length > Entry::kMaxLength) {
length = Entry::kMaxLength;
}
log(EVENT_FMT_START, fmt, length);
}
void Writer::logTimestampFormat()
{
if (!mEnabled) {
return;
}
const nsecs_t ts = systemTime();
if (ts > 0) {
log(EVENT_FMT_TIMESTAMP, &ts, sizeof(ts));
} else {
ALOGE("Failed to get timestamp");
}
}
void Writer::logVFormat(const char *fmt, log_hash_t hash, va_list argp)
{
if (!mEnabled) {
return;
}
Writer::logStart(fmt);
int i;
double d;
float f;
char* s;
size_t length;
int64_t t;
Writer::logTimestampFormat();
log(EVENT_FMT_HASH, &hash, sizeof(hash));
for (const char *p = fmt; *p != '\0'; p++) {
// TODO: implement more complex formatting such as %.3f
if (*p != '%') {
continue;
}
switch(*++p) {
case 's': // string
s = va_arg(argp, char *);
length = strlen(s);
if (length > Entry::kMaxLength) {
length = Entry::kMaxLength;
}
log(EVENT_FMT_STRING, s, length);
break;
case 't': // timestamp
t = va_arg(argp, int64_t);
log(EVENT_FMT_TIMESTAMP, &t, sizeof(t));
break;
case 'd': // integer
i = va_arg(argp, int);
log(EVENT_FMT_INTEGER, &i, sizeof(i));
break;
case 'f': // float
d = va_arg(argp, double); // float arguments are promoted to double in vararg lists
f = (float)d;
log(EVENT_FMT_FLOAT, &f, sizeof(f));
break;
case 'p': // pid
log(EVENT_FMT_PID, mPidTag, mPidTagSize);
break;
// the "%\0" case finishes parsing
case '\0':
--p;
break;
case '%':
break;
default:
ALOGW("NBLog Writer parsed invalid format specifier: %c", *p);
break;
}
}
Entry etr(EVENT_FMT_END, nullptr, 0);
log(etr, true);
}
// ---------------------------------------------------------------------------
LockedWriter::LockedWriter(void *shared, size_t size)
: Writer(shared, size)
{
}
bool LockedWriter::isEnabled() const
{
Mutex::Autolock _l(mLock);
return Writer::isEnabled();
}
bool LockedWriter::setEnabled(bool enabled)
{
Mutex::Autolock _l(mLock);
return Writer::setEnabled(enabled);
}
void LockedWriter::log(const Entry &entry, bool trusted) {
Mutex::Autolock _l(mLock);
Writer::log(entry, trusted);
}
} // namespace NBLog
} // namespace android

@ -0,0 +1,232 @@
/*
* Copyright (C) 2018 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_NBLOG_ENTRY_H
#define ANDROID_MEDIA_NBLOG_ENTRY_H
#include <memory>
#include <stddef.h>
#include <stdint.h>
#include <type_traits>
#include <media/nblog/Events.h>
class audio_utils_fifo_writer;
namespace android {
namespace NBLog {
// entry representation in memory
struct entry {
const uint8_t type;
const uint8_t length;
const uint8_t data[0];
};
// entry tail representation (after data)
struct ending {
uint8_t length;
uint8_t next[0];
};
// 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)
: mEvent(event), mLength(length), mData(data) {}
~Entry() {}
// used during writing to format Entry information as follows:
// [type][length][data ... ][length]
int copyEntryDataAt(size_t offset) const;
private:
friend class Writer;
Event mEvent; // event type
uint8_t mLength; // length of additional data, 0 <= mLength <= kMaxLength
const void *mData; // event type-specific data
static const size_t kMaxLength = 255;
public:
// mEvent, mLength, mData[...], duplicate mLength
static const size_t kOverhead = sizeof(entry) + sizeof(ending);
// endind length of previous entry
static const ssize_t kPreviousLengthOffset = - sizeof(ending) +
offsetof(ending, length);
};
// entry iterator
class EntryIterator {
public:
// Used for dummy initialization. Performing operations on a default-constructed
// EntryIterator other than assigning it to another valid EntryIterator
// is undefined behavior.
EntryIterator();
// Caller's responsibility to make sure entry is not nullptr.
// Passing in nullptr can result in undefined behavior.
explicit EntryIterator(const uint8_t *entry);
EntryIterator(const EntryIterator &other);
// dereference underlying entry
const entry& operator*() const;
const entry* operator->() const;
// advance to next entry
EntryIterator& operator++(); // ++i
// back to previous entry
EntryIterator& operator--(); // --i
// returns an EntryIterator corresponding to the next entry
EntryIterator next() const;
// returns an EntryIterator corresponding to the previous entry
EntryIterator prev() const;
bool operator!=(const EntryIterator &other) const;
int operator-(const EntryIterator &other) const;
bool hasConsistentLength() const;
void copyTo(std::unique_ptr<audio_utils_fifo_writer> &dst) const;
void copyData(uint8_t *dst) const;
// memcpy preferred to reinterpret_cast to avoid potentially unsupported
// unaligned memory access.
#if 0
template<typename T>
inline const T& payload() {
return *reinterpret_cast<const T *>(mPtr + offsetof(entry, data));
}
#else
template<typename T>
inline T payload() const {
static_assert(std::is_trivially_copyable<T>::value
&& !std::is_pointer<T>::value,
"NBLog::EntryIterator payload must be trivially copyable, non-pointer type.");
T payload;
memcpy(&payload, mPtr + offsetof(entry, data), sizeof(payload));
return payload;
}
#endif
inline operator const uint8_t*() const {
return mPtr;
}
private:
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() {}
// build concrete entry of appropriate class from ptr.
static std::unique_ptr<AbstractEntry> buildEntry(const uint8_t *ptr);
// get format entry timestamp
virtual int64_t timestamp() const = 0;
// get format entry's unique id
virtual log_hash_t hash() const = 0;
// entry's author index (-1 if none present)
// a Merger has a vector of Readers, author simply points to the index of the
// Reader that originated the entry
// TODO consider changing to uint32_t
virtual int author() const = 0;
// copy entry, adding author before timestamp, returns iterator to end of entry
virtual EntryIterator copyWithAuthor(std::unique_ptr<audio_utils_fifo_writer> &dst,
int author) const = 0;
protected:
// Entry starting in the given pointer, which shall not be nullptr.
explicit AbstractEntry(const uint8_t *entry) : mEntry(entry) {}
// copies ordinary entry from src to dst, and returns length of entry
// size_t copyEntry(audio_utils_fifo_writer *dst, const iterator &it);
const uint8_t * const mEntry;
};
// API for handling format entry operations
// a formatted entry has the following structure:
// * FMT_START 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
// * ...
// * FMT_END entry
class FormatEntry : public AbstractEntry {
public:
// explicit FormatEntry(const EntryIterator &it);
explicit FormatEntry(const uint8_t *ptr) : AbstractEntry(ptr) {}
~FormatEntry() override = default;
EntryIterator begin() const;
// Entry's format string
const char* formatString() const;
// Enrty's format string length
size_t formatStringLength() const;
// Format arguments (excluding format string, timestamp and author)
EntryIterator args() const;
// get format entry timestamp
int64_t timestamp() const override;
// get format entry's unique id
log_hash_t hash() const override;
// entry's author index (-1 if none present)
// a Merger has a vector of Readers, author simply points to the index of the
// Reader that originated the entry
int author() const override;
// copy entry, adding author before timestamp, returns size of original entry
EntryIterator copyWithAuthor(std::unique_ptr<audio_utils_fifo_writer> &dst,
int author) const override;
};
class HistogramEntry : public AbstractEntry {
public:
explicit HistogramEntry(const uint8_t *ptr) : AbstractEntry(ptr) {}
~HistogramEntry() override = default;
int64_t timestamp() const override;
log_hash_t hash() const override;
int author() const override;
EntryIterator copyWithAuthor(std::unique_ptr<audio_utils_fifo_writer> &dst,
int author) const override;
};
} // namespace NBLog
} // namespace android
#endif // ANDROID_MEDIA_NBLOG_ENTRY_H

@ -0,0 +1,142 @@
/*
* Copyright (C) 2018 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_NBLOG_EVENTS_H
#define ANDROID_MEDIA_NBLOG_EVENTS_H
#include <stddef.h>
#include <stdint.h>
#include <type_traits>
namespace android {
namespace NBLog {
// TODO have a comment somewhere explaining the whole process for adding a new EVENT_
// NBLog Event types. The Events are named to provide contextual meaning for what is logged.
// If adding a new standalone Event here, update the event-to-type mapping by adding a
// MAP_EVENT_TO_TYPE statement below.
// XXX Note that as of the current design, Events should not be renumbered (i.e. reordered)
// if they ever leave memory (for example, written to file, uploaded to cloud, etc.).
// TODO make some sort of interface to keep these "contract" constants.
enum Event : uint8_t {
EVENT_RESERVED,
EVENT_STRING, // ASCII string, not NUL-terminated
// TODO: make timestamp optional
EVENT_TIMESTAMP, // clock_gettime(CLOCK_MONOTONIC)
// Types for Format Entry, i.e. formatted entry
EVENT_FMT_START, // logFormat start event: entry includes format string,
// following entries contain format arguments
// format arguments
EVENT_FMT_AUTHOR, // author index (present in merged logs) tracks entry's
// original log
EVENT_FMT_FLOAT, // floating point value entry
EVENT_FMT_HASH, // unique HASH of log origin, originates from hash of file name
// and line number
EVENT_FMT_INTEGER, // integer value entry
EVENT_FMT_PID, // process ID and process name
EVENT_FMT_STRING, // string value entry
EVENT_FMT_TIMESTAMP, // timestamp value entry
// end of format arguments
EVENT_FMT_END, // end of logFormat argument list
// Types for wakeup timestamp histograms
EVENT_AUDIO_STATE, // audio on/off event: logged on FastMixer::onStateChange call
EVENT_HISTOGRAM_ENTRY_TS, // single datum for timestamp histogram
// Types representing audio performance metrics
EVENT_LATENCY, // difference between frames presented by HAL and frames
// written to HAL output sink, divided by sample rate.
EVENT_OVERRUN, // predicted thread overrun event timestamp
EVENT_THREAD_INFO, // thread type, frameCount and sampleRate, which give context
// for the metrics below.
EVENT_UNDERRUN, // predicted thread underrun event timestamp
EVENT_WARMUP_TIME, // thread warmup time
EVENT_WORK_TIME, // the time a thread takes to do work, e.g. read, write, etc.
EVENT_UPPER_BOUND, // to check for invalid events
};
// NBLog custom-defined structs. Some NBLog Event types map to these structs.
using log_hash_t = uint64_t;
// used for EVENT_HISTOGRAM_ENTRY_TS (not mapped)
struct HistTsEntry {
log_hash_t hash;
int64_t ts;
}; //TODO __attribute__((packed));
// used for EVENT_HISTOGRAM_ENTRY_TS (not mapped)
struct HistTsEntryWithAuthor {
log_hash_t hash;
int64_t ts;
int author;
}; //TODO __attribute__((packed));
enum ThreadType {
UNKNOWN,
MIXER,
CAPTURE,
FASTMIXER,
FASTCAPTURE,
};
inline const char *threadTypeToString(ThreadType type) {
switch (type) {
case MIXER:
return "MIXER";
case CAPTURE:
return "CAPTURE";
case FASTMIXER:
return "FASTMIXER";
case FASTCAPTURE:
return "FASTCAPTURE";
case UNKNOWN:
default:
return "UNKNOWN";
}
}
// mapped from EVENT_THREAD_INFO
struct thread_info_t {
ThreadType type;
size_t frameCount; // number of frames per read or write buffer
unsigned sampleRate; // in frames per second
};
template <Event E> struct get_mapped;
#define MAP_EVENT_TO_TYPE(E, T) \
template<> struct get_mapped<E> { \
static_assert(std::is_trivially_copyable<T>::value \
&& !std::is_pointer<T>::value, \
"NBLog::Event must map to trivially copyable, non-pointer type."); \
typedef T type; \
}
// Maps an NBLog Event type to a C++ POD type.
MAP_EVENT_TO_TYPE(EVENT_LATENCY, double);
MAP_EVENT_TO_TYPE(EVENT_OVERRUN, int64_t);
MAP_EVENT_TO_TYPE(EVENT_THREAD_INFO, thread_info_t);
MAP_EVENT_TO_TYPE(EVENT_UNDERRUN, int64_t);
MAP_EVENT_TO_TYPE(EVENT_WARMUP_TIME, double);
MAP_EVENT_TO_TYPE(EVENT_WORK_TIME, int64_t);
} // namespace NBLog
} // namespace android
#endif // ANDROID_MEDIA_NBLOG_EVENTS_H

@ -0,0 +1,154 @@
/*
* Copyright (C) 2018 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_NBLOG_MERGER_H
#define ANDROID_MEDIA_NBLOG_MERGER_H
#include <memory>
#include <stddef.h>
#include <stdint.h>
#include <vector>
#include <audio_utils/fifo.h>
#include <media/nblog/PerformanceAnalysis.h>
#include <media/nblog/Reader.h>
#include <utils/Condition.h>
#include <utils/Mutex.h>
#include <utils/RefBase.h>
#include <utils/Thread.h>
namespace android {
class String8;
namespace NBLog {
struct Shared;
// TODO update comments to reflect current functionalities
// 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);
~Merger() override = default;
void addReader(const sp<NBLog::Reader> &reader);
// TODO add removeReader
void merge();
// FIXME This is returning a reference to a shared variable that needs a lock
const std::vector<sp<Reader>>& getReaders() 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<sp<Reader>> mReaders;
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 Readers. 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);
// process a particular snapshot of the reader
void processSnapshot(Snapshot &snap, int author);
// call getSnapshot of the content of the reader's buffer and process the data
void getAndProcessSnapshot();
// check for periodic push of performance data to media metrics, and perform
// the send if it is time to do so.
void checkPushToMediaMetrics();
void dump(int fd, int indent = 0);
private:
// FIXME Needs to be protected by a lock,
// because even though our use of it is read-only there may be asynchronous updates
// The object is owned by the Merger class.
const std::vector<sp<Reader>>& mReaders;
// analyzes, compresses and stores the merged data
// contains a separate instance for every author (thread), and for every source file
// location within each author
ReportPerformance::PerformanceAnalysisMap mThreadPerformanceAnalysis;
// compresses and stores audio performance data from each thread's buffers.
// first parameter is author, i.e. thread index.
std::map<int, ReportPerformance::PerformanceData> mThreadPerformanceData;
// how often to push data to Media Metrics
static constexpr nsecs_t kPeriodicMediaMetricsPush = s2ns((nsecs_t)2 * 60 * 60); // 2 hours
// 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);
};
// MergeThread is a thread that contains a Merger. It works as a retriggerable one-shot:
// when triggered, it awakes for a lapse of time, during which it periodically merges; if
// retriggered, the timeout is reset.
// The thread is triggered on AudioFlinger binder activity.
class MergeThread : public Thread {
public:
MergeThread(Merger &merger, MergeReader &mergeReader);
~MergeThread() override;
// Reset timeout and activate thread to merge periodically if it's idle
void wakeup();
// Set timeout period until the merging thread goes idle again
void setTimeoutUs(int time);
private:
bool threadLoop() override;
// 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;
// condition variable to activate merging on timeout >= 0
Condition mCond;
// time left until the thread blocks again (in microseconds)
int mTimeoutUs;
// merging period when the thread is awake
static const int kThreadSleepPeriodUs = 1000000 /*1s*/;
// initial timeout value when triggered
static const int kThreadWakeupPeriodUs = 3000000 /*3s*/;
};
} // namespace NBLog
} // namespace android
#endif // ANDROID_MEDIA_NBLOG_MERGER_H

@ -19,670 +19,10 @@
#ifndef ANDROID_MEDIA_NBLOG_H
#define ANDROID_MEDIA_NBLOG_H
#include <map>
#include <memory>
#include <type_traits>
#include <unordered_set>
#include <vector>
#include <audio_utils/fifo.h>
#include <binder/IMemory.h>
#include <media/nblog/PerformanceAnalysis.h>
#include <media/nblog/ReportPerformance.h>
#include <utils/Mutex.h>
#include <utils/threads.h>
#include <utils/Timers.h>
namespace android {
class String8;
class NBLog {
public:
using log_hash_t = uint64_t;
// FIXME Everything needed for client (writer API and registration) should be isolated
// from the rest of the implementation.
class Writer;
class Reader;
// TODO have a comment somewhere explaining the whole process for adding a new EVENT_
// NBLog Event types. The Events are named to provide contextual meaning for what is logged.
// If adding a new standalone Event here, update the event-to-type mapping by adding a
// MAP_EVENT_TO_TYPE statement below.
enum Event : uint8_t {
EVENT_RESERVED,
EVENT_STRING, // ASCII string, not NUL-terminated
// TODO: make timestamp optional
EVENT_TIMESTAMP, // clock_gettime(CLOCK_MONOTONIC)
// Types for Format Entry, i.e. formatted entry
EVENT_FMT_START, // logFormat start event: entry includes format string,
// following entries contain format arguments
// format arguments
EVENT_FMT_TIMESTAMP, // timestamp value entry
EVENT_FMT_HASH, // unique HASH of log origin, originates from hash of file name
// and line number
EVENT_FMT_STRING, // string value entry
EVENT_FMT_INTEGER, // integer value entry
EVENT_FMT_FLOAT, // floating point value entry
EVENT_FMT_PID, // process ID and process name
EVENT_FMT_AUTHOR, // author index (present in merged logs) tracks entry's
// original log
// end of format arguments
EVENT_FMT_END, // end of logFormat argument list
// Types for wakeup timestamp histograms
EVENT_HISTOGRAM_ENTRY_TS, // single datum for timestamp histogram
EVENT_AUDIO_STATE, // audio on/off event: logged on FastMixer::onStateChange call
// Types representing audio performance metrics
EVENT_THREAD_INFO, // thread type, frameCount and sampleRate, which give context
// for the metrics below.
EVENT_LATENCY, // difference between frames presented by HAL and frames
// written to HAL output sink, divided by sample rate.
EVENT_WORK_TIME, // the time a thread takes to do work, e.g. read, write, etc.
EVENT_WARMUP_TIME, // thread warmup time
EVENT_UNDERRUN, // predicted thread underrun event timestamp
EVENT_OVERRUN, // predicted thread overrun event timestamp
EVENT_UPPER_BOUND, // to check for invalid events
};
// NBLog custom-defined structs. Some NBLog Event types map to these structs.
// mapped from EVENT_THREAD_INFO
struct thread_info_t {
// TODO make type an enum
int type; // Thread type: 0 for MIXER, 1 for CAPTURE,
// 2 for FASTMIXER, 3 for FASTCAPTURE
size_t frameCount; // number of frames per read or write buffer
unsigned sampleRate; // in frames per second
};
template <Event E> struct get_mapped;
#define MAP_EVENT_TO_TYPE(E, T) \
template<> struct get_mapped<E> { \
static_assert(std::is_trivially_copyable<T>::value \
&& !std::is_pointer<T>::value, \
"NBLog::Event must map to trivially copyable, non-pointer type."); \
typedef T type; \
}
// Maps an NBLog Event type to a C++ POD type.
MAP_EVENT_TO_TYPE(EVENT_THREAD_INFO, thread_info_t);
MAP_EVENT_TO_TYPE(EVENT_LATENCY, double);
MAP_EVENT_TO_TYPE(EVENT_WORK_TIME, int64_t);
MAP_EVENT_TO_TYPE(EVENT_WARMUP_TIME, double);
MAP_EVENT_TO_TYPE(EVENT_UNDERRUN, int64_t);
MAP_EVENT_TO_TYPE(EVENT_OVERRUN, int64_t);
private:
// ---------------------------------------------------------------------------
// entry representation in memory
struct entry {
const uint8_t type;
const uint8_t length;
const uint8_t data[0];
};
// entry tail representation (after data)
struct ending {
uint8_t length;
uint8_t next[0];
};
// entry iterator
class EntryIterator {
public:
// Used for dummy initialization. Performing operations on a default-constructed
// EntryIterator other than assigning it to another valid EntryIterator
// is undefined behavior.
EntryIterator();
// Caller's responsibility to make sure entry is not nullptr.
// Passing in nullptr can result in undefined behavior.
explicit EntryIterator(const uint8_t *entry);
EntryIterator(const EntryIterator &other);
// dereference underlying entry
const entry& operator*() const;
const entry* operator->() const;
// advance to next entry
EntryIterator& operator++(); // ++i
// back to previous entry
EntryIterator& operator--(); // --i
// returns an EntryIterator corresponding to the next entry
EntryIterator next() const;
// returns an EntryIterator corresponding to the previous entry
EntryIterator prev() const;
bool operator!=(const EntryIterator &other) const;
int operator-(const EntryIterator &other) const;
bool hasConsistentLength() const;
void copyTo(std::unique_ptr<audio_utils_fifo_writer> &dst) const;
void copyData(uint8_t *dst) const;
// memcpy preferred to reinterpret_cast to avoid potentially unsupported
// unaligned memory access.
#if 0
template<typename T>
inline const T& payload() {
return *reinterpret_cast<const T *>(mPtr + offsetof(entry, data));
}
#else
template<typename T>
inline T payload() const {
static_assert(std::is_trivially_copyable<T>::value
&& !std::is_pointer<T>::value,
"NBLog::EntryIterator payload must be trivially copyable, non-pointer type.");
T payload;
memcpy(&payload, mPtr + offsetof(entry, data), sizeof(payload));
return payload;
}
#endif
inline operator const uint8_t*() const {
return mPtr;
}
private:
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() {}
// build concrete entry of appropriate class from ptr.
static std::unique_ptr<AbstractEntry> buildEntry(const uint8_t *ptr);
// get format entry timestamp
virtual int64_t timestamp() const = 0;
// get format entry's unique id
virtual log_hash_t hash() const = 0;
// entry's author index (-1 if none present)
// a Merger has a vector of Readers, author simply points to the index of the
// Reader that originated the entry
// TODO consider changing to uint32_t
virtual int author() const = 0;
// copy entry, adding author before timestamp, returns iterator to end of entry
virtual EntryIterator copyWithAuthor(std::unique_ptr<audio_utils_fifo_writer> &dst,
int author) const = 0;
protected:
// Entry starting in the given pointer, which shall not be nullptr.
explicit AbstractEntry(const uint8_t *entry);
// copies ordinary entry from src to dst, and returns length of entry
// size_t copyEntry(audio_utils_fifo_writer *dst, const iterator &it);
const uint8_t *mEntry;
};
// API for handling format entry operations
// a formatted entry has the following structure:
// * FMT_START 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
// * ...
// * FMT_END entry
class FormatEntry : public AbstractEntry {
public:
// explicit FormatEntry(const EntryIterator &it);
explicit FormatEntry(const uint8_t *ptr) : AbstractEntry(ptr) {}
virtual ~FormatEntry() {}
EntryIterator begin() const;
// Entry's format string
const char* formatString() const;
// Enrty's format string length
size_t formatStringLength() const;
// Format arguments (excluding format string, timestamp and author)
EntryIterator args() const;
// get format entry timestamp
virtual int64_t timestamp() const override;
// get format entry's unique id
virtual log_hash_t hash() const override;
// entry's author index (-1 if none present)
// a Merger has a vector of Readers, author simply points to the index of the
// Reader that originated the entry
virtual int author() const override;
// copy entry, adding author before timestamp, returns size of original entry
virtual EntryIterator copyWithAuthor(std::unique_ptr<audio_utils_fifo_writer> &dst,
int author) const override;
};
class HistogramEntry : public AbstractEntry {
public:
explicit HistogramEntry(const uint8_t *ptr) : AbstractEntry(ptr) {
}
virtual ~HistogramEntry() {}
virtual int64_t timestamp() const override;
virtual log_hash_t hash() const override;
virtual int author() const override;
virtual EntryIterator copyWithAuthor(std::unique_ptr<audio_utils_fifo_writer> &dst,
int author) const override;
};
// ---------------------------------------------------------------------------
// 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)
: mEvent(event), mLength(length), mData(data) { }
/*virtual*/ ~Entry() { }
// used during writing to format Entry information as follows:
// [type][length][data ... ][length]
int copyEntryDataAt(size_t offset) const;
private:
friend class Writer;
Event mEvent; // event type
uint8_t mLength; // length of additional data, 0 <= mLength <= kMaxLength
const void *mData; // event type-specific data
static const size_t kMaxLength = 255;
public:
// mEvent, mLength, mData[...], duplicate mLength
static const size_t kOverhead = sizeof(entry) + sizeof(ending);
// endind length of previous entry
static const ssize_t kPreviousLengthOffset = - sizeof(ending) +
offsetof(ending, length);
};
// TODO move these somewhere else
struct HistTsEntry {
log_hash_t hash;
int64_t ts;
}; //TODO __attribute__((packed));
struct HistTsEntryWithAuthor {
log_hash_t hash;
int64_t ts;
int author;
}; //TODO __attribute__((packed));
struct HistIntEntry {
log_hash_t hash;
int value;
}; //TODO __attribute__((packed));
public:
// Located in shared memory, must be POD.
// Exactly one process must explicitly call the constructor or use placement new.
// Since this is a POD, the destructor is empty and unnecessary to call it explicitly.
struct Shared {
Shared() /* mRear initialized via default constructor */ { }
/*virtual*/ ~Shared() { }
audio_utils_fifo_index mRear; // index one byte past the end of most recent Entry
char mBuffer[0]; // circular buffer for entries
};
public:
// ---------------------------------------------------------------------------
// FIXME Timeline was intended to wrap Writer and Reader, but isn't actually used yet.
// For now it is just a namespace for sharedSize().
class Timeline : public RefBase {
public:
#if 0
Timeline(size_t size, void *shared = NULL);
virtual ~Timeline();
#endif
// Input parameter 'size' is the desired size of the timeline in byte units.
// Returns the size rounded up to a power-of-2, plus the constant size overhead for indices.
static size_t sharedSize(size_t size);
#if 0
private:
friend class Writer;
friend class Reader;
const size_t mSize; // circular buffer size in bytes, must be a power of 2
bool mOwn; // whether I own the memory at mShared
Shared* const mShared; // pointer to shared memory
#endif
};
// ---------------------------------------------------------------------------
// NBLog Writer API
// ---------------------------------------------------------------------------
// Writer is thread-safe with respect to Reader, but not with respect to multiple threads
// calling Writer methods. If you need multi-thread safety for writing, use LockedWriter.
class Writer : public RefBase {
public:
Writer(); // dummy nop implementation without shared memory
// 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).
Writer(void *shared, size_t size);
Writer(const sp<IMemory>& iMemory, size_t size);
virtual ~Writer();
// FIXME needs comments, and some should be private
void log(const char *string);
void logf(const char *fmt, ...) __attribute__ ((format (printf, 2, 3)));
void logTimestamp();
void logFormat(const char *fmt, log_hash_t hash, ...);
void logEventHistTs(Event event, log_hash_t hash);
// Log data related to Event E. See the event-to-type mapping for the type of data
// corresponding to the event. For example, if you see a mapping statement:
// MAP_TYPE_TO_EVENT(E, T);
// then the usage of this method would be:
// T data = doComputation();
// tlNBLogWriter->log<NBLog::E>(data);
template<Event E>
void log(typename get_mapped<E>::type data) {
log(E, &data, sizeof(data));
}
virtual bool isEnabled() const;
// return value for all of these is the previous isEnabled()
virtual bool setEnabled(bool enabled); // but won't enable if no shared memory
bool enable() { return setEnabled(true); }
bool disable() { return setEnabled(false); }
sp<IMemory> getIMemory() const { return mIMemory; }
// Public logging function implementations should always use one of the
// two log() function calls below to write to shared memory.
protected:
// Writes a single Entry to the FIFO if the writer is enabled.
// This is protected and virtual because LockedWriter uses a lock to protect
// writing to the FIFO before writing to this function.
virtual void log(const Entry &entry, bool trusted = false);
private:
// 0 <= length <= kMaxLength
// Log a single Entry with corresponding event, data, and length.
void log(Event event, const void *data, size_t length);
void logvf(const char *fmt, va_list ap);
// helper functions for logging parts of a formatted entry
void logStart(const char *fmt);
void logTimestampFormat();
void logVFormat(const char *fmt, log_hash_t hash, va_list ap);
Shared* const mShared; // raw pointer to shared memory
sp<IMemory> mIMemory; // ref-counted version, initialized in constructor
// and then const
audio_utils_fifo * const mFifo; // FIFO itself, non-NULL
// unless constructor fails
audio_utils_fifo_writer * const mFifoWriter; // used to write to FIFO, non-NULL
// unless dummy constructor used
bool mEnabled; // whether to actually log
// cached pid and process name to use in %p format specifier
// total tag length is mPidTagSize and process name is not zero terminated
char *mPidTag;
size_t mPidTagSize;
};
// ---------------------------------------------------------------------------
// Similar to Writer, but safe for multiple threads to call concurrently
class LockedWriter : public Writer {
public:
LockedWriter();
LockedWriter(void *shared, size_t size);
bool isEnabled() const override;
bool setEnabled(bool enabled) override;
private:
// Lock needs to be obtained before writing to FIFO.
void log(const Entry &entry, bool trusted = false) override;
mutable Mutex mLock;
};
// ---------------------------------------------------------------------------
// NBLog Reader API
// ---------------------------------------------------------------------------
class Snapshot; // Forward declaration needed for Reader::getSnapshot()
class Reader : public RefBase {
public:
// 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();
bool isIMemory(const sp<IMemory>& iMemory) const;
const std::string &name() const { return mName; }
private:
// Amount of tries for reader to catch up with writer in getSnapshot().
static constexpr int kMaxObtainTries = 3;
// invalidBeginTypes and invalidEndTypes are used to align the Snapshot::begin() and
// Snapshot::end() EntryIterators to valid entries.
static const std::unordered_set<Event> invalidBeginTypes;
static const std::unordered_set<Event> invalidEndTypes;
// 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
audio_utils_fifo_reader * const mFifoReader; // used to read from FIFO,
// non-NULL unless constructor fails
// Searches for the last valid entry in the range [front, back)
// back has to be entry-aligned. Returns nullptr if none enconuntered.
static const uint8_t *findLastValidEntry(const uint8_t *front, const uint8_t *back,
const std::unordered_set<Event> &invalidTypes);
};
// A snapshot of a readers buffer
// This is raw data. No analysis has been done on it
class Snapshot {
public:
~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:
Snapshot() = default;
explicit Snapshot(size_t bufferSize) : mData(new uint8_t[bufferSize]) {}
friend std::unique_ptr<Snapshot> Reader::getSnapshot();
uint8_t * const mData = nullptr;
size_t mLost = 0;
EntryIterator mBegin;
EntryIterator mEnd;
};
// TODO move this to MediaLogService?
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);
// The bufferDump functions are used for debugging only.
static String8 bufferDump(const uint8_t *buffer, size_t size);
static String8 bufferDump(const EntryIterator &it);
};
// ---------------------------------------------------------------------------
// TODO move Merger, MergeReader, and MergeThread to a separate file.
// 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);
virtual ~Merger() {}
void addReader(const sp<NBLog::Reader> &reader);
// TODO add removeReader
void merge();
// FIXME This is returning a reference to a shared variable that needs a lock
const std::vector<sp<Reader>>& getReaders() 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<sp<Reader>> mReaders;
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 Readers. 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);
void dump(int fd, int indent = 0);
// process a particular snapshot of the reader
void processSnapshot(Snapshot &snap, int author);
// call getSnapshot of the content of the reader's buffer and process the data
void getAndProcessSnapshot();
// check for periodic push of performance data to media metrics, and perform
// the send if it is time to do so.
void checkPushToMediaMetrics();
private:
// FIXME Needs to be protected by a lock,
// because even though our use of it is read-only there may be asynchronous updates
// The object is owned by the Merger class.
const std::vector<sp<Reader>>& mReaders;
// analyzes, compresses and stores the merged data
// contains a separate instance for every author (thread), and for every source file
// location within each author
ReportPerformance::PerformanceAnalysisMap mThreadPerformanceAnalysis;
// compresses and stores audio performance data from each thread's buffers.
// first parameter is author, i.e. thread index.
std::map<int, ReportPerformance::PerformanceData> mThreadPerformanceData;
// how often to push data to Media Metrics
static constexpr nsecs_t kPeriodicMediaMetricsPush = s2ns((nsecs_t)2 * 60 * 60); // 2 hours
// 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);
};
// MergeThread is a thread that contains a Merger. It works as a retriggerable one-shot:
// when triggered, it awakes for a lapse of time, during which it periodically merges; if
// retriggered, the timeout is reset.
// The thread is triggered on AudioFlinger binder activity.
class MergeThread : public Thread {
public:
MergeThread(Merger &merger, MergeReader &mergeReader);
virtual ~MergeThread() override;
// Reset timeout and activate thread to merge periodically if it's idle
void wakeup();
// Set timeout period until the merging thread goes idle again
void setTimeoutUs(int time);
private:
virtual bool threadLoop() override;
// 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;
// condition variable to activate merging on timeout >= 0
Condition mCond;
// time left until the thread blocks again (in microseconds)
int mTimeoutUs;
// merging period when the thread is awake
static const int kThreadSleepPeriodUs = 1000000 /*1s*/;
// initial timeout value when triggered
static const int kThreadWakeupPeriodUs = 3000000 /*3s*/;
};
}; // class NBLog
} // namespace android
#include <media/nblog/Entry.h>
#include <media/nblog/Events.h>
#include <media/nblog/Reader.h>
#include <media/nblog/Timeline.h>
#include <media/nblog/Writer.h>
#endif // ANDROID_MEDIA_NBLOG_H

@ -22,6 +22,7 @@
#include <utility>
#include <vector>
#include <media/nblog/Events.h>
#include <media/nblog/ReportPerformance.h>
#include <utils/Timers.h>
@ -142,11 +143,9 @@ struct PerformanceData {
static constexpr Histogram::Config kWarmupConfig = { 5., 10, 10.};
// Thread Info
// TODO make type an enum
int type = -1; // Thread type: 0 for MIXER, 1 for CAPTURE,
// 2 for FASTMIXER, 3 for FASTCAPTURE
size_t frameCount = 0;
unsigned sampleRate = 0;
NBLog::thread_info_t threadInfo{
NBLog::UNKNOWN /*threadType*/, 0 /*frameCount*/, 0 /*sampleRate*/
};
// Performance Data
Histogram workHist{kWorkConfig};
@ -265,8 +264,7 @@ private:
void dump(int fd, int indent, PerformanceAnalysisMap &threadPerformanceAnalysis);
void dumpLine(int fd, int indent, const String8 &body);
} // namespace ReportPerformance
} // namespace ReportPerformance
} // namespace android
#endif // ANDROID_MEDIA_PERFORMANCEANALYSIS_H

@ -0,0 +1,135 @@
/*
* Copyright (C) 2018 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_NBLOG_READER_H
#define ANDROID_MEDIA_NBLOG_READER_H
#include <memory>
#include <stddef.h>
#include <string>
#include <unordered_set>
#include <media/nblog/Entry.h>
#include <media/nblog/Events.h>
#include <utils/RefBase.h>
class audio_utils_fifo;
class audio_utils_fifo_reader;
namespace android {
class IMemory;
class String8;
namespace NBLog {
struct Shared;
// NBLog Reader API
class Snapshot; // Forward declaration needed for Reader::getSnapshot()
class Reader : public RefBase {
public:
// 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);
~Reader() override;
// get snapshot of readers fifo buffer, effectively consuming the buffer
std::unique_ptr<Snapshot> getSnapshot();
bool isIMemory(const sp<IMemory>& iMemory) const;
const std::string &name() const { return mName; }
private:
// Amount of tries for reader to catch up with writer in getSnapshot().
static constexpr int kMaxObtainTries = 3;
// invalidBeginTypes and invalidEndTypes are used to align the Snapshot::begin() and
// Snapshot::end() EntryIterators to valid entries.
static const std::unordered_set<Event> invalidBeginTypes;
static const std::unordered_set<Event> invalidEndTypes;
// 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
audio_utils_fifo_reader * const mFifoReader; // used to read from FIFO,
// non-NULL unless constructor fails
// Searches for the last valid entry in the range [front, back)
// back has to be entry-aligned. Returns nullptr if none enconuntered.
static const uint8_t *findLastValidEntry(const uint8_t *front, const uint8_t *back,
const std::unordered_set<Event> &invalidTypes);
};
// A snapshot of a readers buffer
// This is raw data. No analysis has been done on it
class Snapshot {
public:
~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:
Snapshot() = default;
explicit Snapshot(size_t bufferSize) : mData(new uint8_t[bufferSize]) {}
friend std::unique_ptr<Snapshot> Reader::getSnapshot();
uint8_t * const mData = nullptr;
size_t mLost = 0;
EntryIterator mBegin;
EntryIterator mEnd;
};
// TODO move this to MediaLogService?
class DumpReader : public NBLog::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);
// The bufferDump functions are used for debugging only.
static String8 bufferDump(const uint8_t *buffer, size_t size);
static String8 bufferDump(const EntryIterator &it);
};
} // namespace NBLog
} // namespace android
#endif // ANDROID_MEDIA_NBLOG_READER_H

@ -27,7 +27,6 @@ class Value;
}
namespace android {
namespace ReportPerformance {
struct PerformanceData;
@ -78,8 +77,7 @@ void writeToFile(const std::deque<std::pair<timestamp, Hist>> &hists,
const std::deque<timestamp> &peakTimestamps,
const char * kDirectory, bool append, int author, log_hash_t hash);
} // namespace ReportPerformance
} // namespace ReportPerformance
} // namespace android
#endif // ANDROID_MEDIA_REPORTPERFORMANCE_H

@ -0,0 +1,66 @@
/*
* Copyright (C) 2018 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_NBLOG_TIMELINE_H
#define ANDROID_MEDIA_NBLOG_TIMELINE_H
#include <stddef.h>
#include <audio_utils/fifo_index.h>
#include <utils/RefBase.h>
namespace android {
namespace NBLog {
// Located in shared memory, must be POD.
// Exactly one process must explicitly call the constructor or use placement new.
// Since this is a POD, the destructor is empty and unnecessary to call it explicitly.
struct Shared {
Shared() /* mRear initialized via default constructor */ {}
~Shared() {}
audio_utils_fifo_index mRear; // index one byte past the end of most recent Entry
char mBuffer[0]; // circular buffer for entries
};
// FIXME Timeline was intended to wrap Writer and Reader, but isn't actually used yet.
// For now it is just a namespace for sharedSize().
class Timeline : public RefBase {
public:
#if 0
Timeline(size_t size, void *shared = NULL);
virtual ~Timeline();
#endif
// Input parameter 'size' is the desired size of the timeline in byte units.
// Returns the size rounded up to a power-of-2, plus the constant size overhead for indices.
static size_t sharedSize(size_t size);
#if 0
private:
friend class Writer;
friend class Reader;
const size_t mSize; // circular buffer size in bytes, must be a power of 2
bool mOwn; // whether I own the memory at mShared
Shared* const mShared; // pointer to shared memory
#endif
};
} // namespace NBLog
} // namespace android
#endif // ANDROID_MEDIA_NBLOG_TIMELINE_H

@ -0,0 +1,139 @@
/*
* Copyright (C) 2018 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_NBLOG_WRITER_H
#define ANDROID_MEDIA_NBLOG_WRITER_H
#include <stdarg.h>
#include <stddef.h>
#include <binder/IMemory.h>
#include <media/nblog/Events.h>
#include <utils/Mutex.h>
#include <utils/RefBase.h>
class audio_utils_fifo;
class audio_utils_fifo_writer;
namespace android {
class IMemory;
namespace NBLog {
class Entry;
struct Shared;
// NBLog Writer Interface
// Writer is thread-safe with respect to Reader, but not with respect to multiple threads
// calling Writer methods. If you need multi-thread safety for writing, use LockedWriter.
class Writer : public RefBase {
public:
Writer() = default; // dummy nop implementation without shared memory
// 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).
Writer(void *shared, size_t size);
Writer(const sp<IMemory>& iMemory, size_t size);
~Writer() override;
// FIXME needs comments, and some should be private
void log(const char *string);
void logf(const char *fmt, ...) __attribute__ ((format (printf, 2, 3)));
void logTimestamp();
void logFormat(const char *fmt, log_hash_t hash, ...);
void logEventHistTs(Event event, log_hash_t hash);
// Log data related to Event E. See the event-to-type mapping for the type of data
// corresponding to the event. For example, if you see a mapping statement:
// MAP_TYPE_TO_EVENT(E, T);
// then the usage of this method would be:
// T data = doComputation();
// tlNBLogWriter->log<NBLog::E>(data);
template<Event E>
void log(typename get_mapped<E>::type data) {
log(E, &data, sizeof(data));
}
virtual bool isEnabled() const;
// return value for all of these is the previous isEnabled()
virtual bool setEnabled(bool enabled); // but won't enable if no shared memory
bool enable() { return setEnabled(true); }
bool disable() { return setEnabled(false); }
sp<IMemory> getIMemory() const { return mIMemory; }
// Public logging function implementations should always use one of the
// two log() function calls below to write to shared memory.
protected:
// Writes a single Entry to the FIFO if the writer is enabled.
// This is protected and virtual because LockedWriter uses a lock to protect
// writing to the FIFO before writing to this function.
virtual void log(const Entry &entry, bool trusted = false);
private:
// 0 <= length <= kMaxLength
// Log a single Entry with corresponding event, data, and length.
void log(Event event, const void *data, size_t length);
void logvf(const char *fmt, va_list ap);
// helper functions for logging parts of a formatted entry
void logStart(const char *fmt);
void logTimestampFormat();
void logVFormat(const char *fmt, log_hash_t hash, va_list ap);
Shared* const mShared{}; // raw pointer to shared memory
sp<IMemory> mIMemory{}; // ref-counted version, initialized in constructor
// and then const
audio_utils_fifo * const mFifo{}; // FIFO itself, non-NULL
// unless constructor fails
// or dummy constructor used
audio_utils_fifo_writer * const mFifoWriter{}; // used to write to FIFO, non-NULL
// unless dummy constructor used
bool mEnabled = false; // whether to actually log
// cached pid and process name to use in %p format specifier
// total tag length is mPidTagSize and process name is not zero terminated
char *mPidTag{};
size_t mPidTagSize = 0;
};
// ---------------------------------------------------------------------------
// Similar to Writer, but safe for multiple threads to call concurrently
class LockedWriter : public Writer {
public:
LockedWriter() = default;
LockedWriter(void *shared, size_t size);
bool isEnabled() const override;
bool setEnabled(bool enabled) override;
private:
// Lock needs to be obtained before writing to FIFO.
void log(const Entry &entry, bool trusted = false) override;
mutable Mutex mLock;
};
} // namespace NBLog
} // namespace android
#endif // ANDROID_MEDIA_NBLOG_WRITER_H

@ -195,8 +195,7 @@ void FastMixer::onStateChange()
// to avoid blocking here and to prevent possible priority inversion
mMixer = new AudioMixer(frameCount, mSampleRate);
// FIXME See the other FIXME at FastMixer::setNBLogWriter()
// TODO define an int to thread type mapping for the "2" below.
const NBLog::thread_info_t info = { 2 /*FastMixer*/, frameCount, mSampleRate };
const NBLog::thread_info_t info = { NBLog::FASTMIXER, frameCount, mSampleRate };
LOG_THREAD_INFO(info);
const size_t mixerFrameSize = mSinkChannelCount
* audio_bytes_per_sample(mMixerBufferFormat);

@ -20,6 +20,7 @@
#include <sys/mman.h>
#include <utils/Log.h>
#include <binder/PermissionCache.h>
#include <media/nblog/Merger.h>
#include <media/nblog/NBLog.h>
#include <mediautils/ServiceUtilities.h>
#include "MediaLogService.h"

@ -19,6 +19,7 @@
#include <binder/BinderService.h>
#include <media/IMediaLogService.h>
#include <media/nblog/Merger.h>
#include <media/nblog/NBLog.h>
namespace android {

Loading…
Cancel
Save