search

retrospect-addon / plugin.video.retrospect

Retrospect is a Kodi video add-on which allows you to watch streams of a number of free and publicly available online TV stream sites.
https://www.rieter.net/content/
GNU General Public License v3.0
113 stars 36 forks source link

Skipping frames for Vier.be #1089

Closed basrieter closed 4 years ago

basrieter commented 5 years ago

Original report by Siemon Geeroms (Bitbucket: siemonG, ).

First of all thanks for the add-on!

Almost everthing is working as desired but I have a minor issue playing streams from Vier, every once in a while a few frames are skipped. I first tought this was an issue with buffering on my raspberry but I also have this issue on my laptop. The strange part is that it always occurrs on the exact same time position, for example series "de dag" aflv 3 at 38:24.

Thanks in advanced

Siemon

basrieter commented 5 years ago

Original comment by Bas Rieter (Bitbucket: basrieter, GitHub: basrieter).

Does your Kodi log actually show some warnings about missed frames? I know that for some Dutch channels, they remove the commercials from the stream and that can cause some skipping or repeating in the stream.

basrieter commented 5 years ago

Original comment by Siemon Geeroms (Bitbucket: siemonG, ).

I don't think so because the stream itself is running smooth on the same time position on vier.be. Can it be that it's due to the fact that the ads are not being shown via the addon? These are ads that appear on the stream on the website at a regular time interval and can't be skipped. I will try to publish a log later this evening.

basrieter commented 5 years ago

Original comment by Dag Wieers (Bitbucket: dagwieers, GitHub: dagwieers).

Yes, we have noticed the exact same thing when watching "De Dag" and we have had this with all the episodes of this Series. The effect is that at given intervals the movie jumps back a certain period, and the only way to get past this point is to skip (forward) to some time after this specific time (which is hard to do). Throughout the episode this happens various times and it's really annoying to the point it is unwatchable.

