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

- 于是我第一時(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。
- 既然代碼上面看上去沒(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)題?
- 粗略的看了下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)有找到原因所在。
- 我又重新操作了幾次,發(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)越棘手了。
- 沒(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è)文件:

確實(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()
}
然后再試效果:

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