Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit c8e0e91a authored by Eric Tan's avatar Eric Tan Committed by Android (Google) Code Review
Browse files

Merge changes If9771427,Idde42ba6

* changes:
  Add options to dumpsys media.log and dump visualizations
  Improve ReportPerformance::Histogram implementation and add drawing
parents 718279d6 0513b5df
Loading
Loading
Loading
Loading
+26 −19
Original line number Diff line number Diff line
@@ -34,9 +34,11 @@
#include <utils/Log.h>
#include <utils/Mutex.h>
#include <utils/RefBase.h>
#include <utils/String16.h>
#include <utils/String8.h>
#include <utils/Timers.h>
#include <utils/Thread.h>
#include <utils/Timers.h>
#include <utils/Vector.h>

namespace android {
namespace NBLog {
@@ -145,13 +147,12 @@ void MergeReader::processSnapshot(Snapshot &snapshot, int author)
        } 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_THREAD_PARAMS: {
            const thread_params_t params = it.payload<thread_params_t>();
            data.threadParams = params;
        } break;
        case EVENT_LATENCY: {
            const double latencyMs = it.payload<double>();
            data.latencyHist.add(latencyMs);
@@ -211,23 +212,29 @@ void MergeReader::checkPushToMediaMetrics()
    }
}

void MergeReader::dump(int fd, int indent)
void MergeReader::dump(int fd, const Vector<String16>& args)
{
    // 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;
    // Options for dumpsys
    bool pa = false, json = false, plots = false;
    for (const auto &arg : args) {
        if (arg == String16("--pa")) {
            pa = true;
        } else if (arg == String16("--json")) {
            json = true;
        } else if (arg == String16("--plots")) {
            plots = true;
        }
    }
    if (pa) {
        ReportPerformance::dump(fd, 0 /*indent*/, mThreadPerformanceAnalysis);
    }
    if (json) {
        ReportPerformance::dumpJson(fd, mThreadPerformanceData);
    }
        (*threadData)["threadNum"] = item.first;
        root.append(*threadData);
    if (plots) {
        ReportPerformance::dumpPlots(fd, mThreadPerformanceData);
    }
    Json::StyledWriter writer;
    std::string rootStr = writer.write(root);
    write(fd, rootStr.c_str(), rootStr.size());
}

