microg / GmsCore

Free implementation of Play Services
https://microg.org
Apache License 2.0
8.19k stars 1.69k forks source link

Hessenschau-App is crashing with latest release #1244

Closed john-bill closed 3 years ago

john-bill commented 3 years ago

after upgrading vi F-Droid to latest release the Hessenschau App crashes instantly. Verified on two devices. microG selfcheck is ok. logcat.txt

tobiasKaminsky commented 3 years ago

@mar-v-in I really like MicroG and want to give something "back" and therefore try to help with fixing those bugs… I installed emulator (from https://github.com/microg/android_packages_apps_GmsCore/wiki/Development-Tools) and built master of play-services-core. Now I can reproduce the Hessenschau-app crash.

As always, starting with helping in an unkown project is the hardest… Can you give me some rough hints, what I can do? After I have some experience, I can also put those info in the wiki.

According to logcat there are two crashes:

2020-10-25 11:36:47.516 4941-4941/de.hr.hessenschau E/FirebaseInstanceId: Failed to start service while in background: java.lang.IllegalStateException: Not allowed to start service Intent { act=com.google.firebase.INSTANCE_ID_EVENT pkg=de.hr.hessenschau cmp=de.hr.hessenschau/com.google.firebase.iid.FirebaseInstanceIdService (has extras) }: app is in background uid UidRecord{291254a u0a113 SVC  idle change:idle|uncached procs:1 seq(0,0,0)}

This seems to be the first/real crash: It cannot start the intent correctly. FirebaseInstanceId seems to be within in com.google.firebase.firebase-iid, but I cannot find any reference within microG for this?

After enabling SafetyNet, device regiseration, cloud messaging, I reinstalled Hessenschau and now get:

2020-10-25 12:01:18.536 6111-6132/de.hr.hessenschau E/AndroidRuntime: FATAL EXCEPTION: GoogleApiHandler
    Process: de.hr.hessenschau, PID: 6111
    java.lang.IllegalStateException: A fatal developer error has occurred. Check the logs for further information.
        at com.google.android.gms.common.internal.zze.zzs(Unknown Source:58)
        at com.google.android.gms.common.internal.zzi.zzajo(Unknown Source:51)
        at com.google.android.gms.common.internal.zzh.handleMessage(Unknown Source:270)
        at android.os.Handler.dispatchMessage(Handler.java:107)
        at android.os.Looper.loop(Looper.java:214)
        at android.os.HandlerThread.run(HandlerThread.java:67)
2020-10-25 12:01:18.536 6111-6132/de.hr.hessenschau E/UncaughtException: java.lang.IllegalStateException: A fatal developer error has occurred. Check the logs for further information.
        at com.google.android.gms.common.internal.zze.zzs(Unknown Source:58)
        at com.google.android.gms.common.internal.zzi.zzajo(Unknown Source:51)
        at com.google.android.gms.common.internal.zzh.handleMessage(Unknown Source:270)
        at android.os.Handler.dispatchMessage(Handler.java:107)
        at android.os.Looper.loop(Looper.java:214)
        at android.os.HandlerThread.run(HandlerThread.java:67)

I find com.google.android.gms.common.internal in play-services-basement, but as the above stacktrace is obfuscated, I do not know where/if I can add a breakpoint to those classes.

Do you have an hint for this?

2020-10-25 11:36:47.541 4941-4965/de.hr.hessenschau E/FirebaseCrash: Failed to load crash reporting
    com.google.android.gms.internal.zzdny: com.google.android.gms.dynamite.DynamiteModule$zzc: No acceptable module found. Local version is 0 and remote version is 0.
        at com.google.android.gms.internal.zzdnw.zzbpq(Unknown Source:50)
        at com.google.firebase.crash.zzc.zzbpo(Unknown Source:39)
        at com.google.firebase.crash.zzd.call(Unknown Source:2)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
        at java.lang.Thread.run(Thread.java:919)
     Caused by: com.google.android.gms.dynamite.DynamiteModule$zzc: No acceptable module found. Local version is 0 and remote version is 0.
        at com.google.android.gms.dynamite.DynamiteModule.zza(Unknown Source:285)
        at com.google.android.gms.internal.zzdnw.zzbpq(Unknown Source:7)
        at com.google.firebase.crash.zzc.zzbpo(Unknown Source:39) 
        at com.google.firebase.crash.zzd.call(Unknown Source:2) 
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) 
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) 
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) 
        at java.lang.Thread.run(Thread.java:919) 
