Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We鈥檒l occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

plugins.pluzz: slow to (or never) start playing #3588

Closed
1 of 2 tasks
marmeladema opened this issue Feb 27, 2021 · 1 comment
Closed
1 of 2 tasks

plugins.pluzz: slow to (or never) start playing #3588

marmeladema opened this issue Feb 27, 2021 · 1 comment
Labels
duplicate This issue or pull request already exists plugin issue A Plugin does not work correctly

Comments

@marmeladema
Copy link

First of all, thank you for this project! It's a very nice piece of work that I use almost every day 馃憤

Plugin Issue

  • This is a plugin issue and I have read the contribution guidelines.
  • I am using the latest development version from the master branch.

Description

I am using the latest release version 2.0.0 and I have difficulties to start playing pluzz streams.
The problem is that it takes a very long time to start (> 30 sec), and sometimes never actually start while still working in the "background" (downloading segments etc).
I have attached two logs, one for when it's slow to start (30sec to 1min), but ultimately starts, and a second one where nothing actually ever start playing.
For both logs, the command line used is:

$ streamlink -l trace --hls-audio-select '*' --ffmpeg-copyts --mux-subtitles --https-proxy "socks5h://192.168.178.2:1212" https://www.france.tv/france-2/direct.html best

I am using --ffmpeg-copyts option because of #3438 and I understand some delay is expected but more than 1 minute (when it works) seems too much and I wonder if there is another issue here.

Reproduction steps / Explicit stream URLs to test

  1. Run the command line pasted above.

Log output

Slow start log trace

In this log trace you can see that the command starts at 23:59:46 but the playing actually starts at 00:00:18 which makes it a 32sec delay, which is fairly acceptable in this case but can be much bigger frequently:

