AudioFlinger: refine latency computation if track is drained

Use server timestamp if track has no actively presented frames
(i.e. drained). Sometimes track frames may not have reached the HAL.

Test: audioflinger dumpsys with BT audio
Bug: 80447764
Change-Id: Iffc52f4cfcbadd419c6b6ccfa278e0712f3af4af
diff --git a/services/audioflinger/PlaybackTracks.h b/services/audioflinger/PlaybackTracks.h
index 9a8a154..3381e77 100644
--- a/services/audioflinger/PlaybackTracks.h
+++ b/services/audioflinger/PlaybackTracks.h
@@ -94,10 +94,9 @@
 
     virtual bool        isFastTrack() const { return (mFlags & AUDIO_OUTPUT_FLAG_FAST) != 0; }
 
-    virtual double bufferLatencyMs() {
-        return isStatic() ? 0.
-                : (double)mAudioTrackServerProxy->framesReadySafe() * 1000 / sampleRate();
-    }
+            double      bufferLatencyMs() const override {
+                            return isStatic() ? 0. : TrackBase::bufferLatencyMs();
+                        }
 
 // implement volume handling.
     media::VolumeShaper::Status applyVolumeShaper(
@@ -152,7 +151,7 @@
     bool isResumePending();
     void resumeAck();
     void updateTrackFrameInfo(int64_t trackFramesReleased, int64_t sinkFramesWritten,
-            const ExtendedTimestamp &timeStamp);
+            uint32_t halSampleRate, const ExtendedTimestamp &timeStamp);
 
     sp<IMemory> sharedBuffer() const { return mSharedBuffer; }
 
@@ -200,7 +199,6 @@
 
     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 27d3919..70fb2b9 100644
--- a/services/audioflinger/Threads.cpp
+++ b/services/audioflinger/Threads.cpp
@@ -3265,6 +3265,7 @@
                         t->updateTrackFrameInfo(
                                 t->mAudioTrackServerProxy->framesReleased(),
                                 mFramesWritten,
+                                mSampleRate,
                                 mTimestamp);
                     }
                 }