2020-10-25 11:36:47.541 4941-4967/de.hr.hessenschau E/FirebaseCrash: Failed waiting for crash api to load.

This is then the following up crash, which shows that the crash api is not implemented/working. Having a microG module for logging might help for easier debugging…?

tobiasKaminsky commented 3 years ago
2020-10-25 12:09:28.786 6310-6333/de.hr.hessenschau D/GmsDynamiteLoaderImpl: unimplemented Method: getModuleVersion for com.google.android.gms.firebase_auth

more verbose logcat gives me above error.

Returning 1 in this case, leads me to:

com.google.android.gms D/GmsGcmRegister: onStartCommand: Intent { act=com.google.android.c2dm.intent.REGISTER cmp=com.google.android.gms/org.microg.gms.gcm.PushRegisterService (has extras) }
de.hr.hessenschau I/System.out: <---------removeJSON
com.google.android.gms D/GmsGcmRegister: register[req]: Intent { act=com.google.android.c2dm.intent.REGISTER cmp=com.google.android.gms/org.microg.gms.gcm.PushRegisterService (has extras) } extras=Bundle[{subtype=cWb17i2h75A:APA91bEw9ZQC5rQhJuoRV5ySNxe1G3iiPxoQlSgTiz4N4DVJr8JGM1sKVtzAIr5dzFG0pk36AMTQVM8XtYjZD6LVvo14Ajk6c-qLFTVyVDA7-NYg_uS5UioxeEq1tcZnuvxWThmIth3g, gcm.topic=/topics/news, sender=cWb17i2h75A:APA91bEw9ZQC5rQhJuoRV5ySNxe1G3iiPxoQlSgTiz4N4DVJr8JGM1sKVtzAIr5dzFG0pk36AMTQVM8XtYjZD6LVvo14Ajk6c-qLFTVyVDA7-NYg_uS5UioxeEq1tcZnuvxWThmIth3g, X-subtype=cWb17i2h75A:APA91bEw9ZQC5rQhJuoRV5ySNxe1G3iiPxoQlSgTiz4N4DVJr8JGM1sKVtzAIr5dzFG0pk36AMTQVM8XtYjZD6LVvo14Ajk6c-qLFTVyVDA7-NYg_uS5UioxeEq1tcZnuvxWThmIth3g, app_ver=79, app=PendingIntent{9e6db2f: android.os.BinderProxy@36dd53c}, kid=|ID|0|, osv=29, sig=SSC6F1YsFcjyKETx7Cq6G5t0mpgboWN_wI3o5p_kFNZZF8DZzTFUkayFKB8fP24IxGC0iBBGBVQi6VlaEp_P3465HXQI5FM15T5nIpGIjTBRKiVYzf5vCeqwW32n92SrPAfKKhoI1TxT-NJxoHnROp4rxgFnC5KO-KFLBmu7hjSFhru37vQyN5dBNvAD5tmgRRuf4pRxiPSWzpVeUAfhMpPR1yblTOi7gcLYnEt9rhRZk8x7KjHCwO4Gnwl3Izs7PJwOsa0kDTLZPW9QEJZWFzgnW_MEL6uxMbOrbH9asJEpykeFT8S7g9oryiCrXgoJNhE_7PgoMZNrrLFowB4-Bw, cliv=fiid-11400000, gmsv=203915027, pub2=MIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEAnQpberLCnQQ5ImSpbEfBwBxHl5Z3wrX8VNkumgrkcW-NLYFkEmDN6fVINHyeaLB8R9VT2fRRO6Gl6SZIECSITXnwPDaUuuzvpaXDvualGFRaXpt3rnx5dn47k57N4YutFGeDonQJdouXLRWhMveLrYQP3usl65C26G_f0vUABO-LlYxlsjCMoU4132Abyq_pOYQKtliKonNLVG4byYdnPn9P7_nmzuxwZPmU1elVwSrJcQR3rfHcmtoVG8pPmBQS3Mr34T_M9VzAew_Dw-Xn-QO4Fnkfxz1nxXO09E8tzyT_oA6jBLAicBRheuLXhd7i1vgDa9QKULBJBuZLfrDYDwIDAQAB, X-kid=|ID|0|, appid=cWb17i2h75A, scope=/topics/news, google.messenger=android.os.Messenger@52442c5, gmp_app_id=1:878511340774:android:127798a550a15c81, androidx.contentpager.content.wakelockid=3, app_ver_name=1.7}]
com.google.android.gms W/Bundle: Key app expected String but value was a android.app.PendingIntent.  The default value <null> was returned.
com.google.android.gms W/Bundle: Attempt to cast generated internal exception:
    java.lang.ClassCastException: android.app.PendingIntent cannot be cast to java.lang.String
        at android.os.BaseBundle.getString(BaseBundle.java:1163)
        at org.microg.gms.gcm.RegisterRequest.extraParams(RegisterRequest.java:124)
        at org.microg.gms.gcm.PushRegisterService.register(PushRegisterService.kt:154)
        at org.microg.gms.gcm.PushRegisterService.handleIntent(PushRegisterService.kt:130)
        at org.microg.gms.gcm.PushRegisterService$onStartCommand$1.invokeSuspend(PushRegisterService.kt:119)

