apognu / otter

Music player for Funkwhale
MIT License
216 stars 21 forks source link

Application crashs when resuming an old queue on a server using an S3 backend #42

Closed jqueuniet closed 4 years ago

jqueuniet commented 4 years ago

On S3-based Funkwhale servers, media and related files (covers mainly) only have a short lived key-based permission. Attempt to resume an old queue after permissions lapse will end in failure, only really works with radios since new tracks are dynamically added to the queue. The web player usually skips tracks until it finds one with a valid permission.

Otter is crashing when resume is asked on an old playing queue.

Asking for another resume after the first crash will start playing the current media in "background" while showing the "Otter keeps crashing" dialogue. It will keep playing, either until it ends, or until the crash dialogue is answered by the user. Once the media ends, it will crash for good. I guess it might play from cache.

To reproduce:

  1. Have a S3-based Funkwhale server
  2. Fill the queue with songs, play some of them
  3. Pause, wait for an hour (more if you configured longer TTL for permissions)
  4. Resume playing the queue

Otter should either play the tracks from cache without crashing, find a way to refresh permissions or skip the tracks until it finds a valid one. A button to completely clear the current queue like on the web player would also really help.

apognu commented 4 years ago

Is this particular instance public? I do not have access to an S3-backed Funkwhale instance, so it might be a bit difficult to reproduce on my side, for now.

The crash is the most troubling to me, and I'd try to fix that first. For the underlying issue, the whole queue management and playback strategy would probably have to be rewritten to fetch media location right before playback instead of when adding it to queue.

jqueuniet commented 4 years ago

I'll try to ask around, see if anyone knows about a public S3-based instance. My own is private unfortunately. I could give you an account, but I should take another look at the sign up process first as it was pretty much disabled.

Meanwhile, I took a look at HTTP logs and here is what I saw during the application boot process.

100.64.1.202 - - [02/Jun/2020:21:23:48 +0000] "GET /api/v1/favorites/tracks/all/?playable=true&page_size=50&page=1 HTTP/1.1" 200 20423 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"
100.64.1.202 - - [02/Jun/2020:21:23:48 +0000] "GET /api/v1/playlists/?playable=true&page_size=50&page=1 HTTP/1.1" 200 52 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"
100.64.1.202 - - [02/Jun/2020:21:23:48 +0000] "GET /api/v1/favorites/tracks/all/?playable=true&page_size=50&page=1 HTTP/1.1" 200 20423 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"
100.64.1.202 - - [02/Jun/2020:21:23:49 +0000] "GET /api/v1/listen/ed0591f7-4b39-4225-b4aa-b0e4ae539ca8/?upload=49a4bfd3-5ff2-47f1-acba-b8a832e037d1 HTTP/1.1" 302 0 "-" "Otter/1.0.17 (Linux;Android 10) ExoPlayerLib/2.10.6"
100.64.1.202 - - [02/Jun/2020:21:23:53 +0000] "GET /api/v1/tracks/?favorites=true&playable=true&page_size=50&page=1 HTTP/1.1" 200 239430 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"
100.64.1.202 - - [02/Jun/2020:21:23:53 +0000] "GET /api/v1/artists/?playable=true&page_size=50&page=1 HTTP/1.1" 200 71380 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"
100.64.1.202 - - [02/Jun/2020:21:23:55 +0000] "GET /api/v1/tracks/?favorites=true&playable=true&page_size=50&page=2 HTTP/1.1" 200 240109 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"
100.64.1.202 - - [02/Jun/2020:21:23:56 +0000] "GET /api/v1/albums/?playable=true&page_size=50&page=1 HTTP/1.1" 200 1960236 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"
100.64.1.202 - - [02/Jun/2020:21:23:57 +0000] "GET /api/v1/tracks/?favorites=true&playable=true&page_size=50&page=3 HTTP/1.1" 200 237892 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"
100.64.1.202 - - [02/Jun/2020:21:23:59 +0000] "GET /api/v1/tracks/?favorites=true&playable=true&page_size=50&page=4 HTTP/1.1" 200 238573 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"
100.64.1.202 - - [02/Jun/2020:21:24:00 +0000] "GET /api/v1/tracks/?favorites=true&playable=true&page_size=50&page=5 HTTP/1.1" 200 234824 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"
100.64.1.202 - - [02/Jun/2020:21:24:01 +0000] "GET /api/v1/tracks/?favorites=true&playable=true&page_size=50&page=6 HTTP/1.1" 200 239634 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"
100.64.1.202 - - [02/Jun/2020:21:24:03 +0000] "GET /api/v1/tracks/?favorites=true&playable=true&page_size=50&page=7 HTTP/1.1" 200 237686 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"
100.64.1.202 - - [02/Jun/2020:21:24:04 +0000] "GET /api/v1/tracks/?favorites=true&playable=true&page_size=50&page=8 HTTP/1.1" 200 236954 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"
100.64.1.202 - - [02/Jun/2020:21:24:06 +0000] "GET /api/v1/tracks/?favorites=true&playable=true&page_size=50&page=9 HTTP/1.1" 200 238460 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"
100.64.1.202 - - [02/Jun/2020:21:24:07 +0000] "GET /api/v1/tracks/?favorites=true&playable=true&page_size=50&page=10 HTTP/1.1" 200 237398 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"
100.64.1.202 - - [02/Jun/2020:21:24:08 +0000] "GET /api/v1/tracks/?favorites=true&playable=true&page_size=50&page=11 HTTP/1.1" 200 238374 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"
100.64.1.202 - - [02/Jun/2020:21:24:10 +0000] "GET /api/v1/tracks/?favorites=true&playable=true&page_size=50&page=12 HTTP/1.1" 200 239841 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"
100.64.1.202 - - [02/Jun/2020:21:24:11 +0000] "GET /api/v1/tracks/?favorites=true&playable=true&page_size=50&page=13 HTTP/1.1" 200 239402 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"
100.64.1.202 - - [02/Jun/2020:21:24:13 +0000] "GET /api/v1/tracks/?favorites=true&playable=true&page_size=50&page=14 HTTP/1.1" 200 238886 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"
100.64.1.202 - - [02/Jun/2020:21:24:14 +0000] "GET /api/v1/tracks/?favorites=true&playable=true&page_size=50&page=15 HTTP/1.1" 200 237845 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"
100.64.1.202 - - [02/Jun/2020:21:24:16 +0000] "GET /api/v1/tracks/?favorites=true&playable=true&page_size=50&page=16 HTTP/1.1" 200 236009 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"
100.64.1.202 - - [02/Jun/2020:21:24:17 +0000] "GET /api/v1/tracks/?favorites=true&playable=true&page_size=50&page=17 HTTP/1.1" 200 232347 "-" "Dalvik/2.1.0 (Linux; U; Android 10; Pixel 3a XL Build/QQ2A.200501.001.B2)"

