Videos stuck reloading

[Anskrevy]

Description of issue: Running mpv /path/to/videos-directory mpv loads and plays the videos fine. However, after about 5 minutes, even as soon as 2 minutes or just randomly, a video will load and get stuck loading. I can fast-forward the video and it starts playing again but if I leave it alone for long enough mpv will freeze entirely requiring a forced shutdown.

mpv version: 34.1 using the latest reload.lua

I did a lot of trouble shooting with my config, and checking all my scripts to see which one was causing this issue. I ran mpv --msg-level='reload=debug' --no-msg-color /path/to/videos-directory and got this error

statusline: AV: 00:00:29 / 00:00:29 (98%) A-V: -0.000412 Vb: 980 kbps Ab: 105 kbps
    reload: demuxer_cache.transition continue_stuck {"in_state_time" = 28, "name" = "stuck", "demuxer_cache_time" = 125.621}

This script works great for youtube so I'll use profiles to work around the issue with local videos for the time being.

Please let me know what other info would be helpful in fixing this issue and I will provide it. This is easily reproducible for me but I don't have a lot of experience debugging mpv or scripts so I'm not sure what is and is not relevant.

Thanks.

[4e6]

Interesting, I've never experienced issues with local files. Can you please provide your MPV config and a full debug-level log (--msg-level='reload=debug') from start to the moment when the issue happens. If the issue happens for particular files, it would be helpful if you also provide a link to such file so I could try to reproduce the issue myself.

[Anskrevy]

Can you please provide your MPV config and a full debug-level log (--msg-level='reload=debug') from start to the moment when the issue happens.

Here is a log of the error happening 4 times back to back. I ran this with my entire mpv.conf file commented out but if you still think it is relevant I can provide it. I ran the first two tests in chronological order. Tests 3 and 4 I shuffled the playlist. The error happens as soon as the last video in the log loads. The log goes on for a little while because it took me a moment to register that the video had become stuck.

If the issue happens for particular files, it would be helpful if you also provide a link to such file so I could try to reproduce the issue myself.

It doesn't always happen with the same videos. I have a few directories that I play different files from and it happens with all of those directories at various times with various files. But maybe you see something in the log that indicate something different.

[4e6]

Thanks for the log. I see that you're playing a directory with a bunch of short files, and after it loads the read/035.webm,

Playing: read/035.webm
[reload] paused_for_cache.reset_timer 0
 (+) Video --vid=1 (*) (vp8 476x358 20.000fps)
 (+) Audio --aid=1 --alang=eng (*) (vorbis 2ch 44100Hz)