It might as well be related to the fact that there would be ads at those points in time. (I didn't think of this myself)

basrieter commented 5 years ago

Original comment by Dag Wieers (Bitbucket: dagwieers, GitHub: dagwieers).

When watching the fourth episode now, I noticed it happens too often to be ad-intervals. I had it at 2:40 and again around the 4 minutes, which would be too early for ads (it had only just started, intro+slow start).

basrieter commented 5 years ago

Original comment by Dag Wieers (Bitbucket: dagwieers, GitHub: dagwieers).

It does also skip shortly at other intervals (around 6 minutes into the episode). This might be as a result from the first glitch though, it does seem to be better when stopping and restarting from where we were, but it will still happen.

basrieter commented 5 years ago

Original comment by Dag Wieers (Bitbucket: dagwieers, GitHub: dagwieers).

Videodecoder used is mmal-h264

LibreELEC is v8.95.003

Kodi is v18.0-RC5

Retrospect is v4.1.7.43

basrieter commented 5 years ago

Original comment by Dag Wieers (Bitbucket: dagwieers, GitHub: dagwieers).

I do find this in the logs apparently:

#!log
22:21:17.055 T:1936818848   ERROR: Control 55 in window 10025 has been asked to focus, but it can't
22:29:50.031 T:1936818848  NOTICE: VideoPlayer::OpenFile: plugin://net.rieter.xot/?action=playvideo&pickle=gAIoY21lZGlhaXRlbQpNZWRpYUl0ZW0KcQFvcQJ9cQMoVQhtZXRhRGF0YXEEfVUGcmF0aW5ncQVOVQ5NZWRpYUl0ZW1QYX
J0c3EGXVUJaXNDbG9ha2VkcQeJVQlhY3Rpb25VcmxxCE5VDmlzRHJtUHJvdGVjdGVkcQmJVQRndWlkcQpVQENDMDM5ODZDQ0U3RTk5M0JCREREOEEzQzE5QkYyNTkwQ0JDM0MwMkFENUE3OTAyQkJCMENFOUQwOUVDRDY3NjNVCGNvbXBsZXRlcQuJVQV0aHVtYnEMWPs
AAABodHRwczovL2ltYWdlcy52aWVydmlqZnplcy5iZS93d3cudmllci5iZS9wcm9kdWN0aW9uL21ldGEvbXY1Ym5kYzFuZGswemRtdG50Z3ltaTAwb2R5eWx0bGhvd3l0empsaXl6azJtenE1bm1xMnhrZXl4a2ZxY2dkZXF4dnltdHV4bXppM213djFzeDE3NzdjcjAw
MTc3Nzk5OWFsLmpwZz9hdXRvPWZvcm1hdCZmaXQ9Y3JvcCZoPTQ1MiZpeGxpYj1waHAtMS4xLjAmcT04NSZ3PTY4MiZzPWQxN2RkYWU5ZjI2ZWNkNmNhYTgzYTZmM2ZmODgyZmVmKVUGZmFuYXJ0cQ1YYgAAAHNwZWNpYWw6Ly9wcm9maWxlL2FkZG9uX2RhdGEvbmV0L
nJpZXRlci54b3QvdGV4dHVyZXMvbmV0LnJpZXRlci54b3QuY2hhbm5lbC5iZS52aWVyL3ZpZXJmYW5hcnQuanBncQ5VBmlzTGl2ZXEPiVUEaWNvbnEQWGAAAABzcGVjaWFsOi8vcHJvZmlsZS9hZGRvbl9kYXRhL25ldC5yaWV0ZXIueG90L3RleHR1cmVzL25ldC5yaW
V0ZXIueG90LmNoYW5uZWwuYmUudmllci92aWVyaWNvbi5wbmdxEVUEdHlwZXESVQV2aWRlb3ETVQtIdHRwSGVhZGVyc3EUfXEVVQtkZXNjcmlwdGlvbnEWVQBVC2lzR2VvTG9ja2VkcReIVRVfTWVkaWFJdGVtX190aW1lc3RhbXBxGGNkYXRldGltZQpkYXRldGltZQp
xGVUKB%2bMBERUZAAAAAIVScRpVFl9NZWRpYUl0ZW1fX2luZm9MYWJlbHNxG31VEF9NZWRpYUl0ZW1fX2RhdGVxHFUQMjAxOS0wMS0xNyAyMToyNVUGaXNQYWlkcR2JVQRuYW1lcR5YFQAAAERlIERhZyAtIEFmbGV2ZXJpbmcgNFUJZG9udEdyb3VwcR%2bJVQN1cmxx
IFU7aHR0cHM6Ly93d3cudmllci5iZS92aWRlby9kZS1kYWcvZGUtZGFnL2RlLWRhZy1hZmxldmVyaW5nLTRVBWl0ZW1zcSFdVQlndWlkVmFsdWVxIoohY2fNntDpDLsrkKfVKsDDy5Alvxk8it29O5l%2bzmyYA8wAdWIu&channel=chn_vier
22:29:50.032 T:1193276272  NOTICE: Creating InputStream
22:29:50.035 T:1193276272  NOTICE: Creating Demuxer
22:29:50.346 T:1193276272  NOTICE: Opening stream: 0 source: 256
22:29:50.347 T:1193276272  NOTICE: Creating video codec with codec id: 27
22:29:50.372 T:1193276272  NOTICE: Creating video thread
22:29:50.372 T:1143866224  NOTICE: running thread: video_thread
22:29:50.373 T:1193276272  NOTICE: Opening stream: 1 source: 256
22:29:50.373 T:1193276272  NOTICE: Finding audio codec for: 86018
22:29:50.374 T:1193276272  NOTICE: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder aac
22:29:50.374 T:1193276272  NOTICE: Creating audio thread
22:29:50.375 T:1184883568  NOTICE: running thread: CVideoPlayerAudio::Process()
22:29:50.648 T:1184883568  NOTICE: Creating audio stream (codec id: 86018, channels: 2, sample rate: 48000, no pass-through)
22:31:02.037 T:1184883568  NOTICE: CVideoPlayerAudio::Process - stream stalled
22:31:02.606 T:1903158128  NOTICE: CAESinkPi:AddPackets Underrun (delay:0.00 frames:2400)
22:31:46.675 T:1184883568  NOTICE: CVideoPlayerAudio::Process - stream stalled
22:31:47.243 T:1911550832 WARNING: ActiveAE - large audio sync error: 44329.779729
22:31:47.243 T:1903158128  NOTICE: CAESinkPi:AddPackets Underrun (delay:0.00 frames:2400)
22:31:47.244 T:1911550832 WARNING: ActiveAE - large audio sync error: 44327.811083
22:31:47.244 T:1911550832 WARNING: ActiveAE - large audio sync error: 44327.275614
22:31:47.244 T:1911550832 WARNING: ActiveAE - large audio sync error: 44327.807125
22:31:47.254 T:1911550832 WARNING: ActiveAE - large audio sync error: 44278.112335
22:31:47.664 T:1143866224 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer
22:31:50.246 T:1184883568 WARNING: Previous line repeats 4 times.
22:31:50.246 T:1184883568  NOTICE: CVideoPlayerAudio::Process - stream stalled
22:31:50.249 T:1143866224 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer
22:31:50.637 T:1903158128  NOTICE: CAESinkPi:AddPackets Underrun (delay:0.00 frames:2400)
22:33:21.021 T:1184883568  NOTICE: Previous line repeats 1 times.
22:33:21.022 T:1184883568  NOTICE: CVideoPlayerAudio::Process - stream stalled
22:33:21.530 T:1911550832 WARNING: ActiveAE - large audio sync error: 73129.824990
22:33:21.530 T:1903158128  NOTICE: CAESinkPi:AddPackets Underrun (delay:0.00 frames:2400)
22:33:21.531 T:1911550832 WARNING: ActiveAE - large audio sync error: 73127.882802
22:33:21.532 T:1911550832 WARNING: ActiveAE - large audio sync error: 73127.375250
22:33:21.532 T:1911550832 WARNING: ActiveAE - large audio sync error: 73127.833063
22:33:21.541 T:1911550832 WARNING: ActiveAE - large audio sync error: 73078.287387
22:33:21.947 T:1143866224 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer
22:33:24.548 T:1184883568 WARNING: Previous line repeats 5 times.
22:33:24.548 T:1184883568  NOTICE: CVideoPlayerAudio::Process - stream stalled
22:33:24.948 T:1903158128  NOTICE: CAESinkPi:AddPackets Underrun (delay:0.00 frames:2400)
22:35:30.662 T:1184883568  NOTICE: CVideoPlayerAudio::Process - stream stalled
22:35:31.235 T:1903158128  NOTICE: CAESinkPi:AddPackets Underrun (delay:0.00 frames:2400)
22:36:36.572 T:1184883568  NOTICE: CVideoPlayerAudio::Process - stream stalled
22:36:37.149 T:1903158128  NOTICE: CAESinkPi:AddPackets Underrun (delay:0.00 frames:2400)
22:36:46.985 T:1184883568  NOTICE: CVideoPlayerAudio::Process - stream stalled
22:36:47.739 T:1903158128  NOTICE: CAESinkPi:AddPackets Underrun (delay:0.00 frames:2400)

So it may seem an issue with the stream/buffering after all. But this happened for every episode on different days (last week and this week). We haven't watched any other streams from Vier or Vijf recently, so I don't know if it is a more common problem with Vier and Vijf.

basrieter commented 5 years ago

Original comment by Dag Wieers (Bitbucket: dagwieers, GitHub: dagwieers).

I have been monitoring closely now, when it skips (forward) you get this in the logs:

#!log

22:47:37.569 T:1184883568  NOTICE: CVideoPlayerAudio::Process - stream stalled
22:47:38.315 T:1903158128  NOTICE: CAESinkPi:AddPackets Underrun (delay:0.00 frames:2400)
basrieter commented 5 years ago

Original comment by Dag Wieers (Bitbucket: dagwieers, GitHub: dagwieers).

A short freeze is because of this:

#!log
22:49:19.341 T:1143866224 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer
basrieter commented 5 years ago

Original comment by Bas Rieter (Bitbucket: basrieter, GitHub: basrieter).

Yes, so it is a buffer thing. Could you post a debug retrospect.log. Just want to see what is used for playback. Perhaps I can consult some of the Kodi devs.

basrieter commented 5 years ago

Original comment by Dag Wieers (Bitbucket: dagwieers, GitHub: dagwieers).

Stream stalls for a long time, doesn't seem to recover.

#!log
22:57:54.691 T:1184883568  NOTICE: CVideoPlayerAudio::Process - stream stalled
22:57:55.396 T:1903158128  NOTICE: CAESinkPi:AddPackets Underrun (delay:0.00 frames:2400)
22:57:55.920 T:1143866224 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer
22:57:58.396 T:1184883568 WARNING: Previous line repeats 4 times.
22:57:58.396 T:1184883568  NOTICE: CVideoPlayerAudio::Process - stream stalled
22:57:58.487 T:1143866224 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer

We stopped playback, it did skip backwards but stalls.

basrieter commented 5 years ago

Original comment by Dag Wieers (Bitbucket: dagwieers, GitHub: dagwieers).

I will do so after we have finished this episode. Could we somehow increase the buffer size to outlive the issues ?

basrieter commented 5 years ago

Original comment by Dag Wieers (Bitbucket: dagwieers, GitHub: dagwieers).

Yeah, so once it had a buffer issue at a specific point in time, it skips back (sometimes a few seconds, sometimes a few minutes) replaying fails again at that point (so it starts looping from the point where it returns to and the point where it had the buffer underrun). I think that's the part where the decoder/player could recover better so the user doesn't have to remember the timestamp and try to skip just after that point in time.

basrieter commented 5 years ago

Original comment by Dag Wieers (Bitbucket: dagwieers, GitHub: dagwieers).

Just to test I took another series "Van Rossem" and we see the same problems.

So here is a piece of log where we had a minor skip and jump (a few seconds).

#!log
23:47:50.852 T:1664521072    INFO: ffmpeg[63369370]: [https] Opening 'https://stream2-vod.cdn1.sbs.prd.telenet-ops.be/non-geo/vier/vanrossem/volledigeafleveringen/8b68735ba41c4ac51ff2822a88e9601d7837f447/VAN_ROS
SEM_1_1_F0260507/Output1600/segment23.ts' for reading
23:47:50.853 T:1255134064   DEBUG: CMMALPool::Configure pool:0x57552bf0 960x540 (960x544) pix:-1 size:128 fmt:OPQV
23:48:08.766 T:1143866224   DEBUG: Previous line repeats 448 times.
23:48:08.766 T:1143866224  NOTICE: CVideoPlayerAudio::Process - stream stalled
23:48:08.767 T:1664521072   DEBUG: CVideoPlayer::HandlePlaySpeed - audio stream stalled, triggering re-sync
23:48:08.767 T:1664521072   DEBUG: CVideoPlayer::FlushBuffers - flushing buffers
23:48:08.803 T:1143866224   DEBUG: CDVDAudio::Flush - flush audio stream
23:48:08.803 T:1143866224   DEBUG: CDVDAudio::Pause - pausing audio stream
23:48:08.803 T:1143866224   DEBUG: CVideoPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
23:48:08.803 T:1125716848   DEBUG: CVideoPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
23:48:08.804 T:1664521072   DEBUG: CVideoPlayer::SetCaching - caching state 2
23:48:08.804 T:1664521072   DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000
23:48:08.805 T:1125716848    INFO: CVideoPlayerVideo - Stillframe left, switching to normal playback
23:48:08.806 T:1664521072   DEBUG: demuxer seek to: 286564.000000
23:48:08.814 T:1143866224   DEBUG: CDVDAudio::Pause - pausing audio stream
23:48:08.815 T:1664521072   DEBUG: SeekTime - unknown position after seek
23:48:08.815 T:1664521072   DEBUG: demuxer seek to: 286564.000000, success
23:48:08.815 T:1664521072   DEBUG: CVideoPlayer::FlushBuffers - flushing buffers
23:48:08.824 T:1143866224   DEBUG: CDVDAudio::Flush - flush audio stream
23:48:08.824 T:1143866224   DEBUG: CDVDAudio::Pause - pausing audio stream
23:48:08.827 T:1125716848   DEBUG: CVideoPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
23:48:08.827 T:1143866224   DEBUG: CVideoPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
23:48:08.827 T:1664521072    INFO: ffmpeg[63369370]: [hls,applehttp] Opening 'https://stream2-vod.cdn1.sbs.prd.telenet-ops.be/non-geo/vier/vanrossem/volledigeafleveringen/8b68735ba41c4ac51ff2822a88e9601d7837f447
/VAN_ROSSEM_1_1_F0260507/Output1600/segment22.ts' for reading
23:48:08.901 T:1936818848   DEBUG: ------ Window Init (DialogSeekBar.xml) ------
23:48:08.902 T:1903158128   DEBUG: CAESinkPi:Drain delay:97ms now:0ms
23:48:08.958 T:1664521072    INFO: ffmpeg[63369370]: [hls,applehttp] Opening 'https://stream2-vod.cdn1.sbs.prd.telenet-ops.be/non-geo/vier/vanrossem/volledigeafleveringen/8b68735ba41c4ac51ff2822a88e9601d7837f447
/VAN_ROSSEM_1_1_F0260507/Output1600/segment23.ts' for reading
23:48:09.132 T:1936818848   DEBUG: ------ Window Init (Custom_1109_TopBarOverlay.xml) ------
23:48:09.482 T:1664521072    INFO: ffmpeg[63369370]: [https] Opening 'https://stream2-vod.cdn1.sbs.prd.telenet-ops.be/non-geo/vier/vanrossem/volledigeafleveringen/8b68735ba41c4ac51ff2822a88e9601d7837f447/VAN_ROS
SEM_1_1_F0260507/Output1600/segment24.ts' for reading
23:48:09.547 T:1125716848    INFO: CVideoPlayerVideo - Stillframe left, switching to normal playback
23:48:09.560 T:1255134064   DEBUG: CMMALPool::Configure pool:0x57552bf0 960x540 (960x544) pix:-1 size:128 fmt:OPQV
23:48:09.561 T:1664521072   DEBUG: CVideoPlayer::HandleMessages - player started 1
23:48:09.561 T:1160651632   DEBUG: Thread JobWorker start, auto delete: true
23:48:09.561 T:1160651632   DEBUG: OnAVChange: CApplication::OnAVChange
23:48:09.565 T:1255134064   DEBUG: CMMALPool::Configure pool:0x57552bf0 960x540 (960x544) pix:-1 size:128 fmt:OPQV
23:48:09.587 T:1664521072   DEBUG: Previous line repeats 6 times.
23:48:09.587 T:1664521072   DEBUG: CVideoPlayer::HandleMessages - player started 2
23:48:09.587 T:1664521072   DEBUG: CVideoPlayer::SetCaching - caching state 3
23:48:09.587 T:1664521072   DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000
23:48:09.588 T:1664521072   DEBUG: CVideoPlayer::SetCaching - caching state 0
23:48:09.588 T:1664521072   DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000
23:48:09.588 T:1664521072   DEBUG: VideoPlayer::Sync - Audio - pts: 296192000.000000, cache: 320000.052452, totalcache: 699999.988079
23:48:09.588 T:1664521072   DEBUG: VideoPlayer::Sync - Video - pts: 296240000.000000, cache: 50000.000000, totalcache: 100000.000000
23:48:09.588 T:1125716848   DEBUG: CVideoPlayerVideo - CDVDMsg::GENERAL_RESYNC(296140000.000000)
23:48:09.588 T:1143866224   DEBUG: CVideoPlayerAudio - CDVDMsg::GENERAL_RESYNC(296140000.000000), level: 23, cache: 320000.052452
23:48:09.589 T:1143866224   DEBUG: CDVDAudio::Resume - resume audio stream
23:48:09.590 T:1903158128  NOTICE: CAESinkPi:AddPackets Underrun (delay:0.00 frames:2400)
23:48:09.590 T:1911550832   DEBUG: ActiveAE - start sync of audio stream
23:48:09.615 T:1936818848   DEBUG: CMMALRenderer::RenderUpdate - vsync 16087528 (+1)
23:48:09.635 T:1936814960   DEBUG: CAnnouncementManager - Announcement: OnAVChange from xbmc
23:48:09.638 T:1936814960   DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnAVChange
23:48:09.693 T:1911550832   DEBUG: ActiveAE::SyncStream - average error of -277.445235, start adjusting
23:48:09.694 T:1911550832   DEBUG: ActiveAE::SyncStream - average error -27.445235 below threshold of 30.000000
23:48:09.703 T:1255134064   DEBUG: CMMALPool::Configure pool:0x57552bf0 960x540 (960x544) pix:-1 size:128 fmt:OPQV
23:48:10.746 T:1143866224   DEBUG: Previous line repeats 25 times.
23:48:10.746 T:1143866224   DEBUG: CDVDClock::ErrorAdjust - CVideoPlayerAudio::OutputPacket - error:-92480.099460, adjusted:-92480.099460
23:48:10.939 T:1255134064   DEBUG: CMMALPool::Configure pool:0x57552bf0 960x540 (960x544) pix:-1 size:128 fmt:OPQV
23:48:11.843 T:1936818848   DEBUG: Previous line repeats 25 times.
23:48:11.844 T:1936818848   DEBUG: ------ Window Deinit (DialogSeekBar.xml) ------
23:48:12.001 T:1255134064   DEBUG: CMMALPool::Configure pool:0x57552bf0 960x540 (960x544) pix:-1 size:128 fmt:OPQV
23:48:12.056 T:1936818848   DEBUG: Previous line repeats 3 times.
23:48:12.056 T:1936818848   DEBUG: ------ Window Deinit (Custom_1109_TopBarOverlay.xml) ------
23:48:12.152 T:1255134064   DEBUG: CMMALPool::Configure pool:0x57552bf0 960x540 (960x544) pix:-1 size:128 fmt:OPQV
23:48:14.433 T:1125716848   DEBUG: Previous line repeats 57 times.
23:48:14.433 T:1125716848   DEBUG: CPtsTracker: detected pattern of length 1: 40000.00, frameduration: 40000.000000
basrieter commented 5 years ago

Original comment by Bas Rieter (Bitbucket: basrieter, GitHub: basrieter).

Ok, this is a Kodi streaming issue. I can't fix this. Again: if you attach (don't copy paste) a full debug retrospect.log I might be able to determine who could perhaps check this in the Kodi team.