void MergeReader::handleAuthor(const AbstractEntry &entry, String8 *body)
+69 −22
Original line number Diff line number Diff line
@@ -22,6 +22,7 @@
#include <algorithm>
#include <climits>
#include <deque>
#include <iomanip>
#include <math.h>
#include <numeric>
#include <sstream>
@@ -51,23 +52,21 @@ namespace ReportPerformance {

void Histogram::add(double value)
{
    // TODO Handle domain and range error exceptions?
    const int binIndex = lround((value - mLow) / mBinSize);
    if (binIndex < 0) {
        mLowCount++;
    } else if (binIndex >= mNumBins) {
        mHighCount++;
    } else {
        mBins[binIndex]++;
    if (mBinSize <= 0 || mBins.size() < 2) {
        return;
    }
    // TODO Handle domain and range error exceptions?
    const int unboundedIndex = lround((value - mLow) / mBinSize) + 1;
    // std::clamp is introduced in C++17
    //const int index = std::clamp(unboundedIndex, 0, (int)(mBins.size() - 1));
    const int index = std::max(0, std::min((int)(mBins.size() - 1), unboundedIndex));
    mBins[index]++;
    mTotalCount++;
}

void Histogram::clear()
{
    std::fill(mBins.begin(), mBins.end(), 0);
    mLowCount = 0;
    mHighCount = 0;
    mTotalCount = 0;
}

@@ -81,27 +80,75 @@ std::string Histogram::toString() const {
    static constexpr char kDivider = '|';
    ss << kVersion << "," << mBinSize << "," << mNumBins << "," << mLow << ",{";
    bool first = true;
    if (mLowCount != 0) {
        ss << "-1" << kDivider << mLowCount;
        first = false;
    }
    for (size_t i = 0; i < mNumBins; i++) {
    for (size_t i = 0; i < mBins.size(); i++) {
        if (mBins[i] != 0) {
            if (!first) {
                ss << ",";
            }
            ss << i << kDivider << mBins[i];
            ss << static_cast<int>(i) - 1 << kDivider << mBins[i];
            first = false;
        }
    }
    if (mHighCount != 0) {
        if (!first) {
            ss << ",";
    ss << "}";

    return ss.str();
}
        ss << mNumBins << kDivider << mHighCount;
        first = false;

std::string Histogram::asciiArtString(size_t indent) const {
    if (totalCount() == 0 || mBinSize <= 0 || mBins.size() < 2) {
        return "";
    }
    ss << "}";

    static constexpr char kMarker = '-';
    // One increment is considered one step of a bin's height.
    static constexpr size_t kMarkersPerIncrement = 2;
    static constexpr size_t kMaxIncrements = 64 + 1;
    static constexpr size_t kMaxNumberWidth = 7;
    static const std::string kMarkers(kMarkersPerIncrement * kMaxIncrements, kMarker);
    static const std::string kSpaces(kMarkersPerIncrement * kMaxIncrements, ' ');
    // get the last n characters of s, or the whole string if it is shorter
    auto getTail = [](const size_t n, const std::string &s) {
        return s.c_str() + s.size() - std::min(n, s.size());
    };

    // Since totalCount() > 0, mBins is not empty and maxCount > 0.
    const unsigned maxCount = *std::max_element(mBins.begin(), mBins.end());
    const size_t maxIncrements = log2(maxCount) + 1;

    std::stringstream ss;

    // Non-zero bins must exist at this point because totalCount() > 0.
    size_t firstNonZeroBin = 0;
    // If firstNonZeroBin reaches mBins.size() - 1, then it must be a nonzero bin.
    for (; firstNonZeroBin < mBins.size() - 1 && mBins[firstNonZeroBin] == 0; firstNonZeroBin++) {}
    const size_t firstBinToPrint = firstNonZeroBin == 0 ? 0 : firstNonZeroBin - 1;

    size_t lastNonZeroBin = mBins.size() - 1;
    // If lastNonZeroBin reaches 0, then it must be a nonzero bin.
    for (; lastNonZeroBin > 0 && mBins[lastNonZeroBin] == 0; lastNonZeroBin--) {}
    const size_t lastBinToPrint = lastNonZeroBin == mBins.size() - 1 ? lastNonZeroBin
            : lastNonZeroBin + 1;

    for (size_t bin = firstBinToPrint; bin <= lastBinToPrint; bin++) {
        ss << std::setw(indent + kMaxNumberWidth);
        if (bin == 0) {
            ss << "<";
        } else if (bin == mBins.size() - 1) {
            ss << ">";
        } else {
            ss << mLow + (bin - 1) * mBinSize;
        }
        ss << " |";
        size_t increments = 0;
        const uint64_t binCount = mBins[bin];
        if (binCount > 0) {
            increments = log2(binCount) + 1;
            ss << getTail(increments * kMarkersPerIncrement, kMarkers);
        }
        ss << getTail((maxIncrements - increments + 1) * kMarkersPerIncrement, kSpaces)
                << binCount << "\n";
    }
    ss << "\n";

    return ss.str();
}
+67 −6
Original line number Diff line number Diff line
@@ -40,13 +40,14 @@
namespace android {
namespace ReportPerformance {

std::unique_ptr<Json::Value> dumpToJson(const PerformanceData& data)
static 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"] = (Json::Value::Int)data.threadInfo.type;
    root["frameCount"] = (Json::Value::Int)data.threadInfo.frameCount;
    root["sampleRate"] = (Json::Value::Int)data.threadInfo.sampleRate;
    root["ioHandle"] = data.threadInfo.id;
    root["type"] = NBLog::threadTypeToString(data.threadInfo.type);
    root["frameCount"] = (Json::Value::Int)data.threadParams.frameCount;
    root["sampleRate"] = (Json::Value::Int)data.threadParams.sampleRate;
    root["workMsHist"] = data.workHist.toString();
    root["latencyMsHist"] = data.latencyHist.toString();
    root["warmupMsHist"] = data.warmupHist.toString();
@@ -57,6 +58,61 @@ std::unique_ptr<Json::Value> dumpToJson(const PerformanceData& data)
    return rootPtr;
}

static std::string dumpHistogramsToString(const PerformanceData& data)
{
    std::stringstream ss;
    ss << "==========================================\n";
    ss << "Thread type=" << NBLog::threadTypeToString(data.threadInfo.type)
            << " handle=" << data.threadInfo.id
            << " sampleRate=" << data.threadParams.sampleRate
            << " frameCount=" << data.threadParams.frameCount << "\n";
    ss << "  Thread work times in ms:\n" << data.workHist.asciiArtString(4 /*indent*/);
    ss << "  Thread latencies in ms:\n" << data.latencyHist.asciiArtString(4 /*indent*/);
    ss << "  Thread warmup times in ms:\n" << data.warmupHist.asciiArtString(4 /*indent*/);
    return ss.str();
}

void dumpJson(int fd, const std::map<int, PerformanceData>& threadDataMap)
{
    if (fd < 0) {
        return;
    }

    Json::Value root(Json::arrayValue);
    for (const auto& item : threadDataMap) {
        const ReportPerformance::PerformanceData& data = item.second;
        // Skip threads that do not have performance data recorded yet.
        if (data.empty()) {
            continue;
        }
        std::unique_ptr<Json::Value> dataJson = ReportPerformance::dumpToJson(data);
        if (dataJson == nullptr) {
            continue;
        }
        (*dataJson)["threadNum"] = item.first;
        root.append(*dataJson);
    }
    Json::StyledWriter writer;
    std::string rootStr = writer.write(root);
    write(fd, rootStr.c_str(), rootStr.size());
}

void dumpPlots(int fd, const std::map<int, PerformanceData>& threadDataMap)
{
    if (fd < 0) {
        return;
    }

    for (const auto &item : threadDataMap) {
        const ReportPerformance::PerformanceData& data = item.second;
        if (data.empty()) {
            continue;
        }
        std::string hists = ReportPerformance::dumpHistogramsToString(data);
        write(fd, hists.c_str(), hists.size());
    }
}

bool sendToMediaMetrics(const PerformanceData& data)
{
    // See documentation for these metrics here:
@@ -72,6 +128,11 @@ bool sendToMediaMetrics(const PerformanceData& data)
    static constexpr char kThreadActive[] = "android.media.audiothread.activeMs";
    static constexpr char kThreadDuration[] = "android.media.audiothread.durationMs";

    // Currently, we only allow FastMixer thread data to be sent to Media Metrics.
    if (data.threadInfo.type != NBLog::FASTMIXER) {
        return false;
    }

    std::unique_ptr<MediaAnalyticsItem> item(new MediaAnalyticsItem("audiothread"));

    const Histogram &workHist = data.workHist;
@@ -104,8 +165,8 @@ bool sendToMediaMetrics(const PerformanceData& data)
        // Add thread info fields.
        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);
        item->setInt32(kThreadFrameCount, data.threadParams.frameCount);
        item->setInt32(kThreadSampleRate, data.threadParams.sampleRate);
        // Add time info fields.
        item->setInt64(kThreadActive, data.active / 1000000);
        item->setInt64(kThreadDuration, (systemTime() - data.start) / 1000000);
+19 −5
Original line number Diff line number Diff line
@@ -19,6 +19,7 @@

#include <stddef.h>
#include <stdint.h>
#include <system/audio.h>
#include <type_traits>

namespace android {
@@ -62,11 +63,11 @@ enum Event : uint8_t {
    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_THREAD_INFO,          // see thread_info_t 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_THREAD_PARAMS,        // see thread_params_t below

    EVENT_UPPER_BOUND,          // to check for invalid events
};
@@ -113,10 +114,22 @@ inline const char *threadTypeToString(ThreadType type) {
}

// mapped from EVENT_THREAD_INFO
// These fields always stay the same throughout a thread's lifetime and
// should only need to be logged once upon thread initialization.
// There is currently no recovery mechanism if the log event corresponding
// to this type is lost.
// TODO add this information when adding a reader to MediaLogService?
struct thread_info_t {
    ThreadType type;
    size_t frameCount;      // number of frames per read or write buffer
    unsigned sampleRate;    // in frames per second
    audio_io_handle_t id = -1;      // Thread I/O handle
    ThreadType type = UNKNOWN;      // See enum ThreadType above
};

// mapped from EVENT_THREAD_PARAMS
// These fields are not necessarily constant throughout a thread's lifetime and
// can be logged whenever a thread receives new configurations or parameters.
struct thread_params_t {
    size_t frameCount = 0;          // number of frames per read or write buffer
    unsigned sampleRate = 0;        // in frames per second
};

template <Event E> struct get_mapped;
@@ -135,6 +148,7 @@ 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);
MAP_EVENT_TO_TYPE(EVENT_THREAD_PARAMS, thread_params_t);

}   // namespace NBLog
}   // namespace android
+4 −1
Original line number Diff line number Diff line
@@ -29,9 +29,12 @@
#include <utils/Mutex.h>
#include <utils/RefBase.h>
#include <utils/Thread.h>
#include <utils/Timers.h>
#include <utils/Vector.h>

namespace android {

class String16;
class String8;

namespace NBLog {
@@ -83,7 +86,7 @@ public:
    // the send if it is time to do so.
    void checkPushToMediaMetrics();

    void dump(int fd, int indent = 0);
    void dump(int fd, const Vector<String16>& args);

private:
    // FIXME Needs to be protected by a lock,
Loading