2019/03/13

Hanging M3U8 downloads in ffmpeg

On my ubuntu laptop ffmpeg was regularly hanging while downloading a ".m3u8" video stream. Youtube-dl uses ffmpeg under the hood to download those type of files.

e.g.:
ffmpeg -y -loglevel verbose -headers "Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7? Accept-Language: en-us,en;q=0.5? Accept-Encoding: gzip, deflate? Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8? User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:59.0) Gecko/20100101 Firefox/59.0?" -i https://cdn.provider.url.../content/.../file.m3u8 -tls_verify 1 -c copy -f mp4 "file:resultingfile.mp4" 
This command would stop at some random point when opening a ".ts" video fragment.
[hls,applehttp @ 0xc16300] Opening 'crypto+https://.../fragment.ts' for reading
Waiting for timeouts and playing with the ffmpeg options didn't seem to help.

An strace would indicate the server is not responding, but still is keeping the socket open.

e.g.: (do NOT run strace as a background process with &)
strace ffmpeg -y -loglevel verbose -headers "Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7? Accept-Language: en-us,en;q=0.5? Accept-Encoding: gzip, deflate? Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8? User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:59.0) Gecko/20100101 Firefox/59.0?" -i https://cdn.provider.url.../content/.../file.m3u8 -tls_verify 1 -c copy -f mp4 "file:resultingfile.mp4" > /tmp/ffmpeg.log 2>&1

would gives the following output
... 
socket(AF_INET, SOCK_STREAM|SOCK_CLOEXEC, IPPROTO_TCP) = 5
fcntl64(5, F_GETFL)                     = 0x2 (flags O_RDWR)
fcntl64(5, F_SETFL, O_RDWR|O_NONBLOCK)  = 0
connect(5, {sa_family=AF_INET, sin_port=htons(443), sin_addr=inet_addr("...")}, 16) = -1 EINPROGRESS (Operation now in progress)
poll([{fd=5, events=POLLOUT}], 1, 100)  = 1 ([{fd=5, revents=POLLOUT}])
getsockopt(5, SOL_SOCKET, SO_ERROR, [0], [4]) = 0
open("/etc/ssl/certs/ca-certificates.crt", O_RDONLY|O_LARGEFILE) = 6
fstat64(6, {st_mode=S_IFREG|0644, st_size=235192, ...}) = 0
_llseek(6, 0, [0], SEEK_CUR)            = 0
fstat64(6, {st_mode=S_IFREG|0644, st_size=235192, ...}) = 0
read(6, "-----BEGIN CERTIFICATE-----\nMIIH"..., 233472) = 233472
read(6, "UMlQMAimTHpKG9n/v55IFDlndmQguLvq"..., 4096) = 1720
read(6, "", 4096)                       = 0
close(6)                                = 0
clock_gettime(CLOCK_REALTIME, {tv_sec=1552330418, tv_nsec=452985119}) = 0
gettimeofday({tv_sec=1552330418, tv_usec=453367}, NULL) = 0
gettimeofday({tv_sec=1552330418, tv_usec=453637}, NULL) = 0
poll([{fd=5, events=POLLOUT}], 1, 100)  = 1 ([{fd=5, revents=POLLOUT}])
send(5, "\26\3\1\0\352\1\0\0\346\3\3\\\206\256\373\263ZO\233\356U\344b\204O\3217\275\16fb\331"..., 239, MSG_NOSIGNAL) = 239
poll([{fd=5, events=POLLIN}], 1, 100)   = 0 (Timeout)
poll([{fd=5, events=POLLIN}], 1, 100)   = 0 (Timeout)
poll([{fd=5, events=POLLIN}], 1, 100)   = 0 (Timeout)
...

Perhaps the server was doing some connection throttling?

