Merge "Stores long-term histogram, outlier information"

    ofs.close();

}

// converts a time series into a map. key: buffer period length. value: count

static std::map<int, int> buildBuckets(const std::vector<int64_t> &samples) {

    // TODO allow buckets of variable resolution

    std::map<int, int> buckets;

    for (size_t i = 1; i < samples.size(); ++i) {

        ++buckets[deltaMs(samples[i - 1], samples[i])];

    }

    return buckets;

}

void NBLog::Reader::dump(int fd, size_t indent, NBLog::Reader::Snapshot &snapshot)

{

    //  CallStack cs(LOG_TAG);

    mFd = fd;

    mIndent = indent;

    String8 timestamp, body;

    PerformanceAnalysis performanceAnalyzer; // used to call analysis functions

    // FIXME: this is not thread safe

    static PerformanceAnalysis performanceAnalysis; // used to store data and to call analysis functions

    size_t lost = snapshot.lost() + (snapshot.begin() - EntryIterator(snapshot.data()));

    if (lost > 0) {

        body.appendFormat("warning: lost %zu bytes worth of events", lost);

            memcpy(&hash, &(data->hash), sizeof(hash));

            int64_t ts;

            memcpy(&ts, &data->ts, sizeof(ts));

            const std::pair<log_hash_t, int> key(hash, data->author);

            // TODO might want to filter excessively high outliers, which are usually caused

            // by the thread being inactive.

            mHists[key].push_back(ts);

            // store time series data for each reader in order to bucket it once there

            // is enough data. Then, it is written to recentHists as a histogram.

            mTimeStampSeries[data->author].push_back(ts);

            // if length of the time series has reached kShortHistSize samples, do 1) and 2):

            if (mTimeStampSeries[data->author].size() >= kShortHistSize) {

                // 1) analyze the series to store all outliers and their exact timestamps:

                performanceAnalyzer.storeOutlierData(data->author, mTimeStampSeries[data->author]);

                 // 2) compute its histogram, append this to mRecentHists and erase the time series

                mRecentHists.emplace_front(data->author,

                                           buildBuckets(mTimeStampSeries[data->author]));

                // do not let mRecentHists exceed capacity

                // TODO: turn the FIFO queue into a circular buffer

                if (mRecentHists.size() >= kRecentHistsCapacity) {

                    mRecentHists.pop_back();

                }

                mTimeStampSeries.erase(data->author);

            }

            // if an element in mHists has not grown for a long time, delete

            // TODO copy histogram data only to mRecentHistsBuffer and pop oldest

            performanceAnalysis.logTsEntry(data->author, ts);

            ++entry;

            break;

        }

            break;

        }

    }

    performanceAnalyzer.reportPerformance(&body, mRecentHists);

    performanceAnalysis.reportPerformance(&body);

    if (!body.isEmpty()) {

        dumpLine(timestamp, body);

    }

    // comment in for tests

    // performanceAnalyzer.testFunction();

}

void NBLog::Reader::dump(int fd, size_t indent)