basrieter commented 5 years ago

Original comment by Dag Wieers (Bitbucket: dagwieers, GitHub: dagwieers).

Ok, I will make a new debug log file (by restarting Kodi to start fresh). I didn't know I could attach a file (it didn't show in the comment interface).

basrieter commented 5 years ago

Original comment by Bas Rieter (Bitbucket: basrieter, GitHub: basrieter).

Top right side: more -> attach files. And please make sure it is a retrospect.log after enabling the DEBUG logging in Retrospect, then play the video and then attach the retrospect.log here.

basrieter commented 5 years ago

Original comment by Dag Wieers (Bitbucket: dagwieers, GitHub: dagwieers).

Good you mentioned it. (PS I thought you needed Kodi.log for the developers...)

basrieter commented 5 years ago

Original comment by Dag Wieers (Bitbucket: dagwieers, GitHub: dagwieers).

It did not happen that often when watching this, but I had to restart the playback of the stream because it froze.

basrieter commented 5 years ago

Original comment by Siemon Geeroms (Bitbucket: siemonG, ).

FYI, they are working with ads that interrupt the stream (like youtube does) on their site, could this be the source of the problem?

basrieter commented 5 years ago

Original comment by Bas Rieter (Bitbucket: basrieter, GitHub: basrieter).

