Merge "TimedAudio: Track of the number of pending frames." into ics-aah

Author: johngro

services/audioflinger/AudioFlinger.cpp

@@ -63,6 +63,18 @@
 
 // ----------------------------------------------------------------------------
 
+// Note: the following macro is used for extremely verbose logging message.  In
+// order to run with LOG_ASSERT turned on, we need to have LOG_NDEBUG set to 0;
+// but one side effect of this is to turn all LOGV's as well.  Some messages are
+// so verbose that we want to suppress them even when we have LOG_ASSERT turned
+// on.  Do not uncomment the #def below unless you really know what you are
+// doing and want to see all of the extremely verbose messages.
+//#define VERY_VERY_VERBOSE_LOGGING
+#ifdef VERY_VERY_VERBOSE_LOGGING
+#define LOGVV LOGV
+#else
+#define LOGVV(a...) do { } while(0)
+#endif
 
 namespace android {
 
@@ -3843,6 +3855,7 @@ AudioFlinger::PlaybackThread::TimedTrack::TimedTrack(
             frameCount, sharedBuffer, sessionId),
       mQueueHeadInFlight(false),
       mTrimQueueHeadOnRelease(false),
+      mFramesPendingInQueue(0),
       mTimedSilenceBuffer(NULL),
       mTimedSilenceBufferSize(0),
       mTimedAudioOutputOnTime(false),
@@ -3921,9 +3934,9 @@ void AudioFlinger::PlaybackThread::TimedTrack::trimTimedBufferQueue_l() {
         }
     }
 
