Frequent freezing when loading library in v3.1.0

[lukasgierth]

Describe the Bug/Crash

1. Open the app
2. Library starts to load but freezes
3. Android warns that the app is not responding Sometimes it resumes when i click "wait", sometimes it just keeps freezing there.

Only in version 3.1.0, did tests with a downgrade to 3.0.5 and there everything works fine.

Describe the intended behavior

Library should load without hanging/freezing the app completely

What android version do you use?

Android 13

What device model do you use?

OnePlus 6 (LineageOS)

Bug report

Bug report might follow shortly when i have the time to setup android debugging on my laptop.

Duplicates

• [X] I have checked the Troubleshooting page.
• [X] I have checked this issue for duplicates.
• [X] I have checked that this issue occurs on the lastest version.
• [X] I agree to the Contribution Guidelines.

[OxygenCobalt]

I don't even know how this is happening. It's probably not playlisting since it occurs during the song loading phase. I need a bug report ASAP @lukasgierth.

[OxygenCobalt]

Also, if you can, please take a bug report on one of the CI builds that can be found here, they log extremely valuable information for me to fix the issue @lukasgierth.

[zz-1b]

Same problem with 3.1.0 here on Moto X4 running LineageOS 20.

05-29 16:57:37.705 root 29078 29081 D dumpstate: Adding dir /data/misc/prereboot (recursive: 0) 05-29 16:57:37.710 1000 1745 2062 W InputDispatcher: Window 181b4e9 org.oxycblt.auxio/org.oxycblt.auxio.MainActivity (server) is unresponsive: 181b4e9 org.oxycblt.auxio/org.oxycblt.auxio.MainActivity (server) is not responding. Waited 15003ms for FocusEvent(hasFocus=false) 05-29 16:57:37.711 1000 1745 2062 W InputDispatcher: Canceling events for 181b4e9 org.oxycblt.auxio/org.oxycblt.auxio.MainActivity (server) because it is unresponsive --------- beginning of system 05-29 16:57:37.713 1000 1745 2062 I WindowManager: ANR in Window{181b4e9 u0 org.oxycblt.auxio/org.oxycblt.auxio.MainActivity}. Reason:181b4e9 org.oxycblt.auxio/org.oxycblt.auxio.MainActivity (server) is not responding. Waited 15003ms for FocusEvent(hasFocus=false)

[OxygenCobalt]

Okay, this is really bad. Can you please provide a real log from the debug build I provided here @zz-1b? I don't need the android system logs, I need the logs from the app.

[lukasgierth]

So, i installed the latest debug-ci build. Weirdly enough I can only reproduce the problem in parts. It only takes a long time but does not freeze completely anymore after it loaded the library successfully at least once.

So:

• First run of auxio-debug.apk: freezing and unresponsive After it was successful once:
• Takes a long time at the "loading your music library" screen but eventually finished after 20-30 seconds and functions normally.

i attached the log from auxio-debug. auxio-debug.txt

Edit: Added the logs from a clean auxio-debug launch with cleared cache and storage. Lots of freezing and pressing "wait". auxio-debug_cleanlaunch.txt

[OxygenCobalt]

I don't have enough information from that log @lukasgierth. There's only system logs and I need the app logs (Should be from names like Auxio.*). What command did you use?

[OxygenCobalt]

If you don't want to take logs, here are some various CI APKs from the 3.1.0 development cycle that might allow me to bisect the issue.

From 4fe91c2: Auxio_4fe91c2.zip From 049d2bc: Auxio_049d2bc.zip From b2e899a: Auxio_b2e899a.zip From ca349de: Auxio_ca349de.zip

Note: These are all partially or completely incomplete, don't test anything but the freezing.

@lukasgierth @zz-1b

[zz-1b]

Apparently you did not receive the email I sent outside github yesterday evening with the logs attached.

In case this is not what you are looking for, give a bit more detailed instructions how to retrieve the needed log output, please. AuxioLog.txt

[zz-1b]