and

com.google.android.gms W/Bundle: Key google.messenger expected String but value was a android.os.Messenger.  The default value <null> was returned.
com.google.android.gms W/Bundle: Attempt to cast generated internal exception:
    java.lang.ClassCastException: android.os.Messenger cannot be cast to java.lang.String
        at android.os.BaseBundle.getString(BaseBundle.java:1163)
        at org.microg.gms.gcm.RegisterRequest.extraParams(RegisterRequest.java:124)
        at org.microg.gms.gcm.PushRegisterService.register(PushRegisterService.kt:154)
        at org.microg.gms.gcm.PushRegisterService.handleIntent(PushRegisterService.kt:130)
        at org.microg.gms.gcm.PushRegisterService$onStartCommand$1.invokeSuspend(PushRegisterService.kt:119)
        at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)

and

com.google.android.gms W/Bundle: Key androidx.contentpager.content.wakelockid expected String but value was a java.lang.Integer.  The default value <null> was returned.
com.google.android.gms W/Bundle: Attempt to cast generated internal exception:
    java.lang.ClassCastException: java.lang.Integer cannot be cast to java.lang.String
        at android.os.BaseBundle.getString(BaseBundle.java:1163)
        at org.microg.gms.gcm.RegisterRequest.extraParams(RegisterRequest.java:124)
        at org.microg.gms.gcm.PushRegisterService.register(PushRegisterService.kt:154)
        at org.microg.gms.gcm.PushRegisterService.handleIntent(PushRegisterService.kt:130)
        at org.microg.gms.gcm.PushRegisterService$onStartCommand$1.invokeSuspend(PushRegisterService.kt:119)
        at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
tobiasKaminsky commented 3 years ago

I added some debug output:

com.google.android.gms D/RegisterRequest: Key: gmp_app_id with valued 1:878511340774:android:127798a550a15c81
com.google.android.gms D/RegisterRequest: Key: androidx.contentpager.content.wakelockid with value: 6
com.google.android.gms W/Bundle: Key androidx.contentpager.content.wakelockid expected String but value was a java.lang.Integer.  The default value <null> was returned.
com.google.android.gms W/Bundle: Attempt to cast generated internal exception:
    java.lang.ClassCastException: java.lang.Integer cannot be cast to java.lang.String
        at android.os.BaseBundle.getString(BaseBundle.java:1163)

So it seems that indeed the value is 6 (integer), which leads to this crash.

When I add a cast in RegisterRequest.java: extraParams (L:124):

Object object = extraBundle.get(key);

                if (object instanceof String) {
                    extraParam(key, extraBundle.getString(key));
                } 
                if (object instanceof Integer) {
                    extraParam(key, String.valueOf(extraBundle.getInt(key)));
                }

I do not see any crash, I can hunt down, but only:

de.hr.hessenschau E/UncaughtException: java.lang.IllegalStateException: A fatal developer error has occurred. Check the logs for further information.
        at com.google.android.gms.common.internal.zze.zzs(Unknown Source:58)
        at com.google.android.gms.common.internal.zzi.zzajo(Unknown Source:51)
        at com.google.android.gms.common.internal.zzh.handleMessage(Unknown Source:270)
        at android.os.Handler.dispatchMessage(Handler.java:107)
        at android.os.Looper.loop(Looper.java:214)
        at android.os.HandlerThread.run(HandlerThread.java:67)

where I am now lost…as I do not know in which class/method this happens…

tobiasKaminsky commented 3 years ago

I only find this:

