airsonic icon indicating copy to clipboard operation
airsonic copied to clipboard

Safari playback restart

Open khannurien opened this issue 6 years ago • 12 comments

Problem description

When playing a track using Safari under macOS, playback restarts before the end of the track.

Steps to reproduce

  1. Play a FLAC track with transcoding enabled (that's my setup -- not sure if relevant) ;
  2. Enjoy the music for a while...
  3. Playback resets to 0:00 before the end of the track.

System information

  • Airsonic version: 10.4.1
  • Operating system: macOS 10.14.6
  • Java version: OpenJDK 8
  • Proxy server: nginx
  • Client: web interface
  • Language: French

Additional notes

My setup runs Airsonic using the linuxserver/airsonic image.

Notes: I'm using Safari 13.0.2. Problem does not occur using Firefox.

khannurien avatar Oct 18 '19 10:10 khannurien

How long is the track? I've seen this on Firefox/Linux as well in the web player, especially with longer tracks (say, 60 minutes).

witten avatar Oct 18 '19 18:10 witten

I have sometimes had similar experiences with larger files (~100mb+) when streaming to the subsonic client on android. I'll update when it happens again and try to include a log file.

louisgregg avatar Oct 18 '19 18:10 louisgregg

I don't know if I'm experiencing the same issue as @khannurien, but what I'm seeing is that Airsonic suddenly stops playing the current track just a few minutes into it, and then advances to the next track if there is one. Or stops altogether if it's the last track. In older versions of Airsonic, I used to see the track restart in this scenario, but I believe that was prior to 10.4.1 and specifically this fix. Here are the corresponding logs of all this happening in 10.4.1. This is when I initially hit play (the track is over an hour long):

2019-10-18 22:45:10.201  INFO --- o.a.p.io.PlayQueueInputStream            : 172.18.0.3: witten listening to mixes/Singularity Mix.m4a
2019-10-18 22:45:10.203  INFO --- o.a.p.io.TranscodeInputStream            : Starting transcoder: [/config/transcode/ffmpeg] [-i] [/music/mixes/Singularity Mix.m4a] [-map] [0:0] [-b:a] [192k] [-v] [0] [-f] [mp3] [-] 

And then a few minutes into playing, I see this show up in the logs:

2019-10-18 22:46:30.259  INFO --- o.a.p.c.StreamController                 : 172.18.0.3: Client unexpectedly closed connection while loading http://audio.torsion.org/stream?player=5&id=1178 (java.io.IOException: Connection reset by peer)
2019-10-18 22:46:30.264  INFO --- o.a.p.s.LoggingExceptionResolver         : 172.18.0.3: Client unexpectedly closed connection while loading http://audio.torsion.org/stream?player=5&id=1178 (java.io.IOException: Broken pipe)

And then a while later (less than a minute?) I stop hearing audio in the web player. If the problem is correlated to those connection closed logs, then my only speculation is that the web player has a bit of a buffer of audio, which is why audio doesn't cut out as soon as the broken pipe shows up in the logs.

FYI I looked in my browser console and didn't see anything of note.

Possible related issues: #1218, #723, #892, #685

witten avatar Oct 19 '19 06:10 witten

Hi, seeing this in safari (with flacs) too, usually only a minute or two into the track.

Watching the logs while it plays, the transcoder restarting is when the song restarts in the browser. The first Broken pipes happens soon as I hit play.

Oct 24 14:56:10 TANKAGE java[2820466]: 2019-10-24 14:56:10.912  INFO --- o.a.p.io.TranscodeInputStream            : Starting transcoder: [/var/lib/airsonic/transcode/ffmpeg] [-i] [/tank/media/music/library/martyrdod/2019-Hexhammaren/02 Rannilar.flac] [-map] [0:0] [-b:a] [192k] [-v] [0] [-f] [mp3] [-]
Oct 24 14:56:13 TANKAGE java[2820466]: 2019-10-24 14:56:13.086  INFO --- o.a.p.c.StreamController                 : 10.147.20.128: Client unexpectedly closed connection while loading https://music.93afae5963d77bcd.space/stream?player=93&id=492705 (java.io.IOException: Broken pipe)
Oct 24 14:56:13 TANKAGE java[2820466]: 2019-10-24 14:56:13.102  INFO --- o.a.p.s.LoggingExceptionResolver         : 10.147.20.128: Client unexpectedly closed connection while loading https://music.93afae5963d77bcd.space/stream?player=93&id=492705 (java.io.IOException: Broken pipe)



Oct 24 14:56:55 TANKAGE java[2820466]: 2019-10-24 14:56:55.131  INFO --- o.a.p.io.PlayQueueInputStream            : 10.147.20.128: anuser listening to 2019-Hexhammaren/02 Rannilar.flac
Oct 24 14:56:55 TANKAGE java[2820466]: 2019-10-24 14:56:55.134  INFO --- o.a.p.io.TranscodeInputStream            : Starting transcoder: [/var/lib/airsonic/transcode/ffmpeg] [-i] [/tank/media/music/library/martyrdod/2019-Hexhammaren/02 Rannilar.flac] [-map] [0:0] [-b:a] [192k] [-v] [0] [-f] [mp3] [-]
Oct 24 14:56:57 TANKAGE java[2820466]: 2019-10-24 14:56:57.286  INFO --- o.a.p.c.StreamController                 : 10.147.20.128: Client unexpectedly closed connection while loading https://music.93afae5963d77bcd.space/stream?player=93&id=492705 (java.io.IOException: Broken pipe)
Oct 24 14:56:57 TANKAGE java[2820466]: 2019-10-24 14:56:57.310  INFO --- o.a.p.s.LoggingExceptionResolver         : 10.147.20.128: Client unexpectedly closed connection while loading https://music.93afae5963d77bcd.space/stream?player=93&id=492705 (java.io.IOException: Broken pipe)
![Screen Shot 2019-10-24 at 2 57 25 PM]

I don't know if this was happening before the most recent airsonic update; I wasn't using safari then. It's like, do you want a broken browser, or battery life?

The OK stream is a non transcoded mp3. The red one is a transcoded flac. Screen Shot 2019-10-24 at 5 23 13 PM for whatever reason, it can't make the range response safari wants when it's a transcode

laduke avatar Oct 24 '19 22:10 laduke

Same goes in my logs:

2019-10-27 07:54:45.754 INFO --- o.a.p.io.PlayQueueInputStream : 192.168.16.2: http://mydomain.com listening to sometrack.flac
2019-10-27 07:54:45.757 INFO --- o.a.p.io.TranscodeInputStream : Starting transcoder: [/config/transcode/ffmpeg] [-i] [/music/sometrack.flac] [-map] [0:0] [-b:a] [320k] [-v] [0] [-f] [mp3] [-]
2019-10-27 07:54:46.536 INFO --- o.a.p.c.StreamController : 192.168.16.2: Client unexpectedly closed connection while loading http://mydomain.com/stream?player=2&id=111054 (java.io.IOException: Broken pipe)
2019-10-27 07:54:46.541 INFO --- o.a.p.s.LoggingExceptionResolver : 192.168.16.2: Client unexpectedly closed connection while loading http://mydomain.com/stream?player=2&id=111054 (java.io.IOException: Broken pipe)

I get that error in Safari's console:

Capture d’écran 2019-10-27 à 07 59 17

khannurien avatar Oct 27 '19 07:10 khannurien

Anecdata, FWIW: For the reverse proxy in front of Airsonic, I switched from nginx-proxy (with proxy_max_temp_file_size set to 0) to Traefik v2, and this problem went away entirely.

witten avatar Nov 10 '19 00:11 witten

Anecdata, FWIW: For the reverse proxy in front of Airsonic, I switched from nginx-proxy (with proxy_max_temp_file_size set to 0) to Traefik v2, and this problem went away entirely.

I was using jwilder's nginx-proxy too and just switched to Traefik v2 following your post. Will report if this solves the bug for me!

Update: it didn't work for me. Did you use any specific configuration?

khannurien avatar Nov 10 '19 21:11 khannurien

No specific configuration beyond standard stuff: enabling the Docker provider, enabling TLS (Let's Encrypt), etc. Either switching to Traefik could be unrelated to this issue, or I could be experiencing a different issue than you.

witten avatar Nov 10 '19 22:11 witten

F it, I disabled transcoding in the web player. No solution, no problem :-)

khannurien avatar Nov 11 '19 07:11 khannurien

Update: Even with Traefik, I'm still experiencing this issue. It just gets much further along into the track before failing than it used to with nginx-proxy.

witten avatar Nov 18 '19 01:11 witten

This issue has been automatically marked as stale because it has not had recent activity. Thank you for your contributions.

stale[bot] avatar Feb 16 '20 02:02 stale[bot]

Hi, seeing this in safari (with flacs) too, usually only a minute or two into the track.

Watching the logs while it plays, the transcoder restarting is when the song restarts in the browser. The first Broken pipes happens soon as I hit play.

Oct 24 14:56:10 TANKAGE java[2820466]: 2019-10-24 14:56:10.912  INFO --- o.a.p.io.TranscodeInputStream            : Starting transcoder: [/var/lib/airsonic/transcode/ffmpeg] [-i] [/tank/media/music/library/martyrdod/2019-Hexhammaren/02 Rannilar.flac] [-map] [0:0] [-b:a] [192k] [-v] [0] [-f] [mp3] [-]
Oct 24 14:56:13 TANKAGE java[2820466]: 2019-10-24 14:56:13.086  INFO --- o.a.p.c.StreamController                 : 10.147.20.128: Client unexpectedly closed connection while loading https://music.93afae5963d77bcd.space/stream?player=93&id=492705 (java.io.IOException: Broken pipe)
Oct 24 14:56:13 TANKAGE java[2820466]: 2019-10-24 14:56:13.102  INFO --- o.a.p.s.LoggingExceptionResolver         : 10.147.20.128: Client unexpectedly closed connection while loading https://music.93afae5963d77bcd.space/stream?player=93&id=492705 (java.io.IOException: Broken pipe)



Oct 24 14:56:55 TANKAGE java[2820466]: 2019-10-24 14:56:55.131  INFO --- o.a.p.io.PlayQueueInputStream            : 10.147.20.128: anuser listening to 2019-Hexhammaren/02 Rannilar.flac
Oct 24 14:56:55 TANKAGE java[2820466]: 2019-10-24 14:56:55.134  INFO --- o.a.p.io.TranscodeInputStream            : Starting transcoder: [/var/lib/airsonic/transcode/ffmpeg] [-i] [/tank/media/music/library/martyrdod/2019-Hexhammaren/02 Rannilar.flac] [-map] [0:0] [-b:a] [192k] [-v] [0] [-f] [mp3] [-]
Oct 24 14:56:57 TANKAGE java[2820466]: 2019-10-24 14:56:57.286  INFO --- o.a.p.c.StreamController                 : 10.147.20.128: Client unexpectedly closed connection while loading https://music.93afae5963d77bcd.space/stream?player=93&id=492705 (java.io.IOException: Broken pipe)
Oct 24 14:56:57 TANKAGE java[2820466]: 2019-10-24 14:56:57.310  INFO --- o.a.p.s.LoggingExceptionResolver         : 10.147.20.128: Client unexpectedly closed connection while loading https://music.93afae5963d77bcd.space/stream?player=93&id=492705 (java.io.IOException: Broken pipe)
![Screen Shot 2019-10-24 at 2 57 25 PM]

I don't know if this was happening before the most recent airsonic update; I wasn't using safari then. It's like, do you want a broken browser, or battery life?

The OK stream is a non transcoded mp3. The red one is a transcoded flac. Screen Shot 2019-10-24 at 5 23 13 PM for whatever reason, it can't make the range response safari wants when it's a transcode

The problem is safari and all the native ios/macos audio frameworks don't just send one request and start receiving the stream.

They send a first request with range: 0-1 header to get the first couple of bytes to try to determine the file type.

Then they send a second request for the whole file. If the first request does not return status code 206 with just the first 2 bytes then the second request fails and the file doesn't play.

Subsonice/airsonic transcoder seems to respond with status 200 and just start streaming the whole file on the first request, when the subsequent request comes in it restarts the transcoder, so if you look in your logs you will see 2x " starting transcoder" entries whenever an apple device requests a stream and then usually and eof/broken pipe exception in your logs as you have just started 2 ffmpeg transcode sessions on top of each other.

If you try chrome you can see it sends a single request with range: 0- header which let's the transcoder just start streaming the file. Chrome/Android/Windows native players all work fine like this. It's just Apple that have created some special requirement for themselves.

I know this is an older post but I just came across this and have spent quite a lot of time trying to work around it. The solution needs to be implemented on the server side to handle Apples special requests and I'm a client app developer so short of writing my own media handling framework I'm stuck with Apple's crappy implementation here.

ghenry22 avatar Jul 04 '21 05:07 ghenry22