Not much to see here, only specific thing of note is the listen call, which is returning a 302 redirection to the actual S3 bucket. S3 URLs look like this: https://s3server/bucket/funkwhale/tracks/ed/60/4f/01-my-song.mp3?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=abcdef%2F20200602%2Feu-central-1%2Fs3%2Faws4_request&X-Amz-Date=20200602T212822Z&X-Amz-Expires=3600&X-Amz-SignedHeaders=host&X-Amz-Signature=abcdef

I can't see any HTTP request to the Funkwhale reverse proxy when I press play and the application crash.

apognu commented 4 years ago

I could not reproduce the issue through an unauthorized queue URL. There is indeed a bug with skipping the failed track, which I hope will be fixed soon.

On the other hand, I fixed a crash in 97b7dc2a61aba14191fe7734d3885c1df877151d where the app would force close if I tried to use an unauthorized URL (or an otherwise erroring URL) for the cover art in Android's media controls (in the notification center).

Are your cover arts also stored on S3?

jqueuniet commented 4 years ago

Yes, cover arts are stored on S3 too.

apognu commented 4 years ago

Ok, there is a high probability that this is the root issue. If so, this will be fixed in the next update. But I cannot be sure until then.

I am also trying for the logs copying feature to make the cut into this same release to help reporting issues like this in the future.

apognu commented 4 years ago

If you were willing to uninstall your app from your device, you could test this build from the tip of the develop branch to check the the issue was fixed.

If not, the build includes a way to copy the logs for the latest crash that would help me pinpoint it.

jqueuniet commented 4 years ago

I tried the new tip build, the crash went away with it. I can now resume the track left paused and the playlist continues to the next track without any issue. The only kind of malfunction left is with cover arts, after sufficient time they disappear, leaving only an empty space in the UI where they used to be. Only for the current playqueue, browsing the server content works as expected.

apognu commented 4 years ago

Good news!

Would you mind creating a separate issue for the cover art bug? This seems non-blocking for me so I will work on it starting next week.