Form with attachments broken since v2025.1.0 (custom OpenRosa backend)

mbaudier · March 10, 2025, 4:59am

Hello,

we have been using ODK Collect for years, with a custom backend implementing the OpenRosa protocol, and using XML forms. Since the last update (v2025.1.0) our form fails to install/update when downloading its attachments.

These attachments are dynamically generated CSV files with thousands of entries (but much less than 50k). We are not using entities yet, but our use case (agroforestry monitoring) would clearly fit, and this is only a matter of finding the time to implement it before we switch to this approach.

My question is: what would be the best way to debug this? (It was raised by field workers, but I can reproduce it in my development environment)

I think I remember that ODK Collect was producing logs, but I cannot find them on the phone anymore. Where would they be located?
Or do I have to use Android tools?

Thanks in advance for your help!

Mathieu

seadowg · March 10, 2025, 10:14am

Given you're using a custom implementation of OpenRosa, my guess would be that there is a mismatch in the responses it provides and what Collect expects in the newest release.

Are you able to post example responses that are causing problems? You should remove any actual data/URLs obviously.

mbaudier · March 10, 2025, 3:24pm

Thank you for your quick answer!

This is a bit complicated indeed to untangle the data and the form is quite big, so here are already some excerpts in case there is something obvious.

ODK Collect seems to process /formList properly and also the download of the main form. It fails when downloading one of the additional files listed in /formManifest/* (not clear which one).

From the main form:

...
<!-- Secondary instances -->
<instance id="apafTree"
	src="jr://file/38b99ef0-a29d-45fd-a41f-6b0e1678d139.xml" />
<instance id="apafAction"
	src="jr://file/548a3593-dbf6-4d24-b983-2ed06920216a.xml" />
<instance id="apafPlaceType"
	src="jr://file/bfcc4ccf-fc28-4a0c-b714-16a2a28e942a.xml" />
<instance id="apafPreviousPlaceType"
	src="jr://file/08ec07cf-7000-43b5-8c90-c3a3c193460c.xml" />
<instance id="apafFieldOwnership"
	src="jr://file/052fa6db-3bad-40d0-8598-250346f772fb.xml" />
<instance id="adm"
	src="jr://file/9b300aeb-a470-4abe-abce-f01bda7b940c.xml" />
<instance id="field"
	src="jr://file-csv/38e49362-8e2f-11ec-a901-df9dbc98eafd.csv" />
...
<!-- Example usage of XML secondary instance -->
<select1 ref="/data/adm/term" appearance="minimal">
	<label ref="jr:itext('country')" />
	<itemset nodeset="instance('adm')/adm/term">
		<value ref="@name" />
		<label ref="jr:itext(@name)" />
	</itemset>
</select1>
<select1 ref="/data/adm/term1" appearance="minimal">
	<label ref="jr:itext('adm1')" />
	<itemset
		nodeset="instance('adm')/adm/term[@name=/data/adm/term]/term">
		<value ref="@name" />
		<label ref="@name" />
	</itemset>
</select1>
<select1 ref="/data/adm/term2" appearance="minimal">
	<label ref="jr:itext('adm2')" />
	<itemset
		nodeset="instance('adm')/adm/term[@name=/data/adm/term]/term[@name=/data/adm/term1]/term">
		<value ref="@name" />
		<label ref="@name" />
	</itemset>
</select1>
...
<!-- Example usage of CSV secondary instance -->
<select1 ref="/data/fieldRef" appearance="map">
	<label>Sélectionner le champ (carte)</label>
	<itemset nodeset="instance('field')/root/item">
		<value ref="name" />
		<label ref="display" />
	</itemset>
	<setvalue event="xforms-value-changed"
		ref="/data/fieldTitle"
		value="concat(instance('field')/root/item[name=/data/fieldRef]/givenName, ' ', instance('field')/root/item[name=/data/fieldRef]/sn)" />
</select1>
<select1 ref="/data/fieldRef" appearance="autocomplete">
	<label>Sélectionner le champ (liste)</label>
	<itemset nodeset="instance('field')/root/item">
		<value ref="name" />
		<label ref="display" />
	</itemset>
	<setvalue event="xforms-value-changed"
		ref="/data/fieldTitle"
		value="concat(instance('field')/root/item[name=/data/fieldRef]/givenName, ' ', instance('field')/root/item[name=/data/fieldRef]/sn)" />
</select1>
...

Excerpt from the manifest response:

<manifest xmlns="http://openrosa.org/xforms/xformsManifest">
...
	<mediaFile>
		<filename>9b300aeb-a470-4abe-abce-f01bda7b940c.xml</filename>
		<hash>md5sum:a4d37e3b736908015d79327f1d36ae6c</hash>
		<downloadUrl>https://example.org/api/odk/formManifest/apaf/form/apafSession/manifest/adm</downloadUrl>
	</mediaFile>
	<mediaFile>
		<filename>38e49362-8e2f-11ec-a901-df9dbc98eafd.csv</filename>
		<hash>md5sum:4708b306a1ac83cdebebb65037e46693</hash>
		<downloadUrl>https://example.org/api/odk/formManifest/apaf/form/apafSession/manifest/field</downloadUrl>
	</mediaFile>
...
</manifest>

Excerpt from an XML secondary instance:

<adm jcr:primaryType="entity:terms"
	jcr:uuid="9b300aeb-a470-4abe-abce-f01bda7b940c"
	xmlns:jcr="http://www.jcp.org/jcr/1.0">
	<term name="CI">
		<term name="abidjan">
			<term name="abobo" />
			<term name="adjame" />
...
		</term>
	</term>
</adm>

Excerpt from the CSV file:

name,label,givenName,sn,display,geometry
BF2023xxxxxxxx,Mxxxx Oxxxxxxx,Mxxxx,Oxxxxxxx,BF2023xxxxxxxx (Mxxxx Oxxxxxxx),11.5941000 -1.8476000 359.4 0
BF2023yyyyyyyy,Hxxxxxx Sxxxxxxx,Hxxxxxx,Sxxxxxxx,BF2023yyyyyyyy (Hxxxxxx Sxxxxxxx),11.5907000 -1.9243000 355.8 0

Do you see something which would have changed in the new version?

Is it possible to somehow get more error details in order to narrow down what is failing?

I can send more information if needed.

mbaudier · March 11, 2025, 9:35am

From Android Studio, I have rebuilt previous versions of ODK Collect in order to find out when it stopped working. It was still failing with v2024.3.6 and it started to work with v2024.2.4.

But then, interestingly, it started to work again with newer versions, up to v2025.1.1.
There is now a small 'dirty' label below the version on the welcome page of the app.

With regard to the comment below with a stacktrace, it also now works with the full CSV file, and there is still the same stacktrace with "REQUEST_TIMEOUT". So, I guess this was not directly related.

Please note that I never cleared the virtual phone in Android Studio, having originally configured my test server from v2025.1.0.

This may explain why we only now have problems in the field, when some surveyors configured new phones. Apparently, only the new phones are failing (I will double-check with them).

Here is my test protocol, in chronological order:

v2024.5.0	FAIL
v2024.5.1	FAIL
v2024.3.6	FAIL
v2024.2.4	PASS
v2024.3.0	PASS
v2024.3.1	PASS
v2024.3.5	PASS
v2024.3.6	PASS
v2024.5.0	PASS
v2024.5.1	PASS

I will now stop working on this, in order not to overwhelm you with too much information.
Many thanks again for your help!

mbaudier · March 11, 2025, 12:39pm

I have run ODK Collect from the code in an up-to-date Android Studio. Git tag used below is v2025.1.1 (released yesterday, apparently not yet in Google Play) rather than v2025.1.0 where we have the issue on the phones, but one can observe the same behaviour and logs on both versions.

I am getting timeout errors (see below). I first thought that this was because the query generating the CSV was too long and I tweaked it so that it quickly returns just a subset of the data. But the error still occurs, not immediately but just a few moments after the secondary instances have been downloaded:

2025-03-11 06:20:44.413  8294-8506  ServerFormDownloader    org.odk.collect.android              I  Parsing document /storage/emulated/0/Android/data/org.odk.collect.android/files/projects/2fa4c208-1e57-42a6-b1c1-b1637bb06116/.cache/download-36418591-7f36-4734-bf41-61e7ea7f3c43/apafSession.xml
2025-03-11 06:20:44.422  8294-8294  WindowOnBackDispatcher  org.odk.collect.android              W  sendCancelIfRunning: isInProgress=false callback=android.view.ViewRootImpl$$ExternalSyntheticLambda11@538b6ff
2025-03-11 06:20:44.453  8294-8294  WindowOnBackDispatcher  org.odk.collect.android              W  OnBackInvokedCallback is not enabled for the application.
Set 'android:enableOnBackInvokedCallback="true"' in the application manifest.
2025-03-11 06:20:44.453  8294-8294  LeakCanary              org.odk.collect.android              D  Watching instance of androidx.lifecycle.SavedStateHandlesVM (androidx.lifecycle.SavedStateHandlesVM received ViewModel#onCleared() callback) with key 2a00807c-6ce5-45a7-96d8-3a16680e49ba
2025-03-11 06:20:44.453  8294-8294  LeakCanary              org.odk.collect.android              D  Watching instance of leakcanary.internal.ViewModelClearedWatcher (leakcanary.internal.ViewModelClearedWatcher received ViewModel#onCleared() callback) with key 01e63174-337f-4506-a1a2-b23228486663
2025-03-11 06:20:44.453  8294-8294  LeakCanary              org.odk.collect.android              D  Watching instance of androidx.loader.app.LoaderManagerImpl$LoaderViewModel (androidx.loader.app.LoaderManagerImpl$LoaderViewModel received ViewModel#onCleared() callback) with key 7f710c0d-1ae2-457c-9be1-e968e3951003
2025-03-11 06:20:44.453  8294-8294  LeakCanary              org.odk.collect.android              D  Watching instance of org.odk.collect.android.formentry.RefreshFormListDialogFragment (org.odk.collect.android.formentry.RefreshFormListDialogFragment received Fragment#onDestroy() callback) with key 175a188a-e7b4-4c72-bbf0-f7c7e4138601
2025-03-11 06:20:44.454  8294-8294  WindowOnBackDispatcher  org.odk.collect.android              W  OnBackInvokedCallback is not enabled for the application.
Set 'android:enableOnBackInvokedCallback="true"' in the application manifest.
2025-03-11 06:20:44.585  8294-8475  EGL_emulation           org.odk.collect.android              D  app_time_stats: avg=405.81ms min=4.54ms max=12546.03ms count=33
2025-03-11 06:20:49.529  8294-8399  collect.android         org.odk.collect.android              I  Explicit concurrent mark compact GC freed 3720KB AllocSpace bytes, 6(120KB) LOS objects, 49% free, 12MB/24MB, paused 204us,2.834ms total 73.508ms
2025-03-11 06:21:07.895  8294-9515  m.bft                   org.odk.collect.android              I  Request m.ilm failed with Status ben{errorCode=REQUEST_TIMEOUT, description=last attempt state: REQUIREMENT_START, cause=m.gni: m.gwp: Timed out: m.gua@1dd0ce0[status=PENDING, info=[inputFuture=[m.gub@a4aeb99[status=PENDING, info=[inputFuture=[m.gup@7051e5e[status=PENDING, info=[futures=[m.gwl@7c6d4b0[status=SUCCESS, result=[m.bep@4965f29]], m.gvr@722c23f[status=SUCCESS, result=[{connectivity, true}]], m.gvm@cb6170c[status=PENDING, info=[delegate=[m.gwl@c0bcbba[status=PENDING]]]]]]]], function=[m.bid@3d5a855]]]], function=[m.bfo@200c26a]]]
	at m.gnp.a(:com.google.android.gms.policy_maps_core_dynamite@245125203@245125201032.707632445.707632445:149)
	at m.gtt.d(:com.google.android.gms.policy_maps_core_dynamite@245125203@245125201032.707632445.707632445:3)
	at m.gtv.run(:com.google.android.gms.policy_maps_core_dynamite@245125203@245125201032.707632445.707632445:130)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:487)
	at m.btc$a.run(:com.google.android.gms.policy_maps_core_dynamite@245125203@245125201032.707632445.707632445:23)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
	at m.btr.run(:com.google.android.gms.policy_maps_core_dynamite@245125203@245125201032.707632445.707632445:40)
	at java.lang.Thread.run(Thread.java:1012)
Caused by: m.gwp: Timed out: m.gua@1dd0ce0[status=PENDING, info=[inputFuture=[m.gub@a4aeb99[status=PENDING, info=[inputFuture=[m.gup@7051e5e[status=PENDING, info=[futures=[m.gwl@7c6d4b0[status=SUCCESS, result=[m.bep@4965f29]], m.gvr@722c23f[status=SUCCESS, result=[{connectivity, true}]], m.gvm@cb6170c[status=PENDING, info=[delegate=[m.gwl@c0bcbba[status=PENDING]]]]]]]], function=[m.bid@3d5a855]]]], function=[m.bfo@200c26a]]]
, errorDetails=} , attempts 2
2025-03-11 06:21:07.896  8294-9515  m.brk                   org.odk.collect.android              W  Failed client parameters RPC response.  failure=ben{errorCode=REQUEST_TIMEOUT, description=last attempt state: REQUIREMENT_START, cause=m.gni: m.gwp: Timed out: m.gua@1dd0ce0[status=PENDING, info=[inputFuture=[m.gub@a4aeb99[status=PENDING, info=[inputFuture=[m.gup@7051e5e[status=PENDING, info=[futures=[m.gwl@7c6d4b0[status=SUCCESS, result=[m.bep@4965f29]], m.gvr@722c23f[status=SUCCESS, result=[{connectivity, true}]], m.gvm@cb6170c[status=PENDING, info=[delegate=[m.gwl@c0bcbba[status=PENDING]]]]]]]], function=[m.bid@3d5a855]]]], function=[m.bfo@200c26a]]]
	at m.gnp.a(:com.google.android.gms.policy_maps_core_dynamite@245125203@245125201032.707632445.707632445:149)
	at m.gtt.d(:com.google.android.gms.policy_maps_core_dynamite@245125203@245125201032.707632445.707632445:3)
	at m.gtv.run(:com.google.android.gms.policy_maps_core_dynamite@245125203@245125201032.707632445.707632445:130)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:487)
	at m.btc$a.run(:com.google.android.gms.policy_maps_core_dynamite@245125203@245125201032.707632445.707632445:23)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
	at m.btr.run(:com.google.android.gms.policy_maps_core_dynamite@245125203@245125201032.707632445.707632445:40)
	at java.lang.Thread.run(Thread.java:1012)
Caused by: m.gwp: Timed out: m.gua@1dd0ce0[status=PENDING, info=[inputFuture=[m.gub@a4aeb99[status=PENDING, info=[inputFuture=[m.gup@7051e5e[status=PENDING, info=[futures=[m.gwl@7c6d4b0[status=SUCCESS, result=[m.bep@4965f29]], m.gvr@722c23f[status=SUCCESS, result=[{connectivity, true}]], m.gvm@cb6170c[status=PENDING, info=[delegate=[m.gwl@c0bcbba[status=PENDING]]]]]]]], function=[m.bid@3d5a855]]]], function=[m.bfo@200c26a]]]
, errorDetails=}
2025-03-11 06:21:07.896  8294-9515  m.brx                   org.odk.collect.android              I  Got failed parameters response!
2025-03-11 06:21:07.896  8294-9515  m.brx                   org.odk.collect.android              W  Failed to get a successful parameters response, ben{errorCode=REQUEST_TIMEOUT, description=last attempt state: REQUIREMENT_START, cause=m.gni: m.gwp: Timed out: m.gua@1dd0ce0[status=PENDING, info=[inputFuture=[m.gub@a4aeb99[status=PENDING, info=[inputFuture=[m.gup@7051e5e[status=PENDING, info=[futures=[m.gwl@7c6d4b0[status=SUCCESS, result=[m.bep@4965f29]], m.gvr@722c23f[status=SUCCESS, result=[{connectivity, true}]], m.gvm@cb6170c[status=PENDING, info=[delegate=[m.gwl@c0bcbba[status=PENDING]]]]]]]], function=[m.bid@3d5a855]]]], function=[m.bfo@200c26a]]]
	at m.gnp.a(:com.google.android.gms.policy_maps_core_dynamite@245125203@245125201032.707632445.707632445:149)
	at m.gtt.d(:com.google.android.gms.policy_maps_core_dynamite@245125203@245125201032.707632445.707632445:3)
	at m.gtv.run(:com.google.android.gms.policy_maps_core_dynamite@245125203@245125201032.707632445.707632445:130)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:487)
	at m.btc$a.run(:com.google.android.gms.policy_maps_core_dynamite@245125203@245125201032.707632445.707632445:23)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
	at m.btr.run(:com.google.android.gms.policy_maps_core_dynamite@245125203@245125201032.707632445.707632445:40)
	at java.lang.Thread.run(Thread.java:1012)
Caused by: m.gwp: Timed out: m.gua@1dd0ce0[status=PENDING, info=[inputFuture=[m.gub@a4aeb99[status=PENDING, info=[inputFuture=[m.gup@7051e5e[status=PENDING, info=[futures=[m.gwl@7c6d4b0[status=SUCCESS, result=[m.bep@4965f29]], m.gvr@722c23f[status=SUCCESS, result=[{connectivity, true}]], m.gvm@cb6170c[status=PENDING, info=[delegate=[m.gwl@c0bcbba[status=PENDING]]]]]]]], function=[m.bid@3d5a855]]]], function=[m.bfo@200c26a]]]
, errorDetails=}
m.gni: m.gwp: Timed out: m.gua@1dd0ce0[status=PENDING, info=[inputFuture=[m.gub@a4aeb99[status=PENDING, info=[inputFuture=[m.gup@7051e5e[status=PENDING, info=[futures=[m.gwl@7c6d4b0[status=SUCCESS, result=[m.bep@4965f29]], m.gvr@722c23f[status=SUCCESS, result=[{connectivity, true}]], m.gvm@cb6170c[status=PENDING, info=[delegate=[m.gwl@c0bcbba[status=PENDING]]]]]]]], function=[m.bid@3d5a855]]]], function=[m.bfo@200c26a]]]
	at m.gnp.a(:com.google.android.gms.policy_maps_core_dynamite@245125203@245125201032.707632445.707632445:149)
	at m.gtt.d(:com.google.android.gms.policy_maps_core_dynamite@245125203@245125201032.707632445.707632445:3)
	at m.gtv.run(:com.google.android.gms.policy_maps_core_dynamite@245125203@245125201032.707632445.707632445:130)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:487)
	at m.btc$a.run(:com.google.android.gms.policy_maps_core_dynamite@245125203@245125201032.707632445.707632445:23)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
	at m.btr.run(:com.google.android.gms.policy_maps_core_dynamite@245125203@245125201032.707632445.707632445:40)
	at java.lang.Thread.run(Thread.java:1012)
Caused by: m.gwp: Timed out: m.gua@1dd0ce0[status=PENDING, info=[inputFuture=[m.gub@a4aeb99[status=PENDING, info=[inputFuture=[m.gup@7051e5e[status=PENDING, info=[futures=[m.gwl@7c6d4b0[status=SUCCESS, result=[m.bep@4965f29]], m.gvr@722c23f[status=SUCCESS, result=[{connectivity, true}]], m.gvm@cb6170c[status=PENDING, info=[delegate=[m.gwl@c0bcbba[status=PENDING]]]]]]]], function=[m.bid@3d5a855]]]], function=[m.bfo@200c26a]]]
2025-03-11 06:21:07.896  8294-9515  m.brx                   org.odk.collect.android              I  P/H: Scheduling next update in 10.000000 seconds: retry
2025-03-11 06:21:17.898  8294-9517  m.brx                   org.odk.collect.android              I  P/H: Running update task for account Account {name=signedout@, type=com.google.android.apps.maps} , locale en_US
2025-03-11 06:21:17.898  8294-9517  m.brx                   org.odk.collect.android              I  P/H: Running update task via GWS.
2025-03-11 06:21:17.900  8294-9517  m.bxm                   org.odk.collect.android              I  Requested experimentIds= []
2025-03-11 06:21:17.900  8294-9517  m.brk                   org.odk.collect.android              I  Fetching new client parameters: Account {name=signedout@, type=com.google.android.apps.maps}  en_US

It is not clear to me whether this REQUEST_TIMEOUT is a request over the network, or an internal callback within the Android app.

If it is an HTTP request, I don't see which URL it calls, and I don't know where in the code I should debug to find out (I am not very familiar with Android Studio / IntelliJ).

Could it be that there is a new URL to provide on the server side that we have not yet implemented?
Or that some timeouts have changed?

seadowg · March 11, 2025, 12:39pm

What error are you currently seeing? If you're seeing problems when downloading/updating forms using "Exactly Match Server" mode, could you switch to Manual and try downloading the form that way?

Excerpt from the manifest response:

One thing I'm noticing right away is that your manifest responses are incorrect: the hash prefix md5sum is not valid as only md5 is currently supported by Collect. This won't cause errors as far as I can tell, but it will mean that Collect will redownload the media file every time it checks for an update as it doesn't recognize the hash prefix and therefore will not try and use local hash checks to avoid the download.

mbaudier · March 11, 2025, 2:50pm

What error are you currently seeing? If you're seeing problems when downloading/updating forms using "Exactly Match Server" mode, could you switch to Manual and try downloading the form that way?

On an empty virtual phone with v2025.1.1 the errors are the logs that I have posted separately, and here is a screenshot:

On a virtual phone which had previously v2024.2.4, it is working properly even with v2025.1.1. (cf. my other comment listing the various versions I have tested)

I don't know what is "Exactly Match Server" mode and where it can be configured?

One thing I'm noticing right away is that your manifest responses are incorrect: the hash prefix md5sum is not valid as only md5 is currently supported by Collect.

I have changed it, and when the download is otherwise working it is much more efficient indeed. Thank you!

mbaudier · March 12, 2025, 5:03am

I have found the "Exactly Match Server" setting, but it was set to "Manual". With both settings, the behaviour is the same:

if the form was already downloaded on v2024.2.4, everything works fine
if the form is downloaded the first time on v2025.1.1, it fails after downloading the attachments

I could try to debug from Android Studio, but I would need to know roughly where in the code base is the related logic.

I could also give you access to a test environment, since this is easy to reproduce once one has authenticated access to the backend.

seadowg · March 13, 2025, 11:21am

What error do you see if you hit "Show details"?

I'd expect to see the problem occur in ServerFormUseCases#downloadMediaFiles.

mbaudier · March 13, 2025, 12:22pm

Here is a screenshot:

mbaudier · March 13, 2025, 1:23pm

After some debugging and adding some e.printStackTrace(), I am getting this (on v2025.1.1) :

2025-03-13 14:11:13.190 12520-12668 kotlin.UninitializedPropertyAccessException: lateinit property mainInstanceRoot has not been initialized
2025-03-13 14:11:13.194 12520-12668 	at org.odk.collect.android.formmanagement.metadata.FormMetadataParser.readMetadata(FormMetadataParser.kt:38)
2025-03-13 14:11:13.194 12520-12668 	at org.odk.collect.android.formmanagement.metadata.FormMetadataParser.readMetadata(FormMetadataParser.kt:11)
2025-03-13 14:11:13.195 12520-12668 	at org.odk.collect.android.formmanagement.download.ServerFormDownloader.processOneForm(ServerFormDownloader.java:127)
2025-03-13 14:11:13.196 12520-12668 	at org.odk.collect.android.formmanagement.download.ServerFormDownloader.downloadForm(ServerFormDownloader.java:78)
2025-03-13 14:11:13.196 12520-12668 	at org.odk.collect.android.formmanagement.ServerFormUseCases.downloadForms(ServerFormUseCases.kt:32)
2025-03-13 14:11:13.197 12520-12668 	at org.odk.collect.android.formmanagement.FormsDataService.downloadForms$lambda$2(FormsDataService.kt:85)
2025-03-13 14:11:13.198 12520-12668 	at org.odk.collect.android.formmanagement.FormsDataService.$r8$lambda$ilhmRakkOPMRFkITvl1F-QldG80(Unknown Source:0)
2025-03-13 14:11:13.198 12520-12668 	at org.odk.collect.android.formmanagement.FormsDataService$$ExternalSyntheticLambda3.apply(D8$$SyntheticClass:0)
2025-03-13 14:11:13.199 12520-12668 	at org.odk.collect.shared.locks.ThreadSafeBooleanChangeLock.withLock(ThreadSafeBooleanChangeLock.kt:12)
2025-03-13 14:11:13.199 12520-12668 	at org.odk.collect.android.formmanagement.FormsDataService.downloadForms(FormsDataService.kt:80)
2025-03-13 14:11:13.200 12520-12668 	at org.odk.collect.android.tasks.DownloadFormsTask.doInBackground(DownloadFormsTask.java:54)
2025-03-13 14:11:13.201 12520-12668 	at org.odk.collect.android.tasks.DownloadFormsTask.doInBackground(DownloadFormsTask.java:40)
2025-03-13 14:11:13.201 12520-12668 	at android.os.AsyncTask$3.call(AsyncTask.java:394)
2025-03-13 14:11:13.202 12520-12668 	at java.util.concurrent.FutureTask.run(FutureTask.java:264)
2025-03-13 14:11:13.202 12520-12668 	at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:305)
2025-03-13 14:11:13.203 12520-12668 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
2025-03-13 14:11:13.203 12520-12668 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
2025-03-13 14:11:13.204 12520-12668 	at java.lang.Thread.run(Thread.java:1012)

It seems to happen in collect_app/src/main/java/org/odk/collect/android/formmanagement/metadata/FormMetadataParser.kt :

....
val id = mainInstanceRoot.getAttributeValue(null, "id")
....

(GitHub)

seadowg · March 13, 2025, 2:03pm

Are you able to post (or DM me if that's not appropriate) the full form? It looks like there is a mismatch in what the form metadata parser (that extracts the ID etc from an XForm) expects here. It could be that this is an edge case or that your form doesn't quite meet the spec, but the old parser code was looser.

mbaudier · March 13, 2025, 2:46pm

I have sent it per DM.

seadowg · March 13, 2025, 3:22pm

Ok it looks to me like the problem is that @mbaudier's form has an attribute on the main (primary) instance node and Collect currently expects it to have none.

From looking at the spec, I think Collect is in the wrong here as the main instance is identified simply by being the first node instance declared within model. I'll double-check this with the team and see if we can get a fix out soon.

@mbaudier as an aside, it'd be a good idea to try and keep up and test with Collect beta releases if you're using custom XForms extensions/non-standard Open Rosa implementations. The change that caused this problem was introduced back in September and was available in v2024.3.0-beta.5. Beta releases are announced here.

mbaudier · March 13, 2025, 3:55pm

Yes, I should have done that. I have now configured the Release category in order to receive notifications.