Connection timeout issue with youtube-dl

[mylselgan]

Describe the bug
I face connection timeout issue with youtube-dl
To Reproduce

play =  single("youtube-dl:https://www.youtube.com/watch?v=rmCA3qQkqso")
s = fallback(track_sensitive=true,[(play)])
output.icecast(%mp3

Expected behavior
Buffer the youtube video and output to icecast as mp3 audio stream

Version details

• OS: Ubuntu Xenial (16.04 LTS)
• Version Liquidsoap 1.3.6

Install method
The OPAM way

Log (Level 5)

2019/03/01 15:57:06 >>> LOG START
2019/03/01 15:57:06 [main:3] Liquidsoap 1.3.6
2019/03/01 15:57:06 [main:3] Using: bytes=[distributed with OCaml 4.02 or above] pcre=7.4.1 dtools=0.4.1 duppy=0.8.0 cry=0.6.2 mm=0.4.0 ogg=0.5.2 vorbis=0.7.1 mad=0.4.5 dynlink=[distributed with Ocaml] lame=0.3.3 gstreamer=0.3.0 fdkaac=0.2.1 samplerate=0.1.4 taglib=0.3.3 camomile=1.0.1
2019/03/01 15:57:06 [gstreamer.loader:3] Loaded GStreamer 1.8.3 0
2019/03/01 15:57:06 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz master.
2019/03/01 15:57:06 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.
2019/03/01 15:57:06 [frame:3] Targetting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.
2019/03/01 15:57:06 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.
2019/03/01 15:57:06 [video.converter:4] Couldn't find preferred video converter: gavl.
2019/03/01 15:57:06 [threads:3] Created thread "gstreamer_main_loop" (1 total).
2019/03/01 15:57:06 [audio.converter:4] Using preferred samplerate converter: libsamplerate.
2019/03/01 15:57:06 [threads:3] Created thread "generic queue #1".
2019/03/01 15:57:06 [threads:3] Created thread "generic queue #2".
2019/03/01 15:57:06 [threads:3] Created thread "non-blocking queue #1".
2019/03/01 15:57:06 [threads:3] Created thread "non-blocking queue #2".
2019/03/01 15:57:06 [clock:4] Currently 1 clocks allocated.
2019/03/01 15:57:06 [clock.wallclock_main:4] Starting 1 sources...
2019/03/01 15:57:06 [source:4] Source output.icecast_6321 gets up.
2019/03/01 15:57:06 [source:4] Source fallback_6319 gets up.
2019/03/01 15:57:06 [source:4] Source single_6317 gets up.
2019/03/01 15:57:06 [single_6317:4] Content kind is {audio=2;video=0;midi=0}.
2019/03/01 15:57:06 [single_6317:4] Activations changed: static=[], dynamic=[fallback_6319:Demo_Stream_24kbps:Demo_Stream_24kbps].
2019/03/01 15:57:06 [fallback_6319:4] Activations changed: static=[Demo_Stream_24kbps:Demo_Stream_24kbps], dynamic=[].
2019/03/01 15:57:06 [Demo_Stream_24kbps:4] Activations changed: static=[Demo_Stream_24kbps], dynamic=[].
2019/03/01 15:57:06 [Demo_Stream_24kbps:4] Enabling caching mode: active source.
2019/03/01 15:57:06 [Demo_Stream_24kbps:3] Connecting mount 4 for source@s1.mydoamin.com...
2019/03/01 15:57:06 [protocol.youtube-dl:4] Executing youtube-dl --get-title --get-filename -- "https://www.youtube.com/watch?v=rmCA3qQkqso"
2019/03/01 15:57:06 [lang.run_process:4] Starting process
2019/03/01 15:57:06 [lang.run_process:4] Closing process's stdin
2019/03/01 15:57:06 [Demo_Stream_24kbps:3] Connection setup was successful.
2019/03/01 15:57:06 [threads:3] Created thread "wallclock_main" (2 total).
2019/03/01 15:57:06 [clock:4] Main phase starts.
2019/03/01 15:57:06 [clock.wallclock_main:3] Streaming loop starts, synchronized with wallclock.
2019/03/01 15:57:06 [single_6317:5] Queue is empty!
2019/03/01 15:57:06 [single_6317:5] Failed to prepare track: no file.
2019/03/01 15:57:06 [single_6317:5] Queue is empty!
2019/03/01 15:57:06 [single_6317:5] Failed to prepare track: no file.
2019/03/01 15:57:06 [Demo_Stream_24kbps:3] Source failed (no more tracks) stopping output...
2019/03/01 15:57:06 [Demo_Stream_24kbps:3] Closing connection...
2019/03/01 15:57:06 [single_6317:5] Queue is empty!
2019/03/01 15:57:06 [single_6317:5] Failed to prepare track: no file.
2019/03/01 15:57:06 [single_6317:5] Queue is empty!

[mylselgan]

With the following script

play = playlist.safe("youtube-dl:https://www.youtube.com/watch?v=rmCA3qQkqso")
s = fallback(track_sensitive=true,[(play)])
output.icecast(%mp3

I get following Log which shows connection timeout clearly

2019/03/01 16:12:43 >>> LOG START
2019/03/01 16:12:43 [main:3] Liquidsoap 1.3.6
2019/03/01 16:12:43 [main:3] Using: bytes=[distributed with OCaml 4.02 or above] pcre=7.4.1 dtools=0.4.1 duppy=0.8.0 cry=0.6.2 mm=0.4.0 ogg=0.5.2 vorbis=0.7.1 mad=0.4.5 dynlink=[distributed with Ocaml] lame=0.3.3 gstreamer=0.3.0 fdkaac=0.2.1 samplerate=0.1.4 taglib=0.3.3 camomile=1.0.1
2019/03/01 16:12:43 [gstreamer.loader:3] Loaded GStreamer 1.8.3 0
2019/03/01 16:12:43 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz master.
2019/03/01 16:12:43 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.
2019/03/01 16:12:43 [frame:3] Targetting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.
2019/03/01 16:12:43 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.
2019/03/01 16:12:43 [video.converter:4] Couldn't find preferred video converter: gavl.
2019/03/01 16:12:43 [threads:3] Created thread "gstreamer_main_loop" (1 total).
2019/03/01 16:12:43 [audio.converter:4] Using preferred samplerate converter: libsamplerate.
2019/03/01 16:12:43 [threads:3] Created thread "generic queue #1".
2019/03/01 16:12:43 [threads:3] Created thread "generic queue #2".
2019/03/01 16:12:43 [threads:3] Created thread "non-blocking queue #1".
2019/03/01 16:12:43 [threads:3] Created thread "non-blocking queue #2".
2019/03/01 16:12:43 [clock:4] Currently 1 clocks allocated.
2019/03/01 16:12:43 [clock.wallclock_main:4] Starting 1 sources...
2019/03/01 16:12:43 [source:4] Source output.icecast_6321 gets up.
2019/03/01 16:12:43 [source:4] Source fallback_6319 gets up.
2019/03/01 16:12:43 [source:4] Source playlist.safe_6317 gets up.
2019/03/01 16:12:43 [watch?v=rmCA3qQkqso:3] Loading playlist...
2019/03/01 16:12:43 [protocol.youtube-dl:4] Executing youtube-dl --get-title --get-filename -- "https://www.youtube.com/watch?v=rmCA3qQkqso"
2019/03/01 16:12:43 [lang.run_process:4] Starting process
2019/03/01 16:12:43 [lang.run_process:4] Closing process's stdin
**2019/03/01 16:12:53 [watch?v=rmCA3qQkqso:2] Timeout when resolving playlist URI "youtube-dl:https://www.youtube.com/watch?v=rmCA3qQkqso"!**
2019/03/01 16:12:53 [clock.wallclock_main:2] Error when starting Demo_Stream_24kbps: File "sources/playlist.ml", line 246, characters 8-14: Assertion failed!
2019/03/01 16:12:53 [clock.wallclock_main:3] Raised at file "sources/playlist.ml", line 246, characters 8-64
2019/03/01 16:12:53 [clock.wallclock_main:3] Called from file "sources/playlist.ml", line 510, characters 4-32
2019/03/01 16:12:53 [clock.wallclock_main:3] Called from file "sources/playlist.ml", line 493, characters 4-23
2019/03/01 16:12:53 [clock.wallclock_main:3] Called from file "source.ml", line 388, characters 6-18
2019/03/01 16:12:53 [clock.wallclock_main:3] Called from file "sources/playlist.ml", line 521, characters 4-31
2019/03/01 16:12:53 [clock.wallclock_main:3] Called from file "operators/switch.ml", line 105, characters 9-20
2019/03/01 16:12:53 [clock.wallclock_main:3] Called from file "list.ml", line 106, characters 12-15
2019/03/01 16:12:53 [clock.wallclock_main:3] Called from file "source.ml", line 388, characters 6-18
2019/03/01 16:12:53 [clock.wallclock_main:3] Called from file "outputs/output.ml", line 130, characters 4-20
2019/03/01 16:12:53 [clock.wallclock_main:3] Called from file "source.ml", line 388, characters 6-18
2019/03/01 16:12:53 [clock.wallclock_main:3] Called from file "clock.ml", line 221, characters 15-26
2019/03/01 16:12:53 [Demo_Stream_24kbps:1] Got ill-balanced activations (from Demo_Stream_24kbps)!
2019/03/01 16:12:53 [clock:2] Error when leaving output Demo_Stream_24kbps: File "source.ml", line 414, characters 10-16: Assertion failed!
2019/03/01 16:12:53 [clock:3] Raised at file "source.ml", line 414, characters 10-22
2019/03/01 16:12:53 [clock:3] Called from file "source.ml", line 421, characters 30-58
2019/03/01 16:12:53 [clock:3] Called from file "clock.ml", line 79, characters 6-13
2019/03/01 16:12:53 [clock:4] Main phase starts.
2019/03/01 16:12:53 [main:3] Shutdown started!
2019/03/01 16:12:53 [main:3] Waiting for threads to terminate...
2019/03/01 16:12:53 [threads:3] Shuting down thread gstreamer_main_loop
2019/03/01 16:12:53 [threads:3] Thread "gstreamer_main_loop" terminated (0 remaining).
2019/03/01 16:12:53 [main:3] Threads terminated.
2019/03/01 16:12:53 [threads:3] Shutting down scheduler...
2019/03/01 16:12:53 [threads:3] Scheduler shut down.
2019/03/01 16:12:53 [threads:3] Shutting down queues...
2019/03/01 16:12:53 [threads:3] Thread "generic queue #1" terminated.
2019/03/01 16:12:53 [threads:3] Thread "generic queue #2" terminated.
2019/03/01 16:12:53 [threads:3] Thread "non-blocking queue #1" terminated.
2019/03/01 16:12:53 [threads:3] Thread "non-blocking queue #2" terminated.
2019/03/01 16:12:53 [threads:3] Queues shut down
2019/03/01 16:12:53 [main:3] Cleaning downloaded files...
2019/03/01 16:12:53 [main:3] Freeing memory...

[toots]

You shouldn't use a playlist for a single file but rather a single:

s = single("youtube-dl:https://www.youtube.com/watch?v=rmCA3qQkqso")

(Also the fallback isn't needed if you use it like that)

[mylselgan]

I get following log with single . Please check my opening post for full log

2019/03/01 15:57:06 [single_6317:5] Failed to prepare track: no file.
2019/03/01 15:57:06 [single_6317:5] Queue is empty

[autonarcosis]

What does the command do when you enter it from the shell from the server?

$ youtube-dl --get-title --get-filename -- "https://www.youtube.com/watch?v=rmCA3qQkqso"

This command just retrieves the title and filename. LS hasn't gotten to the routine to download the actual file yet.

[mylselgan]

When I run
$ youtube-dl --get-title --get-filename -- "https://www.youtube.com/watch?v=rmCA3qQkqso"
the output is

Michael Jackson - Billie Jean (30th Anniversary Celebration) (Remastered Widescreen)
Michael Jackson - Billie Jean (30th Anniversary Celebration) (Remastered Widescreen)-rmCA3qQkqso.mp4

My script is

#!/home/radio/.opam/4.07.0/bin/liquidsoap
 set("log.file.path", "/home/radio/liq.log")
 set("log.file",true)
 set("log.stdout",true)
 set("log.level", 5)

s = single("youtube-dl:https://www.youtube.com/watch?v=rmCA3qQkqso")

output.icecast()

The log output

2019/03/13 02:35:37 [protocol.youtube-dl:4] Executing youtube-dl --get-title --get-filename -- "https://www.youtube.com/watch?v=rmCA3qQkqso"
2019/03/13 02:35:37 [lang.run_process:4] Starting process
2019/03/13 02:35:37 [lang.run_process:4] Closing process's stdin
2019/03/13 02:35:37 [Demo_Stream_24kbps:3] Connection setup was successful.
2019/03/13 02:35:37 [threads:3] Created thread "wallclock_main" (2 total).
2019/03/13 02:35:37 [clock:4] Main phase starts.
2019/03/13 02:35:37 [clock.wallclock_main:3] Streaming loop starts, synchronized with wallclock.
2019/03/13 02:35:37 [single_6316:5] Queue is empty!
2019/03/13 02:35:37 [single_6316:5] Failed to prepare track: no file.
2019/03/13 02:35:37 [single_6316:5] Queue is empty!
2019/03/13 02:35:37 [single_6316:5] Failed to prepare track: no file.
2019/03/13 02:35:37 [Demo_Stream_24kbps:3] Source failed (no more tracks) stopping output...
2019/03/13 02:35:37 [Demo_Stream_24kbps:3] Closing connection...
2019/03/13 02:35:37 [single_6316:5] Queue is empty!
2019/03/13 02:35:37 [single_6316:5] Failed to prepare track: no file.
2019/03/13 02:35:38 [single_6316:5] Queue is empty!
2019/03/13 02:35:38 [single_6316:5] Failed to prepare track: no 

[autonarcosis]

You are correct. It is broken. I am not sure what Toots is rambling on about. It is also a failable source which requires fallback.

Even with that, I don't know how this would work. The protocol.liq script executes two passes of youtube-dl.

The first one is the youtube-dl --get-title --get-filename

The second one is youtube-dl -q -f best --no-playlist -o filename

The issue here would be in this instance it would download a video file, which wouldn't satisfy the output request unless you were streaming audio/video.

I doubt this ever worked, or briefly several years ago.

[autonarcosis]

Do you get the same behavior using https:// trying to fetch a file from a web server? I get the same error as well. I suspect this has something to do with calling external processes.

[autonarcosis]

And this code works for me;

`lines = get_process_lines("youtube-dl --get-title --get-filename -- 'https://www.youtube.com/watch?v=rmCA3qQkqso'")
log("lines = #{lines}")
line = list.hd(default="",lines)
log("line = #{line}")

`

2019/03/13 18:23:13 [lang:3] lines = ["Michael Jackson - Billie Jean (30th Anniversary Celebration) (Remastered Widescreen)", "Michael Jackson - Billie Jean (30th Anniversary Celebration) (Remastered Widescreen)-rmCA3qQkqso.mp4"]
2019/03/13 18:23:13 [lang:3] line = Michael Jackson - Billie Jean (30th Anniversary Celebration) (Remastered Widescreen)

[toots]

Are you guys able to test with the latest master branch? There's a fix in it for issue #691, which might be what's going on here.

It's a pretty big change set so it's scheduled to be released with the next major release, which is currently in alpha stage.

@autonarcosis the protocol layer was added with release 1.3.0.

If you are trying to use the youtube video as a audio track, you should be able to combine the youtube-dl protocol with ffmpeg2wav:

ffmpeg2wav:youtube-dl:rmCA3qQkqso