Various improvements to nuplayer playback

- Drastically cut down the number of times we supply the AudioSink with data
by estimating the time until the sink would run out of data and then scheduling
a refill in advance of that.

- Use a dedicated looper for video decoders since they are currently taking
too long to return from OMX_FillThisBuffer (bug 5325201)

- Revise thread priorities for the OMX dispatcher and software codecs, instead
of running them at ANDROID_PRIORITY_AUDIO, they now only run at
ANDROID_PRIORITY_FOREGROUND

- Since threads created by pthread_create inherit all of the parent threads
attributes including thread priority, briefly reset thread priority to
ANDROID_PRIORITY_FOREGROUND before instantiating OMX components and then
restore it.

Change-Id: If9332a3a20dad5485333d68c11de0d2d5d3fffc3

12 files changed, 149 insertions, 63 deletions

diff --git a/media/libmediaplayerservice/nuplayer/NuPlayer.cpp b/media/libmediaplayerservice/nuplayer/NuPlayer.cpp
index ee77f47..6f34ba7 100644
--- a/media/libmediaplayerservice/nuplayer/NuPlayer.cpp
+++ b/media/libmediaplayerservice/nuplayer/NuPlayer.cpp
@@ -299,7 +299,12 @@ void NuPlayer::onMessageReceived(const sp<AMessage> &msg) {
                          sampleRate, numChannels);
 
                     mAudioSink->close();
-                    CHECK_EQ(mAudioSink->open(sampleRate, numChannels), (status_t)OK);
+                    CHECK_EQ(mAudioSink->open(
+                                sampleRate,
+                                numChannels,
+                                AUDIO_FORMAT_PCM_16_BIT,
+                                8 /* bufferCount */),
+                             (status_t)OK);
                     mAudioSink->start();
 
                     mRenderer->signalAudioSinkChanged();
diff --git a/media/libmediaplayerservice/nuplayer/NuPlayer.h b/media/libmediaplayerservice/nuplayer/NuPlayer.h
index cf9185b..41e015b 100644
--- a/media/libmediaplayerservice/nuplayer/NuPlayer.h
+++ b/media/libmediaplayerservice/nuplayer/NuPlayer.h
@@ -70,19 +70,19 @@ private:
     struct StreamingSource;
 
     enum {
-        kWhatSetDataSource,
-        kWhatSetVideoNativeWindow,
-        kWhatSetAudioSink,
-        kWhatMoreDataQueued,
-        kWhatStart,
-        kWhatScanSources,
-        kWhatVideoNotify,
-        kWhatAudioNotify,
-        kWhatRendererNotify,
-        kWhatReset,
-        kWhatSeek,
-        kWhatPause,
-        kWhatResume,
+        kWhatSetDataSource              = '=DaS',
+        kWhatSetVideoNativeWindow       = '=NaW',
+        kWhatSetAudioSink               = '=AuS',
+        kWhatMoreDataQueued             = 'more',
+        kWhatStart                      = 'strt',
+        kWhatScanSources                = 'scan',
+        kWhatVideoNotify                = 'vidN',
+        kWhatAudioNotify                = 'audN',
+        kWhatRendererNotify             = 'renN',
+        kWhatReset                      = 'rset',
+        kWhatSeek                       = 'seek',
+        kWhatPause                      = 'paus',
+        kWhatResume                     = 'rsme',
     };
 
     wp<NuPlayerDriver> mDriver;
diff --git a/media/libmediaplayerservice/nuplayer/NuPlayerDecoder.cpp b/media/libmediaplayerservice/nuplayer/NuPlayerDecoder.cpp
index 81b41ef..56c2773 100644
--- a/media/libmediaplayerservice/nuplayer/NuPlayerDecoder.cpp
+++ b/media/libmediaplayerservice/nuplayer/NuPlayerDecoder.cpp
@@ -59,8 +59,21 @@ void NuPlayer::Decoder::configure(const sp<MetaData> &meta) {
         format->setObject("native-window", mNativeWindow);
     }
 
