使用 VideoView 播放网络视频中断

  自从用了印象笔记之后,好长一段时间都没有把笔记记到博客上了,但是最近遇到的一个 bug,让我发现分享的重要性,也算是帮助面向搜索引擎编程的各位朋友节省一下时间吧。

  最近在 Android 9.0 上遇到了一个视频播放的 bug,现象是播放视频十来分钟之后,播放器就停止播放视频,且不能再继续播放。这种情况只发生在播放网络视频的情况下,在网络不好的时候大概率复现,而且提供了 Android 5.1 的对比机,同样的应用在 Android 5.1 上可以正常播放,并且在网络不好的情况下也会正常加载视频。

问题分析

日志

  好吧,遇见问题第一步,先上日志:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
06-25 18:41:11.792 6272 6311 W MediaHTTPConnection: readAt 55764076 / 7060 => java.net.ProtocolException: unexpected end of stream
06-25 18:41:11.793 1057 6315 E NuCachedSource2: source returned error -1010, 0 retries left

...

06-25 18:42:01.246 1052 1052 E MtkFLVExtractor: flv_byteio_read error: read -1010, need read 1708
06-25 18:42:01.246 1052 1052 E MtkFLVExtractor: Error read file: tmp = -1010
06-25 18:42:01.246 1052 1052 E MtkFLVExtractor: FLV_FILE_EOF
06-25 18:42:01.259 1052 1052 E MtkFLVExtractor: flv_byteio_read error: read -1010, need read 9404963
06-25 18:42:01.259 1052 1052 E MtkFLVExtractor: Error read file: tmp = -1010
06-25 18:42:01.259 1052 1052 E MtkFLVExtractor: FLV_FILE_EOF
06-25 18:42:01.267 1052 1052 E MtkFLVExtractor: flv_byteio_read error: read -1010, need read 6568167
06-25 18:42:01.267 1052 1052 E MtkFLVExtractor: Error read file: tmp = -1010
06-25 18:42:01.268 1052 1052 E MtkFLVExtractor: FLV_FILE_EOF
06-25 18:42:01.268 1052 1052 E MtkFLVExtractor: [ERROR]:FLV_FILE_EOF (AUDIO)1
06-25 18:42:01.303 1052 1052 E MtkFLVExtractor: flv_byteio_read error: read -1010, need read 1082209
06-25 18:42:01.304 1052 1052 E MtkFLVExtractor: Error read file: tmp = -1010
06-25 18:42:01.304 1052 1052 E MtkFLVExtractor: FLV_FILE_EOF
06-25 18:42:01.304 1052 1052 E MtkFLVExtractor: [ERROR]:FLV_FILE_EOF (AUDIO)1

...

06-25 18:42:01.924 1052 1052 E MtkFLVExtractor: flv_byteio_read error: read -1010, need read 12963245
06-25 18:42:01.924 1052 1052 E MtkFLVExtractor: Error read file: tmp = -1010
06-25 18:42:01.924 1052 1052 E MtkFLVExtractor: FLV_FILE_EOF
06-25 18:42:01.935 1052 1052 E MtkFLVExtractor: flv_byteio_read error: read -1010, need read 6063419
06-25 18:42:01.935 1052 1052 E MtkFLVExtractor: Error read file: tmp = -1010
06-25 18:42:01.935 1052 1052 E MtkFLVExtractor: FLV_FILE_EOF

...

06-25 18:42:11.062 6272 6272 W MediaPlayer: Couldn't open http://....vhr: java.io.FileNotFoundException: No content provider: http://....vhr
06-25 18:42:11.063 6272 6272 V MediaHTTPService: MediaHTTPService(android.media.MediaHTTPService@e4eb7f7): Cookies: null
06-25 18:42:11.070 1057 3498 E DrmMtkUtil: [ERROR]isDcf() : failed to dup fd, reason [No such file or directory]

  去掉了部分敏感信息和多余的日志,大致的错误信息如上,通常遇见的异常都是有打印堆栈的,可是这个问题却没有发现有异常的堆栈信息,只能先从已有的日志下手了。

