groggyegg / plugin.video.dramacool

Watch Asian Drama and Korean Show with English subtitles on DramaCool.
MIT License
35 stars 15 forks source link

Rewind/Fast Forward "hangs" ; gets out of sync with video; long delays when resuming video #39

Closed chinenual closed 1 year ago

chinenual commented 2 years ago

Describe the bug

When rewinding or fast forwarding, video eventually stops updating and just "freezes". The time counter continues to advance. When PLAY is resumed, audio and video are out of sync (audio starts playing, video remains frozen for a while - sometimes eventually starts playing in sync). STOP the stream and resume seems to be the only reliable way to resume playback after one of these fast forward episodes.

Does not seem to depend on the proxy I choose (mp4upload, doodstream both fail in same way).

To Reproduce Steps to reproduce the behavior:

  1. Fast forward (or rewind) a stream.
  2. Wait a while - at some point, the video stops updating, but the time counter continues to advance.
  3. Press PLAY. Usually audio will start playing, but video will remain frozen.
  4. Wait a while (30-60s or more) and sometimes the video will catch up - but most often it won't.

The problem seems to happen more quickly at higher FF rates (16x, 32x), but I've seen it happen at 4x too.

Expected behavior Video should update itself while fast forwarding. Video and audio should both play in sync when resuming PLAY after a fast forward.

Log file

This is during an attempt to rewind about 10s :

2022-07-09 13:59:47.553 T:1312    ERROR <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
2022-07-09 14:00:00.780 T:1312     INFO <general>: Skipped 12 duplicate messages..
2022-07-09 14:00:00.780 T:1312    ERROR <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
2022-07-09 14:00:11.190 T:1312     INFO <general>: Skipped 3 duplicate messages..
2022-07-09 14:00:11.190 T:1312    ERROR <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
2022-07-09 14:00:20.175 T:798      INFO <general>: Skipped 5 duplicate messages..

Next set of logs is after pressing PLAY:

2022-07-09 14:00:20.175 T:798   WARNING <general>: ActiveAE - large audio sync error: 137370.876587
2022-07-09 14:00:20.175 T:798   WARNING <general>: ActiveAE - large audio sync error: 137371.875067
2022-07-09 14:00:20.176 T:798   WARNING <general>: ActiveAE - large audio sync error: 137370.876494
2022-07-09 14:00:20.176 T:798   WARNING <general>: ActiveAE - large audio sync error: 137371.876938
2022-07-09 14:00:20.185 T:1312    ERROR <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
2022-07-09 14:00:20.237 T:798      INFO <general>: Skipped 43 duplicate messages..
2022-07-09 14:00:20.237 T:798   WARNING <general>: ActiveAE - large audio sync error: 137320.904677
2022-07-09 14:00:20.287 T:798   WARNING <general>: ActiveAE - large audio sync error: 137321.898298
2022-07-09 14:00:20.337 T:798   WARNING <general>: ActiveAE - large audio sync error: 137271.872511
2022-07-09 14:00:20.387 T:798   WARNING <general>: ActiveAE - large audio sync error: 137221.944039
2022-07-09 14:00:20.437 T:798   WARNING <general>: ActiveAE - large audio sync error: 137171.905974
2022-07-09 14:00:20.487 T:798   WARNING <general>: ActiveAE - large audio sync error: 137121.899872
2022-07-09 14:00:20.537 T:798   WARNING <general>: ActiveAE - large audio sync error: 137071.876086
2022-07-09 14:00:20.587 T:798   WARNING <general>: ActiveAE - large audio sync error: 137021.950501
2022-07-09 14:00:20.637 T:798   WARNING <general>: ActiveAE - large audio sync error: 136971.916456

Additional context I'm not sure how to best diagnose this in order to pinpoint where the problem lies. Other video on demand plugins (e.g. Netflix and PlutoTV) seem to behave normally, so I suspect a problem with the dramacool plugin or one of its dependencies? How can I help get to the bottom of this?

I'm running

groggyegg commented 2 years ago

