subtracks Keeps crashing when using ampache server

The app keeps crashing in emulator when im using it with Ampache server. https://demo.amapche.dev demo/demodemo I am getting the error below but it crashes even without it showing. It seems to work better with navidrome (no errors) but it still crashing at some point. Its crashing faster if im scrolling the playlists. Installed subtracks from playstore and it still crashing in emulator. Seem not to crash on my phone (android 11) but in emulator its always cashing (even if im using the playstore app or if im building it myself from the source). Last version didnt had this problem. After some digging it seem that downloading images causes this error but i am not sure.

WARN [Error: Request does not satisfy expected content type. Expected: image Actual: text] (only on ampache)

Smartphone (please complete the following information):

Device: Pixel 4
OS: Android 9 (same with 8 )
Subtracks version 1.3.0 Installing APK 'app-debug.apk' on 'Pixel_4_API_28(AVD) - 9' for app:debug

May 03 '22 13:05 izyspania

That warning shouldn't cause a crash as far as I can tell, it's just saying that the image fetch failed because ampache responded with text (probably an XML error) instead of an image.

I haven't been able to duplicate this in the release or debug builds in my emulator. Can you hook up Flipper or something similar to get device logs and see if there is a stack trace or something that shows up there?

May 04 '22 02:05 austinried

Hi, it seems that it only happens with Ampache (but i think it did happened with navidrome 1 or 2 times), here are the logs: (With subtracks from google play, but it happens the same when i build it). I am on Windows , maybe it has something to do with it , but other versions were (and still are) working with no problems. Tested with 3 different "fresh" emulators , android 8, 9 11 (with and without google play). Debug info from Android Studio (windows 10, last version).

2022-05-04 17:51:24.353 1783-1811/? E/storaged: getDiskStats failed with result NOT_SUPPORTED and size 0 2022-05-04 17:51:25.541 10902-10922/? E/AndroidRuntime: FATAL EXCEPTION: mqt_native_modules Process: com.subtracks, PID: 10902 java.lang.ArithmeticException: divide by zero at com.ReactNativeBlobUtil.i$a.handleMessage(Unknown Source:96) at android.os.Handler.dispatchMessage(Handler.java:102) at android.os.Looper.loop(Looper.java:193) at com.facebook.react.bridge.queue.MessageQueueThreadImpl$4.run(Unknown Source:37) at java.lang.Thread.run(Thread.java:764) 2022-05-04 17:51:25.602 1931-2000/? E/InputDispatcher: channel '38a2b2c com.subtracks/com.subtracks.MainActivity (server)' ~ Channel is unrecoverably broken and will be disposed! 2022-05-04 17:51:38.158 11090-11090/? E/com.subtracks: Not starting debugger since process cannot load the jdwp agent. 2022-05-04 17:51:38.193 11090-11090/? E/SoLoader: couldn't find DSO to load: libjscexecutor.so SoSource 0: com.facebook.soloader.a[root = /data/data/com.subtracks/lib-main flags = 1] SoSource 1: com.facebook.soloader.a[root = /data/data/com.subtracks/lib-0 flags = 1] SoSource 2: com.facebook.soloader.a[root = /data/data/com.subtracks/lib-1 flags = 1] SoSource 3: com.facebook.soloader.a[root = /data/data/com.subtracks/lib-2 flags = 1] SoSource 4: com.facebook.soloader.a[root = /data/data/com.subtracks/lib-3 flags = 1] SoSource 5: com.facebook.soloader.c[root = /data/app/com.subtracks-9sVm0aEtIK8Cv_AqTSVsGw==/lib/x86 flags = 0] SoSource 6: com.facebook.soloader.c[root = /vendor/lib flags = 2] SoSource 7: com.facebook.soloader.c[root = /system/lib flags = 2] Native lib dir: /data/app/com.subtracks-9sVm0aEtIK8Cv_AqTSVsGw==/lib/x86 result: 0 2022-05-04 17:51:38.199 11090-11090/? E/SoLoader: couldn't find DSO to load: libhermes-executor-debug.so SoSource 0: com.facebook.soloader.a[root = /data/data/com.subtracks/lib-main flags = 1] SoSource 1: com.facebook.soloader.a[root = /data/data/com.subtracks/lib-0 flags = 1] SoSource 2: com.facebook.soloader.a[root = /data/data/com.subtracks/lib-1 flags = 1] SoSource 3: com.facebook.soloader.a[root = /data/data/com.subtracks/lib-2 flags = 1] SoSource 4: com.facebook.soloader.a[root = /data/data/com.subtracks/lib-3 flags = 1] SoSource 5: com.facebook.soloader.c[root = /data/app/com.subtracks-9sVm0aEtIK8Cv_AqTSVsGw==/lib/x86 flags = 0] SoSource 6: com.facebook.soloader.c[root = /vendor/lib flags = 2] SoSource 7: com.facebook.soloader.c[root = /system/lib flags = 2] Native lib dir: /data/app/com.subtracks-9sVm0aEtIK8Cv_AqTSVsGw==/lib/x86 result: 0 2022-05-04 17:51:38.257 1770-1797/? E/SurfaceFlinger: ro.sf.lcd_density must be defined as a build property 2022-05-04 17:51:38.318 1770-2004/? E/SurfaceFlinger: ro.sf.lcd_density must be defined as a build property 2022-05-04 17:51:38.353 11090-11107/? E/eglCodecCommon: GoldfishAddressSpaceHostMemoryAllocator: ioctl_ping failed for device_type=5, ret=-1 2022-05-04 17:51:39.764 11090-11145/? E/cr_VariationsUtils: Failed reading seed file "/data/user/0/com.subtracks/app_webview/variations_seed": /data/user/0/com.subtracks/app_webview/variations_seed (No such file or directory) 1931-1944/? E/memtrack: Couldn't load memtrack module 2022-05-04 17:51:41.510 11090-11090/? E/unknown:FabricViewStateManager: setState called without a StateWrapper 2022-05-04 17:51:41.632 11090-11090/? E/unknown:FabricViewStateManager: setState called without a StateWrapper 2022-05-04 17:51:41.682 11090-11090/? E/unknown:FabricViewStateManager: setState called without a StateWrapper 2022-05-04 17:51:41.818 11090-11090/? E/unknown:FabricViewStateManager: setState called without a StateWrapper 2022-05-04 17:54:24.356 1783-1811/? E/storaged: getDiskStats failed with result NOT_SUPPORTED and size 0

