踩坑之路:MediaPlayer播放完成偶現(xiàn)onCompletion不執(zhí)行問(wèn)題

背景

前段時(shí)間再做一個(gè)需求

  1. 是一個(gè)過(guò)渡頁(yè)面,
  2. 過(guò)渡頁(yè)面播放音頻(播放"終回"音頻)
  3. 音頻播放完畢,跳轉(zhuǎn)到下一個(gè)頁(yè)面

需求其實(shí)挺簡(jiǎn)單的,然后很快就把代碼寫(xiě)完了。跑了兩遍也都是正常執(zhí)行,于是二話不說(shuō)就提測(cè)了。后來(lái)某天測(cè)試提出過(guò)渡頁(yè)面會(huì)卡住,不會(huì)跳轉(zhuǎn)到下一個(gè)頁(yè)面。如下所示,一直卡在終回頁(yè)面上面


不會(huì)跳轉(zhuǎn).gif

  1. 于是我第一時(shí)間想到就是難道是我忘記設(shè)置結(jié)束的回調(diào)方法了?特意去查看了下代碼:
                val voicePlayer = VoicePlayerUnMute()
                voicePlayer.play(mRoundVoiceRes)
                voicePlayer.setOnCompletionListener {
                    LogHelper.i(TAG, "onNextPage tag = $tag")
                    onNextPage()
                }

這里的VoicePlayerUnMute是封裝的MediaPlayer,然后播放指定的音頻文件,設(shè)置了setOnCompletionListener ,代碼好像沒(méi)什么問(wèn)題,于是跑過(guò)去問(wèn)了下情況,了解到這個(gè)是個(gè)偶現(xiàn)的bug。

  1. 既然代碼上面看上去沒(méi)啥問(wèn)題,會(huì)不會(huì)是MediaPlayer在播放的時(shí)候出現(xiàn)了Error,導(dǎo)致onCompletion回調(diào)沒(méi)有執(zhí)行?于是我又加了一點(diǎn)代碼:
                val voicePlayer = VoicePlayerUnMute()
                voicePlayer.play(mRoundVoiceRes)
                voicePlayer.setOnCompletionListener {
                    LogHelper.i(TAG, "onNextPage tag = $tag")
                    onNextPage()
                }
                voicePlayer.setOnErrorListener { _: MediaPlayer, _: Int, _: Int ->
                    LogHelper.i(TAG,"播放出現(xiàn)了錯(cuò)誤")
                    false
                }

由于是偶現(xiàn)的問(wèn)題,所以我多試了幾次,確實(shí)是會(huì)出現(xiàn)幾次頁(yè)面卡住跳轉(zhuǎn)不過(guò)去的現(xiàn)象,但是onError里面并沒(méi)有打印出相應(yīng)的Log。這下有點(diǎn)懵圈了,沒(méi)有出現(xiàn)播放錯(cuò)誤,那到底是出了什么問(wèn)題?

  1. 粗略的看了下onCompletion回調(diào)的執(zhí)行,搜索了一下發(fā)現(xiàn)有兩處:
            case MEDIA_PLAYBACK_COMPLETE:
                {
                    mOnCompletionInternalListener.onCompletion(mMediaPlayer);
                    OnCompletionListener onCompletionListener = mOnCompletionListener;
                    if (onCompletionListener != null)
                        onCompletionListener.onCompletion(mMediaPlayer);
                }
                stayAwake(false);
                return;
            case MEDIA_ERROR:
                Log.e(TAG, "Error (" + msg.arg1 + "," + msg.arg2 + ")");
                boolean error_was_handled = false;
                OnErrorListener onErrorListener = mOnErrorListener;
                if (onErrorListener != null) {
                    error_was_handled = onErrorListener.onError(mMediaPlayer, msg.arg1, msg.arg2);
                }
                {
                    mOnCompletionInternalListener.onCompletion(mMediaPlayer);
                    OnCompletionListener onCompletionListener = mOnCompletionListener;
                    if (onCompletionListener != null && ! error_was_handled) {
                        onCompletionListener.onCompletion(mMediaPlayer);
                    }
                }
                stayAwake(false);
                return;

一處是播放完成的時(shí)候回調(diào),一處是播放出現(xiàn)錯(cuò)誤的時(shí)候出現(xiàn)了回調(diào)。這個(gè)時(shí)候才發(fā)現(xiàn)剛才的猜想完全就是錯(cuò)誤的。所以現(xiàn)在為止還是沒(méi)有找到原因所在。

  1. 我又重新操作了幾次,發(fā)現(xiàn)這幾次不跳轉(zhuǎn)的情況中,有播放完的,也有播放到一半停住的。所以是什么地方調(diào)用MediaPlayer的stop或者pause了?后來(lái)想想又感覺(jué)不可能,自己的player對(duì)象是個(gè)局部變量,用的地方就這么一處,怎么可能會(huì)調(diào)用這幾個(gè)方法。這下就更加疑惑了,MediaPlayer內(nèi)部實(shí)現(xiàn)邏輯太復(fù)雜,一次性想要吃透太困難了,現(xiàn)在bug又必須得盡早改掉,這事看上去越來(lái)越棘手了。
  1. 沒(méi)辦法,只能暫時(shí)比對(duì)一下正常情況下和異常情況下的MediaPlayer的log吧:
