Transcoding fails abruptly during stream

[OpenSrcerer]

Background

Client: Symfonium 9.1.0
LMS 3.51.0 (Docker)

Running behind NGINX with this config:

server {
    # Setup HTTPS certificates
    listen       443 default ssl;
    listen [::]:443 ssl ipv6only=on; # managed by Certbot
    server_name  my.domain.name;

    ssl_certificate /path/to/ssl; # managed by Certbot
    ssl_certificate_key /path/to/key; # managed by Certbot
    include /etc/letsencrypt/options-ssl-nginx.conf; # managed by Certbot
    ssl_dhparam /etc/letsencrypt/ssl-dhparams.pem; # managed by Certbot

    location /lms/ {    
        proxy_pass                            http://localhost:4042/;
    }
}

Issue Description

Media usually plays fine. However, I've noticed that sometimes they abruptly stop - this phenomenon is especially prevalent in longer tracks.
Today I ran a test and found this:

[2024-Mar-31 14:52:26.633] 1 - [info] "wthttp: 172.19.0.1   GET /rest/ping.view?u=Bonkers&p=enc%3A56336e6f6d7370333364&v=1.13.0&c=Symfonium&f=json HTTP/1.0 200 109"
[2024-Mar-31 14:52:26.633] 1 - [info] "WebRequest: took 23.135 ms"

# This seems problematic to me, there's no real "error" thrown here but maybe it makes the transcoding restart?
[flac @ 0x7efee3943000] Could not find codec parameters for stream 1 (Video: mjpeg, none): unspecified size
Consider increasing the value for the 'analyzeduration' and 'probesize' options

# I believe transcoding restarts here
[2024-Mar-31 14:52:40.739] 1 - [info] - 139633201892152 [TRANSCODING] [155] - Transcoding file '/music/public_music/Dream Theater/Dream Theater - Octavarium (2009) [FLAC] [16B-44100kHz]/08. Dream Theater - Octavarium.flac'

[2024-Mar-31 14:52:48.160] 1 - [info] "wthttp: 172.19.0.1   GET /rest/scrobble.view?id=tr-50285&submission=false&u=Bonkers&p=enc%3A56336e6f6d7370333364&v=1.13.0&c=Symfonium&f=json HTTP/1.0 200 109"

On NGINX side I'm getting these logs. The timestamps don't really match up so maybe this is irrelevant, but thought to add it anyway for context.

2024/03/31 14:36:24 [alert] 649#649: *6957 open socket #23 left in connection 11
2024/03/31 14:36:24 [alert] 649#649: *6953 open socket #18 left in connection 15
2024/03/31 14:36:24 [alert] 649#649: *7033 open socket #9 left in connection 17
2024/03/31 14:36:24 [alert] 649#649: aborting

[epoupon]

Hello!

Did you try to increase timeout settings in nginx?
For example:

    proxy_read_timeout 10m;
    proxy_send_timeout 10m;
    keepalive_timeout 10m;

Tell me if that helps.

[OpenSrcerer]

Did you try to increase timeout settings in nginx? For example:

Hi, thank you for your reply!

Yes, I have done that. This is my current configuration:

    location /lms/ {
        proxy_read_timeout 30m; 
        proxy_send_timeout 30m; 
        keepalive_timeout 30m;
        proxy_pass http://localhost:4042/;
    }

On songs that are longer than 8 minutes I usually start having issues. The logs show behavior in exactly the same way as I've described above.

[epoupon]

Can you by chance try without proxy and tell how it behaves?

[hlinden]

I have run into the same behaviour and I've traced it to the way Firefox seems to deal with OGG- (and maybe other) streams of unknown length.

My test track has a length of 10:40. I used the request the webplayer creates on playing a file and pasted it standalone into a tab:

https://server.tld/release/mbid/?wtd=<remvoed>&request=resource&resource=o15867gx&ver=1&trackid=98728&bitrate=192000&format=2

Firefox starts loading and playing the file but during playing occasionally "extends" the displayed overall time, starting with about two minutes and increasing in about 60 seconds intervals.

I dumped the HTTP2 stream using Wireshark and found out, that despite the entire content being transmitted almost immediately, Firefox kept the HTTP2 connection to my reverse proxy open and used the HTTP2 feature "PING" to keep the state alive in roughly 60 second intervals. Those correlated with the displayed playtime being extended and sure enough, when I force a timeout of about 45 seconds in the mod_proxy setttings or otherwise kill the state, e.g. by resetting the state table in my router, firefox stops playing at whatever time mark it has reached.

I tried reproducing that behaviour without a reverse proxy and no TLS in between and sure enough, it is reproducable, but of course without the HTTP2 keep alive magic.

Started playing the same, long file in Firefox and paused after about 2:30. Displayed playtime at that point was 3:19 and it had extended once from about 2:51. Let the whole thing sit for ten minutes and clicked play. Playtime extended a few times and then playback stopped at 9:10 of 9:12 displayed playtime.

At some point in between during the paused state, the server sends a 200 OK out of the blue, and a while later then ACKs a keep alive from the client for the very same connection that has been reset.... it's all a bit weird and I honestly don't understand that part.

EDIT: Note to self: Think about TCP timeouts in the 1:1 NAT part of Docker, maybe.

[epoupon]

This reminds me the local transcode cache discussed in #588

Not sure how other servers do, maybe this would solve all this. The idea would be to start to transcode in a local file, and fake the returned range using some estimated size based on bitrate/length (+ some padding with 0). The client can get/hit the ranges it needs using the cached file, like the current flow without transcoding.

Edit: The major drawback would be for very large files (like several hours of a mix), as it would take a long time before being able to serve the bytes if the user scrolls too far ahead too quickly.