That was my first suggestion. Either way, it is out of my hands.

basrieter commented 5 years ago

Original comment by Pascal Deklerck (Bitbucket: abanink, GitHub: abanink).

I also experience this behaviour: "The effect is that at given intervals the movie jumps back a certain period, and the only way to get past this point is to skip (forward) to some time after this specific time (which is hard to do)."

I managed to create a kodi.log output of exactly the point where it goes into a continuous repeat (until one manually skips forward). The stream I was using, was from vier: "De Dag", aflevering 3, at 18:56.

I'm attach the full file (kodi.log_pascal.gz) and the extract (kodilog_extract_jumpback.txt). One can see that kodi will fetch segments 86,67,88 and 89 over and over again. The retrospect.log file does not output anything at that point (DEBUG is on), and actually it does not say anything once the stream starts playing. I add it anyway (retrospect_pascal.log.gz)

Hope it might help.

basrieter commented 5 years ago

Original comment by Bas Rieter (Bitbucket: basrieter, GitHub: basrieter).

This is a pure Kodi issue, not Retrospect. As you concluded correctly: Retrospect does not log anything, because as soon as we pass the URL to Kodi, we are done. I can already tell you that this is most likely a corrupted stream. Or are there more that have this?

basrieter commented 5 years ago

Original comment by Siemon Geeroms (Bitbucket: siemonG, ).

