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

Commit 1865ec9e authored by Phil Burk's avatar Phil Burk Committed by Android (Google) Code Review
Browse files

Merge changes from topic "audio-histogram"

* changes:
  aaudio: test audio_utils::Histogram
  aaudio: add histogram to clock model
parents d373b0ef cc34ecf2
Loading
Loading
Loading
Loading
+42 −9
Original line number Diff line number Diff line
@@ -18,18 +18,30 @@
//#define LOG_NDEBUG 0
#include <log/log.h>

#define __STDC_FORMAT_MACROS
#include <inttypes.h>
#include <stdint.h>
#include <algorithm>

#include "utility/AudioClock.h"
#include "utility/AAudioUtilities.h"
#include "IsochronousClockModel.h"

using namespace aaudio;

using namespace android::audio_utils;

#ifndef ICM_LOG_DRIFT
#define ICM_LOG_DRIFT   0
#endif // ICM_LOG_DRIFT

// To enable the timestamp histogram, enter this before opening the stream:
//    adb root
//    adb shell setprop aaudio.log_mask 1
// A histogram of the lateness of the timestamps will be cleared when the stream is started.
// It will be updated when the model is stable and receives a timestamp,
// and dumped to the log when the stream is stopped.

IsochronousClockModel::IsochronousClockModel()
        : mMarkerFramePosition(0)
        , mMarkerNanoTime(0)
@@ -39,6 +51,10 @@ IsochronousClockModel::IsochronousClockModel()
        , mLatenessForDriftNanos(kInitialLatenessForDriftNanos)
        , mState(STATE_STOPPED)
{
    if ((AAudioProperty_getLogMask() & AAUDIO_LOG_CLOCK_MODEL_HISTOGRAM) != 0) {
        mHistogramMicros = std::make_unique<Histogram>(kHistogramBinCount,
                kHistogramBinWidthMicros);
    }
}

