Long delay on app start [solved]

Discuss
#1

Hey all,
I’ve had some issues with one of my compiled apps lately. When I compile my Musicplayer app, and install it on one of my devices, it has absurdly long startup times of 20 seconds. I’m testing on a Motorola Moto One with Android 10 and ~ 250 mp3 files. I would like to find out whether that’s my fault or if a Kodular component is causing the issue. The app contains three tabs with lists and loads all these files on initialization. I can’t post the full logcat dump here due to its length, but here are some sections

Logcat 
06-20 18:24:57.334  2905  2917 W qti_sensors_hal: processReportInd: lux: 17, ch0: 1519, ch1: 883
06-20 18:25:02.184  2905  2917 W qti_sensors_hal: processReportInd: lux: 7, ch0: 1294, ch1: 557
06-20 18:25:04.833  2905  3383 W qti_sensors_hal: reportSingleEvent: NearBy 1, pData 731,  highThd 517
06-20 18:25:05.118  2905  3383 W qti_sensors_hal: reportSingleEvent: NearBy 0, pData 304,  highThd 517
06-20 18:25:05.573  2905  3383 W qti_sensors_hal: reportSingleEvent: NearBy 1, pData 626,  highThd 517
06-20 18:25:05.802  2905  3383 W qti_sensors_hal: reportSingleEvent: NearBy 0, pData 146,  highThd 517
06-20 18:25:06.177  2905  2917 W qti_sensors_hal: processReportInd: lux: 16, ch0: 1530, ch1: 861
06-20 18:25:26.548  3614  3716 E system_server: Invalid ID 0x00000000.
06-20 18:25:26.574 15619 15619 E edpandaapps.ja: Not starting debugger since process cannot load the jdwp agent.
06-20 18:25:26.628 15619 15619 W edpandaapps.ja: Class com.google.appinventor.components.runtime.multidex.MultiDex failed lock verification and will run slower.
06-20 18:25:26.628 15619 15619 W edpandaapps.ja: Common causes for lock verification issues are non-optimized dex code
06-20 18:25:26.628 15619 15619 W edpandaapps.ja: and incorrect proguard optimizations.
06-20 18:25:26.631 15619 15619 W edpandaapps.ja: Class android.support.v4.content.FileProvider failed lock verification and will run slower.                    
06-20 18:25:26.640 15619 15619 W edpandaapps.ja: Class android.support.v4.content.ContextCompat failed lock verification and will run slower.                   
06-20 18:25:26.667 15619 15619 W edpandaapps.ja: Class gnu.mapping.Namespace failed lock verification and will run slower.
06-20 18:25:26.696 15619 15619 W edpandaapps.ja: Class android.support.v4.util.SimpleArrayMap failed lock verification and will run slower.                     
06-20 18:25:26.714 15619 15619 W edpandaapps.ja: Class android.support.v4.app.FragmentManagerImpl failed lock verification and will run slower.                 
06-20 18:25:26.716 15619 15619 W edpandaapps.ja: Class gnu.expr.ModuleContext failed lock verification and will run slower.
06-20 18:25:26.720 15619 15619 W edpandaapps.ja: Class gnu.bytecode.Type failed lock verification and will run slower.
06-20 18:25:26.727 15619 15619 W edpandaapps.ja: Class gnu.bytecode.ClassType failed lock verification and will run slower.
06-20 18:25:26.734 15619 15619 W edpandaapps.ja: Class gnu.expr.ModuleBody failed lock verification and will run slower.
06-20 18:25:26.748 15619 15619 W edpandaapps.ja: Class android.support.v4.util.LruCache failed lock verification and will run slower.
06-20 18:25:26.774 15619 15619 W edpandaapps.ja: Class android.support.v4.util.Pools$SynchronizedPool failed lock verification and will run slower.             
06-20 18:25:26.782 15619 15619 W edpandaapps.ja: Class android.support.v7.content.res.AppCompatResources failed lock verification and will run slower.          
06-20 18:25:26.788 15619 15619 W edpandaapps.ja: Class android.support.v7.widget.TintContextWrapper failed lock verification and will run slower.               
06-20 18:25:26.799 15619 15619 W edpandaapps.ja: Class android.support.v7.widget.AppCompatTextViewAutoSizeHelper failed lock verification and will run slower.  
06-20 18:25:26.809 15619 15619 W edpandaapps.ja: Class gnu.mapping.Environment failed lock verification and will run slower.
06-20 18:25:26.812 15619 15619 W edpandaapps.ja: Class gnu.kawa.reflect.FieldLocation failed lock verification and will run slower.
06-20 18:25:26.816 15619 15619 W edpandaapps.ja: Class gnu.mapping.ThreadLocation failed lock verification and will run slower.
06-20 18:25:26.999 15619 15619 W edpandaapps.ja: Class gnu.text.Char failed lock verification and will run slower.
06-20 18:25:27.042 15619 15619 W edpandaapps.ja: Class gnu.kawa.xml.XmlNamespace failed lock verification and will run slower.
06-20 18:25:27.065 15619 15619 W edpandaapps.ja: Class android.support.v4.view.PagerAdapter failed lock verification and will run slower.
06-20 18:25:27.067 15619 15619 W System.err: Form.setChildWidth(): width = -2 parent Width = 360 child = com.google.appinventor.components.runtime.MakeroidViewPager@6c22a02          
06-20 18:25:27.069  2995  2995 E Layer   : [Surface(name=AppWindowToken{9318943 token=Token{16e4ef2 ActivityRecord{856f1fd u0 com.redpandaapps.jam/io.kodular.redpandadevs.musicplayer.Screen1 t12295}}})/@0x3ad546d - animation-leash#0] No local sync point found
06-20 18:25:27.069  2995  2995 E Layer   : [Surface(name=AppWindowToken{1f4b7ae token=Token{75ed829 ActivityRecord{8f191b0 u0 com.motorola.launcher3/com.android.a1launcher.AndroidOneLauncher t11805}}})/@0x1a94d4a - animation-leash#0] No local sync point found
06-20 18:25:27.084 15619 15619 W System.err: Form.setChildWidth(): width = -2 parent Width = 360 child = com.google.appinventor.components.runtime.MakeroidListViewImageText@ba0ed8b  
06-20 18:25:27.089 15619 15619 W System.err: Form.setChildWidth(): width = -2 parent Width = 360 child = com.google.appinventor.components.runtime.MakeroidListViewImageText@fb92281                                                         
06-20 18:25:27.092 15619 15619 W System.err: Form.setChildWidth(): width = -2 parent Width = 360 child = com.google.appinventor.components.runtime.MakeroidListViewImageText@d2ed767  
06-20 18:25:27.095 15619 15619 W System.err: Form.setChildWidth(): width = -2 parent Width = 360 child = com.google.appinventor.components.runtime.MakeroidListViewImageText@6d465bd  
06-20 18:25:27.158 15619 15619 W edpandaapps.ja: Class com.google.android.exoplayer2.ExoPlayerImplInternal failed lock verification and will run slower.        
06-20 18:25:27.343 15619 15619 W System.err: Form.setChildWidth(): width = -2 parent Width = 360 child = com.google.appinventor.components.runtime.MakeroidViewPager@6c22a02          
06-20 18:25:27.353 15619 15619 W System.err: Form.setChildWidth(): width = -2 parent Width = 360 child = com.google.appinventor.components.runtime.MakeroidListViewImageText@ba0ed8b  
06-20 18:25:27.361 15619 15619 W System.err: Form.setChildWidth(): width = -2 parent Width = 360 child = com.google.appinventor.components.runtime.MakeroidListViewImageText@fb92281  
06-20 18:25:27.367 15619 15619 W System.err: Form.setChildWidth(): width = -2 parent Width = 360 child = com.google.appinventor.components.runtime.MakeroidListViewImageText@d2ed767  
06-20 18:25:27.375 15619 15619 W System.err: Form.setChildWidth(): width = -2 parent Width = 360 child = com.google.appinventor.components.runtime.MakeroidListViewImageText@6d465bd  
06-20 18:25:27.381 15619 15619 W System.err: Form.setChildWidth(): width = -2 parent Width = 360 child = com.google.appinventor.components.runtime.VerticalArrangement@32fe280        
06-20 18:25:27.393 15619 15619 W System.err: Form.setChildWidth(): width = 48 parent Width = 360 child = com.google.appinventor.components.runtime.Image@80eadf1
06-20 18:25:27.591 15619 15639 W Gralloc3: mapper 3.x is not supported
06-20 18:25:27.668  1575  1614 W SearchServiceCore: Abort, client detached.
06-20 18:25:27.759  3096 15660 E ResolverController: No valid NAT64 prefix (268, <unspecified>/0)
06-20 18:25:27.783  3078  7700 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:27.784 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:27.796  3078  7700 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:27.797 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:27.808  3078  7700 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:27.808 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:27.819  3078  7700 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:27.820 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:27.832  3078  7700 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:27.832 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:27.843  3078  7700 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:27.843 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:27.855  3078  7700 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:27.856 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:27.866  3078  7700 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:27.866 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:27.878  3078  7700 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:27.878 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:27.888  3078  7700 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:27.889 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:27.899  3078  7700 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:27.899 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:27.911  3078  7700 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:27.911 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:27.924 15619 15619 E KodularMetadata: java.lang.NullPointerException: Attempt to invoke virtual method 'boolean android.graphics.Bitmap.compress(android.graphics.Bitmap$CompressFormat, int, java.io.OutputStream)' on a null object reference
06-20 18:25:27.926 15619 15619 E KodularMetadata: java.lang.NullPointerException: Attempt to invoke virtual method 'boolean android.graphics.Bitmap.compress(android.graphics.Bitmap$CompressFormat, int, java.io.OutputStream)' on a null object reference
06-20 18:25:27.937  3078  4462 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:27.937 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:27.948 15619 15619 E KodularMetadata: java.lang.NullPointerException: Attempt to invoke virtual method 'boolean android.graphics.Bitmap.compress(android.graphics.Bitmap$CompressFormat, int, java.io.OutputStream)' on a null object reference
06-20 18:25:27.950 15619 15619 E KodularMetadata: java.lang.NullPointerException: Attempt to invoke virtual method 'boolean android.graphics.Bitmap.compress(android.graphics.Bitmap$CompressFormat, int, java.io.OutputStream)' on a null object reference
06-20 18:25:27.961  3078  7700 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:27.961 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:27.971  3078  4462 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:27.971 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:27.982  3078  7700 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:27.982 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:27.993  3078  3283 E MetadataRetrieverClient: failed to extract an album art

06-20 18:25:52.881 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:52.893  3078  9636 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:52.893 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:52.903  3078  3283 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:52.903 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:52.915  3078  9636 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:52.915 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:52.926  3078  4462 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:52.926 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:52.937  3078  4462 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:52.938 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:52.947  3078  9636 E MetadataRetrieverClient: failed to extract an album art
06-20 18:25:52.947 15619 15619 E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
06-20 18:25:52.967 15619 15684 W edpandaapps.ja: Class com.bumptech.glide.load.engine.cache.DiskCacheWriteLocker failed lock verification and will run slower.  
06-20 18:25:52.968 15619 15684 W edpandaapps.ja: Class com.bumptech.glide.load.engine.cache.DiskCacheWriteLocker$WriteLockPool failed lock verification and will run slower.          
06-20 18:25:52.968 15619 15684 W edpandaapps.ja: Class com.bumptech.glide.load.engine.cache.SafeKeyGenerator failed lock verification and will run slower.      
06-20 18:25:52.970 15619 15684 W edpandaapps.ja: Class com.bumptech.glide.disklrucache.DiskLruCache$1 failed lock verification and will run slower.             
06-20 18:25:52.971 15619 15684 W edpandaapps.ja: Class com.bumptech.glide.disklrucache.StrictLineReader failed lock verification and will run slower.           
06-20 18:25:52.974 15619 15684 W edpandaapps.ja: Class com.bumptech.glide.disklrucache.DiskLruCache$Editor failed lock verification and will run slower.        
06-20 18:25:52.977 15619 15684 W edpandaapps.ja: Class com.bumptech.glide.util.ByteArrayPool failed lock verification and will run slower.
06-20 18:25:52.979 15619 15684 W edpandaapps.ja: Class com.bumptech.glide.util.ExceptionCatchingInputStream failed lock verification and will run slower.

tldr;

A lot of

E MediaMetadataRetrieverJNI: getEmbeddedPicture: Call to getEmbeddedPicture failed.
E MetadataRetrieverClient: failed to extract an album art

Sometimes also

E KodularMetadata: java.lang.NullPointerException: Attempt to invoke virtual method 'boolean android.graphics.Bitmap.compress(android.graphics.Bitmap$CompressFormat, int, java.io.OutputStream)' on a null object reference

I think the errors are slowing down the application. Please help

Edit: Removed link not related to the topic

Reduced Screen1 startup time
#2

This post was flagged by the community and is temporarily hidden.

#3

“Album art” is probably not embedded in all MP3 files, so this problem arises:
failed to extract an album art.

See here:

1 Like
#4

Turns out that wasn’t the reason. Removing the get album art procedure resulted in an improvement of only one second. I will investigate more and keep you updated. I have some suspicions:

  • tabs layout
  • list view
  • my I18n extension
  • my sort function
#5

Did some more testing: When I disable everything except the tabs and the library list, the app start in about 3 seconds. If I enable everything except sorting everything, the app needs 6 seconds to start. It seems that it was mainly my bad sorting function, but also the list population that takes so long

#6

Yes, maybe, I have to take a closer look at your sorting function, see here:

“Note: it may take several seconds to list the gif files”

1 Like
#7

Another thing i noticed in the logs: lots of Class failed lock verification and will run slower.
See

06-23 01:33:43.167 14107 14107 W daapps.jam_tes: Class android.support.v4.content.FileProvider failed lock verification and will run slower.
06-23 01:33:43.176 14107 14107 W daapps.jam_tes: Class android.support.v4.content.ContextCompat failed lock verification and will run slower.   
06-23 01:33:43.203 14107 14107 W daapps.jam_tes: Class gnu.mapping.Namespace failed lock verification and will run slower.  
06-23 01:33:43.232 14107 14107 W daapps.jam_tes: Class android.support.v4.util.SimpleArrayMap failed lock verification and will run slower. 
06-23 01:33:43.251 14107 14107 W daapps.jam_tes: Class android.support.v4.app.FragmentManagerImpl failed lock verification and will run slower. 
06-23 01:33:43.254 14107 14107 W daapps.jam_tes: Class gnu.expr.ModuleContext failed lock verification and will run slower. 
06-23 01:33:43.258 14107 14107 W daapps.jam_tes: Class gnu.bytecode.Type failed lock verification and will run slower.  
06-23 01:33:43.265 14107 14107 W daapps.jam_tes: Class gnu.bytecode.ClassType failed lock verification and will run slower. 
06-23 01:33:43.274 14107 14107 W daapps.jam_tes: Class gnu.expr.ModuleBody failed lock verification and will run slower.
06-23 01:33:43.291 14107 14107 W daapps.jam_tes: Class android.support.v4.util.LruCache failed lock verification and will run slower.
#8

Try load only list for tab 1, when user click tab 2 load list 2.

I’m sorry i don’t see you last post

#9

I finally got the time down to a reasonable amount. Here’s how I tested and what my solutions were:

Finding out what is slowing down your app

Examine your blocks to find out which of them are executed when the app starts. Divide the code into meaningful parts and mark each section with a log block like so
grafik
Plug your phone with the app installed into your computer and start logcat (Full guide). For me (Windows & info level) the command is .\adb logcat *:I. Then take a close look at the output. For best results, I recommend copying the output with Shift+Ctrl+C into a text editor. You can then easily filter and format the logs. You’ll then have to calculate the runtimes for each section using the timestamps. Write them down to see where times can be improved

Improving app startup time

Here are some methods I used to speed up the app

Cache values globally

Does your app need the same values on every start? If you do not expect them to change often, you can save them in a TinyDB

Cache values locally

Do you have static values or values that are needed in every loop? Better store them in a variable

Sorting

Sorting isn’t trivial, so use a sorting algorithm with good performance. Quicksort is fine probably

Lazy loading

Retrieve values only once they are needed

Lists

Do you really need to load the whole list? Try to load what the user sees first and more items later

Conclusion

I was able to reduce the app start time from 20 seconds to three. That’s almost seven times faster. I’m happy to say that neither the tabs layout from Kodular nor my I18n extension were the cause of the slow app start.

6 Likes
#10

Please clarify what exactly has brought success. Sorting the list, partially retrieving the list … ?

1 Like
#11

I used all methods listed above to bring startup time down. I just wrote it so that it is applicable for other apps as well. In practice, that means

  1. I replaced my self-made sorting algorithm with one from an extension
  2. Instead of retrieving the library directly on startup, I save it to the TinyDB and initialize the list from there. After that I can check if the stored value is different from the freshly read library
  3. I only load the library directly as described in 2. All other tabs are initialized once, when the tab is selected
  4. I moved values that are read from a TinyDB or memory in every loop into local variables
3 Likes
#12

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.