[23:59:46.105630][cli][debug] OS:         Linux-5.10.17_1-x86_64-with-glibc2.32
[23:59:46.105930][cli][debug] Python:     3.9.2
[23:59:46.106022][cli][debug] Streamlink: 2.0.0
[23:59:46.106123][cli][debug] Requests(2.25.1), Socks(1.7.0), Websocket(0.57.0)
[23:59:46.106321][cli][info] Found matching plugin pluzz for URL https://www.france.tv/france-2/direct.html
[23:59:46.106416][cli][debug] Plugin specific arguments:
[23:59:46.106505][cli][debug]  --mux-subtitles=True (mux_subtitles)
[23:59:46.180915][plugins.pluzz][debug] Country: GB
[23:59:46.399161][plugins.pluzz][debug] Video ID: 006194ea-117d-4bcf-94a9-153d999c59ae
[23:59:46.673290][plugins.pluzz][trace] {'format': 'hls', 'url': 'https://simulcast.ftven.fr/simulcast/France_2/hls_fr2/index.m3u8', 'statut': 'ONLINE', 'drm': False, 'geoblocage': None, 'plages_ouverture': [{'debut': None, 'fin': None}]}
[23:59:47.057671][utils.l10n][debug] Language code: en_US
[23:59:47.356047][stream.hls][debug] Using external audio tracks for stream 144p (language=fr, name=Francais), (language=qaa, name=Version Originale), (language=qad, name=Audio Description)
[23:59:47.356807][stream.hls][debug] Using external audio tracks for stream 216p (language=fr, name=Francais), (language=qaa, name=Version Originale), (language=qad, name=Audio Description)
[23:59:47.357507][stream.hls][debug] Using external audio tracks for stream 360p (language=fr, name=Francais), (language=qaa, name=Version Originale), (language=qad, name=Audio Description)
[23:59:47.358057][stream.hls][debug] Using external audio tracks for stream 540p (language=fr, name=Francais), (language=qaa, name=Version Originale), (language=qad, name=Audio Description)
[23:59:47.358603][stream.hls][debug] Using external audio tracks for stream 720p (language=fr, name=Francais), (language=qaa, name=Version Originale), (language=qad, name=Audio Description)
[23:59:47.360853][cli][info] Available streams: 144p (worst), 216p, 360p, 540p, 720p (best)
[23:59:47.361092][cli][info] Opening stream: 720p (hls-multi)
[23:59:47.361300][stream.ffmpegmux][debug] Opening hls substream
[23:59:47.361979][stream.hls][debug] Reloading playlist
[23:59:47.414323][stream.hls][debug] Segments in this playlist are encrypted
[23:59:47.414673][stream.hls][debug] First Sequence: 19431378; Last Sequence: 19431382
[23:59:47.414853][stream.hls][debug] Start offset: 0; Duration: None; Start Sequence: 19431380; End Sequence: None
[23:59:47.415689][stream.hls][debug] Adding segment 19431380 to queue
[23:59:47.420907][stream.ffmpegmux][debug] Opening hls substream
[23:59:47.421551][stream.hls][debug] Reloading playlist
[23:59:47.427708][stream.hls][debug] Adding segment 19431381 to queue
[23:59:47.428270][stream.hls][debug] Adding segment 19431382 to queue
[23:59:55.320397][stream.hls][debug] Segments in this playlist are encrypted
[23:59:55.320771][stream.hls][debug] First Sequence: 19431379; Last Sequence: 19431383
[23:59:55.321050][stream.hls][debug] Start offset: 0; Duration: None; Start Sequence: 19431381; End Sequence: None
[23:59:55.321952][stream.hls][debug] Adding segment 19431381 to queue
[23:59:55.322645][stream.ffmpegmux][debug] Opening hls substream
[23:59:55.327942][stream.hls][debug] Adding segment 19431382 to queue
[23:59:55.328671][stream.hls][debug] Reloading playlist
[23:59:55.329372][stream.hls][debug] Adding segment 19431383 to queue
[23:59:57.429047][stream.hls][debug] Reloading playlist
[00:00:04.454435][stream.hls][debug] Segments in this playlist are encrypted
[00:00:04.454842][stream.hls][debug] First Sequence: 19431381; Last Sequence: 19431385
[00:00:04.455165][stream.hls][debug] Start offset: 0; Duration: None; Start Sequence: 19431383; End Sequence: None
[00:00:04.456182][stream.hls][debug] Adding segment 19431383 to queue
[00:00:04.456516][stream.ffmpegmux][debug] Opening hls substream
[00:00:04.457899][stream.hls][debug] Reloading playlist
[00:00:04.470874][stream.hls][debug] Adding segment 19431384 to queue
[00:00:04.471293][stream.hls][debug] Adding segment 19431385 to queue
[00:00:04.483784][stream.hls][debug] Download of segment 19431380 complete
[00:00:04.518890][stream.hls][debug] Download of segment 19431381 complete
[00:00:06.335864][stream.hls][debug] Reloading playlist
[00:00:09.629478][stream.hls][debug] Segments in this playlist are encrypted
[00:00:09.629850][stream.hls][debug] First Sequence: 19431381; Last Sequence: 19431385
[00:00:09.630146][stream.hls][debug] Start offset: 0; Duration: None; Start Sequence: 19431383; End Sequence: None
[00:00:09.631220][stream.hls][debug] Adding segment 19431383 to queue
[00:00:09.637158][stream.hls][debug] Adding segment 19431384 to queue
[00:00:09.638062][stream.hls][debug] Adding segment 19431385 to queue
[00:00:09.639807][stream.ffmpegmux][debug] ffmpeg command: ffmpeg -nostats -y -i /tmp/ffmpeg-16851-965 -i /tmp/ffmpeg-16851-218 -i /tmp/ffmpeg-16851-985 -i /tmp/ffmpeg-16851-360 -c:v copy -c:a copy -map 0:v? -map 0:a? -map 1:a -map 2:a -map 3:a -copyts -f mpegts pipe:1
[00:00:09.640450][stream.ffmpegmux][debug] Starting copy to pipe: /tmp/ffmpeg-16851-965
[00:00:09.641175][stream.ffmpegmux][debug] Starting copy to pipe: /tmp/ffmpeg-16851-218
[00:00:09.641936][stream.ffmpegmux][debug] Starting copy to pipe: /tmp/ffmpeg-16851-985
[00:00:09.642630][stream.ffmpegmux][debug] Starting copy to pipe: /tmp/ffmpeg-16851-360
[00:00:09.653772][cli][debug] Pre-buffering 8192 bytes
[00:00:12.632486][stream.hls][debug] Segments in this playlist are encrypted
[00:00:12.632930][stream.hls][debug] Adding segment 19431383 to queue
[00:00:12.633349][stream.hls][debug] Adding segment 19431384 to queue
[00:00:12.634394][stream.hls][debug] Download of segment 19431381 complete
[00:00:12.637485][stream.hls][debug] Download of segment 19431382 complete
[00:00:12.639571][stream.hls][debug] Download of segment 19431383 complete
[00:00:12.679938][stream.hls][debug] Download of segment 19431382 complete
[00:00:13.036732][stream.hls][debug] Download of segment 19431383 complete
[00:00:13.463730][stream.hls][debug] Download of segment 19431384 complete
[00:00:15.472141][stream.hls][debug] Reloading playlist
[00:00:18.460449][stream.hls][debug] Download of segment 19431383 complete
[00:00:18.467061][cli][info] Starting player: /bin/vlc
[00:00:18.468261][cli.output][debug] Opening subprocess: /bin/vlc --input-title-format https://www.france.tv/france-2/direct.html -
[00:00:18.905374][stream.hls][debug] Download of segment 19431384 complete
[00:00:18.980292][cli][debug] Writing stream to output
[00:00:19.355769][stream.hls][debug] Download of segment 19431385 complete
[00:00:20.638754][stream.hls][debug] Reloading playlist
[00:00:21.171383][stream.hls][debug] Segments in this playlist are encrypted
[00:00:22.416324][stream.hls][debug] Download of segment 19431383 complete
[00:00:22.634156][stream.hls][debug] Reloading playlist
[00:00:22.772103][stream.hls][debug] Download of segment 19431385 complete
[00:00:22.794970][stream.hls][debug] Segments in this playlist are encrypted
[00:00:22.795483][stream.hls][debug] Adding segment 19431386 to queue
[00:00:22.797731][stream.hls][debug] Segments in this playlist are encrypted
[00:00:22.798138][stream.hls][debug] Adding segment 19431384 to queue
[00:00:22.798584][stream.hls][debug] Adding segment 19431385 to queue
[00:00:22.798889][stream.hls][debug] Adding segment 19431386 to queue
[00:00:22.799174][stream.hls][debug] Adding segment 19431387 to queue
[00:00:26.672603][stream.hls][debug] Reloading playlist
[00:00:27.651606][stream.hls][debug] Segments in this playlist are encrypted
[00:00:27.652088][stream.hls][debug] Adding segment 19431385 to queue
[00:00:28.350184][stream.hls][debug] Download of segment 19431386 complete
[00:00:28.457759][stream.hls][debug] Download of segment 19431384 complete
[00:00:31.310231][stream.hls][debug] Segments in this playlist are encrypted
[00:00:31.310651][stream.hls][debug] Adding segment 19431386 to queue
[00:00:31.311107][stream.hls][debug] Adding segment 19431387 to queue
[00:00:31.363437][stream.hls][debug] Download of segment 19431384 complete
[00:00:31.745829][stream.hls][debug] Download of segment 19431385 complete
[00:00:32.175328][stream.hls][debug] Download of segment 19431386 complete
[00:00:33.796355][stream.hls][debug] Reloading playlist
[00:00:33.803973][stream.hls][debug] Reloading playlist
[00:00:37.344640][stream.hls][debug] Download of segment 19431386 complete
[00:00:37.653062][stream.hls][debug] Reloading playlist
[00:00:37.770566][stream.hls][debug] Download of segment 19431387 complete
[00:00:39.369786][stream.hls][debug] Segments in this playlist are encrypted
[00:00:39.370230][stream.hls][debug] Adding segment 19431387 to queue
[00:00:39.389612][stream.hls][debug] Segments in this playlist are encrypted
[00:00:39.389946][stream.hls][debug] Adding segment 19431388 to queue
[00:00:40.884717][stream.hls][debug] Download of segment 19431385 complete
[00:00:40.894283][cli][info] Player closed
[00:00:40.894610][stream.ffmpegmux][debug] Closing ffmpeg thread
[00:00:40.895001][stream.segmented][debug] Closing worker thread
[00:00:40.895260][stream.segmented][debug] Closing writer thread
[00:00:40.895926][stream.segmented][debug] Closing worker thread
[00:00:40.896221][stream.segmented][debug] Closing writer thread
[00:00:40.901988][stream.ffmpegmux][error] Pipe copy aborted: /tmp/ffmpeg-16851-965
[00:00:40.902429][stream.ffmpegmux][error] Pipe copy aborted: /tmp/ffmpeg-16851-360
[00:00:40.902686][stream.ffmpegmux][error] Pipe copy aborted: /tmp/ffmpeg-16851-985
[00:00:40.902885][stream.ffmpegmux][error] Pipe copy aborted: /tmp/ffmpeg-16851-218
[00:00:41.249068][stream.segmented][debug] Closing worker thread
[00:00:41.249508][stream.segmented][debug] Closing writer thread
[00:00:41.250738][stream.segmented][debug] Closing worker thread
[00:00:41.251443][stream.segmented][debug] Closing writer thread
[00:00:41.252845][stream.hls][debug] Download of segment 19431387 complete
[00:00:41.707943][stream.ffmpegmux][debug] Closed all the substreams
[00:00:41.708332][cli][info] Stream ended
[00:00:41.709390][cli][info] Closing currently open stream...

