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

Commit d097981a authored by Andy Hung's avatar Andy Hung
Browse files

AudioFlinger: Send Thread statistics to mediametrics

Unify with AudioRecord and AudioTrack mediametrics.

Test: mediametrics dumpsys after record, playback
Test: CTS Audio(Record|Track)Test#testMediaMetrics
Bug: 114112762
Change-Id: I6eb554cbf6ff760f9dea568abd3cde82366b51a7
parent f03cb213
Loading
Loading
Loading
Loading
+22 −58
Original line number Diff line number Diff line
@@ -70,70 +70,34 @@ status_t AudioRecord::getMinFrameCount(

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

static std::string audioFormatTypeString(audio_format_t value) {
    std::string formatType;
    if (FormatConverter::toString(value, formatType)) {
        return formatType;
    }
    char rawbuffer[16];  // room for "%d"
    snprintf(rawbuffer, sizeof(rawbuffer), "%d", value);
    return rawbuffer;
}

static std::string audioSourceString(audio_source_t value) {
    std::string source;
    if (SourceTypeConverter::toString(value, source)) {
        return source;
    }
    char rawbuffer[16];  // room for "%d"
    snprintf(rawbuffer, sizeof(rawbuffer), "%d", value);
    return rawbuffer;
}

void AudioRecord::MediaMetrics::gather(const AudioRecord *record)
{
    // key for media statistics is defined in the header
    // attrs for media statistics
    // NB: these are matched with public Java API constants defined
    // in frameworks/base/media/java/android/media/AudioRecord.java
    // These must be kept synchronized with the constants there.
    static constexpr char kAudioRecordEncoding[] = "android.media.audiorecord.encoding";
    static constexpr char kAudioRecordSource[] = "android.media.audiorecord.source";
    static constexpr char kAudioRecordLatency[] = "android.media.audiorecord.latency";
    static constexpr char kAudioRecordSampleRate[] = "android.media.audiorecord.samplerate";
    static constexpr char kAudioRecordChannelCount[] = "android.media.audiorecord.channels";
    static constexpr char kAudioRecordCreated[] = "android.media.audiorecord.createdMs";
    static constexpr char kAudioRecordDuration[] = "android.media.audiorecord.durationMs";
    static constexpr char kAudioRecordCount[] = "android.media.audiorecord.n";
    static constexpr char kAudioRecordError[] = "android.media.audiorecord.errcode";
    static constexpr char kAudioRecordErrorFunction[] = "android.media.audiorecord.errfunc";

    // constructor guarantees mAnalyticsItem is valid

    mAnalyticsItem->setInt32(kAudioRecordLatency, record->mLatency);
    mAnalyticsItem->setInt32(kAudioRecordSampleRate, record->mSampleRate);
    mAnalyticsItem->setInt32(kAudioRecordChannelCount, record->mChannelCount);
    mAnalyticsItem->setCString(kAudioRecordEncoding,
                               audioFormatTypeString(record->mFormat).c_str());
    mAnalyticsItem->setCString(kAudioRecordSource,
                               audioSourceString(record->mAttributes.source).c_str());

    // log total duration recording, including anything currently running [and count].
    nsecs_t active = 0;
#define MM_PREFIX "android.media.audiorecord." // avoid cut-n-paste errors.

    // Java API 28 entries, do not change.
    mAnalyticsItem->setCString(MM_PREFIX "encoding", toString(record->mFormat).c_str());
    mAnalyticsItem->setCString(MM_PREFIX "source", toString(record->mAttributes.source).c_str());
    mAnalyticsItem->setInt32(MM_PREFIX "latency", (int32_t)record->mLatency); // bad estimate.
    mAnalyticsItem->setInt32(MM_PREFIX "samplerate", (int32_t)record->mSampleRate);
    mAnalyticsItem->setInt32(MM_PREFIX "channels", (int32_t)record->mChannelCount);

    // Non-API entries, these can change.
    mAnalyticsItem->setInt32(MM_PREFIX "portId", (int32_t)record->mPortId);
    mAnalyticsItem->setInt32(MM_PREFIX "frameCount", (int32_t)record->mFrameCount);
    mAnalyticsItem->setCString(MM_PREFIX "attributes", toString(record->mAttributes).c_str());
    mAnalyticsItem->setInt64(MM_PREFIX "channelMask", (int64_t)record->mChannelMask);

    // log total duration recording, including anything currently running.
    int64_t activeNs = 0;
    if (mStartedNs != 0) {
        active = systemTime() - mStartedNs;
    }
    mAnalyticsItem->setInt64(kAudioRecordDuration, (mDurationNs + active) / (1000 * 1000));
    mAnalyticsItem->setInt32(kAudioRecordCount, mCount);

    // XXX I don't know that this adds a lot of value, long term
    if (mCreatedNs != 0) {
        mAnalyticsItem->setInt64(kAudioRecordCreated, mCreatedNs / (1000 * 1000));
        activeNs = systemTime() - mStartedNs;
    }
    mAnalyticsItem->setDouble(MM_PREFIX "durationMs", (mDurationNs + activeNs) * 1e-6);
    mAnalyticsItem->setInt64(MM_PREFIX "startCount", (int64_t)mCount);

    if (mLastError != NO_ERROR) {
        mAnalyticsItem->setInt32(kAudioRecordError, mLastError);
        mAnalyticsItem->setCString(kAudioRecordErrorFunction, mLastErrorFunc.c_str());
        mAnalyticsItem->setInt32(MM_PREFIX "lastError.code", (int32_t)mLastError);
        mAnalyticsItem->setCString(MM_PREFIX "lastError.at", mLastErrorFunc.c_str());
    }
}

+14 −56
Original line number Diff line number Diff line
@@ -170,44 +170,8 @@ bool AudioTrack::isDirectOutputSupported(const audio_config_base_t& config,

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

static std::string audioContentTypeString(audio_content_type_t value) {
    std::string contentType;
    if (AudioContentTypeConverter::toString(value, contentType)) {
        return contentType;
    }
    char rawbuffer[16];  // room for "%d"
    snprintf(rawbuffer, sizeof(rawbuffer), "%d", value);
    return rawbuffer;
}

static std::string audioUsageString(audio_usage_t value) {
    std::string usage;
    if (UsageTypeConverter::toString(value, usage)) {
        return usage;
    }
    char rawbuffer[16];  // room for "%d"
    snprintf(rawbuffer, sizeof(rawbuffer), "%d", value);
    return rawbuffer;
}

void AudioTrack::MediaMetrics::gather(const AudioTrack *track)
{

    // key for media statistics is defined in the header
    // attrs for media statistics
    // NB: these are matched with public Java API constants defined
    // in frameworks/base/media/java/android/media/AudioTrack.java
    // These must be kept synchronized with the constants there.
    static constexpr char kAudioTrackStreamType[] = "android.media.audiotrack.streamtype";
    static constexpr char kAudioTrackContentType[] = "android.media.audiotrack.type";
    static constexpr char kAudioTrackUsage[] = "android.media.audiotrack.usage";
    static constexpr char kAudioTrackSampleRate[] = "android.media.audiotrack.samplerate";
    static constexpr char kAudioTrackChannelMask[] = "android.media.audiotrack.channelmask";

    // NB: These are not yet exposed as public Java API constants.
    static constexpr char kAudioTrackUnderrunFrames[] = "android.media.audiotrack.underrunframes";
    static constexpr char kAudioTrackStartupGlitch[] = "android.media.audiotrack.glitch.startup";

    // only if we're in a good state...
    // XXX: shall we gather alternative info if failing?
    const status_t lstatus = track->initCheck();
@@ -216,28 +180,22 @@ void AudioTrack::MediaMetrics::gather(const AudioTrack *track)
        return;
    }

    // constructor guarantees mAnalyticsItem is valid

    const int32_t underrunFrames = track->getUnderrunFrames();
    if (underrunFrames != 0) {
        mAnalyticsItem->setInt32(kAudioTrackUnderrunFrames, underrunFrames);
    }
#define MM_PREFIX "android.media.audiotrack." // avoid cut-n-paste errors.

    if (track->mTimestampStartupGlitchReported) {
        mAnalyticsItem->setInt32(kAudioTrackStartupGlitch, 1);
    }
    // Java API 28 entries, do not change.
    mAnalyticsItem->setCString(MM_PREFIX "streamtype", toString(track->streamType()).c_str());
    mAnalyticsItem->setCString(MM_PREFIX "type",
            toString(track->mAttributes.content_type).c_str());
    mAnalyticsItem->setCString(MM_PREFIX "usage", toString(track->mAttributes.usage).c_str());

    if (track->mStreamType != -1) {
        // deprecated, but this will tell us who still uses it.
        mAnalyticsItem->setInt32(kAudioTrackStreamType, track->mStreamType);
    }
    // XXX: consider including from mAttributes: source type
    mAnalyticsItem->setCString(kAudioTrackContentType,
                               audioContentTypeString(track->mAttributes.content_type).c_str());
    mAnalyticsItem->setCString(kAudioTrackUsage,
                               audioUsageString(track->mAttributes.usage).c_str());
    mAnalyticsItem->setInt32(kAudioTrackSampleRate, track->mSampleRate);
    mAnalyticsItem->setInt64(kAudioTrackChannelMask, track->mChannelMask);
    // Non-API entries, these can change due to a Java string mistake.
    mAnalyticsItem->setInt32(MM_PREFIX "sampleRate", (int32_t)track->mSampleRate);
    mAnalyticsItem->setInt64(MM_PREFIX "channelMask", (int64_t)track->mChannelMask);
    // Non-API entries, these can change.
    mAnalyticsItem->setInt32(MM_PREFIX "portId", (int32_t)track->mPortId);
    mAnalyticsItem->setCString(MM_PREFIX "encoding", toString(track->mFormat).c_str());
    mAnalyticsItem->setInt32(MM_PREFIX "frameCount", (int32_t)track->mFrameCount);
    mAnalyticsItem->setCString(MM_PREFIX "attributes", toString(track->mAttributes).c_str());
}

// hand the user a snapshot of the metrics.
+1 −0
Original line number Diff line number Diff line
@@ -32,6 +32,7 @@ LOCAL_SHARED_LIBRARIES := \
    libbinder \
    libaudioclient \
    libmedialogservice \
    libmediametrics \
    libmediautils \
    libnbaio \
    libnblog \
+71 −0
Original line number Diff line number Diff line
@@ -488,6 +488,8 @@ AudioFlinger::ThreadBase::~ThreadBase()
        sp<IBinder> binder = IInterface::asBinder(mPowerManager);
        binder->unlinkToDeath(mDeathRecipient);
    }

    sendStatistics(true /* force */);
}