Just before/after it crashed:

2022-05-04 17:56:24.358 1783-1811/? E/storaged: getDiskStats failed with result NOT_SUPPORTED and size 0 2022-05-04 17:56:24.842 11090-11090/? E/unknown:FabricViewStateManager: setState called without a StateWrapper \2022-05-04 17:56:32.187 11090-11110/? E/AndroidRuntime: FATAL EXCEPTION: mqt_native_modules Process: com.subtracks, PID: 11090 java.lang.ArithmeticException: divide by zero at com.ReactNativeBlobUtil.i$a.handleMessage(Unknown Source:96) at android.os.Handler.dispatchMessage(Handler.java:102) at android.os.Looper.loop(Looper.java:193) at com.facebook.react.bridge.queue.MessageQueueThreadImpl$4.run(Unknown Source:37) at java.lang.Thread.run(Thread.java:764) 2022-05-04 17:56:32.199 1657-1657/? E/lowmemorykiller: Error writing /proc/11090/oom_score_adj; errno=22 2022-05-04 17:56:32.267 1931-2000/? E/InputDispatcher: channel 'baa28b1 com.subtracks/com.subtracks.MainActivity (server)' ~ Channel is unrecoverably broken and will be disposed!

Edit: other crash: (it happens in a few seconds after i open the app , sometimes if i dont touch it tends to work for longer, i couldnt crash it with Navidrome at the moment but it did with Ampache )