My music library is ~64GB of mp3 files on a micro SD card btw. and the phone not a recent one, obviously. Perhaps that plays a role.

[OxygenCobalt]

Were you able to reproduce a freeze-up and then take a log @zz-1b? I seemingly can't find anything related to a freeze-up in that log.

[lukasgierth]

@OxygenCobalt I did a complete bugreport with "adb bugreport" and then filtered the log txt for auxio.debug. Android development is not really my area so if you could point me in the right direction how to get the log from the app, i would appreciate it! A quick google search did not really give me the useful answer i'm looking for.

And for information about my music database: ~4100 songs, 95% of them ogg opus and the rest mp3. All without embedded covers inside the file.

[OxygenCobalt]

I would prefer it if you just have me the whole log @lukasgierth? This issue is an interaction between Auxio and the android OS, so I need all of the information to figure out what Auxio was doing at the time of the freeze.

[lukasgierth]

@OxygenCobalt mh, i just want to avoid uploading that complete log here because it seems that it includes a lot of private information that i don't want to be public necessarily.

[OxygenCobalt]

Okay, since getting a reasonable log is largely impractical @lukasgierth, can you try the APKs from here and report which ones have the issue and which don't? This would serve the same purpose and allow me to track down the issue.

[lukasgierth]

@OxygenCobalt i will, but sadly earliest this weekend. Too much going on with work this week.

[zz-1b]

Were you able to reproduce a freeze-up and then take a log @zz-1b? I seemingly can't find anything related to a freeze-up in that log.

Yes, that is what i did but I may have cut the wrong part of the log. grep_auxio_logcat.txt

05-29 17:30:18.550 1745 8988 E ActivityManager: ANR in org.oxycblt.auxio.debug

Did you try to reproduce the problem on your side ? Both @lukasgierth and me seem to have large music libraries. Some of the log messages around seem to indicate 'too much foreground processing'.

[OxygenCobalt]

Okay, looks like I still can't really discern what occurred from your logs @zz-1b. Can you try those APKs from here as well and report which work?

And yes, this is most definitely a scale problem. Something about the music loading routine is blocking the main thread in quadratic time and it's near-impossible to reproduce without the same library size. This shouldn't be occurring since the music loading routine is supposed to be on a background thread, but Android's threading model is garbage.

[TheLastZombie]

I have a similar issue – loading works fine, but scrolling through the library tabs (Songs, Albums, etc.) is extremely laggy, and occasionally freezes as well. I assume the root cause is the same, in part because this too only started to happen after updating to 3.1.0, but let me know if I should open a separate issue.

Screencast (too big for GitHub): https://linx.sny.sh/4o2qg2sm.mp4 Bug report (captured with this Canary build): bugreport-OnePlus7Pro-TQ2A.230505.002-2023-06-01-11-48-11.zip

[lukasgierth]

@OxygenCobalt had some time to test the ci builds, didn't need to look for a long time: 4fe91c2 - works as well as 3.0.5 049d2bc - here the trouble starts so coroutines could most likely be the culprit b2e899a - same as 049d2bc ca349de - edit: tested again, is OK

I can narrow down the problem a little bit more after some testing:

1. Loading the library will take a really long time (way longer than before) but can be successfull (and will be in 98% of the time)
2. BUT: Crashes/freezing gets introduced frequently when the screen locks (=goes black) while the app loads the library

After unlocking you either get the 'Auxio isnt responding' or the app crashed.

[OxygenCobalt]

Thanks @lukasgierth. Now that the range is lowered between 4fe91c2 and 049d2bc, can you try to test these APKs in that range?

From 6cfb50a: Auxio_6cfb50a.zip From 08d36df: Auxio_08d36df.zip From 572b0e5: Auxio_572b0e5.zip

[OxygenCobalt]

@TheLastZombie your issue was also reported in #461. I don't see anything weird in your logs except for some garbage collections and some weird spammy input lines like:

06-01 11:48:01.417  1000   924  7784 E sensors-hal: handle_sns_std_sensor_event:74, wise_light: lux 1072 ,period 357 ms, data c 7