every stream of vier that i have checked has this issue

basrieter commented 5 years ago

Original comment by Pascal Deklerck (Bitbucket: abanink, GitHub: abanink).

I want to add that, as a workaround, we watched an episode in a Chrome browser fullscreen window on the same machine and we had no interruption/jumpback issues at all. So is the 'corrupted stream' thesis still likely then?

Bas, did you make a ticket with the kodi team or is there any way we can contribute to the kodi team for this? I have some coding background but I have no experience with kodi nor with streaming so I would need a lot of self-study and maybe never get there at all.

basrieter commented 5 years ago

Original comment by Bas Rieter (Bitbucket: basrieter, GitHub: basrieter).

If it is only "De Dag", aflevering 3, the yes, it is a corrupted stream. You cannot, and should not, compare Kodi playback to browser playback. The streams could come from two completely different servers in a content distribution netwerk. Another thing is dat the stream is not a 100% compliant stream, and ffmpeg (what Kodi) uses just does not like it. The player from Vier.be might be a bit more forgiving.

So if it is just a single episode that has this problem, I don't think it is worth the effort to report a ticket with the Kodi Team. It will most likely be seen as an anomaly. However, if there are more streams that have this problem, then yes, a ticket could be created. But I would prefer the person having these issues (so all in here) to create these tickets. I don't want to be the man in the middle passing messages around. Post the link to the ticket here and I will help with providing more info as required.