2022-05-04 18:05:00.001 1931-1944/? E/memtrack: Couldn't load memtrack module 2022-05-04 18:05:00.009 1931-1944/? E/memtrack: Couldn't load memtrack module 2022-05-04 18:05:12.739 11281-11302/? E/AndroidRuntime: FATAL EXCEPTION: mqt_native_modules Process: com.subtracks, PID: 11281 java.lang.ArithmeticException: divide by zero at com.ReactNativeBlobUtil.i$a.handleMessage(Unknown Source:96) at android.os.Handler.dispatchMessage(Handler.java:102) at android.os.Looper.loop(Looper.java:193) at com.facebook.react.bridge.queue.MessageQueueThreadImpl$4.run(Unknown Source:37) at java.lang.Thread.run(Thread.java:764) 2022-05-04 18:05:09.499 1931-1949/? E/BatteryExternalStatsWorker: no controller energy info supplied for wifi 2022-05-04 18:05:12.824 1931-2000/? E/InputDispatcher: channel '2959846 com.subtracks/com.subtracks.MainActivity (server)' ~ Channel is unrecoverably broken and will be disposed! 2022-05-04 18:05:12.832 1657-1657/? E/lowmemorykiller: Error opening /proc/11281/oom_score_adj; errno=2 2022-05-04 18:05:17.559 12612-11462/? E/memtrack: Couldn't load memtrack module 2022-05-04 18:05:23.415 1885-1885/? E/netmgr: Failed to open QEMU pipe 'qemud:network': Invalid argument 2022-05-04 18:05:23.415 1885-1885/? E/netmgr: WifiForwarder unable to open QEMU pipe: Invalid argument 2022-05-04 18:05:24.365 1783-1811/? E/storaged: getDiskStats failed with result NOT_SUPPORTED and size 0

Edit2: Crashed with Navidrome after some time:

(some warning that could be relevant , the rest are only the errors)

2022-05-04 18:22:39.840 9893-12481/? W/DownloadManager: [526] Stop requested with status HTTP_DATA_ERROR: Failed reading response: javax.net.ssl.SSLProtocolException: Read error: ssl=0xe49a5848: Failure in SSL library, usually a protocol error error:1e000065:Cipher functions:OPENSSL_internal:BAD_DECRYPT (external/boringssl/src/crypto/fipsmodule/cipher/e_aes.c:1307 0xe3c2ba43:0x00000000) error:1000008b:SSL routines:OPENSSL_internal:DECRYPTION_FAILED_OR_BAD_RECORD_MAC (external/boringssl/src/ssl/tls_record.cc:298 0xe3c2ba43:0x00000000)

