Web player doesn't play entire song when paused

[abdulocracy]

I've noticed a bug where, if I return to a song after pausing it, the web player will proceed to the next song in the queue earlier than the end of the current song.

[epoupon]

Hi! Thanks for reporting this. Does it occur in transcoding mode or in raw mode?

[abdulocracy]

Transcoding flac2mp3, don't recall coming across it in raw mode.

[epoupon]

Ok, maybe you paused quite a while then, I will investigate this.

[abdulocracy]

lms            | [2020-Jun-09 20:09:32.808] 1 [/ YWeGtUfY21NrGlgC] [info] - [TRANSCODE] [67] - Transcoding file '/music/Munly & The Lee Lewis Harlots/Munly & The Lee Lewis Harlots/02 Big Black Bull Comes Like a Caesar.flac'
lms            | [2020-Jun-09 20:09:32.858] 1 - [error] "Http::ResponseContinuation: WebWriteEvent::Error"
lms            | 172.18.0.6 - - [2020-Jun-09 20:09:47.223] "GET /release/?wtd=YWeGtUfY21NrGlgC&request=resource&resource=o7u9j0h&rand=50&trackid=49762&bitrate=320000&format=1 HTTP/1.1" 200 16214771
lms            | 172.18.0.6 - - [2020-Jun-09 20:10:22.797] "POST /?wtd=YWeGtUfY21NrGlgC HTTP/1.1" 200 0
lms            | 172.18.0.6 - - [2020-Jun-09 20:11:12.797] "POST /?wtd=YWeGtUfY21NrGlgC HTTP/1.1" 200 0
lms            | 172.18.0.6 - - [2020-Jun-09 20:12:02.804] "POST /?wtd=YWeGtUfY21NrGlgC HTTP/1.1" 200 0
lms            | 172.18.0.6 - - [2020-Jun-09 20:12:31.902] "POST /?wtd=YWeGtUfY21NrGlgC HTTP/1.1" 200 0
lms            | 172.18.0.6 - - [2020-Jun-09 20:12:31.903] "POST /?wtd=YWeGtUfY21NrGlgC HTTP/1.1" 200 50
lms            | 172.18.0.6 - - [2020-Jun-09 20:13:21.923] "POST /?wtd=YWeGtUfY21NrGlgC HTTP/1.1" 200 0
lms            | 172.18.0.6 - - [2020-Jun-09 20:14:11.919] "POST /?wtd=YWeGtUfY21NrGlgC HTTP/1.1" 200 0
lms            | 172.18.0.6 - - [2020-Jun-09 20:15:01.920] "POST /?wtd=YWeGtUfY21NrGlgC HTTP/1.1" 200 0
lms            | 172.18.0.6 - - [2020-Jun-09 20:15:52.031] "POST /?wtd=YWeGtUfY21NrGlgC HTTP/1.1" 200 0
lms            | 172.18.0.6 - - [2020-Jun-09 20:16:41.923] "POST /?wtd=YWeGtUfY21NrGlgC HTTP/1.1" 200 0
lms            | 172.18.0.6 - - [2020-Jun-09 20:17:31.968] "POST /?wtd=YWeGtUfY21NrGlgC HTTP/1.1" 200 0
lms            | 172.18.0.6 - - [2020-Jun-09 20:17:31.969] "POST /?wtd=YWeGtUfY21NrGlgC HTTP/1.1" 200 50
lms            | 172.18.0.6 - - [2020-Jun-09 20:18:21.982] "POST /?wtd=YWeGtUfY21NrGlgC HTTP/1.1" 200 0
lms            | 172.18.0.6 - - [2020-Jun-09 20:19:11.981] "POST /?wtd=YWeGtUfY21NrGlgC HTTP/1.1" 200 0
lms            | 172.18.0.6 - - [2020-Jun-09 20:20:01.985] "POST /?wtd=YWeGtUfY21NrGlgC HTTP/1.1" 200 0
lms            | 172.18.0.6 - - [2020-Jun-09 20:20:19.173] "POST /?wtd=YWeGtUfY21NrGlgC HTTP/1.1" 200 0
lms            | 172.18.0.6 - - [2020-Jun-09 20:20:19.887] "POST /?wtd=YWeGtUfY21NrGlgC HTTP/1.1" 200 1085
lms            | [2020-Jun-09 20:20:20.026] 1 [/ YWeGtUfY21NrGlgC] [info] - [TRANSCODE] [68] - Transcoding file '/music/Munly & The Lee Lewis Harlots/Munly & The Lee Lewis Harlots/03 Old Service Road.flac'
lms            | 172.18.0.6 - - [2020-Jun-09 20:20:28.362] "GET /release/?wtd=YWeGtUfY21NrGlgC&request=resource&resource=o7u9j0h&rand=50&trackid=49766&bitrate=320000&format=1 HTTP/1.1" 200 9454281

Here's the log from a track that I paused for a bit and later was skipped prematurely. Perhaps it provides some useful information.

[epoupon]

Ok I see what is happening. When transcoding, LMS exposes an "unlimited" audio stream (like a live web radio), because it is transcoding on the fly. That makes LMS able to start playing immediately even if you want to play a 8h+ audio file. When seeking on the file, a new stream is started from the requested offset.

The only viable fix I see for this is to just drop the current stream when pausing and start a new one when unpausing. The drawback is that there will be a small delay when unpausing, which duration depends on the network bandwith. For local playing it is nearly unnoticeable for most common files. I think it is acceptable.

[abdulocracy]

Sounds good, I could also test the latency more thoroughly.

[epoupon]

Well I thought I have a fix: detect a network error and reload the player with the current play offset. Unfortunately, it does not work for chrome (errors never fired), and I also discovered that transcoding a really long track (several hours) does not work with firefox: it downloads a lot of stuff (dozens of megabytes) and then closes the connection... So I am quite puzzled with this issue, I will try to find something else, maybe another approach.

[alfureu]

The same is happening in the Subsonic playback, I use Strawberry. Whenever I play and pause, after hitting Play again, I receive an error. I suspect the backend cannot continue to transcode as the playback got interrupted.

[epoupon]

Yes indeed, the connection seems to be closed server side (maybe timeout), which makes the associated transcoder instance close. Usually Subsonic clients cache the whole song so they don't hit that problem. I will then investigate to check why exactly we close the connection after a while.

[epoupon]

Interesting, without proxy I can pause/play the song even after several minutes...