2020-10-20 19:44:26.425 21860-21860/com.youdao.youdaomath D/MediaPlayer: handleMessage msg:(1, 0, 0)
2020-10-20 19:44:26.425 21860-21860/com.youdao.youdaomath V/MediaPlayerNative: getCurrentPosition
2020-10-20 19:44:26.426 21860-21860/com.youdao.youdaomath V/MediaPlayerNative: isPlaying: 0
2020-10-20 19:44:26.429 21860-21860/com.youdao.youdaomath V/MediaPlayerNative: invoke 72
2020-10-20 19:44:26.432 21860-21860/com.youdao.youdaomath V/MediaPlayerNative: isPlaying: 0
2020-10-20 19:44:26.432 21860-21860/com.youdao.youdaomath I/VoicePlayerUnMute2: [VoicePlayerUnMute2] start
2020-10-20 19:44:26.432 21860-21860/com.youdao.youdaomath V/MediaPlayerNative: getDuration_l
2020-10-20 19:44:26.435 21860-21860/com.youdao.youdaomath V/MediaPlayerNative: start
2020-10-20 19:44:26.437 21860-21860/com.youdao.youdaomath V/MediaPlayerNative: MediaPlayer::setVolume(1.000000, 1.000000)
2020-10-20 19:44:26.507 21860-22561/com.youdao.youdaomath V/MediaPlayerNative: message received msg=6, ext1=0, ext2=0
2020-10-20 19:44:26.507 21860-22561/com.youdao.youdaomath V/MediaPlayerNative: unrecognized message: (6, 0, 0)
2020-10-20 19:44:26.508 21860-22561/com.youdao.youdaomath V/MediaPlayerNative: callback application
2020-10-20 19:44:26.508 21860-22561/com.youdao.youdaomath V/MediaPlayerNative: back from callback
2020-10-20 19:44:26.509 21860-21860/com.youdao.youdaomath D/MediaPlayer: handleMessage msg:(6, 0, 0)
2020-10-20 19:44:26.509 21860-21860/com.youdao.youdaomath V/MediaPlayerNative: getCurrentPosition
2020-10-20 19:44:26.510 21860-21860/com.youdao.youdaomath V/MediaPlayerNative: isPlaying: 1
2020-10-20 19:44:26.791 21860-22561/com.youdao.youdaomath V/MediaPlayerNative: message received msg=211, ext1=0, ext2=0
2020-10-20 19:44:26.791 21860-22561/com.youdao.youdaomath V/MediaPlayerNative: unrecognized message: (211, 0, 0)
2020-10-20 19:44:26.791 21860-22561/com.youdao.youdaomath V/MediaPlayerNative: callback application
2020-10-20 19:44:26.791 21860-22561/com.youdao.youdaomath V/MediaPlayerNative: back from callback
2020-10-20 19:44:26.792 21860-21860/com.youdao.youdaomath D/MediaPlayer: handleMessage msg:(211, 0, 0)
2020-10-20 19:44:27.834 21860-22561/com.youdao.youdaomath V/MediaPlayerNative: message received msg=2, ext1=0, ext2=0
2020-10-20 19:44:27.834 21860-22561/com.youdao.youdaomath V/MediaPlayerNative: playback complete
2020-10-20 19:44:27.834 21860-22561/com.youdao.youdaomath V/MediaPlayerNative: callback application
2020-10-20 19:44:27.835 21860-22561/com.youdao.youdaomath V/MediaPlayerNative: back from callback
2020-10-20 19:44:27.835 21860-22561/com.youdao.youdaomath V/MediaPlayerNative: message received msg=211, ext1=0, ext2=0
2020-10-20 19:44:27.835 21860-22561/com.youdao.youdaomath V/MediaPlayerNative: unrecognized message: (211, 0, 0)
2020-10-20 19:44:27.835 21860-22561/com.youdao.youdaomath V/MediaPlayerNative: callback application
2020-10-20 19:44:27.835 21860-21860/com.youdao.youdaomath D/MediaPlayer: handleMessage msg:(2, 0, 0)
2020-10-20 19:44:27.836 21860-22561/com.youdao.youdaomath V/MediaPlayerNative: back from callback