-    size_t trimIndex;
-    for (trimIndex = 0; trimIndex < mTimedBufferQueue.size(); trimIndex++) {
-        int64_t frameCount = mTimedBufferQueue[trimIndex].buffer()->size()
+    size_t trimEnd;
+    for (trimEnd = 0; trimEnd < mTimedBufferQueue.size(); trimEnd++) {
+        int64_t frameCount = mTimedBufferQueue[trimEnd].buffer()->size()
                            / mCblk->frameSize;
         int64_t bufEnd;
 
@@ -3936,25 +3949,63 @@ void AudioFlinger::PlaybackThread::TimedTrack::trimTimedBufferQueue_l() {
                  __PRETTY_FUNCTION__);
             break;
         }
-        bufEnd += mTimedBufferQueue[trimIndex].pts();
+        bufEnd += mTimedBufferQueue[trimEnd].pts();
 
         if (bufEnd > mediaTimeNow)
             break;
 
         // Is the buffer we want to use in the middle of a mix operation right
         // now?  If so, don't actually trim it.  Just wait for the releaseBuffer
         // from the mixer which should be coming back shortly.
-        if (!trimIndex && mQueueHeadInFlight) {
+        if (!trimEnd && mQueueHeadInFlight) {
             mTrimQueueHeadOnRelease = true;
         }
     }
 
     size_t trimStart = mTrimQueueHeadOnRelease ? 1 : 0;
-    if (trimStart < trimIndex) {
-        mTimedBufferQueue.removeItemsAt(trimStart, trimIndex);
+    if (trimStart < trimEnd) {
+        // Update the bookkeeping for framesReady()
+        for (size_t i = trimStart; i < trimEnd; ++i) {
+            updateFramesPendingAfterTrim_l(mTimedBufferQueue[i], "trim");
+        }
+
+        // Now actually remove the buffers from the queue.
+        mTimedBufferQueue.removeItemsAt(trimStart, trimEnd);
     }
 }
 
+void AudioFlinger::PlaybackThread::TimedTrack::trimTimedBufferQueueHead_l(
+        const char* logTag) {
+    LOG_ASSERT(mTimedBufferQueue.size() > 0,
+               "%s called (reason \"%s\"), but timed buffer queue has no"
+               " elements to trim.", __FUNCTION__, logTag);
+
+    updateFramesPendingAfterTrim_l(mTimedBufferQueue[0], logTag);
+    mTimedBufferQueue.removeAt(0);
+}
+
+void AudioFlinger::PlaybackThread::TimedTrack::updateFramesPendingAfterTrim_l(
+        const TimedBuffer& buf,
+        const char* logTag) {
+    uint32_t bufBytes        = buf.buffer()->size();
+    uint32_t consumedAlready = buf.position();
+
+    LOG_ASSERT(consumedAlready <= bufFrames,
+               "Bad bookkeeping while updating frames pending.  Timed buffer is"
+               " only %u bytes long, but claims to have consumed %u"
+               " bytes.  (update reason: \"%s\")",
+               bufFrames, consumedAlready, logTag);
+
+    uint32_t bufFrames = (bufBytes - consumedAlready) / mCblk->frameSize;
+    LOG_ASSERT(mFramesPendingInQueue >= bufFrames,
+               "Bad bookkeeping while updating frames pending.  Should have at"
+               " least %u queued frames, but we think we have only %u.  (update"
+               " reason: \"%s\")",
+               bufFrames, mFramesPendingInQueue, logTag);
+
+    mFramesPendingInQueue -= bufFrames;
+}
+
 status_t AudioFlinger::PlaybackThread::TimedTrack::queueTimedBuffer(
     const sp<IMemory>& buffer, int64_t pts) {
 
@@ -3966,6 +4017,8 @@ status_t AudioFlinger::PlaybackThread::TimedTrack::queueTimedBuffer(
 
     Mutex::Autolock _l(mTimedBufferQueueLock);
 
+    uint32_t bufFrames = buffer->size() / mCblk->frameSize;
+    mFramesPendingInQueue += bufFrames;
     mTimedBufferQueue.add(TimedBuffer(buffer, pts));
 
     return NO_ERROR;
@@ -3974,7 +4027,7 @@ status_t AudioFlinger::PlaybackThread::TimedTrack::queueTimedBuffer(
 status_t AudioFlinger::PlaybackThread::TimedTrack::setMediaTimeTransform(
     const LinearTransform& xform, TimedAudioTrack::TargetTimeline target) {
 
-    LOGV("%s az=%lld bz=%lld n=%d d=%u tgt=%d", __PRETTY_FUNCTION__,
+    LOGVV("setMediaTimeTransform az=%lld bz=%lld n=%d d=%u tgt=%d",
          xform.a_zero, xform.b_zero, xform.a_to_b_numer, xform.a_to_b_denom,
          target);
 
@@ -4050,7 +4103,7 @@ status_t AudioFlinger::PlaybackThread::TimedTrack::getNextBuffer(
                 LOGW("timedGetNextBuffer transform failed");
                 buffer->raw = 0;
                 buffer->frameCount = 0;
-                mTimedBufferQueue.removeAt(0);
+                trimTimedBufferQueueHead_l("getNextBuffer; no transform");
                 return NO_ERROR;
             }
 
@@ -4079,18 +4132,18 @@ status_t AudioFlinger::PlaybackThread::TimedTrack::getNextBuffer(
         int64_t sampleDelta;
         if (llabs(effectivePTS - pts) >= (static_cast<int64_t>(1) << 31)) {
             LOGV("*** head buffer is too far from PTS: dropped buffer");
-            mTimedBufferQueue.removeAt(0);
+            trimTimedBufferQueueHead_l("getNextBuffer, buf pts too far from mix");
             continue;
         }
         if (!mLocalTimeToSampleTransform.doForwardTransform(
                 (effectivePTS - pts) << 32, &sampleDelta)) {
             LOGV("*** too late during sample rate transform: dropped buffer");
-            mTimedBufferQueue.removeAt(0);
+            trimTimedBufferQueueHead_l("getNextBuffer, bad local to sample");
             continue;
         }
 
-        LOGV("*** %s head.pts=%lld head.pos=%d pts=%lld sampleDelta=[%d.%08x]",
-             __PRETTY_FUNCTION__, head.pts(), head.position(), pts,
+        LOGVV("*** getNextBuffer head.pts=%lld head.pos=%d pts=%lld sampleDelta=[%d.%08x]",
+             head.pts(), head.position(), pts,
              static_cast<int32_t>((sampleDelta >= 0 ? 0 : 1) + (sampleDelta >> 32)),
              static_cast<uint32_t>(sampleDelta & 0xFFFFFFFF));
 
@@ -4110,7 +4163,7 @@ status_t AudioFlinger::PlaybackThread::TimedTrack::getNextBuffer(
             // with the last output
             timedYieldSamples_l(buffer);
 
-            LOGV("*** on time: head.pos=%d frameCount=%u", head.position(), buffer->frameCount);
+            LOGVV("*** on time: head.pos=%d frameCount=%u", head.position(), buffer->frameCount);
             return NO_ERROR;
         } else if (sampleDelta > 0) {
             // the gap between the current output position and the proper start of
@@ -4130,7 +4183,7 @@ status_t AudioFlinger::PlaybackThread::TimedTrack::getNextBuffer(
                 // all the remaining samples in the head are too late, so
                 // drop it and move on
                 LOGV("*** too late: dropped buffer");
-                mTimedBufferQueue.removeAt(0);
+                trimTimedBufferQueueHead_l("getNextBuffer, dropped late buffer");
                 continue;
             } else {
                 // skip over the late samples
@@ -4226,9 +4279,16 @@ void AudioFlinger::PlaybackThread::TimedTrack::releaseBuffer(
                 (buffer->frameCount * mCblk->frameSize));
         mQueueHeadInFlight = false;
 
+        LOG_ASSERT(mFramesPendingInQueue >= buffer->frameCount,
+                   "Bad bookkeeping during releaseBuffer!  Should have at"
+                   " least %u queued frames, but we think we have only %u",
+                   buffer->frameCount, mFramesPendingInQueue);
+
+        mFramesPendingInQueue -= buffer->frameCount;
+
         if ((static_cast<size_t>(head.position()) >= head.buffer()->size())
             || mTrimQueueHeadOnRelease) {
-            mTimedBufferQueue.removeAt(0);
+            trimTimedBufferQueueHead_l("releaseBuffer");
             mTrimQueueHeadOnRelease = false;
         }
     } else {
@@ -4243,14 +4303,7 @@ void AudioFlinger::PlaybackThread::TimedTrack::releaseBuffer(
 
 uint32_t AudioFlinger::PlaybackThread::TimedTrack::framesReady() const {
     Mutex::Autolock _l(mTimedBufferQueueLock);
-
-    uint32_t frames = 0;
-    for (size_t i = 0; i < mTimedBufferQueue.size(); i++) {
-        const TimedBuffer& tb = mTimedBufferQueue[i];
-        frames += (tb.buffer()->size() - tb.position())  / mCblk->frameSize;
-    }
-
-    return frames;
+    return mFramesPendingInQueue;
 }
 
 AudioFlinger::PlaybackThread::TimedTrack::TimedBuffer::TimedBuffer()

services/audioflinger/AudioFlinger.h

@@ -697,32 +697,28 @@ class AudioFlinger :
                 TimedBuffer(const sp<IMemory>& buffer, int64_t pts);
                 const sp<IMemory>& buffer() const { return mBuffer; }
                 int64_t pts() const { return mPTS; }
-                int position() const { return mPosition; }
-                void setPosition(int pos) { mPosition = pos; }
+                uint32_t position() const { return mPosition; }
+                void setPosition(uint32_t pos) { mPosition = pos; }
               private:
                 sp<IMemory> mBuffer;
-                int64_t mPTS;
-                int mPosition;
+                int64_t     mPTS;
+                uint32_t    mPosition;
             };
 
+            // Mixer facing methods.
             virtual bool isTimedTrack() const { return true; }
-
             virtual uint32_t framesReady() const;
-
             virtual status_t getNextBuffer(AudioBufferProvider::Buffer* buffer,
                                            int64_t pts);
             virtual void releaseBuffer(AudioBufferProvider::Buffer* buffer);
-            void timedYieldSamples_l(AudioBufferProvider::Buffer* buffer);
-            void timedYieldSilence_l(uint32_t numFrames,
-                                     AudioBufferProvider::Buffer* buffer);
 
+            // Client/App facing methods.
             status_t    allocateTimedBuffer(size_t size,
                                             sp<IMemory>* buffer);
             status_t    queueTimedBuffer(const sp<IMemory>& buffer,
                                          int64_t pts);
             status_t    setMediaTimeTransform(const LinearTransform& xform,
                                               TimedAudioTrack::TargetTimeline target);
-            void        trimTimedBufferQueue_l();
 
           private:
             TimedTrack(const wp<ThreadBase>& thread,
@@ -735,6 +731,14 @@ class AudioFlinger :
                        const sp<IMemory>& sharedBuffer,
                        int sessionId);
 
+            void timedYieldSamples_l(AudioBufferProvider::Buffer* buffer);
+            void timedYieldSilence_l(uint32_t numFrames,
+                                     AudioBufferProvider::Buffer* buffer);
+            void trimTimedBufferQueue_l();
+            void trimTimedBufferQueueHead_l(const char* logTag);
+            void updateFramesPendingAfterTrim_l(const TimedBuffer& buf,
+                                                const char* logTag);
+
             uint64_t            mLocalTimeFreq;
             LinearTransform     mLocalTimeToSampleTransform;
             LinearTransform     mMediaTimeToSampleTransform;
@@ -743,6 +747,7 @@ class AudioFlinger :
             Vector<TimedBuffer> mTimedBufferQueue;
             bool                mQueueHeadInFlight;
             bool                mTrimQueueHeadOnRelease;
+            uint32_t            mFramesPendingInQueue;
 
             uint8_t*            mTimedSilenceBuffer;
             uint32_t            mTimedSilenceBufferSize;