NuPlayer: Fix flush mode decoder error handling

Explicitly handle each flush mode upon decoder error.
Do not clear out affected decoder immediately.
Alter logcat messages for better diagnostics.

Bug: 17638878
Bug: 17679341
Change-Id: I219796c04d65d7c4dd61c0d4f99f9f580241a68b

diff --git a/media/libmediaplayerservice/nuplayer/GenericSource.cpp b/media/libmediaplayerservice/nuplayer/GenericSource.cpp
index 016a764..6859a1a 100644 (file)
--- a/media/libmediaplayerservice/nuplayer/GenericSource.cpp
+++ b/media/libmediaplayerservice/nuplayer/GenericSource.cpp
@@ -75,6 +75,7 @@ void NuPlayer::GenericSource::resetDataSource() {
     mDecryptHandle = NULL;
     mDrmManagerClient = NULL;
     mStarted = false;
+    mStopRead = true;
 }
 
 status_t NuPlayer::GenericSource::setDataSource(
@@ -455,6 +456,7 @@ status_t NuPlayer::GenericSource::prefillCacheIfNecessary() {
 void NuPlayer::GenericSource::start() {
     ALOGI("start");
 
+    mStopRead = false;
     if (mAudioTrack.mSource != NULL) {
         CHECK_EQ(mAudioTrack.mSource->start(), (status_t)OK);
 
@@ -475,6 +477,12 @@ void NuPlayer::GenericSource::stop() {
     // nothing to do, just account for DRM playback status
     setDrmPlaybackStatusIfNeeded(Playback::STOP, 0);
     mStarted = false;
+    if (mIsWidevine) {
+        // For a widevine source we need to prevent any further reads.
+        sp<AMessage> msg = new AMessage(kWhatStopWidevine, id());
+        sp<AMessage> response;
+        (void) msg->postAndAwaitResponse(&response);
+    }
 }
 
 void NuPlayer::GenericSource::pause() {
@@ -693,6 +701,20 @@ void NuPlayer::GenericSource::onMessageReceived(const sp<AMessage> &msg) {
           break;
       }
 
+      case kWhatStopWidevine:
+      {
+          // mStopRead is only used for Widevine to prevent the video source
+          // from being read while the associated video decoder is shutting down.
+          mStopRead = true;
+          if (mVideoTrack.mSource != NULL) {
+              mVideoTrack.mPackets->clear();
+          }
+          sp<AMessage> response = new AMessage;
+          uint32_t replyID;
+          CHECK(msg->senderAwaitsResponse(&replyID));
+          response->postReply(replyID);
+          break;
+      }
       default:
           Source::onMessageReceived(msg);
           break;
@@ -1100,6 +1122,11 @@ void NuPlayer::GenericSource::onSeek(sp<AMessage> msg) {
 }
 
 status_t NuPlayer::GenericSource::doSeek(int64_t seekTimeUs) {
+    // If the Widevine source is stopped, do not attempt to read any
+    // more buffers.
+    if (mStopRead) {
+        return INVALID_OPERATION;
+    }
     if (mVideoTrack.mSource != NULL) {
         int64_t actualTimeUs;
         readBuffer(MEDIA_TRACK_TYPE_VIDEO, seekTimeUs, &actualTimeUs);
@@ -1211,6 +1238,10 @@ void NuPlayer::GenericSource::onReadBuffer(sp<AMessage> msg) {
 
 void NuPlayer::GenericSource::readBuffer(
         media_track_type trackType, int64_t seekTimeUs, int64_t *actualTimeUs, bool formatChange) {
+    // Do not read data if Widevine source is stopped
+    if (mStopRead) {
+        return;
+    }
     Track *track;
     size_t maxBuffers = 1;
     switch (trackType) {

diff --git a/media/libmediaplayerservice/nuplayer/GenericSource.h b/media/libmediaplayerservice/nuplayer/GenericSource.h
index 5ed4d52..f8601ea 100644 (file)
--- a/media/libmediaplayerservice/nuplayer/GenericSource.h
+++ b/media/libmediaplayerservice/nuplayer/GenericSource.h
@@ -93,6 +93,7 @@ private:
         kWhatSelectTrack,
         kWhatSeek,
         kWhatReadBuffer,
+        kWhatStopWidevine,
     };
 
     Vector<sp<MediaSource> > mSources;
@@ -132,6 +133,7 @@ private:
     DrmManagerClient *mDrmManagerClient;
     sp<DecryptHandle> mDecryptHandle;
     bool mStarted;
+    bool mStopRead;
     String8 mContentType;
     AString mSniffedMIME;
     off64_t mMetaDataSize;

diff --git a/media/libmediaplayerservice/nuplayer/NuPlayer.cpp b/media/libmediaplayerservice/nuplayer/NuPlayer.cpp
index ca596fd..d225851 100644 (file)
--- a/media/libmediaplayerservice/nuplayer/NuPlayer.cpp
+++ b/media/libmediaplayerservice/nuplayer/NuPlayer.cpp
@@ -791,6 +791,11 @@ void NuPlayer::onMessageReceived(const sp<AMessage> &msg) {
                     ALOGV("initiating %s decoder shutdown",
                          audio ? "audio" : "video");
 
+                    // Widevine source reads must stop before releasing the video decoder.
+                    if (!audio && mSource != NULL && mSourceFlags & Source::FLAG_SECURE) {
+                        mSource->stop();
+                    }
+
                     getDecoder(audio)->initiateShutdown();
 
                     if (audio) {
@@ -833,30 +838,50 @@ void NuPlayer::onMessageReceived(const sp<AMessage> &msg) {
                 finishFlushIfPossible();
             } else if (what == Decoder::kWhatError) {
                 status_t err;
-                if (!msg->findInt32("err", &err)) {
+                if (!msg->findInt32("err", &err) || err == OK) {
                     err = UNKNOWN_ERROR;
                 }
-                ALOGE("received error from %s decoder %#x", audio ? "audio" : "video", err);
 
-                ALOGI("shutting down %s", audio ? "audio" : "video");
-                if (audio && mFlushingAudio != NONE) {
-                    mRenderer->queueEOS(audio, err);
-                    mAudioDecoder.clear();
-                    ++mAudioDecoderGeneration;
-                    mFlushingAudio = SHUT_DOWN;
-                    finishFlushIfPossible();
-                } else if (!audio && mFlushingVideo != NONE) {
-                    mRenderer->queueEOS(audio, err);
-                    mVideoDecoder.clear();
-                    ++mVideoDecoderGeneration;
-                    mFlushingVideo = SHUT_DOWN;
-                    finishFlushIfPossible();
-                }  else {
-                    mDeferredActions.push_back(
-                            new ShutdownDecoderAction(audio, !audio /* video */));
-                    processDeferredActions();
-                    notifyListener(MEDIA_ERROR, MEDIA_ERROR_UNKNOWN, err);
+                // Decoder errors can be due to Source (e.g. from streaming),
+                // or from decoding corrupted bitstreams, or from other decoder
+                // MediaCodec operations (e.g. from an ongoing reset or seek).
+                //
+                // We try to gracefully shut down the affected decoder if possible,
+                // rather than trying to force the shutdown with something
+                // similar to performReset(). This method can lead to a hang
+                // if MediaCodec functions block after an error, but they should
+                // typically return INVALID_OPERATION instead of blocking.
+
+                FlushStatus *flushing = audio ? &mFlushingAudio : &mFlushingVideo;
+                ALOGE("received error(%#x) from %s decoder, flushing(%d), now shutting down",
+                        err, audio ? "audio" : "video", *flushing);
+
+                switch (*flushing) {
+                    case NONE:
+                        mDeferredActions.push_back(
+                                new ShutdownDecoderAction(audio, !audio /* video */));
+                        processDeferredActions();
+                        break;
+                    case FLUSHING_DECODER:
+                        *flushing = FLUSHING_DECODER_SHUTDOWN; // initiate shutdown after flush.
+                        break; // Wait for flush to complete.
+                    case FLUSHING_DECODER_SHUTDOWN:
+                        break; // Wait for flush to complete.
+                    case SHUTTING_DOWN_DECODER:
+                        break; // Wait for shutdown to complete.
+                    case FLUSHED:
+                        // Widevine source reads must stop before releasing the video decoder.
+                        if (!audio && mSource != NULL && mSourceFlags & Source::FLAG_SECURE) {
+                            mSource->stop();
+                        }
+                        getDecoder(audio)->initiateShutdown(); // In the middle of a seek.
+                        *flushing = SHUTTING_DOWN_DECODER;     // Shut down.
+                        break;
+                    case SHUT_DOWN:
+                        finishFlushIfPossible();  // Should not occur.
+                        break;                    // Finish anyways.
                 }
+                notifyListener(MEDIA_ERROR, MEDIA_ERROR_UNKNOWN, err);
             } else if (what == Decoder::kWhatDrainThisBuffer) {
                 renderBuffer(audio, msg);
             } else {

diff --git a/media/libmediaplayerservice/nuplayer/NuPlayerDecoder.cpp b/media/libmediaplayerservice/nuplayer/NuPlayerDecoder.cpp
index 1a066b7..7814bf1 100644 (file)
--- a/media/libmediaplayerservice/nuplayer/NuPlayerDecoder.cpp
+++ b/media/libmediaplayerservice/nuplayer/NuPlayerDecoder.cpp
@@ -140,6 +140,8 @@ void NuPlayer::Decoder::onConfigure(const sp<AMessage> &format) {
             format, surface, NULL /* crypto */, 0 /* flags */);
     if (err != OK) {
         ALOGE("Failed to configure %s decoder (err=%d)", mComponentName.c_str(), err);
+        mCodec->release();
+        mCodec.clear();
         handleError(err);
         return;
     }
@@ -152,6 +154,8 @@ void NuPlayer::Decoder::onConfigure(const sp<AMessage> &format) {
     err = mCodec->start();
     if (err != OK) {
         ALOGE("Failed to start %s decoder (err=%d)", mComponentName.c_str(), err);
+        mCodec->release();
+        mCodec.clear();
         handleError(err);
         return;
     }
@@ -511,9 +515,9 @@ void NuPlayer::Decoder::onFlush() {
     if (err != OK) {
         ALOGE("failed to flush %s (err=%d)", mComponentName.c_str(), err);
         handleError(err);
-        return;
+        // finish with posting kWhatFlushCompleted.
+        // we attempt to release the buffers even if flush fails.
     }
-
     releaseAndResetMediaBuffers();
 
     sp<AMessage> notify = mNotify->dup();
@@ -551,7 +555,7 @@ void NuPlayer::Decoder::onShutdown() {
     if (err != OK) {
         ALOGE("failed to release %s (err=%d)", mComponentName.c_str(), err);
         handleError(err);
-        return;
+        // finish with posting kWhatShutdownCompleted.
     }
 
     sp<AMessage> notify = mNotify->dup();

diff --git a/media/libmediaplayerservice/nuplayer/NuPlayerDriver.cpp b/media/libmediaplayerservice/nuplayer/NuPlayerDriver.cpp
index a9bca49..1a01d52 100644 (file)
--- a/media/libmediaplayerservice/nuplayer/NuPlayerDriver.cpp
+++ b/media/libmediaplayerservice/nuplayer/NuPlayerDriver.cpp
@@ -27,6 +27,7 @@
 #include <media/stagefright/foundation/ADebug.h>
 #include <media/stagefright/foundation/ALooper.h>
 #include <media/stagefright/MetaData.h>
+#include <media/stagefright/Utils.h>
 
 namespace android {
 
@@ -47,6 +48,7 @@ NuPlayerDriver::NuPlayerDriver()
       mLooping(false),
       mAutoLoop(false),
       mStartupSeekTimeUs(-1) {
+    ALOGV("NuPlayerDriver(%p)", this);
     mLooper->setName("NuPlayerDriver Looper");
 
     mLooper->start(
@@ -61,6 +63,7 @@ NuPlayerDriver::NuPlayerDriver()
 }
 
 NuPlayerDriver::~NuPlayerDriver() {
+    ALOGV("~NuPlayerDriver(%p)", this);
     mLooper->stop();
 }
 
@@ -78,9 +81,9 @@ status_t NuPlayerDriver::setDataSource(
         const sp<IMediaHTTPService> &httpService,
         const char *url,
         const KeyedVector<String8, String8> *headers) {
+    ALOGV("setDataSource(%p) url(%s)", this, uriDebugString(url, false).c_str());
     Mutex::Autolock autoLock(mLock);
 
-    ALOGV("setDataSource: url=%s", url);
     if (mState != STATE_IDLE) {
         return INVALID_OPERATION;
     }
@@ -97,9 +100,9 @@ status_t NuPlayerDriver::setDataSource(
 }
 
 status_t NuPlayerDriver::setDataSource(int fd, int64_t offset, int64_t length) {
+    ALOGV("setDataSource(%p) file(%d)", this, fd);
     Mutex::Autolock autoLock(mLock);
 
-    ALOGV("setDataSource: fd=%d", fd);
     if (mState != STATE_IDLE) {
         return INVALID_OPERATION;
     }
@@ -116,9 +119,9 @@ status_t NuPlayerDriver::setDataSource(int fd, int64_t offset, int64_t length) {
 }
 
 status_t NuPlayerDriver::setDataSource(const sp<IStreamSource> &source) {
+    ALOGV("setDataSource(%p) stream source", this);
     Mutex::Autolock autoLock(mLock);
 
-    ALOGV("setDataSource: stream source");
     if (mState != STATE_IDLE) {
         return INVALID_OPERATION;
     }
@@ -136,6 +139,7 @@ status_t NuPlayerDriver::setDataSource(const sp<IStreamSource> &source) {
 
 status_t NuPlayerDriver::setVideoSurfaceTexture(
         const sp<IGraphicBufferProducer> &bufferProducer) {
+    ALOGV("setVideoSurfaceTexture(%p)", this);
     Mutex::Autolock autoLock(mLock);
 
     if (mSetSurfaceInProgress) {
@@ -163,6 +167,7 @@ status_t NuPlayerDriver::setVideoSurfaceTexture(
 }
 
 status_t NuPlayerDriver::prepare() {
+    ALOGV("prepare(%p)", this);
     Mutex::Autolock autoLock(mLock);
     return prepare_l();
 }
@@ -197,6 +202,7 @@ status_t NuPlayerDriver::prepare_l() {
 }
 
 status_t NuPlayerDriver::prepareAsync() {
+    ALOGV("prepareAsync(%p)", this);
     Mutex::Autolock autoLock(mLock);
 
     switch (mState) {
@@ -218,6 +224,7 @@ status_t NuPlayerDriver::prepareAsync() {
 }
 
 status_t NuPlayerDriver::start() {
+    ALOGD("start(%p)", this);
     Mutex::Autolock autoLock(mLock);
 
     switch (mState) {
@@ -292,6 +299,7 @@ status_t NuPlayerDriver::start() {
 }
 
 status_t NuPlayerDriver::stop() {
+    ALOGD("stop(%p)", this);
     Mutex::Autolock autoLock(mLock);
 
     switch (mState) {
@@ -346,6 +354,7 @@ bool NuPlayerDriver::isPlaying() {
 }
 
 status_t NuPlayerDriver::seekTo(int msec) {
+    ALOGD("seekTo(%p) %d ms", this, msec);
     Mutex::Autolock autoLock(mLock);
 
     int64_t seekTimeUs = msec * 1000ll;
@@ -430,6 +439,7 @@ status_t NuPlayerDriver::getDuration(int *msec) {
 }
 
 status_t NuPlayerDriver::reset() {
+    ALOGD("reset(%p)", this);
     Mutex::Autolock autoLock(mLock);
 
     switch (mState) {
@@ -572,6 +582,7 @@ status_t NuPlayerDriver::getMetadata(
 }
 
 void NuPlayerDriver::notifyResetComplete() {
+    ALOGI("notifyResetComplete(%p)", this);
     Mutex::Autolock autoLock(mLock);
 
     CHECK_EQ(mState, STATE_RESET_IN_PROGRESS);
@@ -580,6 +591,7 @@ void NuPlayerDriver::notifyResetComplete() {
 }
 
 void NuPlayerDriver::notifySetSurfaceComplete() {
+    ALOGV("notifySetSurfaceComplete(%p)", this);
     Mutex::Autolock autoLock(mLock);
 
     CHECK(mSetSurfaceInProgress);
@@ -602,6 +614,7 @@ void NuPlayerDriver::notifyPosition(int64_t positionUs) {
 }
 
 void NuPlayerDriver::notifySeekComplete() {
+    ALOGV("notifySeekComplete(%p)", this);
     Mutex::Autolock autoLock(mLock);
     notifySeekComplete_l();
 }

diff --git a/media/libmediaplayerservice/nuplayer/NuPlayerRenderer.cpp b/media/libmediaplayerservice/nuplayer/NuPlayerRenderer.cpp
index 6d10651..7e5087f 100644 (file)
--- a/media/libmediaplayerservice/nuplayer/NuPlayerRenderer.cpp
+++ b/media/libmediaplayerservice/nuplayer/NuPlayerRenderer.cpp
@@ -1051,7 +1051,7 @@ int64_t NuPlayer::Renderer::getPlayedOutAudioDurationUs(int64_t nowUs) {
             // become stale. Assuming that the MixerThread runs 20ms, with FastMixer at 5ms,
             // the max latency should be about 25ms with an average around 12ms (to be verified).
             // For safety we use 100ms.
-            ALOGW("getTimestamp: returned stale timestamp nowUs(%lld) numFramesPlayedAt(%lld)",
+            ALOGV("getTimestamp: returned stale timestamp nowUs(%lld) numFramesPlayedAt(%lld)",
                     (long long)nowUs, (long long)numFramesPlayedAt);
             numFramesPlayedAt = nowUs - kStaleTimestamp100ms;
         }
@@ -1081,7 +1081,7 @@ int64_t NuPlayer::Renderer::getPlayedOutAudioDurationUs(int64_t nowUs) {
         //     numFramesPlayedAt, by a time amount greater than numFramesPlayed.
         //
         // Both of these are transitory conditions.
-        ALOGW("getPlayedOutAudioDurationUs: negative timestamp %lld set to zero", (long long)durationUs);
+        ALOGV("getPlayedOutAudioDurationUs: negative duration %lld set to zero", (long long)durationUs);
         durationUs = 0;
     }
     ALOGV("getPlayedOutAudioDurationUs(%lld) nowUs(%lld) frames(%u) framesAt(%lld)",