basrieter commented 5 years ago

Original comment by Pascal Deklerck (Bitbucket: abanink, GitHub: abanink).

Totally agreed Bas and thanks for the explanation about the different stream sources. I have personally witnessed the issue in multiple episodes of 'De Dag', so the thesis about the not 100% ffmpeg-compliant stream sounds most plausible to me. So the question is if we/kodi can tweak it. Too bad there's only 24 hours in a day...

basrieter commented 5 years ago

Original comment by Dag Wieers (Bitbucket: dagwieers, GitHub: dagwieers).

The problem appears to happen not just for one episode, or one series, but for multiple (or all?) series at Vier (and possibly Vijf?). It's just that "De Dag" is watched online using Kodi more by people not having a digital TV subscription, I think. At least it is reproducible so it should be possible to fix.

@basrieter Thanks for acknowledging!

basrieter commented 5 years ago

Original comment by Bas Rieter (Bitbucket: basrieter, GitHub: basrieter).

Ok, so report it with the Kodi team. Provide the steps to reproduce it and attach a debug kodi.log to the issue. Also provide them an episode that has this problem and is viewable outside of Belgium. Otherwise, they can't test it.

basrieter commented 5 years ago

Original comment by Dag Wieers (Bitbucket: dagwieers, GitHub: dagwieers).

