Very slow loading of library

[mavit]

Shuttle version:

v1.6.4 (and recent previous Shuttle+ releases).

Device, OS:

Sony Xperia Z5 Compact running Android 7.0 (and recent previous Android releases).

Description of bug:

Shuttle takes several minutes on startup before it can show my music library.

Steps to reproduce:

1. Have a large music collection on an SD card.
2. Open Shuttle.
3. Select Library from the hamburger menu.
4. Click on any of the tabs "Artists", "Albums", "Songs", etc.

If I remove the SD card then the problem goes away (but so does my music collection).

Expected outcome:

The tab contents would be immediately populated with the appropriate information. If this is not possible, some kind of indication of progress or activity would be given instead.

Observations/Actual Result:

The tab contents remains white and empty for one to two minutes. Once one tab has loaded, all of the other tabs are loaded too and will populate immediately if clicked.

[timusus]

Do you have any programming experience? This one might require a bit more investigation on the device (I can't replicate this issue).

[mavit]

I do.

I've had a quick look at adb logcat while this is happening. I'm not sure if it's relevant, but I see something like the following repeated many times a few seconds before the list finally poplates:

03-19 13:53:51.711 17734 17746 E CursorWindow: Could not allocate CursorWindow '/data/user/0/com.android.providers.media/databases/external.db' of size 2097152 due to error -24.
03-19 13:53:51.716 17734 17746 E JavaBinder: *** Uncaught remote exception!  (Exceptions are not yet supported across processes.)
03-19 13:53:51.716 17734 17746 E JavaBinder: android.database.CursorWindowAllocationException: Cursor window allocation of 2048 kb failed. # Open Cursors=969 (# cursors opened by pid 17889=969)
03-19 13:53:51.716 17734 17746 E JavaBinder:    at android.database.CursorWindow.<init>(CursorWindow.java:108)
03-19 13:53:51.716 17734 17746 E JavaBinder:    at android.database.AbstractWindowedCursor.clearOrCreateWindow(AbstractWindowedCursor.java:198)
03-19 13:53:51.716 17734 17746 E JavaBinder:    at android.database.sqlite.SQLiteCursor.fillWindow(SQLiteCursor.java:138)
03-19 13:53:51.716 17734 17746 E JavaBinder:    at android.database.sqlite.SQLiteCursor.getCount(SQLiteCursor.java:132)
03-19 13:53:51.716 17734 17746 E JavaBinder:    at android.database.CursorToBulkCursorAdaptor.getBulkCursorDescriptor(CursorToBulkCursorAdaptor.java:145)
03-19 13:53:51.716 17734 17746 E JavaBinder:    at android.content.ContentProviderNative.onTransact(ContentProviderNative.java:128)
03-19 13:53:51.716 17734 17746 E JavaBinder:    at android.os.Binder.execTransact(Binder.java:565)
03-19 13:53:51.763 17734 17786 E JavaBinder: *** Uncaught remote exception!  (Exceptions are not yet supported across processes.)
03-19 13:53:51.763 17734 17786 E JavaBinder: java.lang.RuntimeException: Could not write CursorWindow to Parcel due to error -24.
03-19 13:53:51.763 17734 17786 E JavaBinder:    at android.database.CursorWindow.nativeWriteToParcel(Native Method)
03-19 13:53:51.763 17734 17786 E JavaBinder:    at android.database.CursorWindow.writeToParcel(CursorWindow.java:705)
03-19 13:53:51.763 17734 17786 E JavaBinder:    at android.database.BulkCursorDescriptor.writeToParcel(BulkCursorDescriptor.java:63)
03-19 13:53:51.763 17734 17786 E JavaBinder:    at android.content.ContentProviderNative.onTransact(ContentProviderNative.java:133)
03-19 13:53:51.763 17734 17786 E JavaBinder:    at android.os.Binder.execTransact(Binder.java:565)

[timusus]

Thanks, this is helpful.

I'm investigating this one. 969 open cursors is a very bad thing.

Are you just displaying the default tabs in Shuttle (genres, recent, artists, albums, songs)? Or have you selected others via settings -> choose tab items?

Can you try removing tabs (via settings -> choose tab items), one at a time, and see if there is a particular tab causing the problem? I would suggest starting with 'genres'.

[timusus]

Interesting, potentially related: http://stevevallay.github.io/blog/2014/11/17/memory-leak/

[timusus]

@mavit can you have another look, and check which process has the pid associated with the huge number of open cursors?

So, get the 'pid' from the the log android.database.CursorWindowAllocationException: Cursor window allocation of 2048 kb failed. # Open Cursors=969 (# cursors opened by pid 17889=969) and match it against the running processes on your phone.

I think it's just adb shell ps.

I'm just trying to figure out if Shuttle is causing the problem, or some other app is exhausting your memory allocation, which then causes problems in Shuttle.

[mavit]

Assuming these error numbers are the same as "normal" Linux, 24 is EMFILE, "Too many open files". I guess this is going to have slightly different causes to those described in the linked blog posting, which talks about ENOMEM, "Out of memory".

The process ID mentioned in the log is:

USER      PID   PPID  VSIZE   RSS    WCHAN              PC   NAME
u0_a273   12546 3478  1575064 171524 SyS_epoll_ 0000000000 S com.simplecity.amp_pro

I was using the default tab set. Switching tabs off and on, I find that the Playlists and Folders tabs load almost immediately. The Songs tab loads in a few seconds, and the Artists, Albums and Suggested tabs in a few seconds more than that. I gave up waiting for the Genres tab to load. Performance feels better the fewer tabs are switched on. top shows fairly high CPU usage, and the phone gets warm.

User 22%, System 34%, IOW 0%, IRQ 0%
User 409 + Nice 12 + Sys 638 + Idle 757 + IOW 0 + IRQ 13 + SIRQ 3 = 1832

  PID USER     PR  NI CPU% S  #THR     VSS     RSS PCY Name
32410 u0_a40   20   0  36% S    24 2668176K  58808K  fg android.process.media
 4796 system   18  -2  17% S   190 2662664K 268964K  fg system_server
  141 root     25   5   2% S     1      0K      0K  fg ksmd
32474 u0_a273  20   0   0% S  2932 5594948K 145848K  fg com.simplecity.amp_pro
...

[timusus]

@mavit thanks for the thorough investigation, I appreciate it. Are you available to chat on slack or hangouts? There's a slack channel listed at the top of the readme, or otherwise my email is t.malseed@gmail.com.

So it sounds like the genres tab is the worst one (I'm not really surprised here, this one does a lot of sql querying to determine genre play counts. I'll have to look into it further.

Your initial issue report says the library takes a few minutes to load, but your latest comments suggests it's just a few seconds (for all tabs except genres). Is that right?

[mavit]

Tabs take several minutes to populate when the Genres tab is enabled but much less when the Genres tab is disabled.

[Dan33185]

I noticed this is closed...am I the only one still dealing with this problem? This was also thought to be related to search issues, which are still occuring for me.

[timusus]

@Dan33185 which version of Shuttle are you using?

This was not thought to be related to search issues, it was the other way around. There was a specific issue to do with genre loading, which on certain devices with lots of genres, caused the entire library to slow down. This has been resolved and verified as fixed by the original reporter, hence why this issue is closed.

Please provide some more details about how this problem presents itself for you.

[Dan33185]

My bad, thought these 2 were related in some ways. My problem is that Shuttle takes about 10-15 seconds to load, and searching still is not working, it just keeps spinning when searching for anything. Using version 1.6.5 B8

[timusus]

It might be easier to continue this conversation on slack: http://shuttle-slack-inviter.herokuapp.com/

The search issue is related to the slow library loading - if your library is taking 10-15 seconds to load, and search is filtering that library, then it kind of makes sense that search isn't working.

The question is.. what's slowing down your library..? I have no idea!

[Dan33185]

Following