@@ -5059,8 +5060,10 @@
     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.) {
+    if (latencyMs != 0.) {
         dprintf(fd, "  NormalMixer latency ms: %.2lf\n", latencyMs);
+    } else {
+        dprintf(fd, "  NormalMixer latency ms: unavail\n");
     }
 
     if (hasFastMixer()) {
diff --git a/services/audioflinger/TrackBase.h b/services/audioflinger/TrackBase.h
index 9f17c3c..dafba1e 100644
--- a/services/audioflinger/TrackBase.h
+++ b/services/audioflinger/TrackBase.h
@@ -106,6 +106,86 @@
                         }
 #endif
 
+            /** returns the buffer contents size converted to time in milliseconds
+             * for PCM Playback or Record streaming tracks. The return value is zero for
+             * PCM static tracks and not defined for non-PCM tracks.
+             *
+             * This may be called without the thread lock.
+             */
+    virtual double      bufferLatencyMs() const {
+                            return mServerProxy->framesReadySafe() * 1000 / sampleRate();
+                        }
+
+            /** returns whether the track supports server latency computation.
+             * This is set in the constructor and constant throughout the track lifetime.
+             */
+
+            bool        isServerLatencySupported() const { return mServerLatencySupported; }
+
+            /** computes the server latency for PCM Playback or Record track
+             * to the device sink/source.  This is the time for the next frame in the track buffer
+             * written or read from the server thread to the device source or sink.
+             *
+             * This may be called without the thread lock, but latencyMs and fromTrack
+             * may be not be synchronized. For example PatchPanel may not obtain the
+             * thread lock before calling.
+             *
+             * \param latencyMs on success is set to the latency in milliseconds of the
+             *        next frame written/read by the server thread to/from the track buffer
+             *        from the device source/sink.
+             * \param fromTrack on success is set to true if latency was computed directly
+             *        from the track timestamp; otherwise set to false if latency was
+             *        estimated from the server timestamp.
+             *        fromTrack may be nullptr or omitted if not required.
+             *
+             * \returns OK or INVALID_OPERATION on failure.
+             */
+            status_t    getServerLatencyMs(double *latencyMs, bool *fromTrack = nullptr) const {
+                            if (!isServerLatencySupported()) {
+                                return INVALID_OPERATION;
+                            }
+
+                            // if no thread lock is acquired, these atomics are not
+                            // synchronized with each other, considered a benign race.
+
+                            const double serverLatencyMs = mServerLatencyMs.load();
+                            if (serverLatencyMs == 0.) {
+                                return INVALID_OPERATION;
+                            }
+                            if (fromTrack != nullptr) {
+                                *fromTrack = mServerLatencyFromTrack.load();
+                            }
+                            *latencyMs = serverLatencyMs;
+                            return OK;
+                        }
+
+            /** computes the total client latency for PCM Playback or Record tracks
+             * for the next client app access to the device sink/source; i.e. the
+             * server latency plus the buffer latency.
+             *
+             * This may be called without the thread lock, but latencyMs and fromTrack
+             * may be not be synchronized. For example PatchPanel may not obtain the
+             * thread lock before calling.
+             *
+             * \param latencyMs on success is set to the latency in milliseconds of the
+             *        next frame written/read by the client app to/from the track buffer
+             *        from the device sink/source.
+             * \param fromTrack on success is set to true if latency was computed directly
+             *        from the track timestamp; otherwise set to false if latency was
+             *        estimated from the server timestamp.
+             *        fromTrack may be nullptr or omitted if not required.
+             *
+             * \returns OK or INVALID_OPERATION on failure.
+             */
+            status_t    getTrackLatencyMs(double *latencyMs, bool *fromTrack = nullptr) const {
+                            double serverLatencyMs;
+                            status_t status = getServerLatencyMs(&serverLatencyMs, fromTrack);
+                            if (status == OK) {
+                                *latencyMs = serverLatencyMs + bufferLatencyMs();
+                            }
+                            return status;
+                        }
+
 protected:
     DISALLOW_COPY_AND_ASSIGN(TrackBase);
 
@@ -222,6 +302,10 @@
     audio_io_handle_t   mThreadIoHandle; // I/O handle of the thread the track is attached to
     audio_port_handle_t mPortId; // unique ID for this track used by audio policy
     bool                mIsInvalid; // non-resettable latch, set by invalidate()
+
+    bool                mServerLatencySupported = false;
+    std::atomic<bool>   mServerLatencyFromTrack{}; // latency from track or server timestamp.
+    std::atomic<double> mServerLatencyMs{};        // last latency pushed from server thread.
 };
 
 // PatchProxyBufferProvider interface is implemented by PatchTrack and PatchRecord.
diff --git a/services/audioflinger/Tracks.cpp b/services/audioflinger/Tracks.cpp
index 6953ebf..37e67af 100644
--- a/services/audioflinger/Tracks.cpp
+++ b/services/audioflinger/Tracks.cpp
@@ -435,7 +435,7 @@
     }
     mName = TRACK_NAME_PENDING;
 
-    mDumpLatency = thread->type() == ThreadBase::MIXER;
+    mServerLatencySupported = thread->type() == ThreadBase::MIXER;
 #ifdef TEE_SINK
     mTee.setId(std::string("_") + std::to_string(mThreadIoHandle)
             + "_" + std::to_string(mId) +
@@ -497,7 +497,7 @@
                   "ST  L dB  R dB  VS dB "
                   "  Server FrmCnt  FrmRdy F Underruns  Flushed"
                   "%s\n",
-                  mDumpLatency ? " Latency" : "");
+                  isServerLatencySupported() ? "   Latency" : "");
 }
 
 void AudioFlinger::PlaybackThread::Track::appendDump(String8& result, bool active)
@@ -593,7 +593,7 @@
 
             mFormat,
             mChannelMask,
-            mAudioTrackServerProxy->getSampleRate(),
+            sampleRate(),
 
             mStreamType,
             20.0 * log10(float_from_gain(gain_minifloat_unpack_left(vlr))),