+    // Current video decoders do not return from OMX_FillThisBuffer
+    // quickly, violating the OpenMAX specs, until that is remedied
+    // we need to invest in an extra looper to free the main event
+    // queue.
+    bool needDedicatedLooper = !strncasecmp(mime, "video/", 6);
+
     mCodec = new ACodec;
-    looper()->registerHandler(mCodec);
+
+    if (needDedicatedLooper && mCodecLooper == NULL) {
+        mCodecLooper = new ALooper;
+        mCodecLooper->setName("NuPlayerDecoder");
+        mCodecLooper->start(false, false, ANDROID_PRIORITY_AUDIO);
+    }
+
+    (needDedicatedLooper ? mCodecLooper : looper())->registerHandler(mCodec);
 
     mCodec->setNotificationMessage(notifyMsg);
     mCodec->initiateSetup(format);
diff --git a/media/libmediaplayerservice/nuplayer/NuPlayerDecoder.h b/media/libmediaplayerservice/nuplayer/NuPlayerDecoder.h
index fabc606..3ab1fcf 100644
--- a/media/libmediaplayerservice/nuplayer/NuPlayerDecoder.h
+++ b/media/libmediaplayerservice/nuplayer/NuPlayerDecoder.h
@@ -43,13 +43,14 @@ protected:
 
 private:
     enum {
-        kWhatCodecNotify,
+        kWhatCodecNotify        = 'cdcN',
     };
 
     sp<AMessage> mNotify;
     sp<NativeWindowWrapper> mNativeWindow;
 
     sp<ACodec> mCodec;
+    sp<ALooper> mCodecLooper;
 
     Vector<sp<ABuffer> > mCSD;
     size_t mCSDIndex;
diff --git a/media/libmediaplayerservice/nuplayer/NuPlayerRenderer.cpp b/media/libmediaplayerservice/nuplayer/NuPlayerRenderer.cpp
index bf83849..3b3fca2 100644
--- a/media/libmediaplayerservice/nuplayer/NuPlayerRenderer.cpp
+++ b/media/libmediaplayerservice/nuplayer/NuPlayerRenderer.cpp
@@ -118,9 +118,24 @@ void NuPlayer::Renderer::onMessageReceived(const sp<AMessage> &msg) {
 
             mDrainAudioQueuePending = false;
 
-            onDrainAudioQueue();
-
-            postDrainAudioQueue();
+            if (onDrainAudioQueue()) {
+                uint32_t numFramesPlayed;
+                CHECK_EQ(mAudioSink->getPosition(&numFramesPlayed),
+                         (status_t)OK);
+
+                uint32_t numFramesPendingPlayout =
+                    mNumFramesWritten - numFramesPlayed;
+
+                // This is how long the audio sink will have data to
+                // play back.
+                int64_t delayUs =
+                    mAudioSink->msecsPerFrame()
+                        * numFramesPendingPlayout * 1000ll;
+
+                // Let's give it more data after about half that time
+                // has elapsed.
+                postDrainAudioQueue(delayUs / 2);
+            }
             break;
         }
 
@@ -182,7 +197,7 @@ void NuPlayer::Renderer::onMessageReceived(const sp<AMessage> &msg) {
     }
 }
 