namespace android {

PerformanceAnalysis::PerformanceAnalysis() : findGlitch(false) {

    kPeriodMsCPU = static_cast<int>(PerformanceAnalysis::kPeriodMs * kRatio);

PerformanceAnalysis::PerformanceAnalysis() {

    // These variables will be (FIXME) learned from the data

    kPeriodMs = 4; // typical buffer period (mode)

    // average number of Ms spent processing buffer

    kPeriodMsCPU = static_cast<int>(kPeriodMs * kRatio);

}

// converts a time series into a map. key: buffer period length. value: count

static std::map<int, int> buildBuckets(const std::vector<int64_t> &samples) {

    // TODO allow buckets of variable resolution

    std::map<int, int> buckets;

    for (size_t i = 1; i < samples.size(); ++i) {

        ++buckets[deltaMs(samples[i - 1], samples[i])];

    }

    return buckets;

}

static int widthOf(int x) {

    return width;

}

// FIXME: delete this temporary test code, recycled for various new functions

void PerformanceAnalysis::testFunction() {

    // produces values (4: 5000000), (13: 18000000)

    // ns timestamps of buffer periods

    const std::vector<int64_t>kTempTestData = {1000000, 4000000, 5000000,

                                               16000000, 18000000, 28000000};

    const int kTestAuthor = 1;

    PerformanceAnalysis::storeOutlierData(kTestAuthor, kTempTestData);

    for (const auto &outlier: mOutlierData) {

        ALOGE("PerformanceAnalysis test %lld: %lld",

              static_cast<long long>(outlier.first), static_cast<long long>(outlier.second));

// Takes a single buffer period timestamp entry with author information and stores it

// in a temporary series of timestamps. Once the series is full, the data is analyzed,

// stored, and emptied.

// TODO: decide whether author or file location information is more important to store

// for now, only stores author (thread)

void PerformanceAnalysis::logTsEntry(int author, int64_t ts) {

    // TODO might want to filter excessively high outliers, which are usually caused

    // by the thread being inactive.

    // Store time series data for each reader in order to bucket it once there

    // is enough data. Then, write to recentHists as a histogram.

    mTimeStampSeries[author].push_back(ts);

    // if length of the time series has reached kShortHistSize samples, do 1) and 2):

    if (mTimeStampSeries[author].size() >= kShortHistSize) {

        // 1) analyze the series to store all outliers and their exact timestamps:

        storeOutlierData(mTimeStampSeries[author]);

        // 2) detect peaks in the outlier series

        detectPeaks();

        // 3) compute its histogram, append this to mRecentHists and erase the time series

        // FIXME: need to store the timestamp of the beginning of each histogram

        // FIXME: Restore LOG_HIST_FLUSH to separate histograms at every end-of-stream event

        // A histogram should not span data between audio off/on timespans

        mRecentHists.emplace_back(author,

                                   buildBuckets(mTimeStampSeries[author]));

        // do not let mRecentHists exceed capacity

        // ALOGD("mRecentHists size: %d", static_cast<int>(mRecentHists.size()));

        if (mRecentHists.size() >= kRecentHistsCapacity) {

            //  ALOGD("popped back mRecentHists");

            mRecentHists.pop_front();

        }

        mTimeStampSeries[author].clear();

    }

}

// Given a series of outlier intervals (mOutlier data),

// looks for changes in distribution (peaks), which can be either positive or negative.

// The function sets the mean to the starting value and sigma to 0, and updates

// them as long as no peak is detected. When a value is more than 'threshold'

// standard deviations from the mean, a peak is detected and the mean and sigma

// are set to the peak value and 0.

void PerformanceAnalysis::detectPeaks() {

    if (mOutlierData.empty()) {

        ALOGD("peak detector called on empty array");

        return;

    }

    // compute mean of the distribution. Used to check whether a value is large

    const double kTypicalDiff = std::accumulate(

        mOutlierData.begin(), mOutlierData.end(), 0,

        [](auto &a, auto &b){return a + b.first;}) / mOutlierData.size();

    // ALOGD("typicalDiff %f", kTypicalDiff);

    // iterator at the beginning of a sequence, or updated to the most recent peak

    std::deque<std::pair<uint64_t, uint64_t>>::iterator start = mOutlierData.begin();

    // the mean and standard deviation are updated every time a peak is detected

    // initialize first time. The mean from the previous sequence is stored

    // for the next sequence. Here, they are initialized for the first time.

    if (mPeakDetectorMean < 0) {

        mPeakDetectorMean = static_cast<double>(start->first);

        mPeakDetectorSd = 0;

    }

    auto sqr = [](auto x){ return x * x; };

    for (auto it = mOutlierData.begin(); it != mOutlierData.end(); ++it) {

        // no surprise occurred:

        // the new element is a small number of standard deviations from the mean

        if ((fabs(it->first - mPeakDetectorMean) < kStddevThreshold * mPeakDetectorSd) ||

             // or: right after peak has been detected, the delta is smaller than average

            (mPeakDetectorSd == 0 && fabs(it->first - mPeakDetectorMean) < kTypicalDiff)) {

            // update the mean and sd:

            // count number of elements (distance between start interator and current)

            const int kN = std::distance(start, it) + 1;

            // usual formulas for mean and sd

            mPeakDetectorMean = std::accumulate(start, it + 1, 0.0,

                                   [](auto &a, auto &b){return a + b.first;}) / kN;

            mPeakDetectorSd = sqrt(std::accumulate(start, it + 1, 0.0,

                      [=](auto &a, auto &b){ return a + sqr(b.first - mPeakDetectorMean);})) /

                      ((kN > 1)? kN - 1 : kN); // kN - 1: mean is correlated with variance

            // ALOGD("value, mean, sd: %f, %f, %f", static_cast<double>(it->first), mean, sd);

        }

        // surprising value: store peak timestamp and reset mean, sd, and start iterator

        else {

            mPeakTimestamps.emplace_back(it->second);

            // TODO: remove pop_front once a circular buffer is in place

            if (mPeakTimestamps.size() >= kShortHistSize) {

                ALOGD("popped back mPeakTimestamps");

                mPeakTimestamps.pop_front();

            }

            mPeakDetectorMean = static_cast<double>(it->first);

            mPeakDetectorSd = 0;

            start = it;

        }

    }

    //for (const auto &it : mPeakTimestamps) {

    //    ALOGE("mPeakTimestamps %f", static_cast<double>(it));

    //}

    return;

}

// Each pair consists of: <outlier timestamp, time elapsed since previous outlier>.

// The timestamp of the beginning of the outlier is recorded.

// The elapsed time is from the timestamp of the previous outlier

// Called by LogTsEntry. The input is a vector of timestamps.

// Finds outliers and writes to mOutlierdata.

// Each value in mOutlierdata consists of: <outlier timestamp, time elapsed since previous outlier>.

// e.g. timestamps (ms) 1, 4, 5, 16, 18, 28 will produce pairs (4, 5), (13, 18).

// This function is applied to the time series before it is converted into a histogram.

void PerformanceAnalysis::storeOutlierData(

    int author, const std::vector<int64_t> &timestamps) {

void PerformanceAnalysis::storeOutlierData(const std::vector<int64_t> &timestamps) {

    if (timestamps.size() < 1) {

        ALOGE("storeOutlierData called on empty vector");

        return;

    }

    author++; // temp to avoid unused error until this value is

    // either TODO: used or discarded from the arglist

    author--;

    uint64_t elapsed = 0;

    int64_t prev = timestamps.at(0);

    // first pass: need to initialize

    if (mElapsed == 0) {

        mPrevNs = timestamps[0];

    }

    for (const auto &ts: timestamps) {

        const uint64_t diff = static_cast<uint64_t>(deltaMs(prev, ts));

        if (diff >= static_cast<uint64_t>(kOutlierMs)) {

            mOutlierData.emplace_back(elapsed, static_cast<uint64_t>(prev));

            elapsed = 0;

        }

        elapsed += diff;

        prev = ts;

    }

    // ALOGE("storeOutlierData: result length %zu", outlierData.size());

    // for (const auto &outlier: OutlierData) {

    //    ALOGE("PerformanceAnalysis test %lld: %lld",

    //          static_cast<long long>(outlier.first), static_cast<long long>(outlier.second));

    //}

        const uint64_t diffMs = static_cast<uint64_t>(deltaMs(mPrevNs, ts));

        if (diffMs >= static_cast<uint64_t>(kOutlierMs)) {

            mOutlierData.emplace_back(mElapsed, static_cast<uint64_t>(mPrevNs));

            // Remove oldest value if the vector is full

            // TODO: remove pop_front once circular buffer is in place

            // FIXME: change kShortHistSize to some other constant. Make sure it is large

            // enough that data will never be lost before being written to a long-term FIFO

            if (mOutlierData.size() >= kShortHistSize) {

                ALOGD("popped back mOutlierData");

                mOutlierData.pop_front();

            }

            mElapsed = 0;

        }

        mElapsed += diffMs;

        mPrevNs = ts;

    }

}

// TODO: implement peak detector

/*

  static void peakDetector() {

  return;

  } */

// TODO put this function in separate file. Make it return a std::string instead of modifying body

// TODO create a subclass of Reader for this and related work

// FIXME: delete this temporary test code, recycled for various new functions

void PerformanceAnalysis::testFunction() {

    // produces values (4: 5000000), (13: 18000000)

    // ns timestamps of buffer periods

    const std::vector<int64_t>kTempTestData = {1000000, 4000000, 5000000,

                                               16000000, 18000000, 28000000};

    PerformanceAnalysis::storeOutlierData(kTempTestData);

    for (const auto &outlier: mOutlierData) {

        ALOGE("PerformanceAnalysis test %lld: %lld",

              static_cast<long long>(outlier.first), static_cast<long long>(outlier.second));

    }

    detectPeaks();

}

// TODO Make it return a std::string instead of modifying body --> is this still relevant?

// FIXME: as can be seen when printing the values, the outlier timestamps typically occur

// in the first histogram 35 to 38 indices from the end (most often 35).

// TODO: build histogram buckets earlier and discard timestamps to save memory

// TODO consider changing all ints to uint32_t or uint64_t

void PerformanceAnalysis::reportPerformance(String8 *body,

                                            const std::deque<std::pair

                                            <int, short_histogram>> &shortHists,

                                            int maxHeight) {

    if (shortHists.size() < 1) {

void PerformanceAnalysis::reportPerformance(String8 *body, int maxHeight) {

    if (mRecentHists.size() < 1) {

        ALOGD("reportPerformance: mRecentHists is empty");

        return;

    }

    // this is temporary code, which only prints out one histogram

    // of all data stored in buffer. The data is not erased, only overwritten.

    ALOGD("reportPerformance: hists size %d", static_cast<int>(mRecentHists.size()));

    // TODO: more elaborate data analysis

    std::map<int, int> buckets;

    for (const auto &shortHist: shortHists) {

    for (const auto &shortHist: mRecentHists) {

        for (const auto &countPair : shortHist.second) {

            buckets[countPair.first] += countPair.second;

        }

    return;

}

bool PerformanceAnalysis::isFindGlitch() const

{

    return findGlitch;

}

void PerformanceAnalysis::setFindGlitch(bool s)

{

    findGlitch = s;

}

}   // namespace android

public:

    // A snapshot of a readers buffer

    // This is raw data. No analysis has been done on it

    class Snapshot {

    public:

        Snapshot() : mData(NULL), mLost(0) {}

    // get snapshot of readers fifo buffer, effectively consuming the buffer

    std::unique_ptr<Snapshot> getSnapshot();

    // dump a particular snapshot of the reader

    // TODO: move dump to PerformanceAnalysis. Model/view/controller design

    void     dump(int fd, size_t indent, Snapshot & snap);

    // dump the current content of the reader's buffer (call getSnapshot() and previous dump())

    void     dump(int fd, size_t indent = 0);

private:

    // TODO: decide whether these belong in NBLog::Reader or in PerformanceAnalysis

    static const int kShortHistSize = 50; // number of samples in a short-term histogram

    static const int kRecentHistsCapacity = 100; // number of short-term histograms stored in memory

    static const std::set<Event> startingTypes;

    static const std::set<Event> endingTypes;

    /*const*/ Shared* const mShared;    // raw pointer to shared memory, actually const but not

    audio_utils_fifo_reader * const mFifoReader;    // used to read from FIFO,

                                                    // non-NULL unless constructor fails

    // stores a short-term histogram of size determined by kShortHistSize

    // TODO: unsigned, unsigned

    using short_histogram = std::map<int, int>;

    // each pair contains a sequence of timestamps (one histogram's worth)

    // pair's log_hash_t is the hash of the source code location where the timestamp was taken

    // pair's int points to the Reader that originated the entry

    std::map<std::pair<log_hash_t, int>, std::vector<int64_t>> mHists;

    // mHistsCopy stores timestamp vectors whose key is the reader thread index.

    // TODO remove old mHists after changing the code

    std::map<int, std::vector<int64_t>> mTimeStampSeries;

    // stores fixed-size short buffer period histograms with hash and thread data

    // TODO: Turn it into a circular buffer for better data flow

    std::deque<std::pair<int, short_histogram>> mRecentHists;

    // TODO: it might be clearer, instead of a direct map from source location to vector of

    // timestamps, if we instead first mapped from source location to an object that

    // represented that location. And one_of its fields would be a vector of timestamps.

#include <map>

#include <deque>

#include <vector>

#include "NBLog.h"

namespace android {

class String8;

class PerformanceAnalysis {

    // This class stores and analyzes audio processing wakeup timestamps from NBLog

    // FIXME: currently, all performance data is stored in deques. Need to add a mutex.

    // FIXME: continue this way until analysis is done in a separate thread. Then, use

    // the fifo writer utilities.

public:

    PerformanceAnalysis();

    // FIXME: decide whether to use 64 or 32 bits

    typedef uint64_t log_hash_t;

    // stores a short-term histogram of size determined by kShortHistSize

    // key: observed buffer period. value: count

    // TODO: unsigned, unsigned

// CHECK: is there a better way to use short_histogram than to write 'using'

// both in this header file and in NBLog.h?

    // TODO: change this name to histogram

    using short_histogram = std::map<int, int>;

// returns a vector of pairs <outlier timestamp, time elapsed since previous outlier

// called by NBLog::Reader::dump before data is converted into histogram

// TODO: currently, the elapsed time

// The resolution is only as good as the ms duration of one shortHist

void storeOutlierData(int author, const std::vector<int64_t> &timestamps);

    using outlierInterval = uint64_t;

    // int64_t timestamps are converted to uint64_t in PerformanceAnalysis::storeOutlierData,

    // and all further analysis functions use uint64_t.

    using timestamp = uint64_t;

    using timestamp_raw = int64_t;

    // Writes wakeup timestamp entry to log and runs analysis

    // author is the thread ID

    // TODO: check. if the thread has multiple histograms, is author info correct

    // FIXME: remove author from arglist. Want to call these function separately on

    // each thread’s data.

    // FIXME: decide whether to store the hash (source file location) instead

    // FIXME: If thread has multiple histograms, check that code works and correct

    // author is stored (test with multiple threads). Need to check that the current

    // code is not receiving data from multiple threads. This could cause odd values.

    void logTsEntry(int author, timestamp_raw ts);

    // FIXME: make peakdetector and storeOutlierData a single function

    // Input: mOutlierData. Looks at time elapsed between outliers

    // finds significant changes in the distribution

    // writes timestamps of significant changes to mPeakTimestamps

    void detectPeaks();

    // runs analysis on timestamp series before it is converted to a histogram

    // finds outliers

    // writes to mOutlierData <time elapsed since previous outlier, outlier timestamp>

    void storeOutlierData(const std::vector<timestamp_raw> &timestamps);

    // input: series of short histograms. Generates a string of analysis of the buffer periods

    // TODO: WIP write more detailed analysis

    // FIXME: move this data visualization to a separate class. Model/view/controller

    void reportPerformance(String8 *body, int maxHeight = 10);

    // TODO: delete this. temp for testing

    void testFunction();

// Given a series, looks for changes in distribution (peaks)

// Returns a 'signal' array of the same length as the series, where each

// value is mapped to -1, 0, or 1 based on whether a negative or positive peak

// was detected, or no significant change occurred.

// The function sets the mean to the starting value and sigma to 0, and updates

// them as long as no peak is detected. When a value is more than 'threshold'

// standard deviations from the mean, a peak is detected and the mean and sigma

// are set to the peak value and 0.

// static void peakDetector();

// input: series of short histograms. output: prints an analysis of the

// data to the console

// TODO: change this so that it writes the analysis to the long-term

// circular buffer and prints an analyses both for the short and long-term

void reportPerformance(String8 *body,

                       const std::deque<std::pair

                       <int, short_histogram>> &shortHists,

                       int maxHeight = 10);

// if findGlitch is true, log warning when buffer periods caused glitch

// TODO adapt this to the analysis in reportPerformance instead of logging

void     alertIfGlitch(const std::vector<int64_t> &samples);

bool     isFindGlitch() const;

void     setFindGlitch(bool s);

    // This function used to detect glitches in a time series

    // TODO incorporate this into the analysis (currently unused)

    void     alertIfGlitch(const std::vector<timestamp_raw> &samples);

    ~PerformanceAnalysis() {}

private:

// stores outlier analysis

std::vector<std::pair<uint64_t, uint64_t>> mOutlierData;

    // stores outlier analysis: <elapsed time between outliers in ms, outlier timestamp>

    std::deque<std::pair<outlierInterval, timestamp>> mOutlierData;

    // stores each timestamp at which a peak was detected

    // a peak is a moment at which the average outlier interval changed significantly

    std::deque<timestamp> mPeakTimestamps;

    // FIFO of small histograms

    // stores fixed-size short buffer period histograms with hash and thread data

    // TODO: Turn it into a circular buffer for better data flow

    std::deque<std::pair<int, short_histogram>> mRecentHists;

// stores long-term audio performance data

// TODO: Turn it into a circular buffer

std::deque<std::pair<int, int>> mPerformanceAnalysis;

    // map from author to vector of timestamps, collected from NBLog

    // when a vector reaches its maximum size, analysis is run and the data is deleted

    std::map<int, std::vector<timestamp_raw>> mTimeStampSeries;

// alert if a local buffer period sequence caused an audio glitch

bool findGlitch;

    // TODO: measure these from the data (e.g., mode) as they may change.

    // const int kGlitchThreshMs = 7;

    // const int kMsPerSec = 1000;

const int kNumBuff = 3; // number of buffers considered in local history

const int kPeriodMs = 4; // current period length is ideally 4 ms

const int kOutlierMs = 7; // values greater or equal to this cause glitches every time

    // Parameters used when detecting outliers

    // TODO: learn some of these from the data, delete unused ones

    // FIXME: decide whether to make kPeriodMs static.

    // The non-const values are (TODO: will be) learned from the data

    static const int kNumBuff = 3; // number of buffers considered in local history

    int kPeriodMs; // current period length is ideally 4 ms

    static const int kOutlierMs = 7; // values greater or equal to this cause glitches

    // DAC processing time for 4 ms buffer

    static constexpr double kRatio = 0.75; // estimate of CPU time as ratio of period length

    int kPeriodMsCPU; // compute based on kPeriodLen and kRatio

    // Peak detection: number of standard deviations from mean considered a significant change

    static const int kStddevThreshold = 5;

    static const int kRecentHistsCapacity = 100; // number of short-term histograms stored in memory

    static const int kShortHistSize = 50; // number of samples in a short-term histogram

    // these variables are stored in-class to ensure continuity while analyzing the timestamp

    // series one short sequence at a time: the variables are not re-initialized every time.

    // FIXME: create inner class for these variables and decide which other ones to add to it

    double mPeakDetectorMean = -1;

    double mPeakDetectorSd = -1;

    // variables for storeOutlierData

    uint64_t mElapsed = 0;

    int64_t mPrevNs = -1;

};

static inline int deltaMs(int64_t ns1, int64_t ns2) {