Never starting log trace

In this log trace you can see that the command starts at 23:54:22 but never actually launches a player at any time. I had to kill the process at some point in order to try again:

[23:54:22.538693][cli][debug] OS:         Linux-5.10.17_1-x86_64-with-glibc2.32
[23:54:22.538939][cli][debug] Python:     3.9.2
[23:54:22.539006][cli][debug] Streamlink: 2.0.0
[23:54:22.539068][cli][debug] Requests(2.25.1), Socks(1.7.0), Websocket(0.57.0)
[23:54:22.539221][cli][info] Found matching plugin pluzz for URL https://www.france.tv/france-2/direct.html
[23:54:22.539288][cli][debug] Plugin specific arguments:
[23:54:22.539353][cli][debug]  --mux-subtitles=True (mux_subtitles)
[23:54:22.605465][plugins.pluzz][debug] Country: GB
[23:54:37.240081][plugins.pluzz][debug] Video ID: 006194ea-117d-4bcf-94a9-153d999c59ae
[23:54:37.546097][plugins.pluzz][trace] {'format': 'hls', 'url': 'https://simulcast.ftven.fr/simulcast/France_2/hls_fr2/index.m3u8', 'statut': 'ONLINE', 'drm': False, 'geoblocage': None, 'plages_ouverture': [{'debut': None, 'fin': None}]}
[23:54:37.849918][utils.l10n][debug] Language code: en_US
[23:54:52.176318][stream.hls][debug] Using external audio tracks for stream 144p (language=fr, name=Francais), (language=qaa, name=Version Originale), (language=qad, name=Audio Description)
[23:54:52.176958][stream.hls][debug] Using external audio tracks for stream 216p (language=fr, name=Francais), (language=qaa, name=Version Originale), (language=qad, name=Audio Description)
[23:54:52.177469][stream.hls][debug] Using external audio tracks for stream 360p (language=fr, name=Francais), (language=qaa, name=Version Originale), (language=qad, name=Audio Description)
[23:54:52.177937][stream.hls][debug] Using external audio tracks for stream 540p (language=fr, name=Francais), (language=qaa, name=Version Originale), (language=qad, name=Audio Description)
[23:54:52.178370][stream.hls][debug] Using external audio tracks for stream 720p (language=fr, name=Francais), (language=qaa, name=Version Originale), (language=qad, name=Audio Description)
[23:54:52.180169][cli][info] Available streams: 144p (worst), 216p, 360p, 540p, 720p (best)
[23:54:52.180361][cli][info] Opening stream: 720p (hls-multi)
[23:54:52.180552][stream.ffmpegmux][debug] Opening hls substream
[23:54:52.181082][stream.hls][debug] Reloading playlist
[23:54:55.482424][stream.hls][debug] Segments in this playlist are encrypted
[23:54:55.482754][stream.hls][debug] First Sequence: 19431348; Last Sequence: 19431352
[23:54:55.482975][stream.hls][debug] Start offset: 0; Duration: None; Start Sequence: 19431350; End Sequence: None
[23:54:55.483813][stream.hls][debug] Adding segment 19431350 to queue
[23:54:55.489045][stream.ffmpegmux][debug] Opening hls substream
[23:54:55.489677][stream.hls][debug] Reloading playlist
[23:54:55.494944][stream.hls][debug] Adding segment 19431351 to queue
[23:54:55.495299][stream.hls][debug] Adding segment 19431352 to queue
[23:55:05.495990][stream.hls][debug] Reloading playlist
[23:55:18.403671][stream.hls][debug] Segments in this playlist are encrypted
[23:55:18.404048][stream.hls][debug] First Sequence: 19431351; Last Sequence: 19431355
[23:55:18.404376][stream.hls][debug] Start offset: 0; Duration: None; Start Sequence: 19431353; End Sequence: None
[23:55:18.405398][stream.hls][debug] Adding segment 19431353 to queue
[23:55:18.405770][stream.ffmpegmux][debug] Opening hls substream
[23:55:18.407692][stream.hls][debug] Reloading playlist
[23:55:18.422071][stream.hls][debug] Adding segment 19431354 to queue
[23:55:18.422508][stream.hls][debug] Adding segment 19431355 to queue
[23:55:25.368428][stream.hls][debug] Segments in this playlist are encrypted
[23:55:25.368786][stream.hls][debug] First Sequence: 19431352; Last Sequence: 19431356
[23:55:25.369402][stream.hls][debug] Start offset: 0; Duration: None; Start Sequence: 19431354; End Sequence: None
[23:55:25.371820][stream.hls][debug] Adding segment 19431354 to queue
[23:55:25.372628][stream.ffmpegmux][debug] Opening hls substream
[23:55:25.373424][stream.hls][debug] Reloading playlist
[23:55:25.387011][stream.hls][debug] Adding segment 19431355 to queue
[23:55:25.387496][stream.hls][debug] Adding segment 19431356 to queue
[23:55:29.423124][stream.hls][debug] Reloading playlist
[23:55:30.080530][stream.hls][debug] Segments in this playlist are encrypted
[23:55:30.080983][stream.hls][debug] Adding segment 19431353 to queue
[23:55:30.083212][stream.hls][debug] Adding segment 19431354 to queue
[23:55:30.083621][stream.hls][debug] Adding segment 19431355 to queue
[23:55:30.085389][stream.hls][debug] Segments in this playlist are encrypted
[23:55:30.085729][stream.hls][debug] First Sequence: 19431353; Last Sequence: 19431357
[23:55:30.085934][stream.hls][debug] Start offset: 0; Duration: None; Start Sequence: 19431355; End Sequence: None
[23:55:30.087574][stream.hls][debug] Adding segment 19431355 to queue
[23:55:30.093746][stream.hls][debug] Adding segment 19431356 to queue
[23:55:30.094160][stream.hls][debug] Adding segment 19431357 to queue
[23:55:30.096319][stream.ffmpegmux][debug] ffmpeg command: ffmpeg -nostats -y -i /tmp/ffmpeg-15040-616 -i /tmp/ffmpeg-15040-601 -i /tmp/ffmpeg-15040-978 -i /tmp/ffmpeg-15040-575 -c:v copy -c:a copy -map 0:v? -map 0:a? -map 1:a -map 2:a -map 3:a -copyts -f mpegts pipe:1
[23:55:30.096967][stream.ffmpegmux][debug] Starting copy to pipe: /tmp/ffmpeg-15040-616
[23:55:30.097632][stream.ffmpegmux][debug] Starting copy to pipe: /tmp/ffmpeg-15040-601
[23:55:30.098317][stream.ffmpegmux][debug] Starting copy to pipe: /tmp/ffmpeg-15040-978
[23:55:30.098979][stream.ffmpegmux][debug] Starting copy to pipe: /tmp/ffmpeg-15040-575
[23:55:30.108975][cli][debug] Pre-buffering 8192 bytes
[23:55:36.388219][stream.hls][debug] Reloading playlist
[23:55:37.139399][stream.hls][debug] Download of segment 19431350 complete
[23:55:37.187099][stream.hls][debug] Download of segment 19431351 complete
[23:55:41.084558][stream.hls][debug] Reloading playlist
[23:55:41.095213][stream.hls][debug] Reloading playlist
[23:55:43.391438][stream.hls][debug] Segments in this playlist are encrypted
[23:55:43.391791][stream.hls][debug] Adding segment 19431357 to queue
[23:55:43.392182][stream.hls][debug] Adding segment 19431358 to queue
[23:55:45.671144][stream.hls][debug] Download of segment 19431355 complete
[23:55:46.692272][stream.hls][debug] Download of segment 19431356 complete
[23:55:47.931281][stream.hls][debug] Download of segment 19431352 complete
[23:55:53.651893][stream.hls][debug] Download of segment 19431357 complete
[23:55:54.392796][stream.hls][debug] Reloading playlist
[23:55:55.268605][stream.hls][debug] Segments in this playlist are encrypted
[23:55:55.269028][stream.hls][debug] Adding segment 19431356 to queue
[23:55:55.269516][stream.hls][debug] Adding segment 19431357 to queue
[23:55:55.269861][stream.hls][debug] Adding segment 19431358 to queue
[23:55:55.270175][stream.hls][debug] Adding segment 19431359 to queue
[23:56:01.542436][stream.hls][debug] Segments in this playlist are encrypted
[23:56:01.542951][stream.hls][debug] Adding segment 19431359 to queue
[23:56:01.544017][stream.hls][debug] Adding segment 19431360 to queue
[23:56:06.270653][stream.hls][debug] Reloading playlist
[23:56:06.693913][stream.hls][debug] Download of segment 19431353 complete
[23:56:07.049504][stream.hls][debug] Segments in this playlist are encrypted
[23:56:07.049875][stream.hls][debug] Adding segment 19431358 to queue
[23:56:07.050316][stream.hls][debug] Adding segment 19431359 to queue
[23:56:07.050667][stream.hls][debug] Adding segment 19431360 to queue
[23:56:07.054593][stream.hls][debug] Segments in this playlist are encrypted
[23:56:07.054956][stream.hls][debug] Adding segment 19431356 to queue
[23:56:07.055311][stream.hls][debug] Adding segment 19431357 to queue
[23:56:07.055681][stream.hls][debug] Adding segment 19431358 to queue
[23:56:07.055982][stream.hls][debug] Adding segment 19431359 to queue
[23:56:11.893327][stream.hls][debug] Segments in this playlist are encrypted
[23:56:11.893692][stream.hls][debug] Adding segment 19431360 to queue
[23:56:11.894152][stream.hls][debug] Adding segment 19431361 to queue
[23:56:12.545349][stream.hls][debug] Reloading playlist
[23:56:14.934973][stream.hls][debug] Download of segment 19431358 complete
[23:56:18.051298][stream.hls][debug] Reloading playlist
[23:56:18.057374][stream.hls][debug] Reloading playlist
[23:56:19.431040][stream.hls][debug] Segments in this playlist are encrypted
[23:56:19.431406][stream.hls][debug] Adding segment 19431361 to queue
[23:56:22.894936][stream.hls][debug] Reloading playlist
[23:56:23.101406][stream.hls][debug] Download of segment 19431359 complete
[23:56:24.850169][stream.hls][debug] Segments in this playlist are encrypted
[23:56:24.850541][stream.hls][debug] Adding segment 19431361 to queue
[23:56:24.850950][stream.hls][debug] Adding segment 19431362 to queue
[23:56:24.855242][stream.hls][debug] Segments in this playlist are encrypted
[23:56:24.855604][stream.hls][debug] Adding segment 19431360 to queue
[23:56:24.856068][stream.hls][debug] Adding segment 19431361 to queue
[23:56:24.891714][stream.hls][debug] Download of segment 19431354 complete
[23:56:28.085254][stream.hls][error] Failed to open segment 19431353: Unable to open URL: https://simulcast.ftven.fr/ZXhwPTE2MTQ0MDUyNzd+YWNsPSUyZip+aG1hYz01OGRhZjE0NGY4NTRkOTdjMjU2ZmYxOTk3ZDU2YmI4ZjE2NjczOWFhZTEyZmM2YWRiM2JiMDBiZjYwMjZmNWI3/simulcast/France_2/hls_fr2/France_2-mp4a_98400_fra=20000-begin=1943132649710778-dur=99840000-seq=19431353.ts (SOCKSHTTPSConnectionPool(host='simulcast.ftven.fr', port=443): Read timed out. (read timeout=10.0))
[23:56:29.676890][stream.hls][debug] Segments in this playlist are encrypted
[23:56:29.677328][stream.hls][debug] Adding segment 19431362 to queue
[23:56:30.432040][stream.hls][debug] Reloading playlist
[23:56:30.492985][stream.hls][debug] Download of segment 19431360 complete
[23:56:32.950365][stream.hls][error] Failed to open segment 19431354: Unable to open URL: https://simulcast.ftven.fr/ZXhwPTE2MTQ0MDUyNzd+YWNsPSUyZip+aG1hYz01OGRhZjE0NGY4NTRkOTdjMjU2ZmYxOTk3ZDU2YmI4ZjE2NjczOWFhZTEyZmM2YWRiM2JiMDBiZjYwMjZmNWI3/simulcast/France_2/hls_fr2/France_2-mp4a_98400_qaa=20002-begin=1943132749550778-dur=100053333-seq=19431354.ts (SOCKSHTTPSConnectionPool(host='simulcast.ftven.fr', port=443): Read timed out. (read timeout=10.0))
[23:56:35.851665][stream.hls][debug] Reloading playlist
[23:56:35.858495][stream.hls][debug] Reloading playlist
[23:56:37.287346][stream.ffmpegmux][error] Pipe copy aborted: /tmp/ffmpeg-15040-601
[23:56:37.873138][stream.hls][debug] Segments in this playlist are encrypted
[23:56:37.873600][stream.hls][debug] Adding segment 19431362 to queue
[23:56:37.874052][stream.hls][debug] Adding segment 19431363 to queue
[23:56:39.293223][stream.hls][debug] Download of segment 19431361 complete
[23:56:40.678133][stream.hls][debug] Reloading playlist
[23:56:42.610739][stream.hls][debug] Segments in this playlist are encrypted
[23:56:42.611156][stream.hls][debug] Adding segment 19431363 to queue
[23:56:42.612057][stream.hls][debug] Adding segment 19431364 to queue
[23:56:42.692271][stream.hls][debug] Segments in this playlist are encrypted
[23:56:42.692695][stream.hls][debug] Adding segment 19431362 to queue
[23:56:42.693048][stream.hls][debug] Adding segment 19431363 to queue
[23:56:44.466008][stream.hls][debug] Download of segment 19431362 complete
[23:56:44.479885][stream.hls][debug] Segments in this playlist are encrypted
[23:56:44.480349][stream.hls][debug] Adding segment 19431363 to queue
[23:56:44.480850][stream.hls][debug] Adding segment 19431364 to queue
[23:56:48.874712][stream.hls][debug] Reloading playlist
[23:56:49.789823][stream.hls][debug] Download of segment 19431363 complete
[23:56:53.030431][stream.hls][debug] Segments in this playlist are encrypted
[23:56:53.030804][stream.hls][debug] Adding segment 19431364 to queue
[23:56:53.031235][stream.hls][debug] Adding segment 19431365 to queue
[23:56:53.612746][stream.hls][debug] Reloading playlist
[23:56:53.886677][stream.hls][debug] Download of segment 19431354 complete
[23:56:53.887565][stream.hls][debug] Download of segment 19431364 complete
[23:56:54.280308][stream.hls][debug] Download of segment 19431355 complete
[23:56:55.481627][stream.hls][debug] Reloading playlist
[23:56:59.598522][stream.hls][debug] Segments in this playlist are encrypted
[23:56:59.598884][stream.hls][debug] Adding segment 19431365 to queue
[23:57:00.061942][stream.hls][debug] Download of segment 19431356 complete
[23:57:01.129385][stream.hls][debug] Segments in this playlist are encrypted
[23:57:01.129769][stream.hls][debug] Adding segment 19431365 to queue
[23:57:03.559688][stream.hls][debug] Download of segment 19431365 complete
[23:57:04.031915][stream.hls][debug] Reloading playlist
[23:57:04.442867][stream.hls][debug] Download of segment 19431357 complete
[23:57:09.480778][stream.hls][debug] Segments in this playlist are encrypted
[23:57:09.481172][stream.hls][debug] Adding segment 19431366 to queue
[23:57:09.484924][stream.hls][debug] Adding segment 19431367 to queue
[23:57:09.907101][stream.hls][debug] Download of segment 19431358 complete
[23:57:10.600041][stream.hls][debug] Reloading playlist
[23:57:10.729310][stream.hls][debug] Download of segment 19431355 complete
[23:57:10.730363][stream.hls][debug] Download of segment 19431356 complete
[23:57:10.731391][stream.hls][debug] Download of segment 19431357 complete
[23:57:10.732517][stream.hls][debug] Download of segment 19431358 complete
[23:57:12.130568][stream.hls][debug] Reloading playlist
[23:57:13.335571][stream.hls][debug] Download of segment 19431359 complete
[23:57:13.750055][stream.hls][debug] Segments in this playlist are encrypted
[23:57:13.750486][stream.hls][debug] Adding segment 19431366 to queue
[23:57:13.750965][stream.hls][debug] Adding segment 19431367 to queue
[23:57:13.763169][stream.hls][debug] Segments in this playlist are encrypted
[23:57:13.763615][stream.hls][debug] Adding segment 19431366 to queue
[23:57:13.764044][stream.hls][debug] Adding segment 19431367 to queue
[23:57:13.764433][stream.hls][debug] Adding segment 19431368 to queue
[23:57:13.771704][stream.hls][debug] Download of segment 19431359 complete
[23:57:18.843814][stream.hls][debug] Download of segment 19431360 complete
[23:57:19.613796][stream.hls][debug] Download of segment 19431360 complete
[23:57:19.682657][stream.hls][debug] Download of segment 19431366 complete
[23:57:20.485773][stream.hls][debug] Reloading playlist
[23:57:23.193841][stream.hls][debug] Download of segment 19431361 complete
[23:57:23.624755][stream.hls][debug] Download of segment 19431361 complete
[23:57:24.029660][stream.hls][debug] Segments in this playlist are encrypted
[23:57:24.030059][stream.hls][debug] Adding segment 19431368 to queue
[23:57:24.033597][stream.hls][debug] Download of segment 19431367 complete
[23:57:24.751738][stream.hls][debug] Reloading playlist
[23:57:24.765119][stream.hls][debug] Reloading playlist
[23:57:29.402799][stream.hls][debug] Download of segment 19431362 complete
[23:57:29.854520][stream.hls][debug] Download of segment 19431362 complete
[23:57:30.379407][stream.hls][debug] Segments in this playlist are encrypted
[23:57:30.379788][stream.hls][debug] Adding segment 19431369 to queue
[23:57:30.382972][stream.hls][debug] Segments in this playlist are encrypted
[23:57:30.383318][stream.hls][debug] Adding segment 19431368 to queue
[23:57:30.383696][stream.hls][debug] Adding segment 19431369 to queue
[23:57:33.226256][stream.hls][debug] Download of segment 19431363 complete
[23:57:33.674032][stream.hls][debug] Download of segment 19431363 complete
[23:57:34.151418][stream.hls][debug] Download of segment 19431368 complete
[23:57:35.030838][stream.hls][debug] Reloading playlist
[23:57:39.464558][stream.hls][debug] Download of segment 19431364 complete
[23:57:39.893812][stream.hls][debug] Download of segment 19431364 complete
[23:57:40.279884][stream.hls][debug] Download of segment 19431369 complete
[23:57:41.060035][stream.hls][debug] Segments in this playlist are encrypted
[23:57:41.060455][stream.hls][debug] Adding segment 19431369 to queue
[23:57:41.380582][stream.hls][debug] Reloading playlist
[23:57:41.385125][stream.hls][debug] Reloading playlist
[23:57:43.603515][stream.hls][debug] Download of segment 19431365 complete
[23:57:44.031252][stream.hls][debug] Segments in this playlist are encrypted
[23:57:44.031627][stream.hls][debug] Adding segment 19431370 to queue
[23:57:44.033795][stream.hls][debug] Segments in this playlist are encrypted
[23:57:44.034104][stream.hls][debug] Adding segment 19431370 to queue
[23:57:44.046161][stream.hls][debug] Download of segment 19431365 complete
[23:57:49.223668][stream.hls][debug] Download of segment 19431366 complete
[23:57:49.703052][stream.hls][debug] Download of segment 19431366 complete
[23:57:50.049126][stream.hls][debug] Download of segment 19431370 complete
[23:57:52.061232][stream.hls][debug] Reloading playlist
[23:57:53.563073][stream.hls][debug] Download of segment 19431367 complete
[23:57:53.999675][stream.hls][debug] Segments in this playlist are encrypted
[23:57:54.000094][stream.hls][debug] Adding segment 19431370 to queue
[23:57:54.000550][stream.hls][debug] Adding segment 19431371 to queue
[23:57:54.000869][stream.hls][debug] Adding segment 19431372 to queue
[23:57:54.006723][stream.hls][debug] Download of segment 19431367 complete
[23:57:55.032752][stream.hls][debug] Reloading playlist
[23:57:55.037206][stream.hls][debug] Reloading playlist
[23:57:59.263943][stream.hls][debug] Download of segment 19431368 complete
[23:57:59.685197][stream.hls][debug] Download of segment 19431368 complete
[23:58:00.750398][stream.hls][debug] Segments in this playlist are encrypted
[23:58:00.750967][stream.hls][debug] Adding segment 19431371 to queue
[23:58:00.751558][stream.hls][debug] Adding segment 19431372 to queue
[23:58:00.756212][stream.hls][debug] Segments in this playlist are encrypted
[23:58:00.756641][stream.hls][debug] Adding segment 19431371 to queue
[23:58:03.010814][stream.hls][debug] Download of segment 19431369 complete
[23:58:03.484569][stream.hls][debug] Download of segment 19431369 complete
[23:58:03.773562][stream.hls][debug] Download of segment 19431371 complete
[23:58:04.265355][stream.hls][debug] Download of segment 19431370 complete
[23:58:04.695433][stream.hls][debug] Download of segment 19431370 complete
[23:58:05.001486][stream.hls][debug] Reloading playlist
[23:58:05.109125][stream.hls][debug] Download of segment 19431372 complete
[23:58:05.535215][stream.hls][debug] Download of segment 19431371 complete
[23:58:05.921629][stream.hls][debug] Download of segment 19431371 complete
[23:58:05.939299][stream.hls][debug] Segments in this playlist are encrypted
[23:58:05.939744][stream.hls][debug] Adding segment 19431373 to queue
[23:58:06.365931][stream.hls][debug] Download of segment 19431372 complete
[23:58:06.840908][stream.hls][debug] Download of segment 19431373 complete
[23:58:11.752457][stream.hls][debug] Reloading playlist
[23:58:11.758566][stream.hls][debug] Reloading playlist
[23:58:11.791915][stream.hls][debug] Segments in this playlist are encrypted
[23:58:11.792290][stream.hls][debug] Adding segment 19431373 to queue
[23:58:11.814313][stream.hls][debug] Segments in this playlist are encrypted
[23:58:11.814703][stream.hls][debug] Adding segment 19431372 to queue
[23:58:11.815159][stream.hls][debug] Adding segment 19431373 to queue
[23:58:12.228873][stream.hls][debug] Download of segment 19431373 complete
[23:58:12.674423][stream.hls][debug] Download of segment 19431372 complete
[23:58:13.120277][stream.hls][debug] Download of segment 19431373 complete
[23:58:16.940478][stream.hls][debug] Reloading playlist
[23:58:16.981148][stream.hls][debug] Segments in this playlist are encrypted
[23:58:16.981706][stream.hls][debug] Adding segment 19431374 to queue
[23:58:17.439455][stream.hls][debug] Download of segment 19431374 complete
[23:58:22.793171][stream.hls][debug] Reloading playlist
[23:58:22.815763][stream.hls][debug] Reloading playlist
[23:58:22.832978][stream.hls][debug] Segments in this playlist are encrypted
[23:58:22.833340][stream.hls][debug] Adding segment 19431374 to queue
[23:58:22.858131][stream.hls][debug] Segments in this playlist are encrypted
[23:58:22.858875][stream.hls][debug] Adding segment 19431374 to queue
[23:58:23.269104][stream.hls][debug] Download of segment 19431374 complete
[23:58:23.670510][stream.hls][debug] Download of segment 19431374 complete
[23:58:27.982749][stream.hls][debug] Reloading playlist
[23:58:28.024649][stream.hls][debug] Segments in this playlist are encrypted
[23:58:28.025056][stream.hls][debug] Adding segment 19431375 to queue
[23:58:28.025482][stream.hls][debug] Adding segment 19431376 to queue
[23:58:28.484464][stream.hls][debug] Download of segment 19431375 complete
[23:58:28.928581][stream.hls][debug] Download of segment 19431376 complete
[23:58:33.833969][stream.hls][debug] Reloading playlist
[23:58:33.859601][stream.hls][debug] Reloading playlist
[23:58:33.874259][stream.hls][debug] Segments in this playlist are encrypted
[23:58:33.874675][stream.hls][debug] Adding segment 19431375 to queue
[23:58:34.026516][stream.hls][debug] Segments in this playlist are encrypted
[23:58:34.026933][stream.hls][debug] Adding segment 19431375 to queue
[23:58:34.339484][stream.hls][debug] Download of segment 19431375 complete
[23:58:34.778537][stream.hls][debug] Download of segment 19431375 complete
[23:58:39.026172][stream.hls][debug] Reloading playlist
[23:58:39.066869][stream.hls][debug] Segments in this playlist are encrypted
[23:58:44.567597][stream.hls][debug] Reloading playlist
[23:58:44.610404][stream.hls][debug] Segments in this playlist are encrypted
[23:58:44.610824][stream.hls][debug] Adding segment 19431377 to queue
[23:58:44.875636][stream.hls][debug] Reloading playlist
[23:58:45.027736][stream.hls][debug] Reloading playlist
[23:58:45.091476][stream.hls][debug] Segments in this playlist are encrypted
[23:58:45.091840][stream.hls][debug] Adding segment 19431376 to queue
[23:58:45.093594][stream.hls][debug] Segments in this playlist are encrypted
[23:58:45.093906][stream.hls][debug] Adding segment 19431376 to queue
[23:58:45.094234][stream.hls][debug] Adding segment 19431377 to queue
[23:58:45.106936][stream.hls][debug] Download of segment 19431377 complete
[23:58:45.689208][stream.hls][debug] Download of segment 19431376 complete
[23:58:46.003786][stream.hls][debug] Download of segment 19431376 complete
[23:58:46.469472][stream.hls][debug] Download of segment 19431377 complete
[23:58:55.611593][stream.hls][debug] Reloading playlist
[23:58:55.650389][stream.hls][debug] Segments in this playlist are encrypted
[23:58:56.092772][stream.hls][debug] Reloading playlist
[23:58:56.097486][stream.hls][debug] Reloading playlist
[23:58:56.136263][stream.hls][debug] Segments in this playlist are encrypted
[23:58:56.136634][stream.hls][debug] Adding segment 19431377 to queue
[23:58:56.139782][stream.hls][debug] Segments in this playlist are encrypted
[23:58:56.140089][stream.hls][debug] Adding segment 19431378 to queue
[23:58:56.700062][stream.hls][debug] Download of segment 19431377 complete
[23:58:56.980010][stream.hls][debug] Download of segment 19431378 complete
[23:59:01.151113][stream.hls][debug] Reloading playlist
[23:59:01.201563][stream.hls][debug] Segments in this playlist are encrypted
[23:59:01.201985][stream.hls][debug] Adding segment 19431378 to queue
[23:59:01.202467][stream.hls][debug] Adding segment 19431379 to queue
[23:59:01.683298][stream.hls][debug] Download of segment 19431378 complete
[23:59:02.139807][stream.hls][debug] Download of segment 19431379 complete
[23:59:07.137318][stream.hls][debug] Reloading playlist
[23:59:07.143250][stream.hls][debug] Reloading playlist
[23:59:07.178681][stream.hls][debug] Segments in this playlist are encrypted
[23:59:07.179478][stream.hls][debug] Adding segment 19431378 to queue
[23:59:07.180376][stream.hls][debug] Adding segment 19431379 to queue
[23:59:07.213395][stream.hls][debug] Segments in this playlist are encrypted
[23:59:07.213770][stream.hls][debug] Adding segment 19431379 to queue
[23:59:07.643584][stream.hls][debug] Download of segment 19431378 complete
[23:59:08.048910][stream.hls][debug] Download of segment 19431379 complete
[23:59:08.450718][stream.hls][debug] Download of segment 19431379 complete
[23:59:12.203209][stream.hls][debug] Reloading playlist
[23:59:12.241065][stream.hls][debug] Segments in this playlist are encrypted
[23:59:17.741889][stream.hls][debug] Reloading playlist
[23:59:17.782767][stream.hls][debug] Segments in this playlist are encrypted
[23:59:17.783214][stream.hls][debug] Adding segment 19431380 to queue
[23:59:18.181232][stream.hls][debug] Reloading playlist
[23:59:18.214700][stream.hls][debug] Reloading playlist
[23:59:18.239932][stream.hls][debug] Segments in this playlist are encrypted
[23:59:18.240299][stream.hls][debug] Adding segment 19431380 to queue
[23:59:18.249156][stream.hls][debug] Download of segment 19431380 complete
[23:59:18.262050][stream.hls][debug] Segments in this playlist are encrypted
[23:59:18.699189][stream.hls][debug] Download of segment 19431380 complete
[23:59:23.762694][stream.hls][debug] Reloading playlist
[23:59:23.808339][stream.hls][debug] Segments in this playlist are encrypted
[23:59:23.808711][stream.hls][debug] Adding segment 19431380 to queue
[23:59:24.269631][stream.hls][debug] Download of segment 19431380 complete

