Okay. If I am watching a recording of a stream that causes issues during a live feed, would that also cause the same bug with the hardware decoder?
Don't know without the logs. I'm just stating what I saw in your logs earlier when you said it was stalled during playback.
@jpblanch75 Are you sure the beta build has a problem, or did the problem just go away because you deleted and reinstalled the app?
I've uploaded a new beta which lets you choose Software decoding on Sony TVs. However I'm pretty sure the Sony TV CPU is too slow for that to work reliably.
Also in your DVR logs I'm seeing lots of random network errors that no one else's logs are showing:
dial tcp: i/o timeout
dial tcp: lookup data.tmsapi.com: No address associated with hostname
502 Bad Gateway
read tcp [2604:6000:1518:4008:5dec:9b4f:4782:9153]:39546->[2600:1f16:e2:8105:356d:89c4:6d72:54ec]:443: read: software caused connection abort
context deadline exceeded (Client.Timeout exceeded while awaiting headers)
Many of these seem to match up with when you're losing video. I'm also seeing the same thing in your client logs.. the video player stops receiving any audio/video data over the network.
I'd recommend turning off ipv6 on your network and also making sure you're using a reliable DNS server. If you're running pihole or some other dns filter, try turning that off for now.
2 Likes
I deleted and reinstalled the beta multiple times before I deleted and stopped the beta. I will say now that I have been streaming for 4 hours since then it still exhibits similar issues.
That is there from when I was playing with ipv6..... not recommended from my point of view.
I'm not losing video.... the stream buffers while the timeline is growing. After the 1-3 on and off minutes of buffereing, I can got back in the timeline where the buffering happened and rewatch it. No errors and blips and I didn't miss any content.
I'm not running anything special. I have a Netgear R7000 Router with a Netgear GS308 switch. Everything is wired.
I just installed the Beta and selected Software and its playing just fine. I told you this TV had a strong enough CPU. I posted what CPU this TV has
[SoC: (Mediatek) MT5893 4xARM Cortex A73 @ 1500Mhz with Mali G71 GPU along with Sony X1 Ultimate Chip]
I will test it and let you know. I'll also try out Hybrid.
@tmm1 I may be mixing issues here, but my initial testing of your latest beta build on my Sony TV indicates that software decoding resolves my issue with frequent short video hitches. I haven't spent a lot of time with it yet, but it seems to be running smoothly. So far so good, but what kind of issues could I expect to see if the CPU was too slow?
2 Likes
If the CPU is overloaded you will generally see frame drops and stuttering.
I'll test it for an extended period of time later tonight to confirm, but so far it is running much better than it ever has before with no stuttering. Thank you.
1 Like
I agree right now as I am not having any moments where the Audio continues while the screen freezes for a second then the screen takes off in Play X4 until it catches up to the audio. That was happening a few times an hour.
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?