OxygenCobalt / Auxio

A simple, rational music player for android
GNU General Public License v3.0
1.82k stars 120 forks source link

Music scanning timeout is too small for large files #697

Closed nphantasm closed 4 months ago

nphantasm commented 4 months ago

Describe the Bug/Crash

When Auxio encounters a large file (largest file is 80MB, ogg container) while scanning media folders for music it incorrectly times out. Older versions were stuck at these files for up to 40 seconds and then continued (tested on 3.2.1). Affected versions: 3.3.0+

  1. Have a big file in some folder Auxio scans
  2. Reinstall app forcing the library to be rebuilt (force rebuild in app probably works too)
  3. Scanning works as expected until it times out on a large file with an error below
  4. Retrying always fails on the same file (file / n)

Describe the intended behavior

There probably should be an option to either ignore the file, or to try to scan specifically this file without a timeout with a warning it might deadlock. If it succeeds, the scan should continue as normal with timeouts.

What android version do you use?

Android 13

What device model do you use?

Realme 9 (RMX3521)

Bug report

Stack trace from error in Auxio

java.lang.Exception: DeviceLibrary creation failed: java.util.concurrent.TimeoutException: Timed out receiving element from channel: kotlinx.coroutines.TimeoutCancellationException: Timed out waiting for 10000 ms
    at org.oxycblt.auxio.music.MusicRepositoryImpl$indexImpl$deviceLibraryJob$1.invokeSuspend(SourceFile:92)
    at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(Unknown Source:8)
    at kotlinx.coroutines.internal.ScopeCoroutine.afterResume(Unknown Source:6)
    at kotlinx.coroutines.AbstractCoroutine.resumeWith(SourceFile:23)
    at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(Unknown Source:31)
    at kotlinx.coroutines.DispatchedTask.run(Unknown Source:94)
    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(SourceFile:92)

Duplicates

OxygenCobalt commented 4 months ago

Yikes, I didn't realize this could occur. I'll increase it to 1 minute.

OxygenCobalt commented 4 months ago

I am actually a tad confused about why this is occuring, 40 seconds seems absurd for an 80 mb OGG file. Did you mean 800mb? Can you provide a sample file @nphantasm? Try not to upload copyrighted material while still providing a file that takes a long time to index.

nphantasm commented 4 months ago