Tested on Ubuntu with Surface Pro 7 and can't reproduce it with Doodstream/Xstreamcdn. Have you tested to reproduce it on other device? Does changing cache size help? https://kodi.wiki/view/HOW-TO:Modify_the_video_cache

chinenual commented 2 years ago

I don't have an alternate device to test with. I'll see if cache size helps.

Anecdotally, I started noticing this rewind/ff behavior after updating from Kodi 18 to 19 - but that coincided with a change in hardware from an amlogic based setup box to the raspberry pi4 - so I can't be sure what specific change (or combination of changes) triggers the problem. I think I originally noticed the problem with one of Majide's plugins (VIKI or OnDramaNice?) (which I no longer use - it's been too long ago to remember exactly).

chinenual commented 2 years ago

I think the cache change is helping! I'll continue to test over the next few days, but the following setting seems to at least have made the simple REW or FF by 2x or 4x work reliably in my early testing.

  <cache>
    <buffermode>1</buffermode>
    <memorysize>139460608</memorysize>
    <readfactor>20</readfactor>
  </cache>

I'm still seeing the plugin crash if I try to FF 32x (after forwarding about 20min worth of video, I get the following error):

2022-07-17 20:25:00.225 T:968   WARNING <general>: OutputPicture - timeout waiting for buffer
2022-07-17 20:25:17.743 T:963      INFO <general>: Skipped 829 duplicate messages..
2022-07-17 20:25:17.743 T:963     ERROR <general>: CCurlFile::FillBuffer - Failed: Couldn't connect to server(7)
2022-07-17 20:25:17.744 T:963   WARNING <general>: CCurlFile::FillBuffer - Reconnect, (re)try 1
2022-07-17 20:25:28.467 T:960   WARNING <general>: CFileCache::Seek - <https://oll238o.dood.video/u5kju4tv6phlsdgge7pg6nyylawk23xucs2hzlwsbv2kmlfdjwnl73uj4cua/k31x2zaqi0~UqYiKbdYlm?token=5yzoqt9b23xsb656d6yinuu4&expiry=1658103729017|User-Agent=Mozilla%2F5.0+%28Windows+NT+10.0%3B+Win64%3B+x64%29+AppleWebKit%2F537.36+%28KHTML%2C+like+Gecko%29+Chrome%2F80.0.3987.132+Safari%2F537.36+OPR%2F67.0.3575.97&Referer=https%3A%2F%2Fdood.ws%2Fd%2Fanphqv4cnpep> failed to get remaining data
2022-07-17 20:25:28.467 T:960      INFO <general>: Process - eof reading from demuxer
2022-07-17 20:25:28.467 T:960      INFO <general>: CVideoPlayer::OnExit()
2022-07-17 20:25:28.467 T:960      INFO <general>: VideoPlayer: eof, waiting for queues to empty
2022-07-17 20:25:28.467 T:960      INFO <general>: Closing stream player 1
2022-07-17 20:25:28.467 T:960      INFO <general>: CDVDMessageQueue(audio)::WaitUntilEmpty
2022-07-17 20:25:28.475 T:960      INFO <general>: Waiting for audio thread to exit
2022-07-17 20:25:28.485 T:969      INFO <general>: thread end: CVideoPlayerAudio::OnExit()
2022-07-17 20:25:28.485 T:960      INFO <general>: Closing audio device
2022-07-17 20:25:28.486 T:960      INFO <general>: Deleting audio codec
2022-07-17 20:25:28.487 T:960      INFO <general>: Closing stream player 2
2022-07-17 20:25:28.487 T:960      INFO <general>: CDVDMessageQueue(video)::WaitUntilEmpty
2022-07-17 20:25:28.487 T:960      INFO <general>: waiting for video thread to exit
2022-07-17 20:25:28.487 T:968     ERROR <general>: Got MSGQ_ABORT or MSGO_IS_ERROR return true
2022-07-17 20:25:28.487 T:968      INFO <general>: thread end: video_thread
2022-07-17 20:25:28.488 T:960      INFO <general>: deleting video codec

I'll experiment with larger cache sizes - maybe that will solve this too!

groggyegg commented 1 year ago

Closing since this seems to be related to hardware.