分析

  推测是有异常发生导致的视频播放中止,一般抓报错的日志都习惯用 adb logcat -s *:E 来过滤掉过多的日志,第一个坑就出在这里,日志的第一行其实也是这个问题最关键的一行,可以看到这居然只是个警告,所以在最开始复现的时候,这些信息都是被忽略掉了。而第二行 NuCachedSource2: source returned error -1010, 0 retries left 出来的时候,视频播放并没有中断,而且还播放了一段时间才停止,直到 flv_byteio_read error: read -1010, need read 1708 出现时视频才停止播放,所以一开始是怀疑视频数据或解码出现了问题。

  可是将视频下载下来之后,视频可以正常播放,那就说明视频的数据和解码是没有问题的,而且既然读到了 EOF 那么有可能是在传输的时候出现的问题。可是当时只打印 Error 的日志并没有反馈什么有用的信息,所以全日志打印了一遍。

  MediaPlayer: Couldn't open http://....vhr: java.io.FileNotFoundException: No content provider: http://....vhr 开始是怀疑这里有问题,但是根据日志搜索查看代码后确认,问题应该在别的地方。但是这里也学习到了另一个知识,关于 Android 9.0 适配的,可以看到这里播放视频使用的是 http 协议的链接,因为应用本身的 targetSdk 只是 19,所以没有影响,但是如果 targetSdk 是 28 或者以上的话,也就是 Android 9.0上,那么就会出问题了,谷歌在 Android 9.0 之后是默认不允许应用明文传输数据了,比如 HTTP 和 FTP 这些协议的请求都是会被拒绝的,但是非要用也可以参考一下 android:usesCleartextTraffic 这个属性。可以参考下面两个链接:

CleartextTrafficPermitted
Android 8: Cleartext HTTP traffic not permitted

  当然这些和我们这次的问题没有关系。有点扯远了,话说回来,在复现过几次之后,最开始的两行日志吸引了我的注意,虽然他们不是在视频中止的时候打印出来的,但是只要他们出现,后面一定会复现这个问题,首先找到日志打印的地方:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
// NuCachedSource2.cpp
void NuCachedSource2::fetchInternal() {

// ...

if (n == 0 || mDisconnecting) {
// ...
} else if (n < 0) {
mFinalStatus = n;
if (n == ERROR_UNSUPPORTED || n == -EPIPE) {
// These are errors that are not likely to go away even if we
// retry, i.e. the server doesn't support range requests or similar.
mNumRetriesLeft = 0;
}

ALOGE("source returned error %zd, %d retries left", n, mNumRetriesLeft);
mCache->releasePage(page);
} else {
// ...
}
}

  看来是 source 返回了 -1010 的错误码,并且重试的次数为 0,怪不得在网络不好的时候播放会直接中止而不是继续加载。搜索一下在 MediaErrors.h 里可以知道 -1010 就是 ERROR_UNSUPPORTED,再往上找可以找到这个错误码是从 MediaHTTPConnection.java 里传下来的:

1
2
3
4
5
6
7
8
9
10
11
12
// MediaHTTPConnection.java
private int readAt(long offset, byte[] data, int size) {
// ...

try {
// ...
} catch (ProtocolException e) {
Log.w(TAG, "readAt " + offset + " / " + size + " => " + e);
return MEDIA_ERROR_UNSUPPORTED;
}
// ...
}

  而这个 ProtocolException 是从 OKHttp 里报上来的,在 Http1xStream.java 里发现:

1
2
3
4
5
6
7
8
9
10
@Override public long read(Buffer sink, long byteCount) throws IOException {
// ...
long read = source.read(sink, Math.min(byteCount, bytesRemainingInChunk));
if (read == -1) {
unexpectedEndOfInput(); // The server didn't supply the promised chunk length.
throw new ProtocolException("unexpected end of stream");
}
bytesRemainingInChunk -= read;
return read;
}

  经过一顿搜索,找到一个和错误日志一样的例子:关于 Android 6.0 的流媒体播放异常,这篇文章让我学到了很多东西,代码跟下来我也只是知道个大概,但是这篇文章倒是让我对这个问题的认识更清晰了。

结论

  把 external 下 OKHttp 里的几个 throw new ProtocolException("unexpected end of stream"); 改成 throw new IOException("unexpected end of stream"); 就可以了,Android 8.1 之前的版本修改 HttpConnection.java,Android 8.1 及之后的版本则修改 Http1xStream.java。改完之后就会发现网络传输出现异常的时候是会有 10 次重试的机会,问题也不再复现了。