No the file size is correct and probably unrelated, because I removed some of those files and the issue persists. What probably causes the long scan times is a combination of slow storage (SD card in my case) and large album art (even with the max 1500x1500 - didn't see any OOM in the logs). When I replace all album art in the directory which times out with a smaller 500x500 one and copy back the files, the scan completes successfully.

I wasn't able to create a test file, because every one I made either didn't reproduce this with even bigger file sizes and same size of album art, or are completely missed and Auxio says it wasn't able to find any media, when I restrict it only to the one test directory.

I also noticed that files with the same album art don't all do this and usually only 1 or 2 are slow (around 20 seconds) and there appears to be some caching on Android's end. If I replace the album art with a different one, the album art sometimes doesn't change even after deleting app data and restarting the phone (intermittent and out of scope for Auxio to deal with). While testing I also found you can initiate the media rescan multiple times for which I'll create another issue if it already isn't one.

Here's a new stack trace I was able to get with a different error:

java.lang.Exception: DeviceLibrary creation failed: java.lang.Exception: Tag extraction failed: java.util.concurrent.TimeoutException: Timed out sending element RawSong(mediaStoreId=1000010714, dateAdded=1706391660, dateModified=1706389198, path=Path(volume=ExternalVolumeImpl(storageVolume=StorageVolume: Karta SD (29E0-1F0E)), components=Music/Alestorm/Curse of the Crystal Coconut/19 - Shit Boat (No Fans) (16th Century Version).opus), size=9644708, durationMs=74316, extensionMimeType=audio/ogg, replayGainTrackAdjustment=null, replayGainAlbumAdjustment=null, musicBrainzId=null, name=Shit Boat (No Fans) (16th Century version), sortName=null, track=19, disc=1, subtitle=null, date=2020, albumMediaStoreId=6031293372557699957, albumMusicBrainzId=cbe627c2-7771-4a88-b77f-685649817ec0, albumName=Curse of the Crystal Coconut, albumSortName=null, releaseTypes=[], artistMusicBrainzIds=[], artistNames=[Alestorm], artistSortNames=[], albumArtistMusicBrainzIds=[], albumArtistNames=[Alestorm], albumArtistSortNames=[], genreNames=[Metal]) to channel: kotlinx.coroutines.TimeoutCancellationException: Timed out waiting for 10000 ms
    at org.oxycblt.auxio.music.MusicRepositoryImpl$indexImpl$deviceLibraryJob$1.invokeSuspend(SourceFile:92)
    at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(Unknown Source:8)
    at kotlinx.coroutines.DispatchedTask.run(Unknown Source:94)
    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(SourceFile:92)

Problematic file metadata:

Input #0, ogg, from '19 - Shit Boat (No Fans) (16th Century Version).opus':
  Duration: 00:01:14.32, start: 0.000000, bitrate: 1038 kb/s
  Stream #0:0: Audio: opus, 48000 Hz, stereo, fltp
    Metadata:
      ALBUM           : Curse of the Crystal Coconut
      album_artist    : Alestorm
      ARTIST          : Alestorm
      DATE            : 2020
      disc            : 1
      DISCTOTAL       : 1
      ENCODER         : opusenc from opus-tools 0.2
      ENCODER_OPTIONS : --bitrate 256 --vbr
      GENRE           : Metal
      MUSICBRAINZ_ALBUMID: cbe627c2-7771-4a88-b77f-685649817ec0
      MUSICBRAINZ_TRACKID: 5535d1a6-c573-476e-84dd-4fe992e8d102
      TITLE           : Shit Boat (No Fans) (16th Century version)
      track           : 19
      TRACKTOTAL      : 22
  Stream #0:1: Video: png, rgb24(pc, gbr/unknown/unknown), 1500x1500 [SAR 1:1 DAR 1:1], 90k tbr, 90k tbn (attached pic)
    Metadata:
      comment         : Cover (front)

19 - Shit Boat (No Fans) (16th Century Version).opus: Ogg data, Opus audio, version 0.1, stereo, 48000 Hz (Input Sample Rate)

Logs from logcat: log-3.2.1-working.txt log-3.3.3-timeout.txt

OxygenCobalt commented 4 months ago

Weird. From that perspective your phone might be dynamically generating the media database on the fly (which is super weird), on top of Auxio doing it's own tag extraction routine. Not much I can do about it.

nphantasm commented 4 months ago

Managed to create some test files that fail both on internal and external storage. What it comes down to is an unnecessarily large file size for album art and indexing ogg/opus files. Other formats may be also affected, but I only tested ogg/opus and MP3. MP3 seems to be unaffected.

Steps to reproduce:

  1. Use the only include selected folders in music library option to limit the number of songs to a smaller amount
  2. Include few folders with working files (~100) and add a folder with the test files (mp3 and opus)
  3. Save the configuration and force rescan
  4. Go back (at this point the rescan might be running twice, in that case let it end and force rescan again, or retry if it failed). The library should be already rebuilding and either the scan will stop at the beginning with the indeterminate progress bar, or fail later
  5. If the error didn't occur, scale the test.png to a bigger size with GIMP for example, export with compression level 0 and add the picture to the file via Musicbrainz Picard, or other means (reencoding the test.wav with opusenc with the --picture flag set) and go back to point 3 after replacing the old file.

If the opus files are removed from the test folder and library is rescanned, the only test file that should show up without problems is the MP3 one.

test.png in the archive is 1500x1500 with compression level 9 (~1MB). For the error to occur with these test files, the album art needs to be stupidly large (7+ MB). However I've seen the error with smaller sizes for other files (~5 MB; still uncompressed PNG).

The files with bigger in the filename were made to fail on my internal storage and have a bigger album art (2000x2000, ~12MB). Files with 1500x1500 compression level 0 PNGs failed only on external storage for me. The index time for the bigger opus file is approximately 18 seconds on internal storage with version 3.2.1.

Encoding options: opusenc --vbr --bitrate 256 --padding 0. Padding doesn't seem to make a difference, but I removed it because the original file in my previous comment doesn't have it either.

test-file.zip (Google Drive)

OxygenCobalt commented 4 months ago

Okay, I can't reproduce that freezeup. Auxio loads the files w/large cover art instantly. I assume this is a consequence of realme weirdness and slow storage. I'll just increase the timeout.

OxygenCobalt commented 4 months ago

Actually, I was able to reproduce it. It does seem like a consequence of ExoPlayer parsing (My guess is that packet streaming or file reads are the bottleneck). Still nothing I can do about it. At least this extreme delay should only occur when re-scanning music, the cache should prevent it from occurring again.

hellpe commented 4 months ago

I'm also reproducing this issue on my Crosscall Action-X5 using Android 12L. I don't know yet how to locate my largest cover art embeds among my +20000 songs library, however.

nphantasm commented 4 months ago

@OxygenCobalt Thanks for your time. I'll look into making a small app that uses ExoPlayer as a test in the next few weeks and I'll create an issue upstream, if I can figure out where the bottleneck is.

@hellpe You have a few options:

  1. Copy the whole library to your computer and use Musicbrainz Picard to load the library and let it sort through it. At the end you'll have all your albums sorted (if they are correctly tagged) and all album art will be visible in the bottom right. Clicking "Show more details" will give you the size of the album art (resolution and file size). You can try working over MTP from your phone directly, but that's usually unreliable and broken for many phones.
  2. Use Auxio's option to only include selected folders in the library (Settings ->Music Folders -> Include) and slowly eliminate folders which don't cause errors.
hellpe commented 4 months ago

@hellpe You have a few options:

1. Copy the whole library to your computer and use Musicbrainz Picard to load the library and let it sort through it. At the end you'll have all your albums sorted (if they are correctly tagged) and all album art will be visible in the bottom right. Clicking "Show more details" will give you the size of the album art (resolution and file size). You can try working over MTP from your phone directly, but that's usually unreliable and broken for many phones.

2. Use Auxio's option to only include selected folders in the library (Settings ->Music Folders -> Include) and slowly eliminate folders which don't cause errors.

Thanks for your advice, but in my case, I'm afraid those are not the most convenient approaches. I have several hundred albums to check one-by-one in Picard, and Auxio (or my file manager app, which is Files by Google) does not allow me to select more than one folder at a time, making it very tedious to locate the files that trigger the issue. I'm gonna explore other options.