ministero-salute / it-dgc-verificac19-sdk-android

Digital Covid Certificate SDK
Apache License 2.0
57 stars 30 forks source link

Crash on startup #88

Closed albertocappellina closed 2 years ago

albertocappellina commented 2 years ago

Describe the bug Quando avvio l'app (che incorpora l'sdk) dopo un po si chiude e nel log degli errori vedo questo crash:

E/AndroidRuntime: FATAL EXCEPTION: DefaultDispatcher-worker-2 Process: it.intesys.dolomitisuperski, PID: 12470 kotlinx.coroutines.CoroutinesInternalError: Fatal exception in coroutines machinery for CancellableContinuation(DispatchedContinuation[Dispatchers.IO, Continuation at it.ministerodellasalute.verificaC19sdk.data.VerifierRepositoryImpl$fetchCertificate$2.invokeSuspend(VerifierRepositoryImpl.kt:152)@842590c]){Completed}@6a9c255. Please read KDoc to 'handleFatalException' method and report this incident to maintainers at kotlinx.coroutines.DispatchedTask.handleFatalException(DispatchedTask.kt:144) at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:115) at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:571) at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:750) at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:678) at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:665) Caused by: java.lang.StackOverflowError: stack size 1039KB

(allego il full log perche' troppo lungo ma in realta' e' un loop)

Smartphone (please complete the following information):

Grazie Alberto

salmattia commented 2 years ago

@albertocappellina ho il tuo stesso problema. Succede solo quando si parte con il db delle chiavi vuoto. Credo sia dovuto al fatto che la funzione private suspend fun fetchCertificate(resumeToken: Long): Boolean? è ricorsiva. Stessa cosa nel branch release/1.0.4

albertocappellina commented 2 years ago

@salmattia ti confermo che avviene solo al primo avvio e non sempre

rawmain commented 2 years ago

Ciao @albertocappellina

@salmattia ti confermo che avviene solo al primo avvio e non sempre

Fammi sapere in primis se riscontri già variazioni di comportamento - lato gestione dispatcher/thread - durante il fetch iniziale della tua app, solo :

  1. cambiando la versione kotlinx_coroutines nella implementation deps/version di app build.gradle dalla 1.3.9 (base corrente per DGC-SDK 1.0.4 e 1.1.0) alla 1.4.3

  2. Aggiungendo force Deps.kotlinx_coroutines al tuo attuale override per allprojects nel root build.gradle (modificato per supporto targetSdk 31)


In secondo luogo, implementa comunque lato vs. codice app/UI ulteriori controlli per status token e KID List prima di procedere con l'acquisizione DGC dopo la scansione dello Skipass.

La whitelabel-app VerificaC19 prevede un controllo blando, ma non consente comunque di procedere, qualora vi siano stati problemi con il primo fetch/sync getCertUpdate (ved. debug e logcat per le entry Cert KID verified).

In caso di anomalie visualizza infatti N/A per data aggiornamento & mantiene disabilitato il pulsante di scansione = l'operatore deve provvedere ad un nuovo fetch, chiudendo e riaprendo l'app.

salmattia commented 2 years ago

Ho cambiato la versione di kotlinx_coroutines a 1.4.3 e forzato la dipendenza con force Deps.kotlinx_coroutines ma senza effetti. C'è ancora il crash quando si parte da db vuoto. Al riavvio dell'app dopo il crash, il fetch delle chiavi viene completato e da quel momento in poi tutto prosegue normalmente.

rawmain commented 2 years ago

Ciao @salmattia

Ho cambiato la versione di kotlinx_coroutines a 1.4.3 e forzato la dipendenza con force Deps.kotlinx_coroutines ma senza effetti.

Tieni conto che ho dato tale indicazione di minima a @albertocappellina , basandomi comunque su (veloce) analisi di logcat & codice delle ultime storerelease dell'app specifica a cui lavora.

Pur non riscontrando analogo KO dopo primo fetch/sync getCertUpdate (OK tutti Cert KID verified, partendo da 0) con diverse configurazioni emulator/real-device, avevo cmq notato uno spawn eccessivo di warning relativi a coroutine - dispatcher context/thread.

Pertanto, gli avevo indicato in primis di testare sul suo codice il bump a 1.4.3 (che include appunto alcuni change/bugfix specifici per thread/dispatcher), onde iniziare a verificare le eventuali variazioni senza ulteriori modifiche.

C'è ancora il crash quando si parte da db vuoto. Al riavvio dell'app dopo il crash, il fetch delle chiavi viene completato e da quel momento in poi tutto prosegue normalmente.

Con la whitelabel-app non risultano ovviamente problemi, in virtù di A. natura (molto) basilare del relativo codice app/UI & B. blando controllo, che evita appunto comunque di procedere con acquisizione qrcodetext in caso di KO primo fetch/sync.

Prova a controllare / confrontare full debug+logcat di 1° avvio KO & 2° avvio OK dell'app a cui stai lavorando, quindi anche entry/events prima dello switch thread IO (network coroutine) -> Default (db.keyDao().deleteAllExcept(validCertList.toTypedArray())).

Nel caso riporta logcat e/o riferimenti codice tua app & vediamo di darci un'occhiata insieme.

salmattia commented 2 years ago

Buongiorno @rawmain allego i log di primo avvio e secondo avvio. La seconda volta riparte ed ho un solo Cert KID verified, poi il sync viene completato con successo. Qui sto usando la versione 1.1.0 del sdk ma adesso ho lo stesso crash con la versione 1.0.4 che stavamo già utilizzando da qualche settimana senza riscontrare problemi. Quindi in qualche modo il numero di chiamate consecutive verso il backend get.dgc.gov.it a "signercertificate/update" è rilevante. Ho fatto una prova con l'app dgp-whitelabel dal branch develop con sdk da branch develop e chiamando verso il backend get.dgc.gov.it mi da lo stesso tipo ti problema. Allego log anche di questo test dgp-whitelabel.txt 2nd_run.txt 1st_run.txt

salmattia commented 2 years ago

@rawmain un aggiornamento. Compilando a release non va in crash. Evidentemente kotlinx_coroutines fa delle cose diverse a debug. Verificato con versione coroutines 1.4.3 e sdk 1.1.0

rawmain commented 2 years ago

Ciao @salmattia

La seconda volta riparte ed ho un solo Cert KID verified, poi il sync viene completato con successo. [...] in qualche modo il numero di chiamate consecutive verso il backend get.dgc.gov.it a "signercertificate/update" è rilevante. Ho fatto una prova con l'app dgp-whitelabel dal branch develop con sdk da branch develop e chiamando verso il backend get.dgc.gov.it mi da lo stesso tipo ti problema. [...] Compilando a release non va in crash. Evidentemente kotlinx_coroutines fa delle cose diverse a debug. Verificato con versione coroutines 1.4.3 e sdk 1.1.0

Innanzitutto, grazie per i log. Ho potuto darci per ora solo un'occhiata veloce, ma ti riporto già alcune considerazioni.

Suggerirei in ogni caso una minima impostazione addizionale per ulteriore controllo build variant debug = abilitazione dei check StrictMode.

Per quanto riguarda app, che integrano DGC-SDK, è già sufficiente l'aggiunta del set predefinito di policy di controllo al constructor dell'application class -> prendendo ad esempio la whitelabel-app VerificaC19, in VerificaApplication :

[...]

import android.os.StrictMode

[...]

    override fun onCreate() {
        if (BuildConfig.BUILD_TYPE == "debug") {
            StrictMode.enableDefaults()
        }
        super.onCreate()
        setWorkManager()
    }

Ciò consente infatti di vedere anche situazioni d'errore relative a gestione/leak della memoria, che in log base compaiono però come warning. Vedansi p.es. event W/System: A resource failed to call close presenti nei tuoi log di KO 1st run tua app & whitelabel-app.

I tuoi log non mostrano anche gli event I zygote64 - relativi a gestione garbage collection, ma la presenza ripetuta dei warning sopracitati (originati da dalvik.system.CloseGuard) unita all'exception di termine fetchCertificate mi orienta su un problema di gestione memoria.

Situazioni riscontrabili con buildtype debug (ved. overhead in esecuzione rispetto a release) p.es. su emulatore Android Studio e non su real-device, in virtù della diversa gestione VM per heap & garbage collection.


Questo è infatti un estratto dell'esecuzione OK su real-device della whitelabel-app prodrelease 1.2.0 + DGC-SDK prodrelease 1.1.0 - buildtype debug :

[...]

12-22 12:38:08.646  4155  4186 I VerifierRepositoryImpl: Cert KID verified
12-22 12:38:08.658  4155  4186 V BaseRepository: Do network coroutine work
12-22 12:38:08.677  4155  4186 I VerifierRepositoryImpl: Cert KID verified
12-22 12:38:08.686  4155  4186 V BaseRepository: Do network coroutine work
12-22 12:38:08.697  4155  4160 I zygote64: Do partial code cache collection, code=247KB, data=164KB
12-22 12:38:08.700  4155  4160 I zygote64: After code cache collection, code=247KB, data=164KB
12-22 12:38:08.700  4155  4160 I zygote64: Increasing code cache capacity to 1024KB
12-22 12:38:08.707  4155  4186 I VerifierRepositoryImpl: Cert KID verified
12-22 12:38:08.714  4155  4186 V BaseRepository: Do network coroutine work
12-22 12:38:08.735  4155  4186 I VerifierRepositoryImpl: Cert KID verified

[...]

12-22 12:38:09.326  4155  4186 I VerifierRepositoryImpl: Cert KID verified
12-22 12:38:09.333  4155  4186 V BaseRepository: Do network coroutine work
12-22 12:38:09.353  4155  4160 I zygote64: Do full code cache collection, code=297KB, data=188KB
12-22 12:38:09.355  4155  4160 I zygote64: After code cache collection, code=292KB, data=166KB
12-22 12:38:09.357  4155  4186 I VerifierRepositoryImpl: Cert KID verified
12-22 12:38:09.372  4155  4186 V BaseRepository: Do network coroutine work

[...]

12-22 12:38:11.462  4155  4186 I VerifierRepositoryImpl: Cert KID verified
12-22 12:38:11.471  4155  4186 V BaseRepository: Do network coroutine work
12-22 12:38:11.506  1529  1543 I PerfService: PerfServiceNative_getPackName
12-22 12:38:11.533  4155  4186 I zygote64: Deoptimizing kotlin.coroutines.CoroutineContext$Element kotlin.coroutines.CombinedContext.get(kotlin.coroutines.CoroutineContext$Key) due to JIT inline cache

[...]

12-22 12:38:11.613  4155  4186 I CRL Status: it.ministerodellasalute.verificaC19sdk.data.remote.model.CrlStatus@47289b1
12-22 12:38:11.613  4155  4186 I outDatedVersion: ok
12-22 12:38:11.613  4155  4186 I noPendingDownload: true
12-22 12:38:11.614  4155  4155 I total_chunk: 1
12-22 12:38:11.615  4155  4186 I SizeOver: false
12-22 12:38:11.666  4155  4189 I zygote64: Deoptimizing long okhttp3.internal.connection.Exchange$ResponseBodySource.read(okio.Buffer, long) due to JIT inline cache
12-22 12:38:11.710  4155  4189 I zygote64: Deoptimizing boolean okio.RealBufferedSource.request(long) due to JIT inline cache
12-22 12:38:11.735  4155  4155 I auth_to_resume: -1
12-22 12:38:11.786  4155  4155 I current_chunk: 1
12-22 12:38:11.813  4155  4186 I processRevokeList:  adding UCVI
12-22 12:38:11.908  4155  4186 I Revoke  : Inserted
12-22 12:38:11.912  4155  4186 I Revoke  : Inserted 1500
12-22 12:38:11.914  4155  4155 I current_chunk: 0
12-22 12:38:11.915  4155  4155 I total_chunk: 0
12-22 12:38:11.934  4155  4186 I CRL Status: it.ministerodellasalute.verificaC19sdk.data.remote.model.CrlStatus@484ee1a
12-22 12:38:11.942  4155  4186 I Reconciliation: final reconciliation completed!
12-22 12:38:11.943  4155  4186 I chunk download: Last chunk processed, versions updated
12-22 12:38:11.944  4155  4188 I LoadKeysWorker: key fetching result: true

Prova pertanto a ricompilare la buildvariant debug della tua app - senza nemmeno imporre override 1.4.3 per kotlin coroutine - con sola aggiunta dei controlli StrictMode.

A quel punto controllane l'esecuzione (debug, logcat, profiler, etc.) da deploy su real-device, non emulatore.


Se può servirti come reference per confronti/verifiche esecuzione, allego Universal APK della whitelabel-app - buildvariant debug - in allineamento a codice attuali prodrelease app/UI e DGC-SDK.

Unitamente a relativo log di esecuzione (compresa acquisizione qrcodetext) su uno dei miei reference-device di test.

albertocappellina commented 2 years ago

Effettivamente i crash avvegono solo quando sono con il variant di debug. non ho evidenza di crash con variant di release (nemmeno in produzione). chiudo la issue