Thank you for taking the time to read this and let me know if I missed an important information or if I should be running more tests / diagnostics.
@marmeladema marmeladema added the plugin issue A Plugin does not work correctly label Feb 27, 2021
@back-to back-to added the duplicate This issue or pull request already exists label Feb 27, 2021
@back-to
Copy link
Collaborator

back-to commented Feb 27, 2021

you are opening 4 streams at the same time with --hls-audio-select '*' --ffmpeg-copyts --mux-subtitles

closing, hls-multi are broken

Duplicate of #3534

if you look at every Stream start Sequence, they are different thats the delay.

[23:59:47.414673][stream.hls][debug] First Sequence: 19431378; Last Sequence: 19431382
[23:59:55.320771][stream.hls][debug] First Sequence: 19431379; Last Sequence: 19431383
[00:00:04.454842][stream.hls][debug] First Sequence: 19431381; Last Sequence: 19431385
[00:00:09.629850][stream.hls][debug] First Sequence: 19431381; Last Sequence: 19431385

one Sequence is 10 sec long #EXTINF:10, so this is a delay of ~30 sec before it can start because of --ffmpeg-copyts

Never starting log trace

[23:54:22.605465][plugins.pluzz][debug] Country: GB
[23:54:37.240081][plugins.pluzz][debug] Video ID: 006194ea-117d-4bcf-94a9-153d999c59ae
[23:54:37.546097][plugins.pluzz][trace] {'format': 'hls', 'url': 'https://simulcast.ftven.fr/simulcast/France_2/hls_fr2/index.m3u8', 'statut': 'ONLINE', 'drm': False, 'geoblocage': None, 'plages_ouverture': [{'debut': None, 'fin': None}]}
[23:54:37.849918][utils.l10n][debug] Language code: en_US
[23:54:52.176318][stream.hls][debug] Using external audio tracks for stream 144p (language=fr, name=Francais), (language=qaa, name=Version Originale), (language=qad, name=Audio Description)

your proxy seems very slow here

[23:54:55.482754][stream.hls][debug] First Sequence: 19431348; Last Sequence: 19431352
[23:55:18.404048][stream.hls][debug] First Sequence: 19431351; Last Sequence: 19431355
[23:55:25.368786][stream.hls][debug] First Sequence: 19431352; Last Sequence: 19431356
[23:55:30.085729][stream.hls][debug] First Sequence: 19431353; Last Sequence: 19431357

one Sequence is 10 sec long #EXTINF:10, so this is a delay of ~50 sec before it can start because of --ffmpeg-copyts

Streamlink is waiting for every Stream because it is bugged a bit see above,
but it also seems like an issue with your internet speed here, you are opening the first playlists to slow so it delays every playlist.

@back-to back-to closed this as completed Feb 27, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
duplicate This issue or pull request already exists plugin issue A Plugin does not work correctly
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@marmeladema @back-to