2022-05-04 18:22:54.026 12533-12533/? E/SoLoader: couldn't find DSO to load: libjscexecutor.so SoSource 0: com.facebook.soloader.a[root = /data/data/com.subtracks/lib-main flags = 1] SoSource 1: com.facebook.soloader.a[root = /data/data/com.subtracks/lib-0 flags = 1] SoSource 2: com.facebook.soloader.a[root = /data/data/com.subtracks/lib-1 flags = 1] SoSource 3: com.facebook.soloader.a[root = /data/data/com.subtracks/lib-2 flags = 1] SoSource 4: com.facebook.soloader.a[root = /data/data/com.subtracks/lib-3 flags = 1] SoSource 5: com.facebook.soloader.c[root = /data/app/com.subtracks-9sVm0aEtIK8Cv_AqTSVsGw==/lib/x86 flags = 0] SoSource 6: com.facebook.soloader.c[root = /vendor/lib flags = 2] SoSource 7: com.facebook.soloader.c[root = /system/lib flags = 2] Native lib dir: /data/app/com.subtracks-9sVm0aEtIK8Cv_AqTSVsGw==/lib/x86 result: 0 2022-05-04 18:22:54.059 12533-12533/? E/SoLoader: couldn't find DSO to load: libhermes-executor-debug.so SoSource 0: com.facebook.soloader.a[root = /data/data/com.subtracks/lib-main flags = 1] SoSource 1: com.facebook.soloader.a[root = /data/data/com.subtracks/lib-0 flags = 1] SoSource 2: com.facebook.soloader.a[root = /data/data/com.subtracks/lib-1 flags = 1] SoSource 3: com.facebook.soloader.a[root = /data/data/com.subtracks/lib-2 flags = 1] SoSource 4: com.facebook.soloader.a[root = /data/data/com.subtracks/lib-3 flags = 1] SoSource 5: com.facebook.soloader.c[root = /data/app/com.subtracks-9sVm0aEtIK8Cv_AqTSVsGw==/lib/x86 flags = 0] SoSource 6: com.facebook.soloader.c[root = /vendor/lib flags = 2] SoSource 7: com.facebook.soloader.c[root = /system/lib flags = 2] Native lib dir: /data/app/com.subtracks-9sVm0aEtIK8Cv_AqTSVsGw==/lib/x86 result: 0 2022-05-04 18:22:54.112 1770-1900/? E/SurfaceFlinger: ro.sf.lcd_density must be defined as a build property 2022-05-04 18:22:54.154 1770-1797/? E/SurfaceFlinger: ro.sf.lcd_density must be defined as a build property 2022-05-04 18:22:54.165 12533-12550/? E/eglCodecCommon: GoldfishAddressSpaceHostMemoryAllocator: ioctl_ping failed for device_type=5, ret=-1 2022-05-04 18:22:55.638 12533-12588/? E/cr_VariationsUtils: Failed reading seed file "/data/user/0/com.subtracks/app_webview/variations_seed": /data/user/0/com.subtracks/app_webview/variations_seed (No such file or directory) 2022-05-04 18:22:56.331 12533-12533/? E/unknown:FabricViewStateManager: setState called without a StateWrapper 2022-05-04 18:22:56.522 12533-12533/? E/unknown:FabricViewStateManager: setState called without a StateWrapper 2022-05-04 18:22:56.657 12533-12533/? E/unknown:FabricViewStateManager: setState called without a StateWrapper 2022-05-04 18:22:56.712 12533-12533/? E/unknown:FabricViewStateManager: setState called without a StateWrapper 2022-05-04 18:22:57.554 12533-12554/? E/AndroidRuntime: FATAL EXCEPTION: mqt_native_modules Process: com.subtracks, PID: 12533 java.lang.ArithmeticException: divide by zero at com.ReactNativeBlobUtil.i$a.handleMessage(Unknown Source:96) at android.os.Handler.dispatchMessage(Handler.java:102) at android.os.Looper.loop(Looper.java:193) at com.facebook.react.bridge.queue.MessageQueueThreadImpl$4.run(Unknown Source:37) at java.lang.Thread.run(Thread.java:764) 2022-05-04 18:22:57.736 12533-12533/? E/unknown:ReactNative: Tried to remove non-existent frame callback 2022-05-04 18:23:04.465 6707-6849/? E/A: Trace PersistentByteStoreInstaller.storeDidFault timed out after 2194819 ms. Complete trace: # com.google.apps.tiktok.tracing.es@a73155dd com.google.apps.tiktok.tracing.ez: at tk_trace.Query: SELECT response_data, write_ms FROM cache_table WHERE request_data=?(Started After:0) at tk_trace.Transaction(Started After:0) at tk_trace.PersistentByteStoreInstaller.storeDidFault(Started After:0) 2022-05-04 18:23:14.804 1931-1949/? E/BatteryExternalStatsWorker: no controller energy info supplied for wifi

May 04 '22 15:05 izyspania

From Flipper ( self build from source ):

FATAL EXCEPTION: mqt_native_modules Process: com.subtracks, PID: 10743 java.lang.ArithmeticException: divide by zero at com.ReactNativeBlobUtil.ReactNativeBlobUtilReq$1.handleMessage(ReactNativeBlobUtilReq.java:200) at android.os.Handler.dispatchMessage(Handler.java:102) at android.os.Looper.loop(Looper.java:223) at com.facebook.react.bridge.queue.MessageQueueThreadImpl$4.run(MessageQueueThreadImpl.java:226) at java.lang.Thread.run(Thread.java:923)

Some other info from logs:

