ThreadMetrics: Add device-based statistics for audio
Compute summary statistics based on the current device
rather than the entire Audio Thread duration.
Test: adb shell dumpsys media.metrics
Bug: 149850236
Change-Id: Ie6d459b06b4a469401ee9e0c194e45ea5ce380c6
diff --git a/services/audioflinger/Threads.cpp b/services/audioflinger/Threads.cpp
index 69bf831..594baf8 100644
--- a/services/audioflinger/Threads.cpp
+++ b/services/audioflinger/Threads.cpp
@@ -492,11 +492,13 @@
}
AudioFlinger::ThreadBase::ThreadBase(const sp<AudioFlinger>& audioFlinger, audio_io_handle_t id,
- type_t type, bool systemReady)
+ type_t type, bool systemReady, bool isOut)
: Thread(false /*canCallJava*/),
mType(type),
mAudioFlinger(audioFlinger),
- mMetricsId(std::string(AMEDIAMETRICS_KEY_PREFIX_AUDIO_THREAD) + std::to_string(id)),
+ mThreadMetrics(std::string(AMEDIAMETRICS_KEY_PREFIX_AUDIO_THREAD) + std::to_string(id),
+ isOut),
+ mIsOut(isOut),
// mSampleRate, mFrameCount, mChannelMask, mChannelCount, mFrameSize, mFormat, mBufferSize
// are set by PlaybackThread::readOutputParameters_l() or
// RecordThread::readInputParameters_l()
@@ -508,13 +510,7 @@
mSystemReady(systemReady),
mSignalPending(false)
{
- mediametrics::LogItem(mMetricsId)
- .setPid(getpid())
- .set(AMEDIAMETRICS_PROP_EVENT, AMEDIAMETRICS_PROP_EVENT_VALUE_CTOR)
- .set(AMEDIAMETRICS_PROP_TYPE, threadTypeToString(type))
- .set(AMEDIAMETRICS_PROP_THREADID, id)
- .record();
-
+ mThreadMetrics.logConstructor(getpid(), threadTypeToString(type), id);
memset(&mPatch, 0, sizeof(struct audio_patch));
}
@@ -531,10 +527,6 @@
}
sendStatistics(true /* force */);
-
- mediametrics::LogItem(mMetricsId)
- .set(AMEDIAMETRICS_PROP_EVENT, AMEDIAMETRICS_PROP_EVENT_VALUE_DTOR)
- .record();
}
status_t AudioFlinger::ThreadBase::readyToRun()
@@ -1835,7 +1827,7 @@
audio_io_handle_t id,
type_t type,
bool systemReady)
- : ThreadBase(audioFlinger, id, type, systemReady),
+ : ThreadBase(audioFlinger, id, type, systemReady, true /* isOut */),
mNormalFrameCount(0), mSinkBuffer(NULL),
mMixerBufferEnabled(AudioFlinger::kEnableExtendedPrecision),
mMixerBuffer(NULL),
@@ -2884,7 +2876,7 @@
}
audio_output_flags_t flags = mOutput->flags;
- mediametrics::LogItem item(mMetricsId);
+ mediametrics::LogItem item(mThreadMetrics.getMetricsId()); // TODO: method in ThreadMetrics?
item.set(AMEDIAMETRICS_PROP_EVENT, AMEDIAMETRICS_PROP_EVENT_VALUE_READPARAMETERS)
.set(AMEDIAMETRICS_PROP_ENCODING, formatToString(mFormat).c_str())
.set(AMEDIAMETRICS_PROP_SAMPLERATE, (int32_t)mSampleRate)
@@ -3142,7 +3134,10 @@
mNumWrites++;
mInWrite = false;
- mStandby = false;
+ if (mStandby) {
+ mThreadMetrics.logBeginInterval();
+ mStandby = false;
+ }
return bytesWritten;
}
@@ -3681,8 +3676,9 @@
// This is where we go into standby
if (!mStandby) {
LOG_AUDIO_STATE();
+ mThreadMetrics.logEndInterval();
+ mStandby = true;
}
- mStandby = true;
sendStatistics(false /* force */);
}
@@ -3986,10 +3982,7 @@
const int32_t throttleMs = (int32_t)mHalfBufferMs - deltaMs;
if ((signed)mHalfBufferMs >= throttleMs && throttleMs > 0) {
- mediametrics::LogItem(mMetricsId)
- // ms units always double
- .set(AMEDIAMETRICS_PROP_THROTTLEMS, (double)throttleMs)
- .record();
+ mThreadMetrics.logThrottleMs((double)throttleMs);
usleep(throttleMs * 1000);
// notify of throttle start on verbose log
@@ -4265,10 +4258,10 @@
*handle = AUDIO_PATCH_HANDLE_NONE;
}
const std::string patchSinksAsString = patchSinksToString(patch);
- mediametrics::LogItem item(mMetricsId);
- item.set(AMEDIAMETRICS_PROP_EVENT, AMEDIAMETRICS_PROP_EVENT_VALUE_CREATEAUDIOPATCH)
- .set(AMEDIAMETRICS_PROP_OUTPUTDEVICES, patchSinksAsString.c_str())
- .record();
+
+ mThreadMetrics.logEndInterval();
+ mThreadMetrics.logCreatePatch(patchSinksAsString);
+ mThreadMetrics.logBeginInterval();
// also dispatch to active AudioTracks for MediaMetrics
for (const auto &track : mActiveTracks) {
track->logEndInterval();
@@ -4816,9 +4809,8 @@
// DeferredOperations handles statistics after setting mixerStatus.
class DeferredOperations {
public:
- DeferredOperations(mixer_state *mixerStatus, const std::string &metricsId)
- : mMixerStatus(mixerStatus)
- , mMetricsId(metricsId) {}
+ explicit DeferredOperations(mixer_state *mixerStatus)
+ : mMixerStatus(mixerStatus) {}
// when leaving scope, tally frames properly.
~DeferredOperations() {
@@ -4841,9 +4833,8 @@
private:
const mixer_state * const mMixerStatus;
- const std::string& __unused mMetricsId;
std::vector<std::pair<sp<Track>, size_t>> mUnderrunFrames;
- } deferredOperations(&mixerStatus, mMetricsId);
+ } deferredOperations(&mixerStatus);
// implicit nested scope for variable capture
bool noFastHapticTrack = true;
@@ -5582,7 +5573,10 @@
status = mOutput->stream->setParameters(keyValuePair);
if (!mStandby && status == INVALID_OPERATION) {
mOutput->standby();
- mStandby = true;
+ if (!mStandby) {
+ mThreadMetrics.logEndInterval();
+ mStandby = true;
+ }
mBytesWritten = 0;
status = mOutput->stream->setParameters(keyValuePair);
}
@@ -6095,7 +6089,10 @@
status = mOutput->stream->setParameters(keyValuePair);
if (!mStandby && status == INVALID_OPERATION) {
mOutput->standby();
- mStandby = true;
+ if (!mStandby) {
+ mThreadMetrics.logEndInterval();
+ mStandby = true;
+ }
mBytesWritten = 0;
status = mOutput->stream->setParameters(keyValuePair);
}
@@ -6690,7 +6687,10 @@
// TODO: Report correction for the other output tracks and show in the dump.
}
- mStandby = false;
+ if (mStandby) {
+ mThreadMetrics.logBeginInterval();
+ mStandby = false;
+ }
return (ssize_t)mSinkBufferSize;
}
@@ -6852,7 +6852,7 @@
audio_io_handle_t id,
bool systemReady
) :
- ThreadBase(audioFlinger, id, RECORD, systemReady),
+ ThreadBase(audioFlinger, id, RECORD, systemReady, false /* isOut */),
mInput(input),
mSource(mInput),
mActiveTracks(&this->mLocalLog),
@@ -7140,7 +7140,10 @@
case TrackBase::STARTING_2:
doBroadcast = true;
- mStandby = false;
+ if (mStandby) {
+ mThreadMetrics.logBeginInterval();
+ mStandby = false;
+ }
activeTrack->mState = TrackBase::ACTIVE;
allStopped = false;
break;
@@ -7581,6 +7584,7 @@
{
if (!mStandby) {
inputStandBy();
+ mThreadMetrics.logEndInterval();
mStandby = true;
}
}
@@ -8553,11 +8557,9 @@
}
const std::string pathSourcesAsString = patchSourcesToString(patch);
- mediametrics::LogItem item(mMetricsId);
- item.set(AMEDIAMETRICS_PROP_EVENT, AMEDIAMETRICS_PROP_EVENT_VALUE_CREATEAUDIOPATCH)
- .set(AMEDIAMETRICS_PROP_INPUTDEVICES, pathSourcesAsString.c_str())
- .set(AMEDIAMETRICS_PROP_SOURCE, toString(mAudioSource).c_str())
- .record();
+ mThreadMetrics.logEndInterval();
+ mThreadMetrics.logCreatePatch(pathSourcesAsString);
+ mThreadMetrics.logBeginInterval();
// also dispatch to active AudioRecords
for (const auto &track : mActiveTracks) {
track->logEndInterval();
@@ -8669,8 +8671,8 @@
AudioFlinger::MmapThread::MmapThread(
const sp<AudioFlinger>& audioFlinger, audio_io_handle_t id,
- AudioHwDevice *hwDev, sp<StreamHalInterface> stream, bool systemReady)
- : ThreadBase(audioFlinger, id, MMAP, systemReady),
+ AudioHwDevice *hwDev, sp<StreamHalInterface> stream, bool systemReady, bool isOut)
+ : ThreadBase(audioFlinger, id, MMAP, systemReady, isOut),
mSessionId(AUDIO_SESSION_NONE),
mPortId(AUDIO_PORT_HANDLE_NONE),
mHalStream(stream), mHalDevice(hwDev->hwDevice()), mAudioHwDev(hwDev),
@@ -8753,7 +8755,10 @@
ALOGE("%s: error mHalStream->start() = %d for first track", __FUNCTION__, ret);
return ret;
}
- mStandby = false;
+ if (mStandby) {
+ mThreadMetrics.logBeginInterval();
+ mStandby = false;
+ }
return NO_ERROR;
}
@@ -8942,7 +8947,10 @@
return INVALID_OPERATION;
}
mHalStream->standby();
- mStandby = true;
+ if (!mStandby) {
+ mThreadMetrics.logEndInterval();
+ mStandby = true;
+ }
releaseWakeLock();
return NO_ERROR;
}
@@ -8960,7 +8968,8 @@
LOG_ALWAYS_FATAL_IF(result != OK, "Error retrieving buffer size from HAL: %d", result);
mFrameCount = mBufferSize / mFrameSize;
- mediametrics::LogItem item(mMetricsId);
+ // TODO: make a readHalParameters call?
+ mediametrics::LogItem item(mThreadMetrics.getMetricsId());
item.set(AMEDIAMETRICS_PROP_EVENT, AMEDIAMETRICS_PROP_EVENT_VALUE_READPARAMETERS)
.set(AMEDIAMETRICS_PROP_ENCODING, formatToString(mFormat).c_str())
.set(AMEDIAMETRICS_PROP_SAMPLERATE, (int32_t)mSampleRate)
@@ -9390,7 +9399,7 @@
AudioFlinger::MmapPlaybackThread::MmapPlaybackThread(
const sp<AudioFlinger>& audioFlinger, audio_io_handle_t id,
AudioHwDevice *hwDev, AudioStreamOut *output, bool systemReady)
- : MmapThread(audioFlinger, id, hwDev, output->stream, systemReady),
+ : MmapThread(audioFlinger, id, hwDev, output->stream, systemReady, true /* isOut */),
mStreamType(AUDIO_STREAM_MUSIC),
mStreamVolume(1.0),
mStreamMute(false),
@@ -9601,7 +9610,7 @@
AudioFlinger::MmapCaptureThread::MmapCaptureThread(
const sp<AudioFlinger>& audioFlinger, audio_io_handle_t id,
AudioHwDevice *hwDev, AudioStreamIn *input, bool systemReady)
- : MmapThread(audioFlinger, id, hwDev, input->stream, systemReady),
+ : MmapThread(audioFlinger, id, hwDev, input->stream, systemReady, false /* isOut */),
mInput(input)
{
snprintf(mThreadName, kThreadNameLength, "AudioMmapIn_%X", id);