上面這個(gè)是正常情況下的log

2020-10-20 19:58:26.416 21860-21860/com.youdao.youdaomath D/MediaPlayer: handleMessage msg:(1, 0, 0)
2020-10-20 19:58:26.416 21860-21860/com.youdao.youdaomath V/MediaPlayerNative: getCurrentPosition
2020-10-20 19:58:26.417 21860-21860/com.youdao.youdaomath V/MediaPlayerNative: isPlaying: 0
2020-10-20 19:58:26.420 21860-21860/com.youdao.youdaomath V/MediaPlayerNative: invoke 72
2020-10-20 19:58:26.424 21860-21860/com.youdao.youdaomath V/MediaPlayerNative: isPlaying: 0
2020-10-20 19:58:26.424 21860-21860/com.youdao.youdaomath I/VoicePlayerUnMute2: [VoicePlayerUnMute2] start
2020-10-20 19:58:26.425 21860-21860/com.youdao.youdaomath V/MediaPlayerNative: getDuration_l
2020-10-20 19:58:26.428 21860-21860/com.youdao.youdaomath V/MediaPlayerNative: start
2020-10-20 19:58:26.431 21860-21860/com.youdao.youdaomath V/MediaPlayerNative: MediaPlayer::setVolume(1.000000, 1.000000)
2020-10-20 19:58:26.488 21860-21884/com.youdao.youdaomath V/MediaPlayerNative: message received msg=6, ext1=0, ext2=0
2020-10-20 19:58:26.488 21860-21884/com.youdao.youdaomath V/MediaPlayerNative: unrecognized message: (6, 0, 0)
2020-10-20 19:58:26.488 21860-21884/com.youdao.youdaomath V/MediaPlayerNative: callback application
2020-10-20 19:58:26.488 21860-21884/com.youdao.youdaomath V/MediaPlayerNative: back from callback
2020-10-20 19:58:26.489 21860-21860/com.youdao.youdaomath D/MediaPlayer: handleMessage msg:(6, 0, 0)
2020-10-20 19:58:26.490 21860-21860/com.youdao.youdaomath V/MediaPlayerNative: getCurrentPosition
2020-10-20 19:58:26.490 21860-21860/com.youdao.youdaomath V/MediaPlayerNative: isPlaying: 1
2020-10-20 19:58:26.763 21860-21884/com.youdao.youdaomath V/MediaPlayerNative: message received msg=211, ext1=0, ext2=0
2020-10-20 19:58:26.763 21860-21884/com.youdao.youdaomath V/MediaPlayerNative: unrecognized message: (211, 0, 0)
2020-10-20 19:58:26.763 21860-21884/com.youdao.youdaomath V/MediaPlayerNative: callback application
2020-10-20 19:58:26.763 21860-21884/com.youdao.youdaomath V/MediaPlayerNative: back from callback
2020-10-20 19:58:26.763 21860-21860/com.youdao.youdaomath D/MediaPlayer: handleMessage msg:(211, 0, 0)
2020-10-20 19:58:27.232 21860-21875/com.youdao.youdaomath D/MediaPlayer: finalize native_finalize called
2020-10-20 19:58:27.232 21860-21875/com.youdao.youdaomath W/MediaPlayer-JNI: MediaPlayer finalized without being released
2020-10-20 19:58:27.232 21860-21875/com.youdao.youdaomath V/MediaPlayerNative: setListener
2020-10-20 19:58:27.232 21860-21875/com.youdao.youdaomath V/MediaPlayerNative: disconnect
2020-10-20 19:58:27.260 21860-21875/com.youdao.youdaomath V/MediaPlayerNative: destructor
2020-10-20 19:58:27.261 21860-21875/com.youdao.youdaomath V/MediaPlayerNative: disconnect
2020-10-20 19:58:27.261 21860-21875/com.youdao.youdaomath D/MediaPlayer: finalize native_finalize finished
2020-10-20 19:58:28.256 21860-21884/com.youdao.youdaomath V/MediaPlayerNative: message received msg=2, ext1=0, ext2=0
2020-10-20 19:58:28.256 21860-21884/com.youdao.youdaomath V/MediaPlayerNative: playback complete
2020-10-20 19:58:28.256 21860-21884/com.youdao.youdaomath V/MediaPlayerNative: callback application
2020-10-20 19:58:28.256 21860-21884/com.youdao.youdaomath V/MediaPlayerNative: back from callback
2020-10-20 19:58:28.257 21860-21884/com.youdao.youdaomath V/MediaPlayerNative: message received msg=211, ext1=0, ext2=0
2020-10-20 19:58:28.257 21860-21884/com.youdao.youdaomath V/MediaPlayerNative: unrecognized message: (211, 0, 0)
2020-10-20 19:58:28.257 21860-21884/com.youdao.youdaomath V/MediaPlayerNative: callback application
2020-10-20 19:58:28.257 21860-21860/com.youdao.youdaomath D/MediaPlayer: handleMessage msg:(2, 0, 0)
2020-10-20 19:58:28.257 21860-21884/com.youdao.youdaomath V/MediaPlayerNative: back from callback
2020-10-20 19:58:28.263 21860-21860/com.youdao.youdaomath D/MediaPlayer: handleMessage msg:(211, 0, 0)

