MediaMetrics: Add AudioFlinger logging
Test: atest mediametrics_tests
Test: mediametrics dumpsys
Bug: 138583596
Change-Id: I2086c5a780744d409052fde4c5ebc1dc92d95ea8
diff --git a/media/libaudioclient/AudioTrack.cpp b/media/libaudioclient/AudioTrack.cpp
index 8cfee50..eda9426 100644
--- a/media/libaudioclient/AudioTrack.cpp
+++ b/media/libaudioclient/AudioTrack.cpp
@@ -296,6 +296,12 @@
// pull together the numbers, before we clean up our structures
mMediaMetrics.gather(this);
+ mediametrics::LogItem(mMetricsId)
+ .set(AMEDIAMETRICS_PROP_EVENT, AMEDIAMETRICS_PROP_EVENT_VALUE_DTOR)
+ .set(AMEDIAMETRICS_PROP_STATE, stateToString(mState))
+ .set(AMEDIAMETRICS_PROP_STATUS, (int32_t)mStatus)
+ .record();
+
if (mStatus == NO_ERROR) {
// Make sure that callback function exits in the case where
// it is looping on buffer full condition in obtainBuffer().
@@ -626,11 +632,23 @@
status_t AudioTrack::start()
{
+ const int64_t beginNs = systemTime();
AutoMutex lock(mLock);
+
+ status_t status = NO_ERROR; // logged: make sure to set this before returning.
+ mediametrics::Defer([&] {
+ mediametrics::LogItem(mMetricsId)
+ .set(AMEDIAMETRICS_PROP_EVENT, AMEDIAMETRICS_PROP_EVENT_VALUE_START)
+ .set(AMEDIAMETRICS_PROP_DURATIONNS, (int64_t)(systemTime() - beginNs))
+ .set(AMEDIAMETRICS_PROP_STATE, stateToString(mState))
+ .set(AMEDIAMETRICS_PROP_STATUS, (int32_t)status)
+ .record(); });
+
ALOGV("%s(%d): prior state:%s", __func__, mPortId, stateToString(mState));
if (mState == STATE_ACTIVE) {
- return INVALID_OPERATION;
+ status = INVALID_OPERATION;
+ return status;
}
mInUnderrun = true;
@@ -703,7 +721,6 @@
mNewPosition = mPosition + mUpdatePeriod;
int32_t flags = android_atomic_and(~(CBLK_STREAM_END_DONE | CBLK_DISABLED), &mCblk->mFlags);
- status_t status = NO_ERROR;
if (!(flags & CBLK_INVALID)) {
status = mAudioTrack->start();
if (status == DEAD_OBJECT) {
@@ -749,7 +766,16 @@
void AudioTrack::stop()
{
+ const int64_t beginNs = systemTime();
+
AutoMutex lock(mLock);
+ mediametrics::Defer([&]() {
+ mediametrics::LogItem(mMetricsId)
+ .set(AMEDIAMETRICS_PROP_EVENT, AMEDIAMETRICS_PROP_EVENT_VALUE_STOP)
+ .set(AMEDIAMETRICS_PROP_DURATIONNS, (int64_t)(systemTime() - beginNs))
+ .set(AMEDIAMETRICS_PROP_STATE, stateToString(mState))
+ .record(); });
+
ALOGV("%s(%d): prior state:%s", __func__, mPortId, stateToString(mState));
if (mState != STATE_ACTIVE && mState != STATE_PAUSED) {
@@ -801,7 +827,15 @@
void AudioTrack::flush()
{
+ const int64_t beginNs = systemTime();
AutoMutex lock(mLock);
+ mediametrics::Defer([&]() {
+ mediametrics::LogItem(mMetricsId)
+ .set(AMEDIAMETRICS_PROP_EVENT, AMEDIAMETRICS_PROP_EVENT_VALUE_FLUSH)
+ .set(AMEDIAMETRICS_PROP_DURATIONNS, (int64_t)(systemTime() - beginNs))
+ .set(AMEDIAMETRICS_PROP_STATE, stateToString(mState))
+ .record(); });
+
ALOGV("%s(%d): prior state:%s", __func__, mPortId, stateToString(mState));
if (mSharedBuffer != 0) {
@@ -834,7 +868,15 @@
void AudioTrack::pause()
{
+ const int64_t beginNs = systemTime();
AutoMutex lock(mLock);
+ mediametrics::Defer([&]() {
+ mediametrics::LogItem(mMetricsId)
+ .set(AMEDIAMETRICS_PROP_EVENT, AMEDIAMETRICS_PROP_EVENT_VALUE_PAUSE)
+ .set(AMEDIAMETRICS_PROP_DURATIONNS, (int64_t)(systemTime() - beginNs))
+ .set(AMEDIAMETRICS_PROP_STATE, stateToString(mState))
+ .record(); });
+
ALOGV("%s(%d): prior state:%s", __func__, mPortId, stateToString(mState));
if (mState == STATE_ACTIVE) {
@@ -876,6 +918,12 @@
return BAD_VALUE;
}
+ mediametrics::LogItem(mMetricsId)
+ .set(AMEDIAMETRICS_PROP_EVENT, AMEDIAMETRICS_PROP_EVENT_VALUE_SETVOLUME)
+ .set(AMEDIAMETRICS_PROP_VOLUME_LEFT, (double)left)
+ .set(AMEDIAMETRICS_PROP_VOLUME_RIGHT, (double)right)
+ .record();
+
AutoMutex lock(mLock);
mVolume[AUDIO_INTERLEAVE_LEFT] = left;
mVolume[AUDIO_INTERLEAVE_RIGHT] = right;
@@ -1027,6 +1075,20 @@
//set effective rates
mProxy->setPlaybackRate(playbackRateTemp);
mProxy->setSampleRate(effectiveRate); // FIXME: not quite "atomic" with setPlaybackRate
+
+ mediametrics::LogItem(mMetricsId)
+ .set(AMEDIAMETRICS_PROP_EVENT, AMEDIAMETRICS_PROP_EVENT_VALUE_SETPLAYBACKPARAM)
+ .set(AMEDIAMETRICS_PROP_SAMPLERATE, (int32_t)mSampleRate)
+ .set(AMEDIAMETRICS_PROP_PLAYBACK_SPEED, (double)mPlaybackRate.mSpeed)
+ .set(AMEDIAMETRICS_PROP_PLAYBACK_PITCH, (double)mPlaybackRate.mPitch)
+ .set(AMEDIAMETRICS_PROP_PREFIX_EFFECTIVE
+ AMEDIAMETRICS_PROP_SAMPLERATE, (int32_t)effectiveRate)
+ .set(AMEDIAMETRICS_PROP_PREFIX_EFFECTIVE
+ AMEDIAMETRICS_PROP_PLAYBACK_SPEED, (double)playbackRateTemp.mSpeed)
+ .set(AMEDIAMETRICS_PROP_PREFIX_EFFECTIVE
+ AMEDIAMETRICS_PROP_PLAYBACK_PITCH, (double)playbackRateTemp.mPitch)
+ .record();
+
return NO_ERROR;
}
@@ -1618,6 +1680,48 @@
mDeathNotifier = new DeathNotifier(this);
IInterface::asBinder(mAudioTrack)->linkToDeath(mDeathNotifier, this);
+ // This is the first log sent from the AudioTrack client.
+ // The creation of the audio track by AudioFlinger (in the code above)
+ // is the first log of the AudioTrack and must be present before
+ // any AudioTrack client logs will be accepted.
+ mMetricsId = std::string(AMEDIAMETRICS_KEY_PREFIX_AUDIO_TRACK) + std::to_string(mPortId);
+ mediametrics::LogItem(mMetricsId)
+ .set(AMEDIAMETRICS_PROP_EVENT, AMEDIAMETRICS_PROP_EVENT_VALUE_CREATE)
+ // the following are immutable
+ .set(AMEDIAMETRICS_PROP_FLAGS, (int32_t)mFlags)
+ .set(AMEDIAMETRICS_PROP_ORIGINALFLAGS, (int32_t)mOrigFlags)
+ .set(AMEDIAMETRICS_PROP_SESSIONID, (int32_t)mSessionId)
+ .set(AMEDIAMETRICS_PROP_TRACKID, mPortId) // dup from key
+ .set(AMEDIAMETRICS_PROP_STREAMTYPE, toString(mStreamType).c_str())
+ .set(AMEDIAMETRICS_PROP_CONTENTTYPE, toString(mAttributes.content_type).c_str())
+ .set(AMEDIAMETRICS_PROP_USAGE, toString(mAttributes.usage).c_str())
+ .set(AMEDIAMETRICS_PROP_THREADID, (int32_t)output.outputId)
+ .set(AMEDIAMETRICS_PROP_SELECTEDDEVICEID, (int32_t)mSelectedDeviceId)
+ .set(AMEDIAMETRICS_PROP_ROUTEDDEVICEID, (int32_t)mRoutedDeviceId)
+ .set(AMEDIAMETRICS_PROP_ENCODING, toString(mFormat).c_str())
+ .set(AMEDIAMETRICS_PROP_CHANNELMASK, (int32_t)mChannelMask)
+ .set(AMEDIAMETRICS_PROP_FRAMECOUNT, (int32_t)mFrameCount)
+ // the following are NOT immutable
+ .set(AMEDIAMETRICS_PROP_VOLUME_LEFT, (double)mVolume[AUDIO_INTERLEAVE_LEFT])
+ .set(AMEDIAMETRICS_PROP_VOLUME_RIGHT, (double)mVolume[AUDIO_INTERLEAVE_RIGHT])
+ .set(AMEDIAMETRICS_PROP_STATE, stateToString(mState))
+ .set(AMEDIAMETRICS_PROP_AUXEFFECTID, (int32_t)mAuxEffectId)
+ .set(AMEDIAMETRICS_PROP_SAMPLERATE, (int32_t)mSampleRate)
+ .set(AMEDIAMETRICS_PROP_PLAYBACK_SPEED, (double)mPlaybackRate.mSpeed)
+ .set(AMEDIAMETRICS_PROP_PLAYBACK_PITCH, (double)mPlaybackRate.mPitch)
+ .set(AMEDIAMETRICS_PROP_PREFIX_EFFECTIVE
+ AMEDIAMETRICS_PROP_SAMPLERATE, (int32_t)effectiveSampleRate)
+ .set(AMEDIAMETRICS_PROP_PREFIX_EFFECTIVE
+ AMEDIAMETRICS_PROP_PLAYBACK_SPEED, (double)effectiveSpeed)
+ .set(AMEDIAMETRICS_PROP_PREFIX_EFFECTIVE
+ AMEDIAMETRICS_PROP_PLAYBACK_PITCH, (double)effectivePitch)
+ .record();
+
+ // mSendLevel
+ // mReqFrameCount?
+ // mNotificationFramesAct, mNotificationFramesReq, mNotificationsPerBufferReq
+ // mLatency, mAfLatency, mAfFrameCount, mAfSampleRate
+
}
exit:
@@ -2294,6 +2398,17 @@
status_t AudioTrack::restoreTrack_l(const char *from)
{
+ status_t result = NO_ERROR; // logged: make sure to set this before returning.
+ const int64_t beginNs = systemTime();
+ mediametrics::Defer([&] {
+ mediametrics::LogItem(mMetricsId)
+ .set(AMEDIAMETRICS_PROP_EVENT, AMEDIAMETRICS_PROP_EVENT_VALUE_RESTORE)
+ .set(AMEDIAMETRICS_PROP_DURATIONNS, (int64_t)(systemTime() - beginNs))
+ .set(AMEDIAMETRICS_PROP_STATE, stateToString(mState))
+ .set(AMEDIAMETRICS_PROP_STATUS, (int32_t)result)
+ .set(AMEDIAMETRICS_PROP_WHERE, from)
+ .record(); });
+
ALOGW("%s(%d): dead IAudioTrack, %s, creating a new one from %s()",
__func__, mPortId, isOffloadedOrDirect_l() ? "Offloaded or Direct" : "PCM", from);
++mSequence;
@@ -2305,7 +2420,8 @@
if (isOffloadedOrDirect_l() || mDoNotReconnect) {
// FIXME re-creation of offloaded and direct tracks is not yet implemented;
// reconsider enabling for linear PCM encodings when position can be preserved.
- return DEAD_OBJECT;
+ result = DEAD_OBJECT;
+ return result;
}
// Save so we can return count since creation.
@@ -2336,7 +2452,7 @@
// following member variables: mAudioTrack, mCblkMemory and mCblk.
// It will also delete the strong references on previous IAudioTrack and IMemory.
// If a new IAudioTrack cannot be created, the previous (dead) instance will be left intact.
- status_t result = createTrack_l();
+ result = createTrack_l();
if (result == NO_ERROR) {
// take the frames that will be lost by track recreation into account in saved position