Yeah, outside access may be an issue, I was thinking of capturing and dumping parts of the streams (from beginning until it happens) so it can be replayed. We can actually do that several times to establish this is a stream problem (and not some other layer).

basrieter commented 5 years ago

Original comment by Bas Rieter (Bitbucket: basrieter, GitHub: basrieter).

If that works. Don't forget to post the link here.

basrieter commented 5 years ago

Original comment by Pascal Deklerck (Bitbucket: abanink, GitHub: abanink).

So I made a set-up trying to reproduce the issue locally. This is what I did:

It seems to me like the issue is reproduced but I'm not sure. I see in the log that ffmpeg is fetching segments 88 and 89 but never seems to get around to fetching segment90. When kodi is out of data, it syncs back to the previous segments. (this could explain why skipping forward a bit allow to continue watching)

Does anyone care to verify that I've actually reproduced the issue? I can send my code & contents; you'll need a local webserver at 'http://streaming.lan' or you'll have to modify these URLs in the code & m3u8 files.

basrieter commented 5 years ago

Original comment by Bas Rieter (Bitbucket: basrieter, GitHub: basrieter).

Ok, I will see if Peak3D is available, but after Leia we are all a bit occupied with make sure 18.1 becomes even nicer.

basrieter commented 5 years ago

Original comment by Bas Rieter (Bitbucket: basrieter, GitHub: basrieter).

Enige wat ik kan doen is de InputStream Adaptive configureren ipv standaard. Moment.

basrieter commented 5 years ago

Original comment by Bas Rieter (Bitbucket: basrieter, GitHub: basrieter).

Please try this one. Wel even zorgen dat je de InputStream Adaptive aan hebt staan binnen de Retrospect add-on settings.

basrieter commented 5 years ago

Original comment by Pascal Deklerck (Bitbucket: abanink, GitHub: abanink).

Quick test: have not seen the loop in 2 test runs. Just some hiccup around segment89. Attached log from fresh start-up.

basrieter commented 5 years ago

Original comment by Bas Rieter (Bitbucket: basrieter, GitHub: basrieter).

@abanink is dat met de nieuwe chn_vier.py?

basrieter commented 5 years ago

Original comment by Pascal Deklerck (Bitbucket: abanink, GitHub: abanink).

@basrieter jep mijn vorige logfile had eigenlijk moeten heten "..._noloop.log" want ik zag geen loop, wel nog hiccups.

basrieter commented 5 years ago

Original comment by Pascal Deklerck (Bitbucket: abanink, GitHub: abanink).

Log file van nieuwe run vanaf begin van De Dag - Aflevering3 met gemodificeerde chan_vier.py. Ongeveer 20 minuten gekeken - daarna gestopt vanwege geen tijd meer. Ervaringen:

