AudioFlinger: Add latency measurements from timestamp
Replaces main and aux buf from track dump.
Bug: 80272001
Test: adb shell dumpsys media.audio_flinger
Change-Id: I5d6565410e652ec7fc6701b171d299dea9f7bc3e
diff --git a/include/private/media/AudioTrackShared.h b/include/private/media/AudioTrackShared.h
index ca119d5..518cc63 100644
--- a/include/private/media/AudioTrackShared.h
+++ b/include/private/media/AudioTrackShared.h
@@ -538,6 +538,10 @@
mTimestampMutator.push(timestamp);
}
+ virtual ExtendedTimestamp getTimestamp() const {
+ return mTimestampMutator.last();
+ }
+
// Flushes the shared ring buffer if the client had requested it using mStreaming.mFlush.
// If flush occurs then:
// cblk->u.mStreaming.mFront, ServerProxy::mFlush and ServerProxy::mFlushed will be modified
diff --git a/media/libaudioclient/include/media/AudioTimestamp.h b/media/libaudioclient/include/media/AudioTimestamp.h
index 498de8e..bdffdac 100644
--- a/media/libaudioclient/include/media/AudioTimestamp.h
+++ b/media/libaudioclient/include/media/AudioTimestamp.h
@@ -135,6 +135,21 @@
return INVALID_OPERATION;
}
+ double getOutputServerLatencyMs(uint32_t sampleRate) const {
+ return getLatencyMs(sampleRate, LOCATION_SERVER, LOCATION_KERNEL);
+ }
+
+ double getLatencyMs(uint32_t sampleRate, Location location1, Location location2) const {
+ if (mTimeNs[location1] > 0 && mTimeNs[location2] > 0) {
+ const int64_t frameDifference =
+ mPosition[location1] - mPosition[location2];
+ const int64_t timeDifferenceNs =
+ mTimeNs[location1] - mTimeNs[location2];
+ return ((double)frameDifference * 1e9 / sampleRate - timeDifferenceNs) * 1e-6;
+ }
+ return 0.;
+ }
+
// convert fields to a printable string
std::string toString() {
std::stringstream ss;
diff --git a/services/audioflinger/FastMixer.cpp b/services/audioflinger/FastMixer.cpp
index 7a02963..caeede9 100644
--- a/services/audioflinger/FastMixer.cpp
+++ b/services/audioflinger/FastMixer.cpp
@@ -489,6 +489,10 @@
timestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL];
mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL] =
timestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL];
+ // We don't compensate for server - kernel time difference and
+ // only update latency if we have valid info.
+ dumpState->mLatencyMs =
+ (double)mNativeFramesWrittenButNotPresented * 1000 / mSampleRate;
} else {
// HAL reported that more frames were presented than were written
mNativeFramesWrittenButNotPresented = 0;
diff --git a/services/audioflinger/FastMixerDumpState.cpp b/services/audioflinger/FastMixerDumpState.cpp
index 2e4fb8c..b3a2520 100644
--- a/services/audioflinger/FastMixerDumpState.cpp
+++ b/services/audioflinger/FastMixerDumpState.cpp
@@ -68,11 +68,11 @@
dprintf(fd, " FastMixer command=%s writeSequence=%u framesWritten=%u\n"
" numTracks=%u writeErrors=%u underruns=%u overruns=%u\n"
" sampleRate=%u frameCount=%zu measuredWarmup=%.3g ms, warmupCycles=%u\n"
- " mixPeriod=%.2f ms\n",
+ " mixPeriod=%.2f ms latency=%.2f ms\n",
FastMixerState::commandToString(mCommand), mWriteSequence, mFramesWritten,
mNumTracks, mWriteErrors, mUnderruns, mOverruns,
mSampleRate, mFrameCount, measuredWarmupMs, mWarmupCycles,
- mixPeriodSec * 1e3);
+ mixPeriodSec * 1e3, mLatencyMs);
#ifdef FAST_THREAD_STATISTICS
// find the interval of valid samples
uint32_t bounds = mBounds;
diff --git a/services/audioflinger/FastMixerDumpState.h b/services/audioflinger/FastMixerDumpState.h
index 8ef31d1..aed6bc5 100644
--- a/services/audioflinger/FastMixerDumpState.h
+++ b/services/audioflinger/FastMixerDumpState.h
@@ -66,6 +66,7 @@
void dump(int fd) const; // should only be called on a stable copy, not the original
+ double mLatencyMs = 0.; // measured latency, default of 0 if no valid timestamp read.
uint32_t mWriteSequence; // incremented before and after each write()
uint32_t mFramesWritten; // total number of frames written successfully
uint32_t mNumTracks; // total number of active fast tracks
diff --git a/services/audioflinger/PlaybackTracks.h b/services/audioflinger/PlaybackTracks.h
index ff9444d..9a8a154 100644
--- a/services/audioflinger/PlaybackTracks.h
+++ b/services/audioflinger/PlaybackTracks.h
@@ -41,7 +41,7 @@
virtual ~Track();
virtual status_t initCheck() const;
- static void appendDumpHeader(String8& result);
+ void appendDumpHeader(String8& result);
void appendDump(String8& result, bool active);
virtual status_t start(AudioSystem::sync_event_t event =
AudioSystem::SYNC_EVENT_NONE,
@@ -75,6 +75,7 @@
bool isOffloadedOrDirect() const { return (mFlags
& (AUDIO_OUTPUT_FLAG_COMPRESS_OFFLOAD
| AUDIO_OUTPUT_FLAG_DIRECT)) != 0; }
+ bool isStatic() const { return mSharedBuffer.get() != nullptr; }
status_t setParameters(const String8& keyValuePairs);
status_t attachAuxEffect(int EffectId);
@@ -93,6 +94,11 @@
virtual bool isFastTrack() const { return (mFlags & AUDIO_OUTPUT_FLAG_FAST) != 0; }
+ virtual double bufferLatencyMs() {
+ return isStatic() ? 0.
+ : (double)mAudioTrackServerProxy->framesReadySafe() * 1000 / sampleRate();
+ }
+
// implement volume handling.
media::VolumeShaper::Status applyVolumeShaper(
const sp<media::VolumeShaper::Configuration>& configuration,
@@ -194,6 +200,7 @@
sp<media::VolumeHandler> mVolumeHandler; // handles multiple VolumeShaper configs and operations
+ bool mDumpLatency = false; // true if track supports latency dumps.
private:
// The following fields are only for fast tracks, and should be in a subclass
int mFastIndex; // index within FastMixerState::mFastTracks[];
diff --git a/services/audioflinger/Threads.cpp b/services/audioflinger/Threads.cpp
index 90e2e8e..e9721fa 100644
--- a/services/audioflinger/Threads.cpp
+++ b/services/audioflinger/Threads.cpp
@@ -1784,7 +1784,7 @@
if (numtracks) {
dprintf(fd, " of which %zu are active\n", numactive);
result.append(prefix);
- Track::appendDumpHeader(result);
+ mTracks[0]->appendDumpHeader(result);
for (size_t i = 0; i < numtracks; ++i) {
sp<Track> track = mTracks[i];
if (track != 0) {
@@ -1804,7 +1804,7 @@
result.append(" The following tracks are in the active list but"
" not in the track list\n");
result.append(prefix);
- Track::appendDumpHeader(result);
+ mActiveTracks[0]->appendDumpHeader(result);
for (size_t i = 0; i < numactive; ++i) {
sp<Track> track = mActiveTracks[i];
if (mTracks.indexOf(track) < 0) {
@@ -5054,6 +5054,10 @@
dprintf(fd, " Thread throttle time (msecs): %u\n", mThreadThrottleTimeMs);
dprintf(fd, " AudioMixer tracks: %s\n", mAudioMixer->trackNames().c_str());
dprintf(fd, " Master mono: %s\n", mMasterMono ? "on" : "off");
+ const double latencyMs = mTimestamp.getOutputServerLatencyMs(mSampleRate);
+ if (latencyMs > 0.) {
+ dprintf(fd, " NormalMixer latency ms: %.2lf\n", latencyMs);
+ }
if (hasFastMixer()) {
dprintf(fd, " FastMixer thread %p tid=%d", mFastMixer.get(), mFastMixer->getTid());
diff --git a/services/audioflinger/Tracks.cpp b/services/audioflinger/Tracks.cpp
index 824dac7..6953ebf 100644
--- a/services/audioflinger/Tracks.cpp
+++ b/services/audioflinger/Tracks.cpp
@@ -435,6 +435,7 @@
}
mName = TRACK_NAME_PENDING;
+ mDumpLatency = thread->type() == ThreadBase::MIXER;
#ifdef TEE_SINK
mTee.setId(std::string("_") + std::to_string(mThreadIoHandle)
+ "_" + std::to_string(mId) +
@@ -489,13 +490,14 @@
}
}
-/*static*/ void AudioFlinger::PlaybackThread::Track::appendDumpHeader(String8& result)
+void AudioFlinger::PlaybackThread::Track::appendDumpHeader(String8& result)
{
- result.append("T Name Active Client Session S Flags "
+ result.appendFormat("T Name Active Client Session S Flags "
" Format Chn mask SRate "
"ST L dB R dB VS dB "
- " Server FrmCnt FrmRdy F Underruns Flushed "
- "Main Buf Aux Buf\n");
+ " Server FrmCnt FrmRdy F Underruns Flushed"
+ "%s\n",
+ mDumpLatency ? " Latency" : "");
}
void AudioFlinger::PlaybackThread::Track::appendDump(String8& result, bool active)
@@ -504,7 +506,7 @@
switch (mType) {
case TYPE_DEFAULT:
case TYPE_OUTPUT:
- if (mSharedBuffer.get() != nullptr) {
+ if (isStatic()) {
trackType = 'S'; // static
} else {
trackType = ' '; // normal
@@ -582,8 +584,7 @@
result.appendFormat("%7s %6u %7u %2s 0x%03X "
"%08X %08X %6u "
"%2u %5.2g %5.2g %5.2g%c "
- "%08X %6zu%c %6zu %c %9u%c %7u "
- "%08zX %08zX\n",
+ "%08X %6zu%c %6zu %c %9u%c %7u",
active ? "yes" : "no",
(mClient == 0) ? getpid() : mClient->pid(),
mSessionId,
@@ -607,11 +608,19 @@
fillingStatus,
mAudioTrackServerProxy->getUnderrunFrames(),
nowInUnderrun,
- (unsigned)mAudioTrackServerProxy->framesFlushed() % 10000000,
-
- (size_t)mMainBuffer, // use %zX as %p appends 0x
- (size_t)mAuxBuffer // use %zX as %p appends 0x
+ (unsigned)mAudioTrackServerProxy->framesFlushed() % 10000000
);
+ if (mDumpLatency) {
+ double latencyMs =
+ mAudioTrackServerProxy->getTimestamp().getOutputServerLatencyMs(mSampleRate);
+ if (latencyMs > 0.) {
+ latencyMs += bufferLatencyMs();
+ result.appendFormat(" %7.3f", latencyMs);
+ } else {
+ result.appendFormat(" Unknown");
+ }
+ }
+ result.append("\n");
}
uint32_t AudioFlinger::PlaybackThread::Track::sampleRate() const {