-void NuPlayer::Renderer::postDrainAudioQueue() {
+void NuPlayer::Renderer::postDrainAudioQueue(int64_t delayUs) {
     if (mDrainAudioQueuePending || mSyncQueues || mPaused) {
         return;
     }
@@ -194,19 +209,33 @@ void NuPlayer::Renderer::postDrainAudioQueue() {
     mDrainAudioQueuePending = true;
     sp<AMessage> msg = new AMessage(kWhatDrainAudioQueue, id());
     msg->setInt32("generation", mAudioQueueGeneration);
-    msg->post();
+    msg->post(delayUs);
 }
 
 void NuPlayer::Renderer::signalAudioSinkChanged() {
     (new AMessage(kWhatAudioSinkChanged, id()))->post();
 }
 
-void NuPlayer::Renderer::onDrainAudioQueue() {
-    for (;;) {
-        if (mAudioQueue.empty()) {
-            break;
-        }
+bool NuPlayer::Renderer::onDrainAudioQueue() {
+    uint32_t numFramesPlayed;
+    CHECK_EQ(mAudioSink->getPosition(&numFramesPlayed), (status_t)OK);
+
+    ssize_t numFramesAvailableToWrite =
+        mAudioSink->frameCount() - (mNumFramesWritten - numFramesPlayed);
+
+#if 0
+    if (numFramesAvailableToWrite == mAudioSink->frameCount()) {
+        LOGI("audio sink underrun");
+    } else {
+        LOGV("audio queue has %d frames left to play",
+             mAudioSink->frameCount() - numFramesAvailableToWrite);
+    }
+#endif
 
+    size_t numBytesAvailableToWrite =
+        numFramesAvailableToWrite * mAudioSink->frameSize();
+
+    while (numBytesAvailableToWrite > 0 && !mAudioQueue.empty()) {
         QueueEntry *entry = &*mAudioQueue.begin();
 
         if (entry->mBuffer == NULL) {
@@ -216,20 +245,7 @@ void NuPlayer::Renderer::onDrainAudioQueue() {
 
             mAudioQueue.erase(mAudioQueue.begin());
             entry = NULL;
-            return;
-        }
-
-        uint32_t numFramesPlayed;
-        CHECK_EQ(mAudioSink->getPosition(&numFramesPlayed), (status_t)OK);
-
-        ssize_t numFramesAvailableToWrite =
-            mAudioSink->frameCount() - (mNumFramesWritten - numFramesPlayed);
-
-        size_t numBytesAvailableToWrite =
-            numFramesAvailableToWrite * mAudioSink->frameSize();
-
-        if (numBytesAvailableToWrite == 0) {
-            break;
+            return false;
         }
 
         if (entry->mOffset == 0) {
@@ -274,10 +290,14 @@ void NuPlayer::Renderer::onDrainAudioQueue() {
             entry = NULL;
         }
 
-        mNumFramesWritten += copy / mAudioSink->frameSize();
+        numBytesAvailableToWrite -= copy;
+        size_t copiedFrames = copy / mAudioSink->frameSize();
+        mNumFramesWritten += copiedFrames;
     }
 
     notifyPosition();
+
+    return !mAudioQueue.empty();
 }
 
 void NuPlayer::Renderer::postDrainVideoQueue() {
@@ -344,7 +364,14 @@ void NuPlayer::Renderer::onDrainVideoQueue() {
     int64_t mediaTimeUs;
     CHECK(entry->mBuffer->meta()->findInt64("timeUs", &mediaTimeUs));
 
-    LOGI("rendering video at media time %.2f secs", mediaTimeUs / 1E6);
+    int64_t realTimeUs = mediaTimeUs - mAnchorTimeMediaUs + mAnchorTimeRealUs;
+    int64_t lateByUs = ALooper::GetNowUs() - realTimeUs;
+
+    if (lateByUs > 40000) {
+        LOGI("video late by %lld us (%.2f secs)", lateByUs, lateByUs / 1E6);
+    } else {
+        LOGV("rendering video at media time %.2f secs", mediaTimeUs / 1E6);
+    }
 #endif
 
     entry->mNotifyConsumed->setInt32("render", true);
diff --git a/media/libmediaplayerservice/nuplayer/NuPlayerRenderer.h b/media/libmediaplayerservice/nuplayer/NuPlayerRenderer.h
index 3a641a2..44c5d44 100644
--- a/media/libmediaplayerservice/nuplayer/NuPlayerRenderer.h
+++ b/media/libmediaplayerservice/nuplayer/NuPlayerRenderer.h
@@ -45,9 +45,9 @@ struct NuPlayer::Renderer : public AHandler {
     void resume();
 
     enum {
-        kWhatEOS,
-        kWhatFlushComplete,
-        kWhatPosition,
+        kWhatEOS                = 'eos ',
+        kWhatFlushComplete      = 'fluC',
+        kWhatPosition           = 'posi',
     };
 
 protected:
@@ -57,14 +57,14 @@ protected:
 
 private:
     enum {
-        kWhatDrainAudioQueue,
-        kWhatDrainVideoQueue,
-        kWhatQueueBuffer,
-        kWhatQueueEOS,
-        kWhatFlush,
-        kWhatAudioSinkChanged,
-        kWhatPause,
-        kWhatResume,
+        kWhatDrainAudioQueue    = 'draA',
+        kWhatDrainVideoQueue    = 'draV',
+        kWhatQueueBuffer        = 'queB',
+        kWhatQueueEOS           = 'qEOS',
+        kWhatFlush              = 'flus',
+        kWhatAudioSinkChanged   = 'auSC',
+        kWhatPause              = 'paus',
+        kWhatResume             = 'resm',
     };
 
     struct QueueEntry {
@@ -102,8 +102,8 @@ private:
 
     int64_t mLastPositionUpdateUs;
 
-    void onDrainAudioQueue();
-    void postDrainAudioQueue();
+    bool onDrainAudioQueue();
+    void postDrainAudioQueue(int64_t delayUs = 0);
 
     void onDrainVideoQueue();
     void postDrainVideoQueue();
diff --git a/media/libmediaplayerservice/nuplayer/StreamingSource.cpp b/media/libmediaplayerservice/nuplayer/StreamingSource.cpp
index a741987..7319e4c 100644
--- a/media/libmediaplayerservice/nuplayer/StreamingSource.cpp
+++ b/media/libmediaplayerservice/nuplayer/StreamingSource.cpp
@@ -52,7 +52,7 @@ bool NuPlayer::StreamingSource::feedMoreTSData() {
         return false;
     }
 
-    for (int32_t i = 0; i < 10; ++i) {
+    for (int32_t i = 0; i < 50; ++i) {
         char buffer[188];
         sp<AMessage> extra;
         ssize_t n = mStreamListener->read(buffer, sizeof(buffer), &extra);
diff --git a/media/libstagefright/ACodec.cpp b/media/libstagefright/ACodec.cpp
index 2ba2273..a2d9e59 100644
--- a/media/libstagefright/ACodec.cpp
+++ b/media/libstagefright/ACodec.cpp
@@ -1377,8 +1377,13 @@ void ACodec::BaseState::onInputBufferFilled(const sp<AMessage> &msg) {
                     memcpy(info->mData->data(), buffer->data(), buffer->size());
                 }
 
-                LOGV("[%s] calling emptyBuffer %p",
-                     mCodec->mComponentName.c_str(), bufferID);
+                if (flags & OMX_BUFFERFLAG_CODECCONFIG) {
+                    LOGV("[%s] calling emptyBuffer %p w/ codec specific data",
+                         mCodec->mComponentName.c_str(), bufferID);
+                } else {
+                    LOGV("[%s] calling emptyBuffer %p w/ time %lld us",
+                         mCodec->mComponentName.c_str(), bufferID, timeUs);
+                }
 
                 CHECK_EQ(mCodec->mOMX->emptyBuffer(
                             mCodec->mNode,
@@ -1396,7 +1401,7 @@ void ACodec::BaseState::onInputBufferFilled(const sp<AMessage> &msg) {
                 LOGV("[%s] Signalling EOS on the input port",
                      mCodec->mComponentName.c_str());
 
-                LOGV("[%s] calling emptyBuffer %p",
+                LOGV("[%s] calling emptyBuffer %p signalling EOS",
                      mCodec->mComponentName.c_str(), bufferID);
 
                 CHECK_EQ(mCodec->mOMX->emptyBuffer(
@@ -1457,8 +1462,8 @@ bool ACodec::BaseState::onOMXFillBufferDone(
         int64_t timeUs,
         void *platformPrivate,
         void *dataPtr) {
-    LOGV("[%s] onOMXFillBufferDone %p",
-         mCodec->mComponentName.c_str(), bufferID);
+    LOGV("[%s] onOMXFillBufferDone %p time %lld us",
+         mCodec->mComponentName.c_str(), bufferID, timeUs);
 
     ssize_t index;
     BufferInfo *info =
@@ -1686,7 +1691,11 @@ void ACodec::UninitializedState::onSetup(
             ++matchIndex) {
         componentName = matchingCodecs.itemAt(matchIndex).string();
 
+        pid_t tid = androidGetTid();
+        int prevPriority = androidGetThreadPriority(tid);
+        androidSetThreadPriority(tid, ANDROID_PRIORITY_FOREGROUND);
         status_t err = omx->allocateNode(componentName.c_str(), observer, &node);
+        androidSetThreadPriority(tid, prevPriority);
 
         if (err == OK) {
             break;
diff --git a/media/libstagefright/chromium_http/support.cpp b/media/libstagefright/chromium_http/support.cpp
index de936c4..f15014e 100644
--- a/media/libstagefright/chromium_http/support.cpp
+++ b/media/libstagefright/chromium_http/support.cpp
@@ -74,10 +74,32 @@ bool logMessageHandler(
     return false;
 }
 
+struct AutoPrioritySaver {
+    AutoPrioritySaver()
+        : mTID(androidGetTid()),
+          mPrevPriority(androidGetThreadPriority(mTID)) {
+        androidSetThreadPriority(mTID, ANDROID_PRIORITY_NORMAL);
+    }
+
+    ~AutoPrioritySaver() {
+        androidSetThreadPriority(mTID, mPrevPriority);
+    }
+
+private:
+    pid_t mTID;
+    int mPrevPriority;
+
+    DISALLOW_EVIL_CONSTRUCTORS(AutoPrioritySaver);
+};
 
 static void InitializeNetworkThreadIfNecessary() {
     Mutex::Autolock autoLock(gNetworkThreadLock);
+
     if (gNetworkThread == NULL) {
+        // Make sure any threads spawned by the chromium framework are
+        // running at normal priority instead of inheriting this thread's.
+        AutoPrioritySaver saver;
+
         gNetworkThread = new base::Thread("network");
         base::Thread::Options options;
         options.message_loop_type = MessageLoop::TYPE_IO;
diff --git a/media/libstagefright/foundation/AMessage.cpp b/media/libstagefright/foundation/AMessage.cpp
index 582bdba..f039bc1 100644
--- a/media/libstagefright/foundation/AMessage.cpp
+++ b/media/libstagefright/foundation/AMessage.cpp
@@ -385,6 +385,15 @@ AString AMessage::debugString(int32_t indent) const {
                             item.u.refValue)->debugString(
                                 indent + strlen(item.mName) + 14).c_str());
                 break;
+            case kTypeRect:
+                tmp = StringPrintf(
+                        "Rect %s(%d, %d, %d, %d)",
+                        item.mName,
+                        item.u.rectValue.mLeft,
+                        item.u.rectValue.mTop,
+                        item.u.rectValue.mRight,
+                        item.u.rectValue.mBottom);
+                break;
             default:
                 TRESPASS();
         }
diff --git a/media/libstagefright/omx/OMX.cpp b/media/libstagefright/omx/OMX.cpp
index bc24dbb..33d3f30 100644
--- a/media/libstagefright/omx/OMX.cpp
+++ b/media/libstagefright/omx/OMX.cpp
@@ -85,7 +85,7 @@ OMX::CallbackDispatcher::CallbackDispatcher(OMXNodeInstance *owner)
     : mOwner(owner),
       mDone(false) {
     mThread = new CallbackDispatcherThread(this);
-    mThread->run("OMXCallbackDisp", ANDROID_PRIORITY_AUDIO);
+    mThread->run("OMXCallbackDisp", ANDROID_PRIORITY_FOREGROUND);
 }
 
 OMX::CallbackDispatcher::~CallbackDispatcher() {
diff --git a/media/libstagefright/omx/SimpleSoftOMXComponent.cpp b/media/libstagefright/omx/SimpleSoftOMXComponent.cpp
index f7330f3..b705d00 100644
--- a/media/libstagefright/omx/SimpleSoftOMXComponent.cpp
+++ b/media/libstagefright/omx/SimpleSoftOMXComponent.cpp
@@ -42,7 +42,7 @@ SimpleSoftOMXComponent::SimpleSoftOMXComponent(
     mLooper->start(
             false, // runOnCallingThread
             false, // canCallJava
-            PRIORITY_AUDIO);
+            ANDROID_PRIORITY_FOREGROUND);
 }
 
 void SimpleSoftOMXComponent::prepareForDestruction() {