I can't even parse this, so I'd seriously recommend trying the APKs here and here and reporting which ones have the issue. That would be extremely useful to allow me to bisect the issue.

[OxygenCobalt]

Okay, #461 was resolved by fixing the image loading routine. I doubt it will change much here, but if you want to try that APK, it's available here: Auxio_Img3.zip

@zz-1b @lukasgierth

[lukasgierth]

@OxygenCobalt 6cfb50a - OK 08d36df - BAD 572b0e5 - BAD

would be great if someone could confirm this result, maybe @zz-1b .

[OxygenCobalt]

Hey @lukasgierth, I'm somewhat confused by your reported result for ca349de. You said it failed, but then you said it succeeded for 4fe91c2, which came after. Is it possible that you mis-reported something? Or do I need to look back even further?

Anyway, disregarding that anomaly, I've narrowed it to down to one APK. If this fails, I may know the issue now:

Auxio_d0a6835.zip

[lukasgierth]

@OxygenCobalt i did test ca349de again and you are totally correct. Works just fine! Maybe i installed one of the bad ones again instead of this when testing yesterday. I was quite tired after all.

I will test d0a6835 now.

Edit: @OxygenCobalt no, this commit (d0a6835) is still fine. Has to be one after that.

[OxygenCobalt]

Okay, I'm pretty sure I've identified and fixed the issue. I think was an unfortunate interaction between two errors I made when working on 3.1.0:

1. Using Dispatchers.Main to update library information, including the check if the library is meaningfully different. This would have no cost, except
2. Music comparison was made more thorough in 3.1.0, which makes library comparison obscenely expensive.

This probably caused the insane freezing that you saw. Please test this APK to see if the issue is resolved @lukasgierth.

Auxio_457.zip

[lukasgierth]

@OxygenCobalt yes and no. The interface (+loading animation) doesn't freeze anymore, but every start of the app now needs around 50 seconds to load my library ("Loading your music library..."). That's not intended isn't it?

[OxygenCobalt]

Yeah, the problem is I've only removed problem 1, and the stupidly long loading routine remains. I'm going to try optimizing it. Otherwise, this issue seems resolved then (save that part) @lukasgierth.

[lukasgierth]

@OxygenCobalt yes i would say it's fixed and this issue can be closed! The really long loading is annoying of course but it doesn't crash/freeze anymore. :)

[OxygenCobalt]

Here's possibly an APK that improves the loading performance a bit @lukasgierth:

Auxio_457Rev2.zip

I actually think the bottleneck might be elsewhere, though. An expensive comparison like that shouldn't actually occur on the first load, so it might stem from library creation.

[lukasgierth]

@OxygenCobalt yeah, the bottleneck for the long loading times has to be elsewhere. This rev2 apk doesn't impact the loading time. That's the last thing i can test for today/now though, it's nearly midnight here in Germany.

[OxygenCobalt]

No issue. I think I'm narrowing it down to song processing. Sorry for making you stay up so late! @lukasgierth

[zz-1b]

I can confirm Lukas' findings.

Auxio_457Rev2.zip

does not freeze on my Moto X4 either, while initial loading of the library takes some minutes now. Thanks a lot!

[OxygenCobalt]

Okay, good. I believe I actually fixed that slow loading process. It was seemingly caused by me not short-circuiting separator parsing and spending an obscene amount of time doing that. You can test the 3.1.1 build in #465 @zz-1b @lukasgierth to see if load times have improved at all.

[zz-1b]

The loading phase ist much shorter now for me with the 3.1.1 build in https://github.com/OxygenCobalt/Auxio/pull/465.

[lukasgierth]

Finally had time to also test it, looks/works great! The loading is not only rock stable now but also really fast. As fast or even faster than in 3.0.5! Great work @OxygenCobalt :)

[OxygenCobalt]

No issue @zz-1b @lukasgierth, I actually hope to make it even faster eventually by building the music library in parallel with song loading, that will happen as soon as I can find a way to make it deterministic.