@@ -610,14 +610,16 @@
             nowInUnderrun,
             (unsigned)mAudioTrackServerProxy->framesFlushed() % 10000000
             );
-    if (mDumpLatency) {
-        double latencyMs =
-                mAudioTrackServerProxy->getTimestamp().getOutputServerLatencyMs(mSampleRate);
-        if (latencyMs > 0.) {
-            latencyMs += bufferLatencyMs();
-            result.appendFormat(" %7.3f", latencyMs);
+
+    if (isServerLatencySupported()) {
+        double latencyMs;
+        bool fromTrack;
+        if (getTrackLatencyMs(&latencyMs, &fromTrack) == OK) {
+            // Show latency in msec, followed by 't' if from track timestamp (the most accurate)
+            // or 'k' if estimated from kernel because track frames haven't been presented yet.
+            result.appendFormat(" %7.2lf %c", latencyMs, fromTrack ? 't' : 'k');
         } else {
-            result.appendFormat(" Unknown");
+            result.appendFormat("%10s", mCblk->mServer != 0 ? "unavail" : "new");
         }
     }
     result.append("\n");
@@ -677,6 +679,13 @@
     mAudioTrackServerProxy->setTimestamp(timestamp);
 
     // We do not set drained here, as FastTrack timestamp may not go to very last frame.
+
+    // Compute latency.
+    // TODO: Consider whether the server latency may be passed in by FastMixer
+    // as a constant for all active FastTracks.
+    const double latencyMs = timestamp.getOutputServerLatencyMs(sampleRate());
+    mServerLatencyFromTrack.store(true);
+    mServerLatencyMs.store(latencyMs);
 }
 
 // Don't call for fast tracks; the framesReady() could result in priority inversion
@@ -1241,7 +1250,7 @@
 //To be called with thread lock held
 void AudioFlinger::PlaybackThread::Track::updateTrackFrameInfo(
         int64_t trackFramesReleased, int64_t sinkFramesWritten,
-        const ExtendedTimestamp &timeStamp) {
+        uint32_t halSampleRate, const ExtendedTimestamp &timeStamp) {
     //update frame map
     mFrameMap.push(trackFramesReleased, sinkFramesWritten);
 
@@ -1250,6 +1259,7 @@
     // Our timestamps are only updated when the track is on the Thread active list.
     // We need to ensure that tracks are not removed before full drain.
     ExtendedTimestamp local = timeStamp;
+    bool drained = true; // default assume drained, if no server info found
     bool checked = false;
     for (int i = ExtendedTimestamp::LOCATION_MAX - 1;
             i >= ExtendedTimestamp::LOCATION_SERVER; --i) {
@@ -1258,18 +1268,25 @@
             local.mPosition[i] = mFrameMap.findX(local.mPosition[i]);
             // check drain state from the latest stage in the pipeline.
             if (!checked && i <= ExtendedTimestamp::LOCATION_KERNEL) {
-                mAudioTrackServerProxy->setDrained(
-                        local.mPosition[i] >= mAudioTrackServerProxy->framesReleased());
+                drained = local.mPosition[i] >= mAudioTrackServerProxy->framesReleased();
                 checked = true;
             }
         }
     }
-    if (!checked) { // no server info, assume drained.
-        mAudioTrackServerProxy->setDrained(true);
-    }
+
+    mAudioTrackServerProxy->setDrained(drained);
     // Set correction for flushed frames that are not accounted for in released.
     local.mFlushed = mAudioTrackServerProxy->framesFlushed();
     mServerProxy->setTimestamp(local);
+
+    // Compute latency info.
+    const bool useTrackTimestamp = !drained;
+    const double latencyMs = useTrackTimestamp
+            ? local.getOutputServerLatencyMs(sampleRate())
+            : timeStamp.getOutputServerLatencyMs(halSampleRate);
+
+    mServerLatencyFromTrack.store(useTrackTimestamp);
+    mServerLatencyMs.store(latencyMs);
 }
 
 // ----------------------------------------------------------------------------