上面這個(gè)是異常情況的log

這一看還真看出點(diǎn)名堂來(lái),仔細(xì)發(fā)現(xiàn)異常情況下多了下面這段log:

2020-10-20 19:58:27.232 21860-21875/com.youdao.youdaomath D/MediaPlayer: finalize native_finalize called
2020-10-20 19:58:27.232 21860-21875/com.youdao.youdaomath W/MediaPlayer-JNI: MediaPlayer finalized without being released
2020-10-20 19:58:27.232 21860-21875/com.youdao.youdaomath V/MediaPlayerNative: setListener
2020-10-20 19:58:27.232 21860-21875/com.youdao.youdaomath V/MediaPlayerNative: disconnect
2020-10-20 19:58:27.260 21860-21875/com.youdao.youdaomath V/MediaPlayerNative: destructor
2020-10-20 19:58:27.261 21860-21875/com.youdao.youdaomath V/MediaPlayerNative: disconnect
2020-10-20 19:58:27.261 21860-21875/com.youdao.youdaomath D/MediaPlayer: finalize native_finalize finished

看樣子似乎是被release調(diào)了?
根據(jù)第二行l(wèi)og:

2020-10-20 19:58:27.232 21860-21875/com.youdao.youdaomath W/MediaPlayer-JNI: MediaPlayer finalized without being released

認(rèn)定應(yīng)該是JNI里面打出來(lái)的log,MediaPlayer是android.media包下面的類文件,那么JNI名字應(yīng)該是android_media_MediaPlayer.cpp,于是在源碼社區(qū)搜索了一下這個(gè)文件:


image.png

確實(shí)是有相應(yīng)的文件,那么就打開(kāi)文件搜索下"MediaPlayer finalized without being released"這個(gè)log:

static void
android_media_MediaPlayer_native_finalize(JNIEnv *env, jobject thiz)
{
    ALOGV("native_finalize");
    sp<MediaPlayer> mp = getMediaPlayer(env, thiz);
    if (mp != NULL) {
        ALOGW("MediaPlayer finalized without being released");
    }
    android_media_MediaPlayer_release(env, thiz);
}

以此反推,MediaPlayer.java里面應(yīng)該是調(diào)用了native_finalize方法,繼續(xù)往下搜索:

private native final void native_finalize();

果然有這么一個(gè)方法,在查看下調(diào)用的地方:

    @Override
    protected void finalize() {
        baseRelease();
        native_finalize();
    }

finalize方法調(diào)用,看到這里,我直接裂開(kāi)了有沒(méi)有。finalize方法是虛擬機(jī)在GC的時(shí)候調(diào)用的,具體可以看下這篇Java虛擬機(jī)內(nèi)存管理機(jī)制。我的Player對(duì)象就直接被GC了么?目前暫時(shí)也沒(méi)有去證明,既然找到了原因,那就改以下代碼,直接將player對(duì)象設(shè)置成類的成員變量:

    /**
     * 播放回合的音頻播放器
     */
    private var mRoundVoicePlayer = VoicePlayerUnMute()
                mRoundVoicePlayer.play(mRoundVoiceRes)
                mRoundVoicePlayer.setOnCompletionListener {
                    LogHelper.i(TAG, "onNextPage tag = $tag")
                    onNextPage()
                }

然后再試效果:


修改后.gif

的確應(yīng)該是改好了(原來(lái)試驗(yàn)10次大概會(huì)出現(xiàn)3次卡主不動(dòng),改完之后就試了十幾次都沒(méi)再出現(xiàn)過(guò)了)


真是一個(gè)讓人胃疼的Bug。。。

?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請(qǐng)聯(lián)系作者
【社區(qū)內(nèi)容提示】社區(qū)部分內(nèi)容疑似由AI輔助生成,瀏覽時(shí)請(qǐng)結(jié)合常識(shí)與多方信息審慎甄別。
平臺(tái)聲明:文章內(nèi)容(如有圖片或視頻亦包括在內(nèi))由作者上傳并發(fā)布,文章內(nèi)容僅代表作者本人觀點(diǎn),簡(jiǎn)書(shū)系信息發(fā)布平臺(tái),僅提供信息存儲(chǔ)服務(wù)。

友情鏈接更多精彩內(nèi)容