1) enkele keren stopt het beeld terwijl de audio voortgaat. Dit lost zichzelf op na enkele (max 5) seconden en is m.i. minor (maar is dus niet vlekkeloos).

2) na download van segment 102 gaat het volledig mis en blijft het beeld stilstaan, ook geen audio. In de logfile vind je typisch terug

11:26:44.290 T:140442276460288 WARNING: ActiveAE - large audio sync error: 1331306.976818
11:26:44.354 T:140442276460288 WARNING: ActiveAE - large audio sync error: 1331256.965211
11:26:44.385 T:140442276460288 WARNING: ActiveAE - large audio sync error: 1331206.964095
11:26:44.448 T:140442276460288 WARNING: ActiveAE - large audio sync error: 1331156.963244
11:26:44.480 T:140442276460288 WARNING: ActiveAE - large audio sync error: 1331106.963099
11:26:44.544 T:140442276460288 WARNING: ActiveAE - large audio sync error: 1331056.964711
11:26:44.548 T:140440738883328 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer

Het vreemde is dat segment102 2 keer gedownload wordt; alsof kodi vergeten is om het volgende segment te downloaden, en daardoor met een lege buffer komt te zitten. Ik moest manueel wat doorspoelen om de boel te deblokkeren.

basrieter commented 5 years ago

Original comment by Bas Rieter (Bitbucket: basrieter, GitHub: basrieter).

Heb je ook een debug retrospect.log? Daar staat info in die ik nodig heb. Er moet wel een playback van de stream in staan.

basrieter commented 5 years ago

Original comment by Pascal Deklerck (Bitbucket: abanink, GitHub: abanink).

attached.

Goeie run begint op 11:04:33

Weet niet of erin staat wat je nodig hebt...

basrieter commented 5 years ago

Original comment by Bas Rieter (Bitbucket: basrieter, GitHub: basrieter).

@abanink Zijn deze streams regio gebonden?

BTW: de log retrospect.log is geen debug log. Dus ik kan er weinig mee.

basrieter commented 5 years ago

Original comment by Bas Rieter (Bitbucket: basrieter, GitHub: basrieter).

Zijn er vergelijkbare streams die gratis/niet regio gebonden zijn? Anders wordt het voor het Kodi team niet makkelijk om het te bekijken.

basrieter commented 5 years ago

Original comment by Bas Rieter (Bitbucket: basrieter, GitHub: basrieter).

Zouden jullie het eens kunnen proberen met de laatste chn_vier.py, met de InputStream Adaptive ingeschakeld binnen Retrospect en binnen de InputStream Adaptive zelf de optie Media naar Video? Je hebt dan enkel video, maar speelt ie dan wel door?

basrieter commented 5 years ago

Original comment by Pascal Deklerck (Bitbucket: abanink, GitHub: abanink).

Hello Bas

vergelijking van zelfde stream met videoOnly en audioVideo. Verschil is duidelijk: met video alleen heb ik geen issues gemerkt, met audio erbij bevriest het beeld regelmatig; soms voor ong. 5 seconden, soms definitief tot je genoeg doorspoelt.

basrieter commented 5 years ago

Original comment by Bas Rieter (Bitbucket: basrieter, GitHub: basrieter).

Het issue zit hem dus in de audio stream. Ga het melden.

basrieter commented 5 years ago

Original comment by Bas Rieter (Bitbucket: basrieter, GitHub: basrieter).

So the conclusion is: the vier.be streams have crappy audio. Not something we (Team Kodi) can fix right now. It is the main responsibility of vier.be (but don't start complaining that their streams don't play on Kodi, because the might not like that at all).

Could you try a lower bitrate for vier.be? You can set that via the context menu.

basrieter commented 5 years ago

Original comment by Steffoon (Bitbucket: steffoon, ).

There's definitely something funky with their stream segments. Funny thing about ffmpeg is that it has the Vier streaming issues we are experiencing here, but it perfectly works downloading and converting into mp4/mkv for playing back afterwards.

Not a real fix but perhaps a good enough temporary workaround until something better comes along.

basrieter commented 5 years ago

Original comment by Wouter van noort (Bitbucket: Arathonk , GitHub: Arathonk ).

Bas, I have the same problem, what should we do with "chn_vier.py"? And how can I lower the bitrate for just Vier.be?

basrieter commented 5 years ago

Original comment by Bas Rieter (Bitbucket: basrieter, GitHub: basrieter).

You replace the original one and then enable the adaptive inputstream add-on from the Retrospect settings.