Type Time PID Tag Message 22:00:38.296 10743 System.err at com.facebook.react.bridge.queue.NativeRunnable.run(Native Method) 22:00:38.296 10743 System.err at android.os.Handler.handleCallback(Handler.java:938) 22:00:38.296 10743 System.err at android.os.Handler.dispatchMessage(Handler.java:99) 22:00:38.296 10743 System.err at com.facebook.react.bridge.queue.MessageQueueThreadHandler.dispatchMessage(MessageQueueThreadHandler.java:27) 22:00:38.296 10743 System.err at android.os.Looper.loop(Looper.java:223) 22:00:38.296 10743 System.err at com.facebook.react.bridge.queue.MessageQueueThreadImpl$4.run(MessageQueueThreadImpl.java:226) 22:00:38.296 10743 System.err at java.lang.Thread.run(Thread.java:923) 22:00:38.751 10743 ReactNativeJS 'image', 'text/xml; charset=utf-8' 22:00:39.279 542 system_server oneway function results will be dropped but finished with status OK and parcel size 4 22:00:39.494 10743 ReactNative [GESTURE HANDLER] Initialize gesture handler for root view com.facebook.react.ReactRootView{ba26aa8 V.E...... .......D 0,0-1080,2208 #1} 22:00:37.484 542 system_server oneway function results will be dropped but finished with status OK and parcel size 4 22:00:39.508 10743 unknown:FabricViewStateManager setState called without a StateWrapper 22:00:39.846 10743 System.err java.lang.Exception: File does not exist 22:00:39.846 10743 System.err at com.rnfs.RNFSManager.unlink(RNFSManager.java:654) 22:00:39.846 10743 System.err at java.lang.reflect.Method.invoke(Native Method) 22:00:39.846 10743 System.err at com.facebook.react.bridge.JavaMethodWrapper.invoke(JavaMethodWrapper.java:372) 22:00:39.846 10743 System.err at com.facebook.react.bridge.JavaModuleWrapper.invoke(JavaModuleWrapper.java:188) 22:00:39.846 10743 System.err at com.facebook.react.bridge.queue.NativeRunnable.run(Native Method) 22:00:39.846 10743 System.err at android.os.Handler.handleCallback(Handler.java:938) 22:00:39.847 10743 System.err at android.os.Handler.dispatchMessage(Handler.java:99) 22:00:39.847 10743 System.err at com.facebook.react.bridge.queue.MessageQueueThreadHandler.dispatchMessage(MessageQueueThreadHandler.java:27) 22:00:38.273 10743 unknown:WrappingUtils Don't know how to round that drawable: com.facebook.react.views.image.ReactImageDownloadListener$EmptyDrawable@b545cf6 22:00:39.847 10743 System.err at android.os.Looper.loop(Looper.java:223) 22:00:39.847 10743 System.err at com.facebook.react.bridge.queue.MessageQueueThreadImpl$4.run(MessageQueueThreadImpl.java:226) 22:00:39.847 10743 System.err at java.lang.Thread.run(Thread.java:923) 22:00:40.292 10743 unknown:WrappingUtils Don't know how to round that drawable: com.facebook.react.views.image.ReactImageDownloadListener$EmptyDrawable@364db4d 22:00:40.293 10743 unknown:WrappingUtils Don't know how to round that drawable: com.facebook.react.views.image.ReactImageDownloadListener$EmptyDrawable@7510602 22:00:40.294 10743 unknown:WrappingUtils Don't know how to round that drawable: com.facebook.react.views.image.ReactImageDownloadListener$EmptyDrawable@4e05b13 22:00:38.276 10743 unknown:WrappingUtils Don't know how to round that drawable: com.facebook.react.views.image.ReactImageDownloadListener$EmptyDrawable@264f5c9 22:00:38.295 10743 System.err java.lang.Exception: File does not exist 22:00:38.295 10743 System.err at com.rnfs.RNFSManager.unlink(RNFSManager.java:654) 22:00:38.295 10743 System.err at java.lang.reflect.Method.invoke(Native Method) 22:00:38.295 10743 System.err at com.facebook.react.bridge.JavaMethodWrapper.invoke(JavaMethodWrapper.java:372) 22:00:38.295 10743 System.err at com.facebook.react.bridge.JavaModuleWrapper.invoke(JavaModuleWrapper.java:188)

May 04 '22 19:05 izyspania

java.lang.ArithmeticException: divide by zero at com.ReactNativeBlobUtil.ReactNativeBlobUtilReq$1.handleMessage(ReactNativeBlobUtilReq.java:200)

Is that the one that pops up in the Crash Reporter in Flipper? I could see how that one might cause a crash, and it looks like that's an area of the code I recently touched to add progress reporting from the Android Download Manager in the React Native Blob Util package. Weird that it only happens for Ampache, I guess the server is just set up to report a 0 byte file size sometimes. That area of the code should not attempt to divide by zero in any case so I'll put in a PR over there for it.

May 05 '22 06:05 austinried

Yes , thats what i get with Crash Reporter in Flipper, it does the same with Navidrome but it takes more time till i get the crash (most of the time is fine but it happened few times) , with Ampache i cant use the app more than 20 - 30 secs.

May 05 '22 08:05 izyspania

I saw your pull request and i changed that line with your fix and it works perfect (so far).

May 06 '22 14:05 izyspania

Great to hear, I'll plan on using my own subtracks branch of my fork over there in the next release if it doesn't get merged/released soon.

May 07 '22 10:05 austinried