You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
The debug apk took somewhere between 3.5 to 5 seconds to load the questionnaire and 20 to 25s to save the questionnaire
The release apk took around 2 to 3.5 seconds to load the questionnaire and 10 to 15 seconds to save.
Both test carried out with different devices with different patients counts.
Example
device 1: with 49 patients
device 2: 5587 patients
i don't think we need to do this for all questionnaires, just take a typical questionnaire for example, and just print out the timestamp before and after the questionnaire fragment call.
After profiling FHIRCore with logging additions (commit), we've identified these performance bottlenecks.
When saving a questionnaire, the T.updateFrom(updatedResource: Resource) function, represented by updateFromCalcTime in the logs, consistently took around 2 seconds per resource, contributing to a total time of up to 12 seconds for one of our tests that took ~14s.
fun <T:Resource> T.updateFrom(updatedResource:Resource): T {
Logs Saving medicines questionnaire form
2025-09-10 23:33:25.609 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => Encounter/patient-visit-2025-09-10-2a6eb945-29a3-4621-8e45-f4e6f3397dda
2025-09-10 23:33:25.634 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => 24.104875ms
2025-09-10 23:33:25.635 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => Encounter/eee7b508-676e-4da5-a833-7d8ff560cf78
2025-09-10 23:33:25.645 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => 10.057125ms
2025-09-10 23:33:25.646 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => MedicationRequest/dc-med-318956006-2025-09-10-2a6eb94529a346218e45f4e6f3397dda
2025-09-10 23:33:25.649 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => 2.461875ms
2025-09-10 23:33:25.649 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => MedicationRequest/dc-med-376209006-2025-09-10-2a6eb94529a346218e45f4e6f3397dda
2025-09-10 23:33:25.651 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => 1.870084ms
2025-09-10 23:33:25.651 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => MedicationRequest/dc-med-325278007-2025-09-10-2a6eb94529a346218e45f4e6f3397dda
2025-09-10 23:33:25.653 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => 1.596250ms
2025-09-10 23:33:25.654 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => Patient/2a6eb945-29a3-4621-8e45-f4e6f3397dda
2025-09-10 23:33:25.666 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => 3.559375ms
2025-09-10 23:33:25.667 8285-8355 System.out org...opensrp.diabetesCompassClinic I saveExtractedResources: => Encounter
2025-09-10 23:33:25.667 8285-8355 System.out org...opensrp.diabetesCompassClinic I addOrUpdate: => Encounter
2025-09-10 23:33:25.669 8285-8355 System.out org...opensrp.diabetesCompassClinic I Gets => 1.407166ms
2025-09-10 23:33:28.202 8285-8355 System.out org...opensrp.diabetesCompassClinic I updateFromCalcTime: => 2.532677460s
2025-09-10 23:33:28.250 8285-8355 System.out org...opensrp.diabetesCompassClinic I Updates: => 47.910167ms
2025-09-10 23:33:28.250 8285-8355 System.out org...opensrp.diabetesCompassClinic I Gets => 1.407166ms, updates => 47.910167ms
2025-09-10 23:33:28.251 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => Patient/2a6eb945-29a3-4621-8e45-f4e6f3397dda
2025-09-10 23:33:28.260 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => 9.077708ms
2025-09-10 23:33:28.261 8285-8355 System.out org...opensrp.diabetesCompassClinic I saveExtractedResources: => Encounter
2025-09-10 23:33:28.261 8285-8355 System.out org...opensrp.diabetesCompassClinic I addOrUpdate: => Encounter
2025-09-10 23:33:28.283 8285-8355 System.out org...opensrp.diabetesCompassClinic I CreateTime: => 19.457584ms
2025-09-10 23:33:28.284 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => Patient/2a6eb945-29a3-4621-8e45-f4e6f3397dda
2025-09-10 23:33:28.294 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => 9.823125ms
2025-09-10 23:33:28.295 8285-8355 System.out org...opensrp.diabetesCompassClinic I saveExtractedResources: => MedicationRequest
2025-09-10 23:33:28.295 8285-8355 System.out org...opensrp.diabetesCompassClinic I addOrUpdate: => MedicationRequest
2025-09-10 23:33:28.297 8285-8355 System.out org...opensrp.diabetesCompassClinic I Gets => 1.708875ms
2025-09-10 23:33:30.670 8285-8355 System.out org...opensrp.diabetesCompassClinic I updateFromCalcTime: => 2.372386043s
2025-09-10 23:33:30.697 8285-8355 System.out org...opensrp.diabetesCompassClinic I Updates: => 26.591417ms
2025-09-10 23:33:30.697 8285-8355 System.out org...opensrp.diabetesCompassClinic I Gets => 1.708875ms, updates => 26.591417ms
2025-09-10 23:33:30.698 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => Patient/2a6eb945-29a3-4621-8e45-f4e6f3397dda
2025-09-10 23:33:30.702 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => 3.509833ms
2025-09-10 23:33:30.702 8285-8355 System.out org...opensrp.diabetesCompassClinic I saveExtractedResources: => MedicationRequest
2025-09-10 23:33:30.702 8285-8355 System.out org...opensrp.diabetesCompassClinic I addOrUpdate: => MedicationRequest
2025-09-10 23:33:30.710 8285-8355 System.out org...opensrp.diabetesCompassClinic I Gets => 7.425ms
2025-09-10 23:33:32.966 8285-8355 System.out org...opensrp.diabetesCompassClinic I updateFromCalcTime: => 2.255935501s
2025-09-10 23:33:32.987 8285-8355 System.out org...opensrp.diabetesCompassClinic I Updates: => 20.280416ms
2025-09-10 23:33:32.993 8285-8355 System.out org...opensrp.diabetesCompassClinic I Gets => 7.425ms, updates => 20.280416ms
2025-09-10 23:33:32.994 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => Patient/2a6eb945-29a3-4621-8e45-f4e6f3397dda
2025-09-10 23:33:32.999 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => 4.671708ms
2025-09-10 23:33:32.999 8285-8355 System.out org...opensrp.diabetesCompassClinic I saveExtractedResources: => MedicationRequest
2025-09-10 23:33:32.999 8285-8355 System.out org...opensrp.diabetesCompassClinic I addOrUpdate: => MedicationRequest
2025-09-10 23:33:33.001 8285-8355 System.out org...opensrp.diabetesCompassClinic I Gets => 1.568250ms
2025-09-10 23:33:35.253 8285-8355 System.out org...opensrp.diabetesCompassClinic I updateFromCalcTime: => 2.252223418s
2025-09-10 23:33:35.277 8285-8355 System.out org...opensrp.diabetesCompassClinic I Updates: => 18.797500ms
2025-09-10 23:33:35.278 8285-8355 System.out org...opensrp.diabetesCompassClinic I Gets => 1.568250ms, updates => 18.797500ms
2025-09-10 23:33:35.278 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => Patient/2a6eb945-29a3-4621-8e45-f4e6f3397dda
2025-09-10 23:33:35.282 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => 3.183458ms
2025-09-10 23:33:35.282 8285-8355 System.out org...opensrp.diabetesCompassClinic I saveExtractedResources: => MedicationRequest
2025-09-10 23:33:35.282 8285-8355 System.out org...opensrp.diabetesCompassClinic I addOrUpdate: => MedicationRequest
2025-09-10 23:33:35.283 8285-8355 System.out org...opensrp.diabetesCompassClinic I Gets => 878.792us
2025-09-10 23:33:37.437 8285-8355 System.out org...opensrp.diabetesCompassClinic I updateFromCalcTime: => 2.153086585s
2025-09-10 23:33:37.460 8285-8355 System.out org...opensrp.diabetesCompassClinic I Updates: => 17.12ms
2025-09-10 23:33:37.460 8285-8355 System.out org...opensrp.diabetesCompassClinic I Gets => 878.792us, updates => 17.12ms
2025-09-10 23:33:37.461 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => Patient/2a6eb945-29a3-4621-8e45-f4e6f3397dda
2025-09-10 23:33:37.464 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => 3.324500ms
2025-09-10 23:33:37.465 8285-8355 System.out org...opensrp.diabetesCompassClinic I addOrUpdate: => QuestionnaireResponse
2025-09-10 23:33:37.497 8285-8355 System.out org...opensrp.diabetesCompassClinic I CreateTime: => 31.109792ms
2025-09-10 23:33:37.498 8285-8355 System.out org...opensrp.diabetesCompassClinic I updateResourcesLastUpdatedProperty: =>
2025-09-10 23:33:37.498 8285-8355 System.out org...opensrp.diabetesCompassClinic I updateResourcesLastUpdatedProperty: => Patient
2025-09-10 23:33:37.498 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => Patient/2a6eb945-29a3-4621-8e45-f4e6f3397dda
2025-09-10 23:33:37.501 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => 3.339750ms
2025-09-10 23:33:37.501 8285-8355 System.out org...opensrp.diabetesCompassClinic I addOrUpdate: => Patient
2025-09-10 23:33:37.513 8285-8355 System.out org...opensrp.diabetesCompassClinic I Gets => 11.198916ms
2025-09-10 23:33:39.581 8285-8355 System.out org...opensrp.diabetesCompassClinic I updateFromCalcTime: => 2.067735918s
2025-09-10 23:33:39.614 8285-8355 System.out org...opensrp.diabetesCompassClinic I Updates: => 32.688750ms
2025-09-10 23:33:39.614 8285-8355 System.out org...opensrp.diabetesCompassClinic I Gets => 11.198916ms, updates => 32.688750ms
2025-09-10 23:33:39.615 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => Patient/2a6eb945-29a3-4621-8e45-f4e6f3397dda
2025-09-10 23:33:39.618 8285-8355 System.out org...opensrp.diabetesCompassClinic I loadResource: => 3.070791ms
total ~14s 9ms
When loading a questionnaire the ResourceMapper.populate function, represented by resourceMapperPopulate in the logs, took up to 5 seconds although in some occassions it could take less than 1s
Evaluate the necessity of the T.updateFrom(updatedResource: Resource) function and in case its needed, try to optimise and - @rkareko@LZRS@ajhmohammed (FHIRCore) Moved to a separate coroutineScope within the default dispatcher thread
- [ ] For loading of a questionnaire, check whether a questionnaire has launchContext extension to prevent redundant call to ResourceMapper.populate function @rkareko@LZRS (FHIRCore)
- [ ] In the sdc, we can add a check to only do ResourceMapper.populate population processing only a questionnaire has launchContext extension @LZRS (SDC) Doesn't seem to work for questionnaires using fhirpath expression today() as an initialExpression, without defined launchContext extension
For the getQuestionnaireFragmentBuilder and for the extension function Resource.encodeResourceToString(), ensure that only a single instance of FhirContext.forR4().getCustomJsonParser() is used, to shave off time used to initialize every time @rkareko@LZRS (FHIRCore)
Explore triggering pre-initialization of the fhirPathEngine beforehand (on app start-up) to remove time taken to initialize it when loading a questionnaire @LZRS
- [ ] Launch generateCarePlan and executeCQL into a separate thread to not block saving @LZRS Pulled back on this as some CarePlans were not getting generated in time to interact with a patient's profile
Evaluate feasibility (UI/UX) of asynchronous saving of questionnaire especially when extracted resources are many @rkareko@LZRS (FHIRCore)
@ajhmohammed will assist with testing the effectiveness of the above steps
Hi Fikri,
Any idea why we aren't seeing any improvements on registration?
Can you provide a breakdown (like you did for the forms above) on what's
happening there?
Thanks,
Matt
My short guess is, it's because of we run PlanDefinition which generates all the tasks the patient needs (around 44 tasks) on submission of registration form. This doesn't happen on other forms.
I'll re-check registration form and get back to you on the details.
Cool that makes sense.
If it’s for tasks it strike me plandef should be able to be run in the
background and may you leave the first forms not driven by tasks to access
from a ui perspective
Hi @jingtang10 , @mberg & @rkareko, I have tested this version of the app witht the users and got a very postive feedback. Unfortunately when testing app, I found out that the auto calculated date field on the form did not auto populate after this change.
Just to make sure, i recompiled the app with the main branch and its confirmed that the performance improvement made a breaking change.
Activity
ajhmohammed commentedon Aug 5, 2025
The debug apk took somewhere between 3.5 to 5 seconds to load the questionnaire and 20 to 25s to save the questionnaire
The release apk took around 2 to 3.5 seconds to load the questionnaire and 10 to 15 seconds to save.
Both test carried out with different devices with different patients counts.
Example
device 1: with 49 patients
device 2: 5587 patients
ajhmohammed commentedon Aug 17, 2025
Stats from Prod Instance Release APK.
Total Number of Patients: 5624
Other Resources count
Total Number of Resources: 727342
Device Information
Available Forms and Stats (Offline Test) - Arranged in the priority order
jingtang10 commentedon Sep 8, 2025
@ajhmohammed thanks for sharing this.
can you please profile the specific api calls?
i don't think we need to do this for all questionnaires, just take a typical questionnaire for example, and just print out the timestamp before and after the questionnaire fragment call.
and to do this more systematically, we can use https://developer.android.com/studio/profile. but let's have a rough idea first.
ajhmohammed commentedon Sep 10, 2025
ajhmohammed commentedon Sep 11, 2025
After commenting out DefaultRespository.kt line no. 260
// val updateFrom = res.updateFrom(resource)
LZRS commentedon Sep 11, 2025
After profiling FHIRCore with logging additions (commit), we've identified these performance bottlenecks.
When saving a questionnaire, the
T.updateFrom(updatedResource: Resource)function, represented byupdateFromCalcTimein the logs, consistently took around 2 seconds per resource, contributing to a total time of up to 12 seconds for one of our tests that took ~14s.fhircore/android/engine/src/main/java/org/smartregister/fhircore/engine/util/extension/ResourceExtension.kt
Line 131 in 21d6d95
Logs Saving medicines questionnaire form
total ~14s 9ms
When loading a questionnaire the
ResourceMapper.populatefunction, represented byresourceMapperPopulatein the logs, took up to 5 seconds although in some occassions it could take less than 1sfhircore/android/quest/src/main/java/org/smartregister/fhircore/quest/ui/questionnaire/QuestionnaireViewModel.kt
Line 1145 in 21d6d95
and
getQuestionnaireFragmentBuilderconsistently took 1-2 secondsfhircore/android/quest/src/main/java/org/smartregister/fhircore/quest/ui/questionnaire/QuestionnaireActivity.kt
Line 418 in 21d6d95
with
questionnaire.json(),questionnaireResponse.json()andlaunchContextResources .associate { Pair(it.resourceType.name.lowercase(), it.encodeResourceToString()) }each taking ~600msLogs Loading medicines form
total ~7s 349ms
mberg commentedon Sep 11, 2025
On the loading forms
2025-09-11 00:20:11.827 9887-9887 System.out org...opensrp.diabetesCompassClinic I populationTime: => 5.235959252s
This is taking 5 seconds which is where the bulk of the slowness is. What is happening here?
mberg commentedon Sep 11, 2025
I guess that's the populate. What does that do? If that fetching the resources to prefill into the form?
LZRS commentedon Sep 11, 2025
Yeah, it populates the questionnaire with resources referenced through the
sdc-questionnaire-launchContextextensionLZRS commentedon Sep 16, 2025
The next steps of action will be
T.updateFrom(updatedResource: Resource)function and in case its needed, try to optimise and - @rkareko @LZRS @ajhmohammed (FHIRCore)Moved to a separate coroutineScope within the
defaultdispatcher thread- [ ] For loading of a questionnaire, check whether a questionnaire haslaunchContextextension to prevent redundant call toResourceMapper.populatefunction @rkareko @LZRS (FHIRCore)- [ ] In the sdc, we can add a check to only doResourceMapper.populatepopulation processing only a questionnaire has launchContext extension @LZRS (SDC)Doesn't seem to work for questionnaires using fhirpath expression
today()as an initialExpression, without definedlaunchContextextensionFor the
getQuestionnaireFragmentBuilderand for the extension functionResource.encodeResourceToString(), ensure that only a single instance ofFhirContext.forR4().getCustomJsonParser()is used, to shave off time used to initialize every time @rkareko @LZRS (FHIRCore)Explore triggering pre-initialization of the fhirPathEngine beforehand (on app start-up) to remove time taken to initialize it when loading a questionnaire @LZRS
- [ ] LaunchgenerateCarePlanandexecuteCQLinto a separate thread to not block saving @LZRSPulled back on this as some CarePlans were not getting generated in time to interact with a patient's profile
@ajhmohammed will assist with testing the effectiveness of the above steps
15 remaining items
mberg commentedon Oct 9, 2025
FikriMilano commentedon Oct 9, 2025
@mberg
My short guess is, it's because of we run PlanDefinition which generates all the tasks the patient needs (around 44 tasks) on submission of registration form. This doesn't happen on other forms.
I'll re-check registration form and get back to you on the details.
mberg commentedon Oct 9, 2025
ajhmohammed commentedon Dec 5, 2025
Hi @jingtang10 , @mberg & @rkareko, I have tested this version of the app witht the users and got a very postive feedback. Unfortunately when testing app, I found out that the auto calculated date field on the form did not auto populate after this change.
Just to make sure, i recompiled the app with the main branch and its confirmed that the performance improvement made a breaking change.
jingtang10 commentedon Dec 5, 2025
@LZRS has a fix for it I think
LZRS commentedon Dec 5, 2025
Yes, I have the fix here ohs-foundation/android-fhir#2923
Whereby the widgets UI were not getting updated for calculated expressions.
Although, I'll have to confirm if the fix works for Android views that had not been migrated to compose.
LZRS commentedon Dec 5, 2025
@ajhmohammed Could you confirm which branch you were using? I believe the performance improvement work had already been merged to the main branch
ajhmohammed commentedon Dec 5, 2025
Hi @LZRS & @jingtang10 my bad, its a wrong branch. The bug was on the branch #3804
LZRS commentedon Dec 5, 2025
Oh, okay. No worries
Update Questionnaire population with sdc changes on immutability
LZRS commentedon Dec 10, 2025
@ajhmohammed The PR #3804 has been updated with a fix
@rkareko