status_t AudioFlinger::ThreadBase::readyToRun()
@@ -571,6 +573,15 @@ void AudioFlinger::ThreadBase::sendIoConfigEvent(audio_io_config_event event, pi
// sendIoConfigEvent_l() must be called with ThreadBase::mLock held
void AudioFlinger::ThreadBase::sendIoConfigEvent_l(audio_io_config_event event, pid_t pid)
{
    // The audio statistics history is exponentially weighted to forget events
    // about five or more seconds in the past.  In order to have
    // crisper statistics for mediametrics, we reset the statistics on
    // an IoConfigEvent, to reflect different properties for a new device.
    mIoJitterMs.reset();
    mLatencyMs.reset();
    mProcessTimeMs.reset();
    mTimestampVerifier.discontinuity();

    sp<ConfigEvent> configEvent = (ConfigEvent *)new IoConfigEvent(event, pid);
    sendConfigEvent_l(configEvent);
}
@@ -1651,6 +1662,65 @@ void AudioFlinger::ThreadBase::broadcast_l()
    mWaitWorkCV.broadcast();
}

// Call only from threadLoop() or when it is idle.
// Do not call from high performance code as this may do binder rpc to the MediaMetrics service.
void AudioFlinger::ThreadBase::sendStatistics(bool force)
{
    // Do not log if we have no stats.
    // We choose the timestamp verifier because it is the most likely item to be present.
    const int64_t nstats = mTimestampVerifier.getN() - mLastRecordedTimestampVerifierN;
    if (nstats == 0) {
        return;
    }

    // Don't log more frequently than once per 12 hours.
    // We use BOOTTIME to include suspend time.
    const int64_t timeNs = systemTime(SYSTEM_TIME_BOOTTIME);
    const int64_t sinceNs = timeNs - mLastRecordedTimeNs; // ok if mLastRecordedTimeNs = 0
    if (!force && sinceNs <= 12 * NANOS_PER_HOUR) {
        return;
    }

    mLastRecordedTimestampVerifierN = mTimestampVerifier.getN();
    mLastRecordedTimeNs = timeNs;

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

#define MM_PREFIX "android.media.audiothread." // avoid cut-n-paste errors.

    // thread configuration
    item->setInt32(MM_PREFIX "id", (int32_t)mId); // IO handle
    // item->setInt32(MM_PREFIX "portId", (int32_t)mPortId);
    item->setCString(MM_PREFIX "type", threadTypeToString(mType));
    item->setInt32(MM_PREFIX "sampleRate", (int32_t)mSampleRate);
    item->setInt64(MM_PREFIX "channelMask", (int64_t)mChannelMask);
    item->setCString(MM_PREFIX "encoding", toString(mFormat).c_str());
    item->setInt32(MM_PREFIX "frameCount", (int32_t)mFrameCount);
    item->setCString(MM_PREFIX "outDevice", toString(mOutDevice).c_str());
    item->setCString(MM_PREFIX "inDevice", toString(mInDevice).c_str());

    // thread statistics
    if (mIoJitterMs.getN() > 0) {
        item->setDouble(MM_PREFIX "ioJitterMs.mean", mIoJitterMs.getMean());
        item->setDouble(MM_PREFIX "ioJitterMs.std", mIoJitterMs.getStdDev());
    }
    if (mProcessTimeMs.getN() > 0) {
        item->setDouble(MM_PREFIX "processTimeMs.mean", mProcessTimeMs.getMean());
        item->setDouble(MM_PREFIX "processTimeMs.std", mProcessTimeMs.getStdDev());
    }
    const auto tsjitter = mTimestampVerifier.getJitterMs();
    if (tsjitter.getN() > 0) {
        item->setDouble(MM_PREFIX "timestampJitterMs.mean", tsjitter.getMean());
        item->setDouble(MM_PREFIX "timestampJitterMs.std", tsjitter.getStdDev());
    }
    if (mLatencyMs.getN() > 0) {
        item->setDouble(MM_PREFIX "latencyMs.mean", mLatencyMs.getMean());
        item->setDouble(MM_PREFIX "latencyMs.std", mLatencyMs.getStdDev());
    }

    item->selfrecord();
}

// ----------------------------------------------------------------------------
//      Playback
// ----------------------------------------------------------------------------
@@ -3447,6 +3517,7 @@ bool AudioFlinger::PlaybackThread::threadLoop()
                        LOG_AUDIO_STATE();
                    }
                    mStandby = true;
                    sendStatistics(false /* force */);
                }

                if (mActiveTracks.isEmpty() && mConfigEvents.isEmpty()) {
+7 −0
Original line number Diff line number Diff line
@@ -399,6 +399,9 @@ public:

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

                // deliver stats to mediametrics.
                void                sendStatistics(bool force);

    mutable     Mutex                   mLock;

protected:
@@ -522,6 +525,10 @@ protected:
                audio_utils::Statistics<double> mProcessTimeMs{0.995 /* alpha */};
                audio_utils::Statistics<double> mLatencyMs{0.995 /* alpha */};

                // Save the last count when we delivered statistics to mediametrics.
                int64_t                 mLastRecordedTimestampVerifierN = 0;
                int64_t                 mLastRecordedTimeNs = 0;  // BOOTTIME to include suspend.

                bool                    mIsMsdDevice = false;
                // A condition that must be evaluated by the thread loop has changed and
                // we must not wait for async write callback in the thread loop before evaluating it