IsochronousClockModel::~IsochronousClockModel() {
@@ -54,6 +70,9 @@ void IsochronousClockModel::start(int64_t nanoTime) {
    ALOGV("start(nanos = %lld)\n", (long long) nanoTime);
    mMarkerNanoTime = nanoTime;
    mState = STATE_STARTING;
    if (mHistogramMicros) {
        mHistogramMicros->clear();
    }
}

void IsochronousClockModel::stop(int64_t nanoTime) {
@@ -63,6 +82,9 @@ void IsochronousClockModel::stop(int64_t nanoTime) {
    setPositionAndTime(convertTimeToPosition(nanoTime), nanoTime);
    // TODO should we set position?
    mState = STATE_STOPPED;
    if (mHistogramMicros) {
        dumpHistogram();
    }
}

bool IsochronousClockModel::isStarting() const {
@@ -113,6 +135,9 @@ void IsochronousClockModel::processTimestamp(int64_t framePosition, int64_t nano
        }
        break;
    case STATE_RUNNING:
        if (mHistogramMicros) {
            mHistogramMicros->add(latenessNanos / AAUDIO_NANOS_PER_MICROSECOND);
        }
        // Modify estimated position based on lateness.
        // This affects the "early" side of the window, which controls output glitches.
        if (latenessNanos < 0) {
@@ -121,10 +146,9 @@ void IsochronousClockModel::processTimestamp(int64_t framePosition, int64_t nano
            // Or we may be drifting due to a fast HW clock.
            setPositionAndTime(framePosition, nanoTime);
#if ICM_LOG_DRIFT
            int microsDelta = (int) (nanosDelta / 1000);
            int expectedMicrosDelta = (int) (expectedNanosDelta / 1000);
            int earlyDeltaMicros = (int) ((expectedNanosDelta - nanosDelta)/ 1000);
            ALOGD("%s() - STATE_RUNNING - #%d, %4d micros EARLY",
                __func__, mTimestampCount, expectedMicrosDelta - microsDelta);
                __func__, mTimestampCount, earlyDeltaMicros);
#endif
        } else if (latenessNanos > mLatenessForDriftNanos) {
            // When we are on the late side, it may be because of preemption in the kernel,
@@ -242,10 +266,19 @@ int64_t IsochronousClockModel::convertLatestTimeToPosition(int64_t nanoTime) con
}

void IsochronousClockModel::dump() const {
    ALOGD("mMarkerFramePosition = %16lld", (long long) mMarkerFramePosition);
    ALOGD("mMarkerNanoTime      = %16lld", (long long) mMarkerNanoTime);
    ALOGD("mSampleRate          = %8d", mSampleRate);
    ALOGD("mFramesPerBurst      = %8d", mFramesPerBurst);
    ALOGD("mState               = %8d", mState);
    ALOGD("max lateness nanos   = %8d", mMaxMeasuredLatenessNanos);
    ALOGD("mMarkerFramePosition = %" PRIu64, mMarkerFramePosition);
    ALOGD("mMarkerNanoTime      = %" PRIu64, mMarkerNanoTime);
    ALOGD("mSampleRate          = %6d", mSampleRate);
    ALOGD("mFramesPerBurst      = %6d", mFramesPerBurst);
    ALOGD("mMaxMeasuredLatenessNanos = %6d", mMaxMeasuredLatenessNanos);
    ALOGD("mState               = %6d", mState);
}

void IsochronousClockModel::dumpHistogram() const {
    if (!mHistogramMicros) return;
    std::istringstream istr(mHistogramMicros->dump());
    std::string line;
    while (std::getline(istr, line)) {
        ALOGD("lateness, %s", line.c_str());
    }
}
+11 −0
Original line number Diff line number Diff line
@@ -18,6 +18,9 @@
#define ANDROID_AAUDIO_ISOCHRONOUS_CLOCK_MODEL_H

#include <stdint.h>

#include <audio_utils/Histogram.h>

#include "utility/AudioClock.h"

namespace aaudio {
@@ -122,6 +125,8 @@ public:

    void dump() const;

    void dumpHistogram() const;

private:

    int32_t getLateTimeOffsetNanos() const;
@@ -140,6 +145,9 @@ private:
    // Initial small threshold for causing a drift later in time.
    static constexpr int32_t   kInitialLatenessForDriftNanos = 10 * 1000;

    static constexpr int32_t   kHistogramBinWidthMicros = 50;
    static constexpr int32_t   kHistogramBinCount = 128;

    int64_t             mMarkerFramePosition; // Estimated HW position.
    int64_t             mMarkerNanoTime;      // Estimated HW time.
    int32_t             mSampleRate;
@@ -153,6 +161,9 @@ private:

    int32_t             mTimestampCount = 0;  // For logging.

    // distribution of timestamps relative to earliest
    std::unique_ptr<android::audio_utils::Histogram>   mHistogramMicros;

    void update();
};

+4 −0
Original line number Diff line number Diff line
@@ -359,6 +359,10 @@ int32_t AAudioProperty_getOutputMMapOffsetMicros() {
    return AAudioProperty_getMMapOffsetMicros(__func__, AAUDIO_PROP_OUTPUT_MMAP_OFFSET_USEC);
}

int32_t AAudioProperty_getLogMask() {
    return property_get_int32(AAUDIO_PROP_LOG_MASK, 0);
}

aaudio_result_t AAudio_isFlushAllowed(aaudio_stream_state_t state) {
    aaudio_result_t result = AAUDIO_OK;
    switch (state) {
+14 −0
Original line number Diff line number Diff line
@@ -162,6 +162,20 @@ int32_t AAudioProperty_getInputMMapOffsetMicros();
int32_t AAudioProperty_getOutputMMapOffsetMicros();
#define AAUDIO_PROP_OUTPUT_MMAP_OFFSET_USEC   "aaudio.out_mmap_offset_usec"

// These are powers of two that can be combined as a bit mask.
// AAUDIO_LOG_CLOCK_MODEL_HISTOGRAM must be enabled before the stream is opened.
#define AAUDIO_LOG_CLOCK_MODEL_HISTOGRAM   1
#define AAUDIO_LOG_RESERVED_2              2
#define AAUDIO_LOG_RESERVED_4              4
#define AAUDIO_LOG_RESERVED_8              8

/**
 * Use a mask to enable various logs in AAudio.
 * @return mask that enables various AAudio logs, such as AAUDIO_LOG_CLOCK_MODEL_HISTOGRAM
 */
int32_t AAudioProperty_getLogMask();
#define AAUDIO_PROP_LOG_MASK   "aaudio.log_mask"

/**
 * Is flush allowed for the given state?
 * @param state
+11 −0
Original line number Diff line number Diff line
@@ -215,3 +215,14 @@ cc_test {
    srcs: ["test_full_queue.cpp"],
    shared_libs: ["libaaudio"],
}

cc_test {
    name: "test_histogram",
    defaults: ["libaaudio_tests_defaults"],
    srcs: ["test_histogram.cpp"],
    shared_libs: [
        "libaudioutils",
        "libcutils",
        "libutils",
    ],
}
Loading