[reload] debug_info {"duration" = "41.853000", "pause" = "no", "stream_end" = "4491259", "event" = {"event" = "file-loaded"}, "paused_for_cache" = "no", "seekable" = "yes", "cache_buffering_state" = "100", "time_pos" = "0.000000"}
VO: [gpu] 476x358 => 477x358 yuv420p
AV: 00:00:29 / 00:00:30 (97%) A-V: 0.000017 Vb: 98 kbps Ab: 67 kbps
[reload] paused_for_cache.reset_timer 0
AV: 00:00:29 / 00:00:30 (97%) A-V: 0.000017 Vb: 98 kbps Ab: 67 kbps
[reload] demuxer_cache.transition continue_fetch {"in_state_time" = 388, "name" = "fetch", "demuxer_cache_time" = 1.453}
AV: 00:00:29 / 00:00:30 (97%) A-V: 0.000017 Vb: 98 kbps Ab: 67 kbps
[reload] demuxer_cache.transition fetch_to_stale {"in_state_time" = 0, "name" = "stale", "demuxer_cache_time" = 1.453}
AV: 00:00:29 / 00:00:30 (97%) A-V: 0.000017 Vb: 98 kbps Ab: 67 kbps
[reload] demuxer_cache.transition continue_stale {"in_state_time" = 2, "name" = "stale", "demuxer_cache_time" = 1.453}
AV: 00:00:29 / 00:00:30 (97%) A-V: 0.000017 Vb: 98 kbps Ab: 67 kbps
[reload] demuxer_cache.transition continue_stale {"in_state_time" = 4, "name" = "stale", "demuxer_cache_time" = 1.453}
AV: 00:00:29 / 00:00:30 (97%) A-V: 0.000017 Vb: 98 kbps Ab: 67 kbps
[reload] demuxer_cache.transition continue_stale {"in_state_time" = 6, "name" = "stale", "demuxer_cache_time" = 1.453}
AV: 00:00:29 / 00:00:30 (97%) A-V: 0.000017 Vb: 98 kbps Ab: 67 kbps
[reload] demuxer_cache.transition continue_stale {"in_state_time" = 8, "name" = "stale", "demuxer_cache_time" = 1.453}
AV: 00:00:29 / 00:00:30 (97%) A-V: 0.000017 Vb: 98 kbps Ab: 67 kbps
[reload] demuxer_cache.transition continue_stale {"in_state_time" = 10, "name" = "stale", "demuxer_cache_time" = 1.453}
AV: 00:00:29 / 00:00:30 (97%) A-V: 0.000017 Vb: 98 kbps Ab: 67 kbps
[reload] demuxer_cache.transition continue_stale {"in_state_time" = 12, "name" = "stale", "demuxer_cache_time" = 1.453}
AV: 00:00:29 / 00:00:30 (97%) A-V: 0.000017 Vb: 98 kbps Ab: 67 kbps
[reload] demuxer_cache.transition continue_stale {"in_state_time" = 14, "name" = "stale", "demuxer_cache_time" = 1.453}
AV: 00:00:29 / 00:00:30 (97%) A-V: 0.000017 Vb: 98 kbps Ab: 67 kbps
[reload] demuxer_cache.transition continue_stale {"in_state_time" = 16, "name" = "stale", "demuxer_cache_time" = 1.453}
AV: 00:00:29 / 00:00:30 (97%) A-V: 0.000017 Vb: 98 kbps Ab: 67 kbps
[reload] demuxer_cache.transition continue_stale {"in_state_time" = 18, "name" = "stale", "demuxer_cache_time" = 1.453}
AV: 00:00:29 / 00:00:30 (97%) A-V: 0.000017 Vb: 98 kbps Ab: 67 kbps
[reload] demuxer_cache.transition continue_stale {"in_state_time" = 20, "name" = "stale", "demuxer_cache_time" = 1.453}
AV: 00:00:29 / 00:00:30 (97%) A-V: 0.000017 Vb: 98 kbps Ab: 67 kbps
[reload] demuxer_cache.transition stale_to_stuck {"in_state_time" = 0, "name" = "stuck", "demuxer_cache_time" = 1.453}
AV: 00:00:29 / 00:00:30 (97%) A-V: 0.000017 Vb: 98 kbps Ab: 67 kbps
[reload] demuxer_cache.transition continue_stuck {"in_state_time" = 2, "name" = "stuck", "demuxer_cache_time" = 1.453}
AV: 00:00:29 / 00:00:30 (97%) A-V: 0.000017 Vb: 98 kbps Ab: 67 kbps
[reload] demuxer_cache.transition continue_stuck {"in_state_time" = 4, "name" = "stuck", "demuxer_cache_time" = 1.453}
AV: 00:00:29 / 00:00:30 (97%) A-V: 0.000017 Vb: 98 kbps Ab: 67 kbps

Exiting... (Quit)
[reload] Exiting...

the playback gets "paused" on the 29'th second, making the plugin think that the playback got stuck. For me, this situation looks similar to the #10 issue that was reported recently.

When this issue happens, can you resume the playback by pausing and unpausing the video (pressing the spacebar two times)? Did you notice if this situation when the video gets "paused" after loading happened before (without using the reload plugin)?

[Anskrevy]

When this issue happens, can you resume the playback by pausing and unpausing the video (pressing the spacebar two times)?

No I cannot. I can get it to resume playback by pressing ctrl+r, fast forwarding, or going to the next item on the playlist. If I do any of those things playback will resume but audio cuts out for about 5 seconds. Pressing spacebar twice, or any number of times, does nothing for me.

Did you notice if this situation when the video gets "paused" after loading happened before (without using the reload plugin)?

No I didn't. If I remove reload.lua from my scripts directory everything plays without this issue.

[4e6]

I found an issue with the number rounding #15 that may trigger the behavior that you're experiencing. Please check if it fixes the issue for you.

[Anskrevy]

I found an issue with the number rounding #15 that may trigger the behavior that you're experiencing. Please check if it fixes the issue for you.

Unfortunately not. I ran three tests and got two crashes. The 1st and 3rd stopped playing while the 2nd test played all files in the folder, about 50 videos. Here is the error log. The log only includes the tests where the video froze. I don't have a log of the test that completed successfully. The number of videos was so large that I can't scroll back far enough in my terminal to see the start of the successful test.