Merge "Variable time resolution in histogram (Jiffy)"

namespace ReportPerformance {

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);

}

static int widthOf(int x) {

    int width = 0;

    while (x > 0) {

// buckets the time interval into a histogram, searches for

// outliers, analyzes the outlier series for unexpectedly

// small or large values and stores these as peaks

void PerformanceAnalysis::logTsEntry(int64_t ts) {

void PerformanceAnalysis::logTsEntry(timestamp ts) {

    // after a state change, start a new series and do not

    // record time intervals in-between

    if (mOutlierDistribution.mPrevTs == 0) {

        mOutlierDistribution.mPrevTs = ts;

    if (mBufferPeriod.mPrevTs == 0) {

        mBufferPeriod.mPrevTs = ts;

        return;

    }

    // calculate time interval between current and previous timestamp

    const msInterval diffMs = static_cast<msInterval>(

        deltaMs(mBufferPeriod.mPrevTs, ts));

    const int diffJiffy = deltaJiffy(mBufferPeriod.mPrevTs, ts);

    // update buffer period distribution

    // old versus new weight ratio when updating the buffer period mean

    static constexpr double exponentialWeight = 0.999;

    // update buffer period mean with exponential weighting

    mBufferPeriod.mMean = (mBufferPeriod.mMean < 0) ? diffMs :

            exponentialWeight * mBufferPeriod.mMean + (1.0 - exponentialWeight) * diffMs;

    // set mOutlierFactor to a smaller value for the fastmixer thread

    const int kFastMixerMax = 10;

    // NormalMixer times vary much more than FastMixer times.

    // TODO: mOutlierFactor values are set empirically based on what appears to be

    // an outlier. Learn these values from the data.

    mBufferPeriod.mOutlierFactor = mBufferPeriod.mMean < kFastMixerMax ? 1.8 : 2.5;

    // set outlier threshold

    mBufferPeriod.mOutlier = mBufferPeriod.mMean * mBufferPeriod.mOutlierFactor;

    // Check whether the time interval between the current timestamp

    // and the previous one is long enough to count as an outlier

    const bool isOutlier = detectAndStoreOutlier(ts);

    const bool isOutlier = detectAndStoreOutlier(diffMs);

    // If an outlier was found, check whether it was a peak

    if (isOutlier) {

        /*bool isPeak =*/ detectAndStorePeak(

    // if the current histogram has spanned its maximum time interval.

    if (mHists.empty() ||

        deltaMs(mHists[0].first, ts) >= kMaxLength.HistTimespanMs) {

        mHists.emplace_front(static_cast<uint64_t>(ts), std::map<int, int>());

        mHists.emplace_front(ts, std::map<int, int>());

        // When memory is full, delete oldest histogram

        // TODO: use a circular buffer

        if (mHists.size() >= kMaxLength.Hists) {

        }

    }

    // add current time intervals to histogram

    ++mHists[0].second[deltaMs(mOutlierDistribution.mPrevTs, ts)];

    ++mHists[0].second[diffJiffy];

    // update previous timestamp

    mOutlierDistribution.mPrevTs = ts;

    mBufferPeriod.mPrevTs = ts;

}

// forces short-term histogram storage to avoid adding idle audio time interval

// to buffer period data

void PerformanceAnalysis::handleStateChange() {

    mOutlierDistribution.mPrevTs = 0;

    mBufferPeriod.mPrevTs = 0;

    return;

}

// 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.

bool PerformanceAnalysis::detectAndStorePeak(outlierInterval diff, timestamp ts) {

bool PerformanceAnalysis::detectAndStorePeak(msInterval diff, timestamp ts) {

    bool isPeak = false;

    if (mOutlierData.empty()) {

        return false;

    // Initialize short-term mean at start of program

    if (mOutlierDistribution.mMean == 0) {

        mOutlierDistribution.mMean = static_cast<double>(diff);

        mOutlierDistribution.mMean = diff;

    }

    // Update length of current sequence of outliers

    mOutlierDistribution.mN++;

    // If statement checks whether a large deviation from the mean occurred.

    // Check whether a large deviation from the mean occurred.

    // If the standard deviation has been reset to zero, the comparison is

    // instead to the mean of the full mOutlierInterval sequence.

    if ((fabs(static_cast<double>(diff) - mOutlierDistribution.mMean) <

    if ((fabs(diff - mOutlierDistribution.mMean) <

            mOutlierDistribution.kMaxDeviation * mOutlierDistribution.mSd) ||

            (mOutlierDistribution.mSd == 0 &&

            fabs(diff - mOutlierDistribution.mMean) <

        mOutlierDistribution.mN = 0;

        mOutlierDistribution.mM2 = 0;

    }

    ALOGD("outlier distr %f %f", mOutlierDistribution.mMean, mOutlierDistribution.mSd);

    return isPeak;

}

// and writes to mOutlierdata in the following format:

// Time elapsed since previous outlier: Timestamp of start of outlier

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

bool PerformanceAnalysis::detectAndStoreOutlier(const int64_t ts) {

bool PerformanceAnalysis::detectAndStoreOutlier(const msInterval diffMs) {

    bool isOutlier = false;

    const int64_t diffMs = static_cast<int64_t>(deltaMs(mOutlierDistribution.mPrevTs, ts));

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

    if (diffMs >= mBufferPeriod.mOutlier) {

        isOutlier = true;

        mOutlierData.emplace_front(mOutlierDistribution.mElapsed,

                                  static_cast<uint64_t>(mOutlierDistribution.mPrevTs));

        mOutlierData.emplace_front(

                mOutlierDistribution.mElapsed, mBufferPeriod.mPrevTs);

        // Remove oldest value if the vector is full

        // TODO: turn this into a circular buffer

        // TODO: make sure kShortHistSize is large enough that that data will never be lost

    return isOutlier;

}

// computes the column width required for a specific histogram value

inline int numberWidth(int number, int leftPadding) {

    return std::max(std::max(widthOf(number) + 4, 3), leftPadding + 2);

}

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

// TODO consider changing all ints to uint32_t or uint64_t

// TODO Make it return a std::string instead of modifying body

// TODO: move this to ReportPerformance, probably make it a friend function of PerformanceAnalysis

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

    if (mHists.empty()) {

        ALOGD("reportPerformance: mHists is empty");

        return;

    }

    }

    // underscores and spaces length corresponds to maximum width of histogram

    static const int kLen = 40;

    static const int kLen = 100;

    std::string underscores(kLen, '_');

    std::string spaces(kLen, ' ');

    }

    int height = log2(maxCount) + 1; // maxCount > 0, safe to call log2

    const int leftPadding = widthOf(1 << height);

    const int colWidth = std::max(std::max(widthOf(maxDelta) + 1, 3), leftPadding + 2);

    const int bucketWidth = numberWidth(maxDelta, leftPadding);

    int scalingFactor = 1;

    // scale data if it exceeds maximum height

    if (height > maxHeight) {

    body->appendFormat("\n%s", " ");

    body->appendFormat("%*s", leftPadding, " ");

    for (auto const &x : buckets) {

        const int colWidth = numberWidth(x.first / kJiffyPerMs, leftPadding);

        body->appendFormat("%*d", colWidth, x.second);

    }

    // write histogram ascii art

        const int value = 1 << row;

        body->appendFormat("%.*s", leftPadding, spaces.c_str());

        for (auto const &x : buckets) {

            const int colWidth = numberWidth(x.first / kJiffyPerMs, leftPadding);

            body->appendFormat("%.*s%s", colWidth - 1,

                               spaces.c_str(), x.second < value ? " " : "|");

        }

    // print x-axis

    const int columns = static_cast<int>(buckets.size());

    body->appendFormat("%*c", leftPadding, ' ');

    body->appendFormat("%.*s", (columns + 1) * colWidth, underscores.c_str());

    body->appendFormat("%.*s", (columns + 1) * bucketWidth, underscores.c_str());

    body->appendFormat("\n%s", " ");

    // write footer with bucket labels

    body->appendFormat("%*s", leftPadding, " ");

    for (auto const &x : buckets) {

        body->appendFormat("%*d", colWidth, x.first);

        const int colWidth = numberWidth(x.first / kJiffyPerMs, leftPadding);

        body->appendFormat("%*.*f", colWidth, 1,

                           static_cast<double>(x.first) / kJiffyPerMs);

    }

    body->appendFormat("%.*s%s", colWidth, spaces.c_str(), "ms\n");

    body->appendFormat("%.*s%s", bucketWidth, spaces.c_str(), "ms\n");

    // Now report glitches

    body->appendFormat("\ntime elapsed between glitches and glitch timestamps\n");

    }

}

// TODO: decide whether to use this or whether it is overkill, and it is enough

// to only treat as glitches single wakeup call intervals which are too long.

// Ultimately, glitch detection will be directly on the audio signal.

// TODO: learn what timestamp sequences correlate with glitches instead of

// manually designing a heuristic. Ultimately, detect glitches directly from audio.

// Produces a log warning if the timing of recent buffer periods caused a glitch

// Computes sum of running window of three buffer periods

// Checks whether the buffer periods leave enough CPU time for the next one

// e.g. if a buffer period is expected to be 4 ms and a buffer requires 3 ms of CPU time,

// here are some glitch cases:

// 4 + 4 + 6 ; 5 + 4 + 5; 2 + 2 + 10

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

    std::deque<int> periods(kNumBuff, kPeriodMs);

    for (size_t i = 2; i < samples.size(); ++i) { // skip first time entry

        periods.push_front(deltaMs(samples[i - 1], samples[i]));

        periods.pop_back();

        // TODO: check that all glitch cases are covered

        if (std::accumulate(periods.begin(), periods.end(), 0) > kNumBuff * kPeriodMs +

            kPeriodMs - kPeriodMsCPU) {

                periods.assign(kNumBuff, kPeriodMs);

        }

    }

    return;

}

// void PerformanceAnalysis::alertIfGlitch(const std::vector<int64_t> &samples) {

//    std::deque<int> periods(kNumBuff, kPeriodMs);

//  for (size_t i = 2; i < samples.size(); ++i) { // skip first time entry

//      periods.push_front(deltaMs(samples[i - 1], samples[i]));

//      periods.pop_back();

//      // TODO: check that all glitch cases are covered

//      if (std::accumulate(periods.begin(), periods.end(), 0) > kNumBuff * kPeriodMs +

//          kPeriodMs - kPeriodMsCPU) {

//              periods.assign(kNumBuff, kPeriodMs);

//      }

//  }

//  return;

//}

//------------------------------------------------------------------------------

// Writes outlier intervals, timestamps, and histograms spanning long time intervals to a file.

// TODO: format the data efficiently and write different types of data to different files

void writeToFile(const std::deque<std::pair<timestamp, Histogram>> &hists,

                 const std::deque<std::pair<outlierInterval, timestamp>> &outlierData,

                 const std::deque<std::pair<msInterval, timestamp>> &outlierData,

                 const std::deque<timestamp> &peakTimestamps,

                 const char * directory, bool append, int author, log_hash_t hash) {

    if (outlierData.empty() || hists.empty()) {

    for (const auto &hist : hists) {

        hfs << "\ttimestamp\n";

        hfs << hist.first << "\n";

        hfs << "\tbuckets and counts\n";

        hfs << "\tbuckets (in ms) and counts\n";

        for (const auto &bucket : hist.second) {

            hfs << bucket.first << ": " << bucket.second << "\n";

            hfs << bucket.first / static_cast<double>(kJiffyPerMs)

                    << ": " << bucket.second << "\n";

        }

        hfs << "\n"; // separate histograms with a newline

    }

public:

    typedef uint64_t log_hash_t;

    using log_hash_t = ReportPerformance::log_hash_t;

    // FIXME Everything needed for client (writer API and registration) should be isolated

    //       from the rest of the implementation.

        static std::unique_ptr<AbstractEntry> buildEntry(const uint8_t *ptr);

        // get format entry timestamp

        // TODO consider changing to uint64_t

        virtual int64_t      timestamp() const = 0;

        // get format entry's unique id

 * limitations under the License.

 */

// Non-blocking event logger intended for safe communication between processes via shared memory

// Non-blocking event logger intended for safe communication between

// processes via shared memory

#ifndef ANDROID_MEDIA_PERFORMANCEANALYSIS_H

#define ANDROID_MEDIA_PERFORMANCEANALYSIS_H

    // the fifo writer utilities.

public:

    PerformanceAnalysis();

    PerformanceAnalysis() {};

    friend void dump(int fd, int indent,

                     PerformanceAnalysisMap &threadPerformanceAnalysis);

    // Writes wakeup timestamp entry to log and runs analysis

    // TODO: make this thread safe. Each thread should have its own instance

    // of PerformanceAnalysis.

    void logTsEntry(timestamp_raw ts);

    void logTsEntry(timestamp 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

    bool detectAndStorePeak(outlierInterval delta, timestamp ts);

    bool detectAndStorePeak(msInterval delta, timestamp ts);

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

    // finds outliers

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

    bool detectAndStoreOutlier(const timestamp_raw timestamp);

    bool detectAndStoreOutlier(const msInterval diffMs);

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

    // Generates a string of analysis of the buffer periods and prints to console

    // 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);

    // This function detects glitches in a time series.

    // TODO: decide whether to use this or whether it is overkill, and it is enough

    // to only treat as glitches single wakeup call intervals which are too long.

    // Ultimately, glitch detection will be directly on the audio signal.

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

    // TODO: learn what timestamp sequences correlate with glitches instead of

    // manually designing a heuristic. Ultimately, detect glitches directly from audio.

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

private:

    // stores outlier analysis:

    // <elapsed time between outliers in ms, outlier beginning timestamp>

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

    std::deque<std::pair<msInterval, 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<std::pair<timestamp, Histogram>> mHists;

    // Parameters used when detecting outliers

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

    // TODO: put used variables in a struct

    struct BufferPeriod {

        double    mMean = -1;          // average time between audio processing wakeups

        double    mOutlierFactor = -1; // values > mMean * mOutlierFactor are outliers

        double    mOutlier = -1;       // this is set to mMean * mOutlierFactor

        timestamp mPrevTs = -1;        // previous timestamp

    } mBufferPeriod;

    // TODO: delete values below if unused or add them to the BufferPeriod struct

    // FIXME: decide whether to make kPeriodMs static.

    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

    // 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

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

    // int kPeriodMsCPU; // compute based on kPeriodLen and kRatio

    // capacity allocated to data structures

    // TODO: make these values longer when testing is finished

    struct MaxLength {

        size_t Hists; // number of histograms stored in memory

        size_t TimeStamps; // histogram size, e.g. maximum length of timestamp series

        size_t TimeStamps; // histogram size

        size_t Outliers; // number of values stored in outlier array

        size_t Peaks; // number of values stored in peak array

        // maximum elapsed time between first and last timestamp of a long-term histogram

        int HistTimespanMs;

        int HistTimespanMs; // maximum histogram timespan

    };

    static constexpr MaxLength kMaxLength = {.Hists = 20, .TimeStamps = 1000,

            .Outliers = 100, .Peaks = 100, .HistTimespanMs = 5 * kMsPerSec };

    // 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.

    // TODO: use m prefix

    // these variables ensure continuity while analyzing the timestamp

    // series one sample at a time.

    // TODO: change this to a running variance/mean class

    struct OutlierDistribution {

        double mMean = 0; // sample mean since previous peak

        double mSd = 0; // sample sd since previous peak

        outlierInterval mElapsed = 0; // time since previous detected outlier

        int64_t mPrevTs = -1; // previous timestamp

        // number of standard deviations from mean considered a significant change

        const int kMaxDeviation = 5;

        double mTypicalDiff = 0; // global mean of outliers

        msInterval mMean = 0;         // sample mean since previous peak

        msInterval mSd = 0;           // sample sd since previous peak

        msInterval mElapsed = 0;      // time since previous detected outlier

        const int  kMaxDeviation = 5; // standard deviations from the mean threshold

        msInterval mTypicalDiff = 0;  // global mean of outliers

        double     mN = 0;            // length of sequence since the last peak

        double mM2 = 0;

        double     mM2 = 0;           // used to calculate sd

    } mOutlierDistribution;

};

namespace ReportPerformance {

const int kMsPerSec = 1000;

constexpr int kMsPerSec = 1000;

// stores a histogram: key: observed buffer period. value: count

constexpr int kJiffyPerMs = 10; // time unit for histogram as a multiple of milliseconds

// stores a histogram: key: observed buffer period (multiple of jiffy). value: count

// TODO: unsigned, unsigned

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

using outlierInterval = uint64_t;

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

// and all analysis functions use uint64_t.

using timestamp = uint64_t;

using timestamp_raw = int64_t;

using msInterval = double;

using jiffyInterval = double;

using timestamp = int64_t;

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

// TODO: the code has a mix of typedef and using. Standardize to one or the other.

typedef uint64_t log_hash_t;

using log_hash_t = uint64_t;

// TODO: should this return an int64_t?

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

    return (ns2 - ns1) / (1000 * 1000);

}

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

    return (kJiffyPerMs * (ns2 - ns1)) / (1000 * 1000);

}

static inline uint32_t log2(uint32_t x) {

    // This works for x > 0

    return 31 - __builtin_clz(x);

}

// TODO: delete dump in NBLog::Reader and add it here

// Writes outlier intervals, timestamps, and histograms spanning long time

// intervals to a file.

void writeToFile(const std::deque<std::pair<timestamp, Histogram>> &hists,

                 const std::deque<std::pair<outlierInterval, timestamp>> &outlierData,

                 const std::deque<std::pair<msInterval, timestamp>> &outlierData,

                 const std::deque<timestamp> &peakTimestamps,

                 const char * kDirectory, bool append, int author, log_hash_t hash);