Workaround: proxy all trafic with tinyproxy
  • Install tinyproxy: sudo apt install tinyproxy
  • tweak the  following config items: sudo nano /etc/tinyproxy/tinyproxy.conf
    # I lowered the timeout from 600s to 60s
    Timeout 60

    ...
    # only accept localhost connections
    Allow 127.0.0.1

    ...
    #'stealth mode'
    DisableViaHeader Yes
  • restart the daemon:
    sudo systemctl restart tinyproxy
  • a quick test will validate the proxy is working:
    wget https://www.google.com -e use_proxy=yes -e http_proxy=127.0.0.1:8888
If you download the m3u8 stream through the proxy, any hickup in the download will trigger a timeout in the proxy and let the download proceed on.

ffmpeg syntax: (recent ffmpeg versions have a -http_proxy option)

http_proxy="http://127.0.0.1:8888" ffmpeg -y -loglevel verbose -headers "Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7? Accept-Language: en-us,en;q=0.5? Accept-Encoding: gzip, deflate? Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8? User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:59.0) Gecko/20100101 Firefox/59.0?" -i https://cdn.provider.url.../content/.../file.m3u8 -tls_verify 1 -c copy -f mp4 "file:resultingfile.mp4"

Youtube-dl syntax:
youtube-dl --proxy http://127.0.0.1:8888/ ...

You can check the tinyproxy log to validate the proxy is working correctly:

sudo tail -f /var/log/tinyproxy/tinyproxy.log                                                                                                                                 
INFO      Mar 13 12:34:53 [525]: No upstream proxy for ...
CONNECT   Mar 13 12:34:53 [525]: Established connection to host "ondemand-b.lwc.vrtcdn.be" using file descriptor 8.
INFO      Mar 13 12:34:53 [525]: Not sending client headers to remote machine
CONNECT   Mar 13 12:34:54 [523]: Connect (file descriptor 7): localhost [127.0.0.1]
CONNECT   Mar 13 12:34:54 [523]: Request (file descriptor 7): CONNECT ...:443 HTTP/1.1
INFO      Mar 13 12:34:54 [523]: No upstream proxy for ...
CONNECT   Mar 13 12:34:54 [523]: Established connection to host "..." using file descriptor 8.
INFO      Mar 13 12:34:54 [523]: Not sending client headers to remote machine
INFO      Mar 13 12:34:54 [525]: Closed connection between local client (fd:7) and remote client (fd:8)
INFO      Mar 13 12:34:54 [523]: Closed connection between local client (fd:7) and remote client (fd:8)






7 comments:

  1. use flag -timeout before flag -i
    http://ffmpeg.org/ffmpeg-all.html#http

    ReplyDelete
  2. That doesn't work and on that page in that section there was nothing written about '-timeout'

    ReplyDelete
  3. This comment has been removed by the author.

    ReplyDelete
  4. I've been experiencing the exact same issue while downloading livestreams from Twitch.
    I thought of checking the output of strace like you did and got something very similar:

    poll([{fd=6, events=POLLIN}], 1, 100) = 0 (Timeout)
    poll([{fd=6, events=POLLIN}], 1, 100) = 0 (Timeout)
    poll([{fd=6, events=POLLIN}], 1, 100) = 0 (Timeout)
    poll([{fd=6, events=POLLIN}], 1, 100) = 0 (Timeout)
    poll([{fd=6, events=POLLIN}], 1, 100) = 0 (Timeout)
    poll([{fd=6, events=POLLIN}], 1, 100) = 0 (Timeout)

    lsof confirms that this fd belongs to a connection to Twitch

    ffmpeg 9049 joel 6u IPv4 7684477 0t0 TCP 192.168.1.100:38734->video-weaver.mad01.hls.ttvnw.net:https (ESTABLISHED)

    Apparently ffmpeg has a flag named "rw_timeout" that should enforce a read timeout on the TCP socket. By default it has a value of -1, meaning that in the worst case it would hang forever. I'll give that a try before I go tinyproxy.

    Edit: Since it looks you're also using youtube-dl, you would be able to specify this flag like so: youtube-dl --external-downloader-args '-rw_timeout 10000000' ...

    ReplyDelete
  5. Thanks for sharing! But I think that this solution is a little bit difficult to beginner. They are supposed to use something like HLS downloaders.

    ReplyDelete