This is a GREAT question. If you record the same show you are watching live..... when you go back and rewatch it ff the DVR you will not see the problem.
Switched back to using the hardware decoder. Issue just happened and I'm able to rewind and then fast forward which allows me to get back to the live feed. If I rewind and let it play over that section, the problem re-occurs and if I let the video player spin long enough, the broadcast picks back up at the next commercial break. In this instance, it happens exactly when they cut from commercial back to the normal broadcast.
@tmm1 I realize you suspect a bug in the nvidia decoder and I'd love to understand why you've ruled out any issues with the video player and attribute this solely to the hardware decoder
The android decoding api is very simple: you feed packets in and get video frames out. If we're feeding packets in but never getting and video frames, then the vendor backend is not working correctly. If this only happens on some channels, then its further proof of a decoder issue because nothing in our app changes between those channels.
That's not to say we couldn't investigate and find some sort of work-around, but in our experience that workaround usually ends up being "switch to software decoding". Nvidia has confirmed several bugs in their mpeg2 hardware decoder in the past and told us explicitly that they cannot be fixed. We've also experienced several h264 hardware decoding bugs on the SHIELD, particularly around 1080i content, and that's why most of the Channels customers in the UK also have to use software decoding. My hunch is that this is a similar problem, but since I cannot reproduce it on my own SHIELD I have no way to be sure.
Thanks for the explanation. Do you know if any of these Shield bugs carryover to hardware acceleration on nvidia desktop GPUs?
Continuing to test on my Sony TV, Hybrid seems to be working fine too. It is only pure Hardware decoding that is having the issue with video freezing.
So, if the solution is to use Software or Hybrid decoding, I'm ok with that. That is much better than any option I had a day ago.
I am still curious though why Hardware decoding works for recorded content. Why would it be any different for the hardware to decode a recorded program than it is for a live program? It seems strange that it works for one, but not the other.
But I'm not going to worry too much about it, as long as we can continue to have the Software and Hybrid options, since that appears to be an acceptable workaround.
2 Likes
Sounds similar to the effects that 2 of my OTA stations do when using Hardware decode on my Shield,,,,they stream fine with Hybrid and Software decode option.
For me on those 2 channels, with hardware decode, plays fine for a min, then it is a super slow frame rate, then after a bit, the video jumps forward like at 4x spead and catches up to the audio, that is if u just leave it alone, i can also seek forward or back and it plays the same part of the stream fine for a very short time, then does it again.
I am having the same experience.
Yea I've been asking the same question. It makes no sense to me.
Update, first I want to say that Software/Hybrid has fixed every issue I have with the player except the buffering problem.
I have uploaded a video to show the buffering, then after the buffering stops, going back in the timestamp to show that where is was buffering I can go back and play thru it smoothly without ever missing a frame. Nothing is showing up in the DVR log and I have submitted a Client log.
The log is interesting..... Talks about the buffer going from 100% to 0% etc......
Here is part of the log during the buffering:
03-31 22:51:59.691 17789 17837 V mpv : [cplayer] VO: Description: Shader-based GPU Renderer
03-31 22:52:01.269 17789 17789 V mpvstats: AV: 391.487 A-V: 0.000 Dropped: 0 Cache: 14.379s + 0KB
03-31 22:52:04.271 17789 17789 V mpvstats: AV: 394.490 A-V: 0.000 Dropped: 0 Cache: 15.360s + 0KB
03-31 22:52:07.271 17789 17789 V mpvstats: AV: 397.493 A-V: 0.000 Dropped: 0 Cache: 12.373s + 0KB
03-31 22:52:10.272 17789 17789 V mpvstats: AV: 400.496 A-V: 0.000 Dropped: 0 Cache: 13.483s + 0KB
03-31 22:52:13.273 17789 17789 V mpvstats: AV: 403.499 A-V: 0.000 Dropped: 0 Cache: 14.592s + 0KB
03-31 22:52:16.276 17789 17789 V mpvstats: AV: 406.485 A-V: 0.000 Dropped: 0 Cache: 15.616s + 0KB
03-31 22:52:19.277 17789 17789 V mpvstats: AV: 409.488 A-V: 0.000 Dropped: 0 Cache: 12.629s + 0KB
03-31 22:52:22.278 17789 17789 V mpvstats: AV: 412.491 A-V: 0.000 Dropped: 0 Cache: 13.739s + 0KB
03-31 22:52:25.279 17789 17789 V mpvstats: AV: 415.494 A-V: 0.000 Dropped: 0 Cache: 14.805s + 0KB
03-31 22:52:28.280 17789 17789 V mpvstats: AV: 418.497 A-V: 0.000 Dropped: 0 Cache: 15.872s + 0KB
03-31 22:52:31.281 17789 17789 V mpvstats: AV: 421.500 A-V: 0.000 Dropped: 0 Cache: 12.885s + 0KB
03-31 22:52:34.282 17789 17789 V mpvstats: AV: 424.503 A-V: 0.000 Dropped: 0 Cache: 13.995s + 0KB
03-31 22:52:37.284 17789 17789 V mpvstats: AV: 427.506 A-V: 0.000 Dropped: 0 Cache: 15.061s + 0KB
03-31 22:52:40.284 17789 17789 V mpvstats: AV: 430.509 A-V: 0.000 Dropped: 0 Cache: 12.160s + 0KB
03-31 22:52:43.286 17789 17789 V mpvstats: AV: 433.512 A-V: 0.000 Dropped: 0 Cache: 13.269s + 0KB
03-31 22:52:46.286 17789 17789 V mpvstats: AV: 436.499 A-V: 0.000 Dropped: 0 Cache: 10.539s + 0KB
03-31 22:52:49.289 17789 17789 V mpvstats: AV: 439.502 A-V: 0.001 Dropped: 0 Cache: 11.349s + 0KB
03-31 22:52:52.290 17789 17789 V mpvstats: AV: 442.505 A-V: 0.000 Dropped: 0 Cache: 12.459s + 0KB
03-31 22:52:55.290 17789 17789 V mpvstats: AV: 445.508 A-V: 0.000 Dropped: 0 Cache: 13.483s + 0KB
03-31 22:52:58.291 17789 17789 V mpvstats: AV: 448.511 A-V: 0.000 Dropped: 0 Cache: 10.496s + 0KB
03-31 22:53:01.293 17789 17789 V mpvstats: AV: 451.514 A-V: 0.000 Dropped: 0 Cache: 11.605s + 0KB
03-31 22:53:04.293 17789 17789 V mpvstats: AV: 454.517 A-V: 0.000 Dropped: 0 Cache: 8.619s + 0KB
03-31 22:53:07.294 17789 17789 V mpvstats: AV: 457.520 A-V: 0.000 Dropped: 0 Cache: 5.632s + 0KB
03-31 22:53:10.296 17789 17789 V mpvstats: AV: 460.506 A-V: 0.000 Dropped: 0 Cache: 6.613s + 0KB
03-31 22:53:13.298 17789 17789 V mpvstats: AV: 463.509 A-V: 0.000 Dropped: 0 Cache: 3.627s + 0KB
03-31 22:53:16.299 17789 17789 V mpvstats: AV: 466.512 A-V: 0.000 Dropped: 0 Cache: 4.736s + 0KB
03-31 22:53:19.300 17789 17789 V mpvstats: AV: 469.515 A-V: 0.000 Dropped: 0 Cache: 9.941s + 0KB
03-31 22:53:22.302 17789 17789 V mpvstats: AV: 472.518 A-V: 0.000 Dropped: 0 Cache: 11.093s + 0KB
03-31 22:53:25.303 17789 17789 V mpvstats: AV: 475.521 A-V: 0.000 Dropped: 0 Cache: 12.203s + 0KB
03-31 22:53:28.304 17789 17789 V mpvstats: AV: 478.524 A-V: 0.000 Dropped: 0 Cache: 13.312s + 0KB
03-31 22:53:31.305 17789 17789 V mpvstats: AV: 481.527 A-V: 0.000 Dropped: 0 Cache: 14.336s + 0KB
03-31 22:53:34.306 17789 17789 V mpvstats: AV: 484.530 A-V: 0.000 Dropped: 0 Cache: 11.349s + 0KB
03-31 22:53:37.308 17789 17789 V mpvstats: AV: 487.533 A-V: 0.000 Dropped: 0 Cache: 12.416s + 0KB
03-31 22:53:40.309 17789 17789 V mpvstats: AV: 490.519 A-V: 0.000 Dropped: 0 Cache: 13.568s + 0KB
03-31 22:53:43.310 17789 17789 V mpvstats: AV: 493.522 A-V: 0.000 Dropped: 0 Cache: 14.635s + 0KB
03-31 22:53:46.311 17789 17789 V mpvstats: AV: 496.525 A-V: 0.000 Dropped: 0 Cache: 11.648s + 0KB
03-31 22:53:49.311 17789 17789 V mpvstats: AV: 499.528 A-V: 0.000 Dropped: 0 Cache: 12.715s + 0KB
03-31 22:53:52.313 17789 17789 V mpvstats: AV: 502.531 A-V: 0.000 Dropped: 0 Cache: 13.781s + 0KB
03-31 22:53:55.314 17789 17789 V mpvstats: AV: 505.534 A-V: 0.000 Dropped: 0 Cache: 14.635s + 0KB
03-31 22:53:58.315 17789 17789 V mpvstats: AV: 508.537 A-V: 0.000 Dropped: 0 Cache: 11.904s + 0KB
03-31 22:54:01.316 17789 17789 V mpvstats: AV: 511.540 A-V: 0.000 Dropped: 0 Cache: 13.013s + 0KB
03-31 22:54:04.317 17789 17789 V mpvstats: AV: 514.543 A-V: 0.000 Dropped: 0 Cache: 14.123s + 0KB
03-31 22:54:07.318 17789 17789 V mpvstats: AV: 517.530 A-V: 0.000 Dropped: 0 Cache: 15.232s + 0KB
03-31 22:54:10.321 17789 17789 V mpvstats: AV: 520.533 A-V: 0.000 Dropped: 0 Cache: 12.245s + 0KB
03-31 22:54:13.323 17789 17789 V mpvstats: AV: 523.536 A-V: 0.000 Dropped: 0 Cache: 13.355s + 0KB
03-31 22:54:16.323 17789 17789 V mpvstats: AV: 526.539 A-V: 0.000 Dropped: 0 Cache: 14.421s + 0KB
03-31 22:54:19.324 17789 17789 V mpvstats: AV: 529.542 A-V: 0.000 Dropped: 0 Cache: 15.061s + 0KB
03-31 22:54:22.326 17789 17789 V mpvstats: AV: 532.545 A-V: 0.000 Dropped: 0 Cache: 12.416s + 0KB
03-31 22:54:25.326 17789 17789 V mpvstats: AV: 535.548 A-V: 0.000 Dropped: 0 Cache: 13.568s + 0KB
03-31 22:54:28.327 17789 17789 V mpvstats: AV: 538.551 A-V: 0.000 Dropped: 0 Cache: 14.677s + 0KB
03-31 22:54:31.328 17789 17789 V mpvstats: AV: 541.537 A-V: 0.000 Dropped: 0 Cache: 11.691s + 0KB
03-31 22:54:34.328 17789 17789 V mpvstats: AV: 544.540 A-V: 0.000 Dropped: 0 Cache: 12.800s + 0KB
03-31 22:54:37.329 17789 17789 V mpvstats: AV: 547.543 A-V: 0.000 Dropped: 0 Cache: 9.771s + 0KB
03-31 22:54:40.331 17789 17789 V mpvstats: AV: 550.546 A-V: 0.000 Dropped: 0 Cache: 6.699s + 0KB
03-31 22:54:43.332 17789 17789 V mpvstats: AV: 553.549 A-V: 0.000 Dropped: 0 Cache: 7.765s + 0KB
03-31 22:54:46.333 17789 17789 V mpvstats: AV: 556.552 A-V: 0.000 Dropped: 0 Cache: 4.779s + 0KB
03-31 22:54:49.334 17789 17789 V mpvstats: AV: 559.555 A-V: 0.000 Dropped: 0 Cache: 6.016s + 0KB
03-31 22:54:52.335 17789 17789 V mpvstats: AV: 562.558 A-V: 0.000 Dropped: 0 Cache: 3.029s + 0KB
03-31 22:54:55.335 17789 17789 V mpvstats: AV: 565.561 A-V: 0.000 Dropped: 0 Cache: 0.043s + 0KB
03-31 22:54:55.350 17789 17837 V mpv : event: unpause
03-31 22:54:55.350 17789 17837 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
03-31 22:54:55.351 17789 17837 V mpv : property: buffering = true
03-31 22:54:55.351 17789 17789 V PlayerActivity: state PLAYING -> BUFFERING
03-31 22:54:55.351 17789 17789 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=529.0911887777778, end=565.9446887777777}], cache-end=566.0041665555556, reader-pts=566.0041665555556, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=31168448, fw-bytes=380288, debug-low-level-seeks=0, debug-ts-last=565.5776556666667, ts-per-stream=[{type=video, duration=0.3503555555555522, reader=565.6610666666667, end=566.0114222222222}, {type=audio, duration=0.0, reader=566.0208555555556, end=566.0208555555556}]}
03-31 22:54:55.674 17789 17837 V mpv : event: unpause
03-31 22:54:55.675 17789 17837 V mpv : [cplayer] End buffering (waited 0.319790 secs) [3.712000s].
03-31 22:54:55.678 17789 17837 V mpv : property: buffering = false
03-31 22:54:55.679 17789 17789 V PlayerActivity: state BUFFERING -> PLAYING
03-31 22:54:56.477 17789 17789 V mpvstats: AV: 566.529 A-V: 0.000 Dropped: 11 Cache: 2.816s + 0KB
03-31 22:54:58.335 17789 17789 V mpvstats: AV: 568.397 A-V: 0.000 Dropped: 11 Cache: 2.987s + 0KB
03-31 22:55:01.338 17789 17789 V mpvstats: AV: 571.400 A-V: 0.000 Dropped: 11 Cache: 14.549s + 0KB
03-31 22:55:04.338 17789 17789 V mpvstats: AV: 574.403 A-V: 0.000 Dropped: 11 Cache: 15.701s + 0KB
03-31 22:55:07.340 17789 17789 V mpvstats: AV: 577.406 A-V: 0.000 Dropped: 11 Cache: 12.715s + 0KB
03-31 22:55:10.341 17789 17789 V mpvstats: AV: 580.392 A-V: 0.000 Dropped: 11 Cache: 13.696s + 0KB
03-31 22:55:13.342 17789 17789 V mpvstats: AV: 583.412 A-V: 0.000 Dropped: 11 Cache: 14.848s + 0KB
03-31 22:55:16.344 17789 17789 V mpvstats: AV: 586.398 A-V: 0.000 Dropped: 11 Cache: 11.904s + 0KB
03-31 22:55:19.344 17789 17789 V mpvstats: AV: 589.401 A-V: 0.000 Dropped: 11 Cache: 12.928s + 0KB
03-31 22:55:22.346 17789 17789 V mpvstats: AV: 592.404 A-V: 0.000 Dropped: 11 Cache: 14.037s + 0KB
03-31 22:55:25.346 17789 17789 V mpvstats: AV: 595.407 A-V: 0.000 Dropped: 11 Cache: 15.104s + 0KB
03-31 22:55:28.347 17789 17789 V mpvstats: AV: 598.410 A-V: 0.000 Dropped: 11 Cache: 16.171s + 0KB
03-31 22:55:31.348 17789 17789 V mpvstats: AV: 601.413 A-V: 0.000 Dropped: 11 Cache: 13.269s + 0KB
03-31 22:55:34.349 17789 17789 V mpvstats: AV: 604.416 A-V: 0.000 Dropped: 11 Cache: 10.283s + 0KB
03-31 22:55:37.350 17789 17789 V mpvstats: AV: 607.419 A-V: 0.000 Dropped: 11 Cache: 11.349s + 0KB
03-31 22:55:40.351 17789 17789 V mpvstats: AV: 610.406 A-V: 0.000 Dropped: 11 Cache: 12.501s + 0KB
03-31 22:55:43.351 17789 17789 V mpvstats: AV: 613.409 A-V: 0.000 Dropped: 11 Cache: 13.568s + 0KB
03-31 22:55:46.352 17789 17789 V mpvstats: AV: 616.412 A-V: 0.000 Dropped: 11 Cache: 10.581s + 0KB
03-31 22:55:49.352 17789 17789 V mpvstats: AV: 619.415 A-V: 0.000 Dropped: 11 Cache: 11.563s + 0KB
03-31 22:55:52.356 17789 17789 V mpvstats: AV: 622.418 A-V: 0.000 Dropped: 11 Cache: 13.141s + 0KB
03-31 22:55:55.357 17789 17789 V mpvstats: AV: 625.421 A-V: 0.000 Dropped: 11 Cache: 14.251s + 0KB
03-31 22:55:58.359 17789 17789 V mpvstats: AV: 628.424 A-V: 0.000 Dropped: 11 Cache: 11.264s + 0KB
03-31 22:56:01.359 17789 17789 V mpvstats: AV: 631.410 A-V: 0.000 Dropped: 11 Cache: 10.325s + 0KB
03-31 22:56:01.824 17789 17837 D mpv : [ffmpeg/video] h264: Reinit context to 1280x720, pix_fmt: yuv420p
03-31 22:56:01.891 17789 17837 V mpv : [vd] Decoder format: 1280x720 [0:1] yuv420p bt.709/bt.709/bt.1886/limited/auto CL=mpeg2/4/h264 (auto 0.000000/0.000000/0.000000)
03-31 22:56:04.359 17789 17789 V mpvstats: AV: 634.412 A-V: 0.000 Dropped: 11 Cache: 9.344s + 0KB
03-31 22:56:07.361 17789 17789 V mpvstats: AV: 637.415 A-V: 0.000 Dropped: 11 Cache: 14.421s + 0KB
03-31 22:56:10.363 17789 17789 V mpvstats: AV: 640.418 A-V: 0.000 Dropped: 11 Cache: 11.435s + 0KB
03-31 22:56:13.363 17789 17789 V mpvstats: AV: 643.421 A-V: 0.000 Dropped: 11 Cache: 12.629s + 0KB
03-31 22:56:16.363 17789 17789 V mpvstats: AV: 646.424 A-V: 0.000 Dropped: 11 Cache: 13.781s + 0KB
03-31 22:56:19.363 17789 17789 V mpvstats: AV: 649.427 A-V: 0.000 Dropped: 11 Cache: 11.776s + 0KB
03-31 22:56:22.363 17789 17789 V mpvstats: AV: 652.430 A-V: 0.000 Dropped: 11 Cache: 9.687s + 0KB
03-31 22:56:25.366 17789 17789 V mpvstats: AV: 655.400 A-V: 0.000 Dropped: 11 Cache: 10.071s + 0KB
03-31 22:56:28.367 17789 17789 V mpvstats: AV: 658.436 A-V: 0.000 Dropped: 11 Cache: 11.181s + 0KB
03-31 22:56:31.368 17789 17789 V mpvstats: AV: 661.406 A-V: 0.000 Dropped: 11 Cache: 12.290s + 0KB
03-31 22:56:34.370 17789 17789 V mpvstats: AV: 664.409 A-V: 0.000 Dropped: 11 Cache: 9.301s + 0KB
03-31 22:56:37.370 17789 17789 V mpvstats: AV: 667.412 A-V: 0.000 Dropped: 11 Cache: 6.315s + 0KB
03-31 22:56:40.371 17789 17789 V mpvstats: AV: 670.415 A-V: 0.000 Dropped: 11 Cache: 3.328s + 0KB
03-31 22:56:43.371 17789 17789 V mpvstats: AV: 673.418 A-V: 0.000 Dropped: 11 Cache: 0.341s + 0KB
03-31 22:56:43.645 17789 17837 V mpv : event: unpause
03-31 22:56:43.646 17789 17837 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
03-31 22:56:43.646 17789 17837 V mpv : property: buffering = true
03-31 22:56:43.646 17789 17789 V PlayerActivity: state PLAYING -> BUFFERING
03-31 22:56:43.647 17789 17789 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=625.4040887777778, end=673.1839554444445}], cache-end=674.2087887777777, reader-pts=674.2087887777777, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=32148096, fw-bytes=299072, debug-low-level-seeks=0, debug-ts-last=674.2016444444445, ts-per-stream=[{type=video, duration=0.3336666666666588, reader=673.8679777777778, end=674.2016444444445}, {type=audio, duration=0.0, reader=674.2254777777778, end=674.2254777777778}]}
03-31 22:56:43.969 17789 17837 V mpv : event: unpause
03-31 22:56:43.969 17789 17837 V mpv : [cplayer] End buffering (waited 0.321596 secs) [2.090667s].
03-31 22:56:43.971 17789 17837 V mpv : property: buffering = false
03-31 22:56:43.973 17789 17789 V PlayerActivity: state BUFFERING -> PLAYING
03-31 22:56:44.539 17789 17789 V mpvstats: AV: 674.452 A-V: 0.000 Dropped: 18 Cache: 7.125s + 0KB
03-31 22:56:46.372 17789 17789 V mpvstats: AV: 676.287 A-V: 0.000 Dropped: 18 Cache: 14.635s + 0KB
03-31 22:56:49.374 17789 17789 V mpvstats: AV: 679.279 A-V: 0.000 Dropped: 18 Cache: 11.605s + 0KB
03-31 22:56:52.376 17789 17789 V mpvstats: AV: 682.282 A-V: 0.000 Dropped: 18 Cache: 9.301s + 0KB
03-31 22:56:55.377 17789 17789 V mpvstats: AV: 685.285 A-V: 0.000 Dropped: 18 Cache: 12.544s + 0KB
03-31 22:56:58.378 17789 17789 V mpvstats: AV: 688.288 A-V: 0.000 Dropped: 18 Cache: 9.557s + 0KB
03-31 22:57:01.379 17789 17789 V mpvstats: AV: 691.291 A-V: 0.000 Dropped: 18 Cache: 6.571s + 0KB
03-31 22:57:04.381 17789 17789 V mpvstats: AV: 694.283 A-V: 0.000 Dropped: 18 Cache: 3.499s + 0KB
03-31 22:57:07.382 17789 17789 V mpvstats: AV: 697.286 A-V: 0.000 Dropped: 18 Cache: 0.512s + 0KB
03-31 22:57:07.869 17789 17837 V mpv : event: unpause
03-31 22:57:07.869 17789 17837 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
03-31 22:57:07.873 17789 17837 V mpv : property: buffering = true
03-31 22:57:07.874 17789 17789 V PlayerActivity: state PLAYING -> BUFFERING
03-31 22:57:07.876 17789 17789 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=646.3571665555555, end=698.0532887777778}], cache-end=698.3154554444444, reader-pts=698.3154554444444, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=31879040, fw-bytes=426752, debug-low-level-seeks=0, debug-ts-last=698.3321444444445, ts-per-stream=[{type=video, duration=0.30028888888887195, reader=697.9698666666667, end=698.2701555555556}, {type=audio, duration=0.0, reader=698.3321444444445, end=698.3321444444445}]}
03-31 22:57:10.383 17789 17789 V mpvstats: AV: 697.786 A-V: 0.000 Dropped: 18 Cache: 0.000s + 0KB
03-31 22:57:13.384 17789 17789 V mpvstats: AV: 697.786 A-V: 0.000 Dropped: 18 Cache: 0.000s + 0KB
03-31 22:57:16.385 17789 17789 V mpvstats: AV: 697.786 A-V: 0.000 Dropped: 18 Cache: 0.000s + 0KB
03-31 22:57:19.386 17789 17789 V mpvstats: AV: 697.786 A-V: 0.000 Dropped: 18 Cache: 0.000s + 0KB
03-31 22:57:22.388 17789 17789 V mpvstats: AV: 697.786 A-V: 0.000 Dropped: 18 Cache: 0.000s + 0KB
03-31 22:57:25.389 17789 17789 V mpvstats: AV: 697.786 A-V: 0.000 Dropped: 18 Cache: 0.000s + 0KB
03-31 22:57:27.387 17789 24263 V Streamer: mpv read bytes:0 after retries:32000 (pos:481198080)
03-31 22:57:28.389 17789 17789 V mpvstats: AV: 697.786 A-V: 0.000 Dropped: 18 Cache: 0.000s + 0KB
03-31 22:57:31.391 17789 17789 V mpvstats: AV: 697.786 A-V: 0.000 Dropped: 18 Cache: 0.000s + 0KB
03-31 22:57:34.392 17789 17789 V mpvstats: AV: 697.786 A-V: 0.000 Dropped: 18 Cache: 0.000s + 0KB
03-31 22:57:37.393 17789 17789 V mpvstats: AV: 697.786 A-V: 0.000 Dropped: 18 Cache: 0.000s + 0KB
03-31 22:57:40.393 17789 17789 V mpvstats: AV: 697.786 A-V: 0.000 Dropped: 18 Cache: 0.000s + 0KB
03-31 22:57:43.395 17789 17789 V mpvstats: AV: 697.786 A-V: 0.000 Dropped: 18 Cache: 0.000s + 0KB
03-31 22:57:46.397 17789 17789 V mpvstats: AV: 697.786 A-V: 0.000 Dropped: 18 Cache: 0.000s + 0KB
03-31 22:57:49.397 17789 17789 V mpvstats: AV: 697.786 A-V: 0.000 Dropped: 18 Cache: 0.000s + 0KB
03-31 22:57:52.399 17789 17789 V mpvstats: AV: 697.786 A-V: 0.000 Dropped: 18 Cache: 0.000s + 0KB
03-31 22:57:55.400 17789 17789 V mpvstats: AV: 697.786 A-V: 0.000 Dropped: 18 Cache: 0.000s + 0KB
03-31 22:57:56.052 17789 17837 V mpv : event: unpause
03-31 22:57:56.052 17789 17837 V mpv : [cplayer] End buffering (waited 48.179167 secs) [1.621333s].
03-31 22:57:56.054 17789 17837 V mpv : property: buffering = false
03-31 22:57:56.056 17789 17789 V PlayerActivity: state BUFFERING -> PLAYING
03-31 22:57:56.206 17789 17837 E mpv : [ffmpeg/video] h264: error while decoding MB 58 25, bytestream -13
03-31 22:57:56.212 17789 17837 V mpv : [ffmpeg/video] h264: concealing 1591 DC, 1591 AC, 1591 MV errors in P frame
03-31 22:57:56.596 17789 17789 V mpvstats: AV: 698.554 A-V: 0.000 Dropped: 25 Cache: 1.365s + 0KB
03-31 22:57:57.910 17789 17837 V mpv : event: unpause
03-31 22:57:57.910 17789 17837 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
03-31 22:57:57.911 17789 17837 V mpv : property: buffering = true
03-31 22:57:57.911 17789 17789 V PlayerActivity: state PLAYING -> BUFFERING
03-31 22:57:57.912 17789 17789 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=648.4258887777778, end=698.3535776666666}], cache-end=700.3634554444444, reader-pts=700.3634554444444, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=31871360, fw-bytes=192704, debug-low-level-seeks=0, debug-ts-last=700.338888888889, ts-per-stream=[{type=video, duration=0.30028888888887195, reader=700.0386000000001, end=700.338888888889}, {type=audio, duration=0.0, reader=700.3801444444445, end=700.3801444444445}]}
03-31 22:57:58.400 17789 17789 V mpvstats: AV: 699.888 A-V: 0.000 Dropped: 25 Cache: 0.000s + 0KB
03-31 22:58:01.401 17789 17789 V mpvstats: AV: 699.888 A-V: 0.000 Dropped: 25 Cache: 0.000s + 0KB
03-31 22:58:04.402 17789 17789 V mpvstats: AV: 699.888 A-V: 0.000 Dropped: 25 Cache: 0.000s + 0KB
03-31 22:58:07.403 17789 17789 V mpvstats: AV: 699.888 A-V: 0.000 Dropped: 25 Cache: 0.000s + 0KB
03-31 22:58:10.406 17789 17789 V mpvstats: AV: 699.888 A-V: 0.000 Dropped: 25 Cache: 0.000s + 0KB
03-31 22:58:13.408 17789 17789 V mpvstats: AV: 699.888 A-V: 0.000 Dropped: 25 Cache: 0.000s + 0KB
03-31 22:58:16.409 17789 17789 V mpvstats: AV: 699.888 A-V: 0.000 Dropped: 25 Cache: 0.000s + 0KB
03-31 22:58:19.409 17789 17789 V mpvstats: AV: 699.888 A-V: 0.000 Dropped: 25 Cache: 0.000s + 0KB
03-31 22:58:22.410 17789 17789 V mpvstats: AV: 699.888 A-V: 0.000 Dropped: 25 Cache: 0.000s + 0KB
03-31 22:58:25.411 17789 17789 V mpvstats: AV: 699.888 A-V: 0.000 Dropped: 25 Cache: 0.000s + 0KB
03-31 22:58:28.411 17789 17789 V mpvstats: AV: 699.888 A-V: 0.000 Dropped: 25 Cache: 0.000s + 0KB
03-31 22:58:28.528 17789 24263 V Streamer: mpv read bytes:0 after retries:32000 (pos:482476032)
03-31 22:58:31.412 17789 17789 V mpvstats: AV: 699.888 A-V: 0.000 Dropped: 25 Cache: 0.000s + 0KB
03-31 22:58:34.413 17789 17789 V mpvstats: AV: 699.888 A-V: 0.000 Dropped: 25 Cache: 0.000s + 0KB
03-31 22:58:37.414 17789 17789 V mpvstats: AV: 699.888 A-V: 0.000 Dropped: 25 Cache: 0.000s + 0KB
03-31 22:58:40.415 17789 17789 V mpvstats: AV: 699.888 A-V: 0.000 Dropped: 25 Cache: 0.000s + 0KB
03-31 22:58:43.415 17789 17789 V mpvstats: AV: 699.888 A-V: 0.000 Dropped: 25 Cache: 0.000s + 0KB
03-31 22:58:46.416 17789 17789 V mpvstats: AV: 699.888 A-V: 0.000 Dropped: 25 Cache: 0.000s + 0KB
03-31 22:58:49.418 17789 17789 V mpvstats: AV: 699.888 A-V: 0.000 Dropped: 25 Cache: 0.000s + 0KB
03-31 22:58:52.419 17789 17789 V mpvstats: AV: 699.888 A-V: 0.000 Dropped: 25 Cache: 0.000s + 0KB
03-31 22:58:55.419 17789 17789 V mpvstats: AV: 699.888 A-V: 0.000 Dropped: 25 Cache: 0.000s + 0KB
03-31 22:58:55.863 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 0% -> 4%) [0.042667s].
03-31 22:58:55.864 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 4% -> 0%) [0.000000s].
03-31 22:58:55.904 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 0% -> 38%) [0.384000s].
03-31 22:58:56.100 17789 17837 V mpv : event: unpause
03-31 22:58:56.100 17789 17837 V mpv : [cplayer] End buffering (waited 58.188897 secs) [2.005333s].
03-31 22:58:56.101 17789 17837 V mpv : property: buffering = false
03-31 22:58:56.102 17789 17789 V PlayerActivity: state BUFFERING -> PLAYING
03-31 22:58:56.236 17789 17837 E mpv : [ffmpeg/video] h264: cabac decode of qscale diff failed at 33 14
03-31 22:58:56.236 17789 17837 E mpv : [ffmpeg/video] h264: error while decoding MB 33 14, bytestream -6
03-31 22:58:56.236 17789 17837 V mpv : [ffmpeg/video] h264: concealing 2496 DC, 2496 AC, 2496 MV errors in P frame
03-31 22:58:56.644 17789 17789 V mpvstats: AV: 700.623 A-V: 0.000 Dropped: 31 Cache: 1.323s + 0KB
03-31 22:58:57.957 17789 17837 V mpv : event: unpause
03-31 22:58:57.957 17789 17837 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
03-31 22:58:57.957 17789 17837 V mpv : property: buffering = true
03-31 22:58:57.957 17789 17789 V PlayerActivity: state PLAYING -> BUFFERING
03-31 22:58:57.959 17789 17789 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=650.1609554444444, end=700.7893443333334}], cache-end=702.4114554444444, reader-pts=702.4114554444444, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=31947584, fw-bytes=120576, debug-low-level-seeks=0, debug-ts-last=702.4281444444445, ts-per-stream=[{type=video, duration=0.266944444444448, reader=702.1073222222223, end=702.3742666666667}, {type=audio, duration=0.0, reader=702.4281444444445, end=702.4281444444445}]}
03-31 22:58:58.419 17789 17789 V mpvstats: AV: 701.957 A-V: 0.000 Dropped: 31 Cache: 0.000s + 0KB
03-31 22:59:01.421 17789 17789 V mpvstats: AV: 701.957 A-V: 0.000 Dropped: 31 Cache: 0.000s + 0KB
03-31 22:59:04.421 17789 17789 V mpvstats: AV: 701.957 A-V: 0.000 Dropped: 31 Cache: 0.000s + 0KB
03-31 22:59:06.683 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 0% -> 4%) [0.042667s].
03-31 22:59:06.684 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 4% -> 0%) [0.000000s].
03-31 22:59:06.855 17789 17837 V mpv : event: unpause
03-31 22:59:06.855 17789 17837 V mpv : [cplayer] End buffering (waited 8.899287 secs) [2.005333s].
03-31 22:59:06.861 17789 17837 V mpv : property: buffering = false
03-31 22:59:06.861 17789 17789 V PlayerActivity: state BUFFERING -> PLAYING
03-31 22:59:07.423 17789 17789 V mpvstats: AV: 702.691 A-V: 0.000 Dropped: 38 Cache: 1.323s + 0KB
03-31 22:59:07.653 17789 17789 V mpvstats: AV: 702.925 A-V: 0.000 Dropped: 38 Cache: 1.067s + 0KB
03-31 22:59:08.695 17789 17837 V mpv : event: unpause
03-31 22:59:08.695 17789 17837 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
03-31 22:59:08.696 17789 17837 V mpv : property: buffering = true
03-31 22:59:08.696 17789 17789 V PlayerActivity: state PLAYING -> BUFFERING
03-31 22:59:08.697 17789 17789 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=651.8626665555555, end=704.025911}], cache-end=704.4594554444444, reader-pts=704.4594554444444, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=32123712, fw-bytes=124544, debug-low-level-seeks=0, debug-ts-last=704.442988888889, ts-per-stream=[{type=video, duration=0.30028888888898564, reader=704.1427, end=704.442988888889}, {type=audio, duration=0.0, reader=704.4761444444445, end=704.4761444444445}]}
03-31 22:59:10.423 17789 17789 V mpvstats: AV: 703.993 A-V: 0.000 Dropped: 38 Cache: 0.000s + 0KB
03-31 22:59:13.423 17789 17789 V mpvstats: AV: 703.993 A-V: 0.000 Dropped: 38 Cache: 0.000s + 0KB
03-31 22:59:16.424 17789 17789 V mpvstats: AV: 703.993 A-V: 0.000 Dropped: 38 Cache: 0.000s + 0KB
03-31 22:59:17.405 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 0% -> 4%) [0.042667s].
03-31 22:59:17.407 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 4% -> 0%) [0.000000s].
03-31 22:59:17.423 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 0% -> 25%) [0.256000s].
03-31 22:59:17.611 17789 17837 V mpv : event: unpause
03-31 22:59:17.612 17789 17837 V mpv : [cplayer] End buffering (waited 8.916875 secs) [1.962667s].
03-31 22:59:17.615 17789 17837 V mpv : property: buffering = false
03-31 22:59:17.615 17789 17789 V PlayerActivity: state BUFFERING -> PLAYING
03-31 22:59:18.672 17789 17789 V mpvstats: AV: 705.260 A-V: 0.000 Dropped: 45 Cache: 0.768s + 0KB
03-31 22:59:19.352 17789 17837 V mpv : event: unpause
03-31 22:59:19.354 17789 17837 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
03-31 22:59:19.356 17789 17837 V mpv : property: buffering = true
03-31 22:59:19.356 17789 17789 V PlayerActivity: state PLAYING -> BUFFERING
03-31 22:59:19.357 17789 17789 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=653.7311776666667, end=704.4930332222223}], cache-end=706.4647887777778, reader-pts=706.4647887777778, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=32130752, fw-bytes=154816, debug-low-level-seeks=0, debug-ts-last=706.4449888888889, ts-per-stream=[{type=video, duration=0.3336666666666588, reader=706.1113222222223, end=706.4449888888889}, {type=audio, duration=0.0, reader=706.4814777777779, end=706.4814777777779}]}
03-31 22:59:19.438 17789 17789 V mpvstats: AV: 705.961 A-V: 0.000 Dropped: 45 Cache: 0.000s + 0KB
03-31 22:59:22.440 17789 17789 V mpvstats: AV: 705.961 A-V: 0.000 Dropped: 45 Cache: 0.000s + 0KB
03-31 22:59:23.912 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 0% -> 4%) [0.042667s].
03-31 22:59:25.441 17789 17789 V mpvstats: AV: 705.961 A-V: 0.000 Dropped: 45 Cache: 0.043s + 0KB
03-31 22:59:26.316 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 4% -> 81%) [0.810667s].
03-31 22:59:26.366 17789 17837 V mpv : event: unpause
03-31 22:59:26.366 17789 17837 V mpv : [cplayer] End buffering (waited 7.011712 secs) [2.036100s].
03-31 22:59:26.378 17789 17837 V mpv : property: buffering = false
03-31 22:59:26.379 17789 17789 V PlayerActivity: state BUFFERING -> PLAYING
03-31 22:59:26.678 17789 17789 V mpvstats: AV: 706.462 A-V: 0.000 Dropped: 51 Cache: 6.175s + 0KB
03-31 22:59:27.026 17789 17837 W mpv : [ad] Invalid audio PTS: 707.318122 -> 708.330222
03-31 22:59:28.455 17789 17789 V mpvstats: AV: 708.597 A-V: 0.671 Dropped: 51 Cache: 24.533s + 0KB
03-31 22:59:31.458 17789 17789 V mpvstats: AV: 712.234 A-V: 0.027 Dropped: 51 Cache: 44.075s + 0KB
03-31 22:59:34.459 17789 17789 V mpvstats: AV: 715.270 A-V: 0.000 Dropped: 51 Cache: 67.029s + 0KB
03-31 22:59:37.463 17789 17789 V mpvstats: AV: 718.240 A-V: 0.000 Dropped: 51 Cache: 86.033s + 0KB
03-31 22:59:40.463 17789 17789 V mpvstats: AV: 721.276 A-V: 0.000 Dropped: 51 Cache: 95.035s + 0KB
03-31 22:59:43.465 17789 17789 V mpvstats: AV: 724.246 A-V: 0.000 Dropped: 51 Cache: 95.035s + 0KB
03-31 22:59:46.465 17789 17789 V mpvstats: AV: 727.249 A-V: 0.000 Dropped: 51 Cache: 95.035s + 0KB
03-31 22:59:49.466 17789 17789 V mpvstats: AV: 730.252 A-V: 0.000 Dropped: 51 Cache: 95.035s + 0KB
03-31 22:59:52.467 17789 17789 V mpvstats: AV: 733.255 A-V: 0.000 Dropped: 51 Cache: 95.009s + 0KB
03-31 22:59:55.468 17789 17789 V mpvstats: AV: 736.258 A-V: 0.000 Dropped: 51 Cache: 95.009s + 0KB
03-31 22:59:58.469 17789 17789 V mpvstats: AV: 739.254 A-V: 0.000 Dropped: 51 Cache: 95.009s + 0KB
03-31 23:00:01.471 17789 17789 V mpvstats: AV: 742.257 A-V: 0.000 Dropped: 51 Cache: 95.009s + 0KB
03-31 23:00:04.471 17789 17789 V mpvstats: AV: 745.260 A-V: 0.000 Dropped: 51 Cache: 95.009s + 0KB
03-31 23:00:04.998 17789 17789 V mpv : seeking by 30.0 from 745.7935555555556
03-31 23:00:04.999 17789 17837 D mpv : [cplayer] Run command: seek, flags=64, args=[30.000000, relative, unused]
Here is the video of the event:
This is an issue with our audio driver that I am investigating some fixes for. What does your log say earlier if you search for "Setting bufferSize"?
For now one workaround is to pause the player for 5s and let it buffer so it doesn't run out.
1 Like
[ao/audiotrack] Setting bufferSize = 28800
So that could be the problem causing the buffering?
I need the entire log line. What does the rest say in parenthesis?
Each android tv has different buffer requirements for seamless audio playback.
03-31 23:03:05.800 17789 17837 V mpv : [ao/audiotrack] Setting bufferSize = 28800 (driver=16416, min=19200, max=28800)
03-31 23:03:05.800 17789 17837 V mpv : [ao/audiotrack] device buffer: 14400 samples.
03-31 23:03:05.800 17789 17837 V mpv : [ao/audiotrack] using soft-buffer of 14400 samples.
03-31 23:03:05.800 17789 17837 I mpv : [cplayer] AO: [audiotrack] 48000Hz stereo 2ch s16
03-31 23:03:05.800 17789 17837 V mpv : [cplayer] AO: Description: Android AudioTrack audio outputThank you. I will upload a new beta tomorrow with a fix for this problem.
Thank you. For the heck of it I went to an OTA channel and enabled surround sound. I got a totally different line.
04-01 00:57:45.676 17789 17837 V mpv : [ao/audiotrack] Setting bufferSize = 4800 (driver=4104, min=0, max=0)
That's normal for Dolby stream since it does passthrough
1 Like
If you see buffering pauses w/ Dolby please paste the logs for the buffering events similar to before.
If I have Surround enabled and watch a OTA 480i SD channel it's bad. I can pause it for a few seconds and then it plays fine.
Do you want that?
Edit; just in case
04-01 01:07:38.769 17789 17789 V PlayerActivity: onStart
04-01 01:07:38.770 17789 17789 V PlayerActivity: onResume
04-01 01:07:38.787 17789 17789 V mpvstats: AV: 417.377 A-V: 0.000 Dropped: 0 Cache: 0.000s + 0KB
04-01 01:07:38.824 17789 17855 D mali_winsys: EGLint new_window_surface(egl_winsys_display *, void *, EGLSurface, EGLConfig, egl_winsys_surface **, EGLBoolean) returns 0x3000
04-01 01:07:38.886 17789 17789 V VideoPlayer: surfaceCreated: video
04-01 01:07:38.887 17789 17837 D mpv : [cplayer] Setting option 'wid' = 12658 (flags = 64) -> 0
04-01 01:07:38.888 17789 17837 D mpv : [cplayer] Setting option 'android-surface-size' = "1920x1080" (flags = 64) -> 0
04-01 01:07:38.904 17789 17789 V VideoPlayer: surfaceCreated: subtitles
04-01 01:07:38.905 17789 17837 D mpv : [cplayer] Setting option 'mediacodec-embed-osd-surface' = 12650 (flags = 64) -> 0
04-01 01:07:38.907 17789 17837 D mpv : [cplayer] Run command: loadfile, flags=64, args=[hdhr://6.4, replace, start=none,pause=no,sid=no]
04-01 01:07:38.908 17789 17837 V mpv : event: start-file
04-01 01:07:38.908 17789 17837 D mpv : [cplayer] Setting option 'start' = 'none' (flags = 80)
04-01 01:07:38.908 17789 17837 D mpv : [cplayer] Setting option 'pause' = 'no' (flags = 80)
04-01 01:07:38.908 17789 17837 D mpv : [cplayer] Setting option 'sid' = 'no' (flags = 80)
04-01 01:07:38.908 17789 17837 I mpv : [cplayer] Playing: hdhr://6.4
04-01 01:07:38.908 17789 17837 V mpv : [stream_callback] Opening hdhr://6.4
04-01 01:07:38.910 17789 26673 V Streamer: ch6.4 has 2 possible sources
04-01 01:07:38.910 17789 26673 V Streamer: trying 10481E46: http://192.168.5.45:5004/auto/v6.4?transcode=none
04-01 01:07:38.914 17789 26673 V Streamer: http socket receiveBufferSize = 1048576
04-01 01:07:38.948 17789 17789 V PlayerActivity: state STOPPED -> LOADING
04-01 01:07:39.128 17789 26673 V Streamer: started with 2333829932 byte buffer in /data/user/0/com.getchannels.dvr.app.beta/cache/channels-streamer.ts
04-01 01:07:39.128 17789 26673 V Streamer: seek(0) = 0 -> 0
04-01 01:07:39.129 17789 17837 D mpv : [stream_callback] Stream opened successfully.
04-01 01:07:39.129 17789 17837 V mpv : [demux] Trying demuxers for level=force.
04-01 01:07:39.129 17789 17837 D mpv : [demux] Trying demuxer: lavf (force-level: force)
04-01 01:07:39.196 17789 17855 W libEGL : EGLNativeWindowType 0xb2dc1808 disconnect failed
04-01 01:07:39.225 17789 17837 V mpv : [lavf] Found 'mpegts' at score=50 size=2048.
04-01 01:07:39.226 17789 17837 V mpv : [lavf] avformat_open_input() finished after 2632 bytes.
04-01 01:07:39.227 17789 17837 D mpv : [ffmpeg/demuxer] mpegts: Before avformat_find_stream_info() pos: 0 bytes read:2632 seeks:0 nb_streams:2
04-01 01:07:40.042 17789 17837 V mpv : [ffmpeg/demuxer] mpegts: Skipping duration calculation in estimate_timings_from_pts
04-01 01:07:40.042 17789 26673 V Streamer: seek(0) = 421120 -> 0
04-01 01:07:40.043 17789 17837 D mpv : [ffmpeg/demuxer] mpegts: After avformat_find_stream_info() pos: 0 bytes read:421120 seeks:1 frames:42
04-01 01:07:40.043 17789 17837 V mpv : [lavf] avformat_find_stream_info() finished after 0 bytes.
04-01 01:07:40.043 17789 17837 V mpv : [demux] Detected file format: mpegts (libavformat)
04-01 01:07:40.043 17789 17837 V mpv : [cplayer] Opening done: hdhr://6.4
04-01 01:07:40.044 17789 17837 V mpv : event: tracks-changed
04-01 01:07:40.044 17789 17837 V mpv : event: tracks-changed
04-01 01:07:40.044 17789 17837 V mpv : event: metadata-update
04-01 01:07:40.044 17789 17837 D mpv : [global] config path: 'sub' -/-> '/data/user/0/com.getchannels.dvr.app.beta/files/mpv/sub'
04-01 01:07:40.044 17789 17837 V mpv : [lavf] select track 0
04-01 01:07:40.044 17789 17837 V mpv : [lavf] select track 1
04-01 01:07:40.044 17789 17837 I mpv : [cplayer] (+) Video --vid=1 (mpeg2video 704x480 29.970fps)
04-01 01:07:40.044 17789 17837 I mpv : [cplayer] (+) Audio --aid=1 --alang=eng (ac3 2ch 48000Hz 192kbps)
04-01 01:07:40.047 17789 26677 D mali_winsys: EGLint new_window_surface(egl_winsys_display *, void *, EGLSurface, EGLConfig, egl_winsys_surface **, EGLBoolean) returns 0x3000
04-01 01:07:40.062 17789 17837 V mpv : [vd] Container reported FPS: 29.970030
04-01 01:07:40.062 17789 17837 V mpv : [vd] Codec list:
04-01 01:07:40.062 17789 17837 V mpv : [vd] mpeg2video - MPEG-2 video
04-01 01:07:40.062 17789 17837 V mpv : [vd] mpegvideo (mpeg2video) - MPEG-1 video
04-01 01:07:40.062 17789 17837 V mpv : [vd] mpeg2_mediacodec (mpeg2video) - MPEG-2 Android MediaCodec decoder
04-01 01:07:40.063 17789 17837 V mpv : [vd] Opening decoder mpeg2video
04-01 01:07:40.063 17789 17837 V mpv : [vd] Looking at hwdec mpeg2_mediacodec-mediacodec-copy...
04-01 01:07:40.063 17789 17837 V mpv : [vd] Trying hardware decoding via mpeg2_mediacodec-mediacodec-copy.
04-01 01:07:40.063 17789 17837 V mpv : [vd] Using underlying hw-decoder 'mpeg2_mediacodec'
04-01 01:07:40.063 17789 17837 V mpv : [vd] Pixel formats supported by decoder: mediacodec
04-01 01:07:40.063 17789 17837 V mpv : [vd] Codec profile: Main (0x4)
04-01 01:07:40.063 17789 17837 V mpv : [vd] Requesting pixfmt 'mediacodec' from decoder.
04-01 01:07:40.063 17789 17837 V mpv : [ffmpeg/video] mpeg2_mediacodec: Using surface 0x0
04-01 01:07:40.063 17789 17837 W mpv : [ffmpeg/video] mpeg2_mediacodec: Unsupported or unknown profile
04-01 01:07:40.069 17789 17836 D MtkACodecPlugin: MtkACodecPlugin createAPlugin
04-01 01:07:40.070 17789 26679 D MtkACodecPlugin: OMX.MTK.VIDEO.DECODER.MPEG2 needRmClient (680)
04-01 01:07:40.070 17789 26679 D MtkACodecPlugin: OMX.MTK.VIDEO.DECODER.MPEG2 mNeedVdpImgrz (686)
04-01 01:07:40.073 17789 26679 I OMXClient: IOmx service obtained
04-01 01:07:40.099 17789 26678 D MtkMediaCodecPlugin: No surfaceTextureClient, [OMX.MTK.VIDEO.DECODER.MPEG2] set mOutputPath = 1024 L(158)
04-01 01:07:40.112 17789 26679 I ACodec : codec does not support config priority (err -1010)
04-01 01:07:40.160 17789 17837 E mpv : [ffmpeg/video] mpeg2_mediacodec: Output color format 0x7f000103 (value=2130706691) is not supported
04-01 01:07:40.160 17789 17837 E mpv : [ffmpeg/video] mpeg2_mediacodec: Output color format is not supported
04-01 01:07:40.160 17789 17837 E mpv : [ffmpeg/video] mpeg2_mediacodec: Failed to configure context
04-01 01:07:40.160 17789 17837 E mpv : [ffmpeg/video] mpeg2_mediacodec: MediaCodec 0x918a1000 failed to start
04-01 01:07:40.201 17789 17836 D MediaCodec: mState = 0, mHaveKick = 0, L(711)
04-01 01:07:40.202 17789 17836 D MtkACodecPlugin: MtkACodecPlugin destoryAPlugin
04-01 01:07:40.203 17789 17837 E mpv : [vd] Could not open codec.
04-01 01:07:40.204 17789 17837 V mpv : [vd] Falling back to software decoding.
04-01 01:07:40.204 17789 17837 V mpv : event: audio-reconfig
04-01 01:07:40.204 17789 17837 V mpv : [vd] Detected 4 logical cores.
04-01 01:07:40.204 17789 17837 V mpv : [vd] Requesting 5 threads for decoding.
04-01 01:07:40.204 17789 17837 V mpv : [vd] Selected codec: mpeg2video (MPEG-2 video)
04-01 01:07:40.205 17789 17837 V mpv : [vf] User filter list:
04-01 01:07:40.205 17789 17837 V mpv : [vf] (empty)
04-01 01:07:40.206 17789 17837 V mpv : event: audio-reconfig
04-01 01:07:40.206 17789 17837 V mpv : event: file-loaded
04-01 01:07:40.206 17789 17837 V mpv : [ad] Codec list:
04-01 01:07:40.206 17789 17837 V mpv : [ad] raw_ac3 (ac3) - raw audio pass-through decoder
04-01 01:07:40.206 17789 17789 V PlayerActivity: state LOADING -> LOADED
04-01 01:07:40.206 17789 17837 V mpv : [ad] Opening decoder raw_ac3
04-01 01:07:40.206 17789 17837 V mpv : [ad] Selected codec: raw_ac3 (raw audio pass-through decoder)
04-01 01:07:40.206 17789 17837 V mpv : [af] User filter list:
04-01 01:07:40.206 17789 17837 V mpv : [af] (empty)
04-01 01:07:40.206 17789 17837 V mpv : [cplayer] Starting playback...
04-01 01:07:40.211 17789 17837 V mpv : property: track-list has 2 entries
04-01 01:07:40.226 17789 17836 W AudioTrack: Use of stream types is deprecated for operations other than volume control
04-01 01:07:40.226 17789 17836 W AudioTrack: See the documentation of AudioTrack() for what to use instead with android.media.AudioAttributes to qualify your playback use case
04-01 01:07:40.256 17789 17837 V mpv : event: audio-reconfig
04-01 01:07:40.256 17789 17837 V mpv : event: video-reconfig
04-01 01:07:40.259 17789 17837 V mpv : event: unpause
04-01 01:07:40.259 17789 17837 V mpv : event: tracks-changed
04-01 01:07:40.259 17789 17837 V mpv : event: video-reconfig
04-01 01:07:40.260 17789 17837 V mpv : [ad] In: channels=2 samplerate=48000 bitrate=192000
04-01 01:07:40.260 17789 17837 V mpv : property: buffering = true
04-01 01:07:40.260 17789 17789 V PlayerActivity: state LOADED -> BUFFERING
04-01 01:07:40.262 17789 17837 V mpv : property: track-list has 3 entries
04-01 01:07:40.262 17789 17837 V mpv : [af] [in] 48000Hz stereo 2ch raw-ac3 192kbps
04-01 01:07:40.262 17789 17837 V mpv : [af] [userspeed] 48000Hz stereo 2ch raw-ac3 192kbps
04-01 01:07:40.262 17789 17837 V mpv : [af] [userspeed] (disabled)
04-01 01:07:40.262 17789 17837 V mpv : [af] [convert] 48000Hz stereo 2ch raw-ac3 192kbps
04-01 01:07:40.262 17789 17837 V mpv : [ao] Trying audio driver 'audiotrack'
04-01 01:07:40.262 17789 17837 V mpv : [ao/audiotrack] requested format: 48000 Hz, stereo channels, raw-ac3
04-01 01:07:40.262 17789 17837 V mpv : [ao/audiotrack] Setting bufferSize = 2400 (driver=4104, min=0, max=0)
04-01 01:07:40.262 17789 17837 V mpv : [ao/audiotrack] device buffer: 2400 samples.
04-01 01:07:40.263 17789 17837 V mpv : [ao/audiotrack] using soft-buffer of 5376 samples.
04-01 01:07:40.263 17789 17837 I mpv : [cplayer] AO: [audiotrack] 48000Hz stereo 2ch raw-ac3 192kbps
04-01 01:07:40.263 17789 17837 V mpv : [cplayer] AO: Description: Android AudioTrack audio output
04-01 01:07:40.263 17789 17837 V mpv : [af] [convert] (disabled)
04-01 01:07:40.263 17789 17837 V mpv : [af] [out] 48000Hz stereo 2ch raw-ac3 192kbps
04-01 01:07:40.263 17789 17837 D mpv : [vd] DR parameter change to 704x480 yuv420p align=16
04-01 01:07:40.263 17789 17837 D mpv : [vd] Allocating new DR image...
04-01 01:07:40.263 17789 17837 D mpv : [vd] ...failed..
04-01 01:07:40.263 17789 17837 V mpv : [vd] DR failed - disabling.
04-01 01:07:40.263 17789 17837 V mpv : [vd] Using software decoding.
04-01 01:07:40.263 17789 17837 V mpv : [vd] Decoder format: 704x480 [40:33] yuv420p auto/auto/auto/limited/auto CL=mpeg2/4/h264 (auto 0.000000/0.000000/0.000000)
04-01 01:07:40.263 17789 17837 V mpv : [vf] [in] 704x480 [40:33] yuv420p bt.601/bt.601-525/bt.1886/limited/display SP=1.000000 CL=mpeg2/4/h264
04-01 01:07:40.263 17789 17837 V mpv : [vf] [userdeint] 704x480 [40:33] yuv420p bt.601/bt.601-525/bt.1886/limited/display SP=1.000000 CL=mpeg2/4/h264
04-01 01:07:40.263 17789 17837 V mpv : [vf] [userdeint] (disabled)
04-01 01:07:40.263 17789 17837 V mpv : [vf] [autorotate] 704x480 [40:33] yuv420p bt.601/bt.601-525/bt.1886/limited/display SP=1.000000 CL=mpeg2/4/h264
04-01 01:07:40.263 17789 17837 V mpv : [vf] [autorotate] (disabled)
04-01 01:07:40.263 17789 17837 V mpv : [vf] [convert] 704x480 [40:33] yuv420p bt.601/bt.601-525/bt.1886/limited/display SP=1.000000 CL=mpeg2/4/h264
04-01 01:07:40.264 17789 17837 V mpv : [vf] [convert] (disabled)
04-01 01:07:40.264 17789 17837 V mpv : [vf] [out] 704x480 [40:33] yuv420p bt.601/bt.601-525/bt.1886/limited/display SP=1.000000 CL=mpeg2/4/h264
04-01 01:07:40.264 17789 17837 I mpv : [cplayer] VO: [gpu] 704x480 => 853x480 yuv420p
04-01 01:07:40.264 17789 17837 V mpv : [cplayer] VO: Description: Shader-based GPU Renderer
04-01 01:07:40.264 17789 17837 V mpv : [cplayer] first video frame after restart shown
04-01 01:07:40.264 17789 17837 I mpv : [cplayer] Track switched:
04-01 01:07:40.264 17789 17837 I mpv : [cplayer] (+) Video --vid=1 (mpeg2video 704x480 29.970fps)
04-01 01:07:40.264 17789 17837 I mpv : [cplayer] (+) Audio --aid=1 --alang=eng (ac3 2ch 48000Hz 192kbps)
04-01 01:07:40.264 17789 17837 V mpv : [cplayer] Set property: aid=1 -> 1
04-01 01:07:40.264 17789 17837 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 13%) [0.133467s].
04-01 01:07:40.264 17789 17837 I mpv : [cplayer] (+) Video --vid=1 (mpeg2video 704x480 29.970fps)
04-01 01:07:40.264 17789 17837 I mpv : [cplayer] (+) Audio --aid=1 --alang=eng (ac3 2ch 48000Hz 192kbps)
04-01 01:07:40.264 17789 17837 I mpv : [cplayer] Subs --sid=1 (*) (eia_608)
04-01 01:07:40.264 17789 17837 D mpv : [cplayer] Setting option 'cache-pause-initial' = "0.3" (flags = 64) -> 0
04-01 01:07:40.264 17789 17837 D mpv : [cplayer] Setting option 'cache-pause-wait' = "0.25" (flags = 64) -> 0
04-01 01:07:40.264 17789 17837 D mpv : [cplayer] Setting option 'cache-pause-fill' = "0.75" (flags = 64) -> 0
04-01 01:07:40.473 17789 17837 V mpv : event: playback-restart
04-01 01:07:40.473 17789 17837 V mpv : [cplayer] starting audio playback
04-01 01:07:40.474 17789 17837 V mpv : [cplayer] playback restart complete @ 0.859767
04-01 01:07:40.914 17789 17837 V mpv : event: unpause
04-01 01:07:40.914 17789 17837 V mpv : [cplayer] End buffering (waited 0.654588 secs) [0.320000s].
04-01 01:07:40.923 17789 17837 V mpv : property: buffering = false
04-01 01:07:40.924 17789 17789 V PlayerActivity: state BUFFERING -> PLAYING
04-01 01:07:41.002 17789 17837 V mpv : event: unpause
04-01 01:07:41.002 17789 17837 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
04-01 01:07:41.002 17789 17837 V mpv : property: buffering = true
04-01 01:07:41.003 17789 17789 V PlayerActivity: state PLAYING -> BUFFERING
04-01 01:07:41.004 17789 17789 V mpvstats: demuxer-cache-state: {seekable-ranges=[], cache-end=1.5360000000000582, reader-pts=1.5360000000000582, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=891584, fw-bytes=377600, debug-low-level-seeks=0, debug-ts-last=24551.9123, ts-per-stream=[{type=video, duration=0.867533333330357, reader=24551.04476666667, end=24551.9123}, {type=audio, duration=0.0, reader=24551.6209, end=24551.6209}]}
04-01 01:07:41.116 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 0% -> 4%) [0.032000s].
04-01 01:07:41.116 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 4% -> 0%) [0.000000s].
04-01 01:07:41.116 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 0% -> 17%) [0.128000s].
04-01 01:07:41.416 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 17% -> 38%) [0.288000s].
04-01 01:07:41.460 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 38% -> 59%) [0.448000s].
04-01 01:07:41.667 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 59% -> 81%) [0.608000s].
04-01 01:07:41.790 17789 17789 V mpvstats: AV: 0.927 A-V: -0.009 Dropped: 0 Cache: 0.768s + 0KB
04-01 01:07:41.922 17789 17837 V mpv : event: unpause
04-01 01:07:41.922 17789 17837 V mpv : [cplayer] End buffering (waited 0.951755 secs) [0.768000s].
04-01 01:07:41.928 17789 17837 V mpv : property: buffering = false
04-01 01:07:41.929 17789 17789 V PlayerActivity: state BUFFERING -> PLAYING
04-01 01:07:42.138 17789 26691 W AudioTrack: releaseBuffer() track 0xb2ceed00 disabled due to previous underrun, restarting
04-01 01:07:42.774 17789 17789 V mpvstats: AV: 1.761 A-V: -0.001 Dropped: 12 Cache: 0.800s + 0KB
04-01 01:07:42.847 17789 26691 W AudioTrack: releaseBuffer() track 0xb2ceed00 disabled due to previous underrun, restarting
04-01 01:07:42.879 17789 17837 W mpv : [cplayer]
04-01 01:07:42.879 17789 17837 W mpv : [cplayer] Audio/Video desynchronisation detected! Possible reasons include too slow
04-01 01:07:42.880 17789 17837 W mpv : [cplayer] hardware, temporary CPU spikes, broken drivers, and broken files. Audio
04-01 01:07:42.880 17789 17837 W mpv : [cplayer] position will not match to the video (see A-V status field).
04-01 01:07:42.880 17789 17837 W mpv : [cplayer]
04-01 01:07:43.050 17789 26691 W AudioTrack: releaseBuffer() track 0xb2ceed00 disabled due to previous underrun, restarting
04-01 01:07:43.193 17789 17837 V mpv : event: unpause
04-01 01:07:43.193 17789 17837 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
04-01 01:07:43.195 17789 17837 V mpv : property: buffering = true
04-01 01:07:43.195 17789 17789 V PlayerActivity: state PLAYING -> BUFFERING
04-01 01:07:43.197 17789 17789 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=0.0, end=3.583999999998923}], cache-end=3.6159999999981665, reader-pts=3.6159999999981665, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=1978304, fw-bytes=321216, debug-low-level-seeks=0, debug-ts-last=24553.280333333336, ts-per-stream=[{type=video, duration=0.7674333333307004, reader=24553.280333333336, end=24554.047766666667}, {type=audio, duration=0.0, reader=24553.7009, end=24553.7009}]}
04-01 01:07:43.201 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 0% -> 21%) [0.160000s].
04-01 01:07:43.201 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 21% -> 8%) [0.064000s].
04-01 01:07:43.444 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 8% -> 29%) [0.224000s].
04-01 01:07:43.694 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 29% -> 72%) [0.544000s].
04-01 01:07:43.775 17789 17789 V mpvstats: AV: 3.195 A-V: 0.167 Dropped: 43 Cache: 0.544s + 0KB
04-01 01:07:43.945 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 72% -> 93%) [0.704000s].
04-01 01:07:44.200 17789 17837 V mpv : event: unpause
04-01 01:07:44.200 17789 17837 V mpv : [cplayer] End buffering (waited 1.003032 secs) [1.024000s].
04-01 01:07:44.206 17789 17837 V mpv : property: buffering = false
04-01 01:07:44.206 17789 17789 V PlayerActivity: state BUFFERING -> PLAYING
04-01 01:07:44.777 17789 17789 V mpvstats: AV: 3.996 A-V: 0.000 Dropped: 52 Cache: 0.128s + 0KB
04-01 01:07:44.792 17789 17789 V mpvstats: AV: 4.030 A-V: 0.000 Dropped: 52 Cache: 0.128s + 0KB
04-01 01:07:46.558 17789 17837 V mpv : event: unpause
04-01 01:07:46.558 17789 17837 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
04-01 01:07:46.560 17789 17837 V mpv : property: buffering = true
04-01 01:07:46.560 17789 17789 V PlayerActivity: state PLAYING -> BUFFERING
04-01 01:07:46.562 17789 17789 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=0.0, end=6.943999999999505}], cache-end=6.9759999999987485, reader-pts=6.9759999999987485, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=3775488, fw-bytes=795008, debug-low-level-seeks=0, debug-ts-last=24557.417800000003, ts-per-stream=[{type=video, duration=1.5348666666686768, reader=24555.882933333334, end=24557.417800000003}, {type=audio, duration=0.0, reader=24557.0609, end=24557.0609}]}
04-01 01:07:46.591 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 0% -> 21%) [0.160000s].
04-01 01:07:46.714 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 21% -> 42%) [0.320000s].
04-01 01:07:46.915 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 42% -> 63%) [0.480000s].
04-01 01:07:47.166 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 63% -> 85%) [0.640000s].
04-01 01:07:47.216 17789 17836 W AudioTrack: retrograde timestamp position corrected, -107520 = 0 - 107520
04-01 01:07:47.218 17789 17837 V mpv : event: unpause
04-01 01:07:47.218 17789 17837 V mpv : [cplayer] End buffering (waited 0.657649 secs) [0.800000s].
04-01 01:07:47.224 17789 17837 V mpv : property: buffering = false
04-01 01:07:47.225 17789 17789 V PlayerActivity: state BUFFERING -> PLAYING
04-01 01:07:47.295 17789 17837 V mpv : event: unpause
04-01 01:07:47.296 17789 17837 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
04-01 01:07:47.296 17789 17837 V mpv : property: buffering = true
04-01 01:07:47.304 17789 17789 V PlayerActivity: state PLAYING -> BUFFERING
04-01 01:07:47.304 17789 17789 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=0.0, end=7.266166666664503}], cache-end=7.775999999998021, reader-pts=7.775999999998021, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=4107456, fw-bytes=614080, debug-low-level-seeks=0, debug-ts-last=24556.850566666668, ts-per-stream=[{type=video, duration=1.4347666666653822, reader=24556.850566666668, end=24558.285333333333}, {type=audio, duration=0.0, reader=24557.8609, end=24557.8609}]}
04-01 01:07:47.360 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 0% -> 21%) [0.160000s].
04-01 01:07:47.360 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 21% -> 17%) [0.128000s].
04-01 01:07:47.665 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 17% -> 38%) [0.288000s].
04-01 01:07:47.715 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 38% -> 59%) [0.448000s].
04-01 01:07:47.790 17789 17789 V mpvstats: AV: 6.766 A-V: 0.014 Dropped: 79 Cache: 0.448s + 0KB
04-01 01:07:47.811 17789 17789 V mpvstats: AV: 6.766 A-V: 0.014 Dropped: 79 Cache: 0.448s + 0KB
04-01 01:07:47.915 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 59% -> 81%) [0.608000s].
04-01 01:07:48.168 17789 17837 V mpv : event: unpause
04-01 01:07:48.168 17789 17837 V mpv : [cplayer] End buffering (waited 0.871082 secs) [0.928000s].
04-01 01:07:48.174 17789 17837 V mpv : property: buffering = false
04-01 01:07:48.176 17789 17789 V PlayerActivity: state BUFFERING -> PLAYING
04-01 01:07:48.792 17789 17789 V mpvstats: AV: 8.134 A-V: 0.000 Dropped: 103 Cache: 0.032s + 0KB
04-01 01:07:48.892 17789 17837 V mpv : event: unpause
04-01 01:07:48.892 17789 17837 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
04-01 01:07:48.893 17789 17837 V mpv : property: buffering = true
04-01 01:07:48.893 17789 17789 V PlayerActivity: state PLAYING -> BUFFERING
04-01 01:07:48.894 17789 17789 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=0.0, end=8.767666666666628}], cache-end=9.376000000000204, reader-pts=9.376000000000204, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=4644992, fw-bytes=452736, debug-low-level-seeks=0, debug-ts-last=24558.35206666667, ts-per-stream=[{type=video, duration=1.5348666666686768, reader=24558.352066666666, end=24559.886933333335}, {type=audio, duration=0.0, reader=24559.460900000002, end=24559.460900000002}]}
04-01 01:07:48.965 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 0% -> 21%) [0.160000s].
04-01 01:07:49.166 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 21% -> 42%) [0.320000s].
04-01 01:07:49.416 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 42% -> 63%) [0.480000s].
04-01 01:07:49.465 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 63% -> 85%) [0.640000s].
04-01 01:07:49.667 17789 17836 W AudioTrack: retrograde timestamp position corrected, -27904 = 0 - 27904
04-01 01:07:49.670 17789 17837 V mpv : event: unpause
04-01 01:07:49.673 17789 17837 V mpv : [cplayer] End buffering (waited 0.775228 secs) [0.800000s].
04-01 01:07:49.677 17789 17837 V mpv : property: buffering = false
04-01 01:07:49.677 17789 17789 V PlayerActivity: state BUFFERING -> PLAYING
04-01 01:07:49.806 17789 17789 V mpvstats: AV: 9.135 A-V: 0.000 Dropped: 126 Cache: 0.576s + 0KB
04-01 01:07:49.883 17789 26691 W AudioTrack: releaseBuffer() track 0xb2ceed00 disabled due to previous underrun, restarting
04-01 01:07:50.016 17789 17837 V mpv : event: unpause
04-01 01:07:50.017 17789 17837 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
04-01 01:07:50.017 17789 17837 V mpv : property: buffering = true
04-01 01:07:50.017 17789 17789 V PlayerActivity: state PLAYING -> BUFFERING
04-01 01:07:50.018 17789 17789 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=0.0, end=10.463999999999942}], cache-end=10.495999999999185, reader-pts=10.495999999999185, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=5061760, fw-bytes=515008, debug-low-level-seeks=0, debug-ts-last=24560.9213, ts-per-stream=[{type=video, duration=1.5348666666686768, reader=24559.386433333333, end=24560.9213}, {type=audio, duration=0.0, reader=24560.5809, end=24560.5809}]}
04-01 01:07:50.073 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 0% -> 4%) [0.032000s].
04-01 01:07:50.074 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 4% -> 0%) [0.000000s].
04-01 01:07:50.074 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 0% -> 17%) [0.128000s].
04-01 01:07:50.074 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 17% -> 8%) [0.064000s].
04-01 01:07:50.418 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 8% -> 51%) [0.384000s].
04-01 01:07:50.668 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 51% -> 72%) [0.544000s].
04-01 01:07:50.717 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 72% -> 93%) [0.704000s].
04-01 01:07:50.808 17789 17789 V mpvstats: AV: 9.302 A-V: 0.935 Dropped: 127 Cache: 0.704s + 0KB
04-01 01:07:50.827 17789 17789 V mpvstats: AV: 9.302 A-V: 0.935 Dropped: 127 Cache: 0.704s + 0KB
04-01 01:07:50.921 17789 17837 V mpv : event: unpause
04-01 01:07:50.922 17789 17837 V mpv : [cplayer] End buffering (waited 0.902576 secs) [0.864000s].
04-01 01:07:50.925 17789 17837 V mpv : property: buffering = false
04-01 01:07:50.926 17789 17789 V PlayerActivity: state BUFFERING -> PLAYING
04-01 01:07:51.145 17789 26691 W AudioTrack: releaseBuffer() track 0xb2ceed00 disabled due to previous underrun, restarting
04-01 01:07:51.297 17789 17837 V mpv : event: unpause
04-01 01:07:51.297 17789 17837 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
04-01 01:07:51.298 17789 17837 V mpv : property: buffering = true
04-01 01:07:51.298 17789 17789 V PlayerActivity: state PLAYING -> BUFFERING
04-01 01:07:51.299 17789 17789 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=0.0, end=10.569466666667722}], cache-end=11.775999999998021, reader-pts=11.775999999998021, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=5639616, fw-bytes=698176, debug-low-level-seeks=0, debug-ts-last=24562.1225, ts-per-stream=[{type=video, duration=1.5348666666650388, reader=24560.587633333336, end=24562.1225}, {type=audio, duration=0.0, reader=24561.8609, end=24561.8609}]}
04-01 01:07:51.355 17789 17837 V mpv : [cplayer] Still buffering (buffer went from 0% -> 21%) [0.160000s].
04-01 01:07:51.355 17789 17837 V mpv : [cplayer] StillSame here. SD channels are completely unwatchable with Surround enabled. I have disabled it for now.