de.hr.hessenschau W/DynamiteModule: Local module descriptor class for com.google.android.gms.crash not found.
de.hr.hessenschau D/GmsDynamiteLoaderImpl: returning v1 for crash
de.hr.hessenschau I/DynamiteModule: Considering local module com.google.android.gms.crash:0 and remote module com.google.android.gms.crash:1
de.hr.hessenschau I/DynamiteModule: Selected remote version of com.google.android.gms.crash, version >= 1
de.hr.hessenschau D/GmsDynamiteLoaderImpl: unimplemented Method: createModuleContext for com.google.android.gms.crash at version 1, returning gms context
de.hr.hessenschau I/System.out: cachedTimestamp: Sun Oct 25 12:36:37 GMT+01:00 2020
de.hr.hessenschau I/System.out: currentTimestamp: Sun Oct 25 12:35:56 GMT+01:00 2020
de.hr.hessenschau E/FirebaseCrash: Failed to load crash reporting
    com.google.android.gms.internal.zzdny: com.google.android.gms.dynamite.DynamiteModule$zzc: Failed to instantiate module class: com.google.firebase.crash.internal.api.FirebaseCrashApiImpl
com.google.android.gms D/GmsMeasureSvcImpl: f4: de.hr.hessenschau
com.google.android.gms D/SafeParcel: Unknown field id 2 in com.google.android.gms.measurement.internal.EventParcel, skipping.
com.google.android.gms D/SafeParcel: Unknown field id 3 in com.google.android.gms.measurement.internal.EventParcel, skipping.
com.google.android.gms D/SafeParcel: Unknown field id 4 in com.google.android.gms.measurement.internal.EventParcel, skipping.
com.google.android.gms D/SafeParcel: Unknown field id 5 in com.google.android.gms.measurement.internal.EventParcel, skipping.
com.google.android.gms D/GmsMeasureSvcImpl: f1: de.hr.hessenschau
com.google.android.gms D/GmsMeasureSvcImpl: f11: de.hr.hessenschau
com.google.android.gms D/GmsMeasureSvcImpl: f10: null
com.google.android.gms D/GmsFirebaseAuth: bound by: GetServiceRequest{serviceId=FIREBASE_AUTH, gmsVersion=11400000, packageName='de.hr.hessenschau', extras=Bundle[{com.google.firebase.auth.API_KEY=AIzaSyDirEgOco_83TD4hbjFIFw8mF7_YeCQODk}]}
de.hr.hessenschau W/DynamiteModule: Local module descriptor class for com.google.firebase.auth not found.
de.hr.hessenschau D/GmsDynamiteLoaderImpl: returning v1 for firebase_auth
de.hr.hessenschau E/AndroidRuntime: FATAL EXCEPTION: GoogleApiHandler
    Process: de.hr.hessenschau, PID: 9408
    java.lang.IllegalStateException: A fatal developer error has occurred. Check the logs for further information.
mar-v-in commented 3 years ago

@tobiasKaminsky

To solve this issue, one has to find out what is the reason for GoogleApiHandler to throw this IllegalStateException: A fatal developer error has occurred. Check the logs for further information.. The error message itself is not helpful at all in debugging, but there probably is a good reason for it to be thrown.

tobiasKaminsky commented 3 years ago

@mar-v-in thank you for your valuable feedback to understand the internal handling of microG!

To solve this issue, one has to find out what is the reason for GoogleApiHandler to throw this IllegalStateException: A fatal developer error has occurred. Check the logs for further information.

Do you have an idea how to debug this? As far as I can see GoogleApiHandler is related to Firebase, but not directly debugable… E.g. I cannot set a breakpoint in Android Studio, nor I can add debug code to calling apk, as it is closed source…

tobiasKaminsky commented 3 years ago

Interesting, when I add a breakpoint to BaseService.java:47 and just keep debugger breaking at this point, I can use the app without problems.

E.g. I cannot set a breakpoint in Android Studio, nor I can add debug code to calling apk, as it is closed source…

I searched a lot on the internet to find out how I can try to debug this…but I still have no clue. If you have any tip, this would be awesome!

john-bill commented 3 years ago

there is a new version of the Hessenschau app (1.9.1). Now the app is still crashing, but when you restart two or three times it is running without problems - until the next complete restart. Other apps of the same developer (Radio Station) are working without problems. Not shure if this is really a microG or more an application bug...

john-bill commented 3 years ago

tested on two devices, seems this bug is fixed with the latest release v0.2.15.204713.

Thanks for the great work!