Can't use auto export db from Gadgetbridge to Nextcloud

[Woundorf]

I use the Gadgetbridge app and have it configured to export its db every few hours to Nextcloud. This worked well until some time ago when it ceased to work. Judging from version dates, it was most probably with the update to v3.14.0 (maybe related to changes in #6917, but I don't know enough to affirm it).

In the logcat I can see that a NetworkOnMainThreadException is thrown, thus I guess it's closely related to #7350. Looking in the Gadgetbridge code the exception is thrown when trying to create an OutputStream on the Nextcloud URI, in a call like this:

OutputStream out = context.getContentResolver().openOutputStream(dstUri)

Note that this works with things like Dropbox, that's why I think it can be considered a bug in Nextcloud, although I can also report these details to Gadgetbridge.

Steps to reproduce

(Assuming that it can be reproduced with a just created Gadgetbridge database)

1. Install Gadgetbridge
2. Configure an auto export location to Nextcloud
3. Go to Database management
4. Click on Run AutoExport Now

Expected behaviour

• Database is exported and synchronized to the server.

Actual behaviour

• On step 2 an empty file is created and synchronized to the server.
• On step 4 it fails with a generic error (if logcat is not inspected).

Can you reproduce this problem on https://try.nextcloud.com?

• Irrelevant

Environment data

Android version: 7.1.2

Device model: LG H870

Stock or customized system: LineageOS 14.1

Nextcloud app version: 3.14.2

Nextcloud server version: 19.0.2.2

Reverse proxy: none

Logs

Logcat log

01-13 17:40:12.107 I/nodomain.freeyourgadget.gadgetbridge.util.GB(4389): Exportant base de dades…
01-13 17:40:12.110 I/nodomain.freeyourgadget.gadgetbridge.database.PeriodicExporter(4389): Exporting DB
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): Download of /Gadgetbridge/database.db to /storage/emulated/0/Android/media/com.nextcloud.client/nextcloud/tmp/XXXXXXXXXX/Gadgetbridge/database.db: Unexpected exception
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): android.os.NetworkOnMainThreadException
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at android.os.StrictMode$AndroidBlockGuardPolicy.onNetwork(StrictMode.java:1303)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at java.net.Inet6AddressImpl.lookupHostByName(Inet6AddressImpl.java:86)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at java.net.Inet6AddressImpl.lookupAllHostAddr(Inet6AddressImpl.java:74)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at java.net.InetAddress.getByName(InetAddress.java:708)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at com.owncloud.android.lib.common.network.AdvancedSslSocketFactory.getInetAddressForHost(AdvancedSslSocketFactory.java:192)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at com.owncloud.android.lib.common.network.AdvancedSslSocketFactory.createSocket(AdvancedSslSocketFactory.java:182)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at org.apache.commons.httpclient.HttpConnection.open(HttpConnection.java:707)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at org.apache.commons.httpclient.MultiThreadedHttpConnectionManager$HttpConnectionAdapter.open(MultiThreadedHttpConnectionManager.java:1361)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at org.apache.commons.httpclient.HttpMethodDirector.executeWithRetry(HttpMethodDirector.java:387)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at org.apache.commons.httpclient.HttpMethodDirector.executeMethod(HttpMethodDirector.java:171)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:397)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:323)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at com.owncloud.android.lib.common.OwnCloudClient.executeMethod(OwnCloudClient.java:219)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at com.owncloud.android.lib.resources.files.DownloadFileRemoteOperation.downloadFile(DownloadFileRemoteOperation.java:111)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at com.owncloud.android.lib.resources.files.DownloadFileRemoteOperation.run(DownloadFileRemoteOperation.java:88)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at com.owncloud.android.lib.common.operations.RemoteOperation.execute(RemoteOperation.java:184)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at com.owncloud.android.operations.DownloadFileOperation.run(DownloadFileOperation.java:168)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at com.owncloud.android.lib.common.operations.RemoteOperation.execute(RemoteOperation.java:184)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at com.owncloud.android.providers.DocumentsStorageProvider.openDocument(DocumentsStorageProvider.java:204)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at android.provider.DocumentsProvider.openAssetFile(DocumentsProvider.java:921)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at android.content.ContentProvider$Transport.openAssetFile(ContentProvider.java:389)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at android.content.ContentProviderNative.onTransact(ContentProviderNative.java:262)
01-13 17:40:12.138 E/DownloadFileRemoteOperation(18945): 	at android.os.Binder.execTransact(Binder.java:565)
01-13 17:40:12.139 I/DownloadFileOperation(18945): Download of /Gadgetbridge/database.db to /storage/emulated/0/Android/media/com.nextcloud.client/nextcloud/XXXXXXXXXX/Gadgetbridge/database.db: Unexpected exception
01-13 17:40:12.139 E/DocumentsStorageProvider(18945): RemoteOperationResult(mSuccess=false, mHttpCode=-1, mHttpPhrase=null, mException=android.os.NetworkOnMainThreadException, mCode=HOST_NOT_AVAILABLE, getLogMessage=Unexpected exception)
01-13 17:40:12.147 I/nodomain.freeyourgadget.gadgetbridge.database.PeriodicExporter(4389): Exception while exporting DB: java.io.FileNotFoundException: Error downloading file: database.db
01-13 17:40:12.147 I/nodomain.freeyourgadget.gadgetbridge.database.PeriodicExporter(4389): 	at android.database.DatabaseUtils.readExceptionWithFileNotFoundExceptionFromParcel(DatabaseUtils.java:144) ~[na:0.0]
01-13 17:40:12.147 I/nodomain.freeyourgadget.gadgetbridge.database.PeriodicExporter(4389): 	at android.content.ContentProviderProxy.openAssetFile(ContentProviderNative.java:621) ~[na:0.0]
01-13 17:40:12.147 I/nodomain.freeyourgadget.gadgetbridge.database.PeriodicExporter(4389): 	at android.content.ContentResolver.openAssetFileDescriptor(ContentResolver.java:1004) ~[na:0.0]
01-13 17:40:12.147 I/nodomain.freeyourgadget.gadgetbridge.database.PeriodicExporter(4389): 	at android.content.ContentResolver.openOutputStream(ContentResolver.java:746) ~[na:0.0]
01-13 17:40:12.147 I/nodomain.freeyourgadget.gadgetbridge.database.PeriodicExporter(4389): 	at android.content.ContentResolver.openOutputStream(ContentResolver.java:722) ~[na:0.0]
01-13 17:40:12.147 I/nodomain.freeyourgadget.gadgetbridge.database.PeriodicExporter(4389): 	at nodomain.freeyourgadget.gadgetbridge.database.PeriodicExporter.onReceive(PeriodicExporter.java:84) ~[na:0.0]
01-13 17:40:12.147 I/nodomain.freeyourgadget.gadgetbridge.database.PeriodicExporter(4389): 	at android.app.ActivityThread.handleReceiver(ActivityThread.java:3065) ~[na:0.0]
01-13 17:40:12.147 I/nodomain.freeyourgadget.gadgetbridge.database.PeriodicExporter(4389): 	at android.app.ActivityThread.-wrap18(ActivityThread.java) ~[na:0.0]
01-13 17:40:12.147 I/nodomain.freeyourgadget.gadgetbridge.database.PeriodicExporter(4389): 	at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1580) ~[na:0.0]
01-13 17:40:12.147 I/nodomain.freeyourgadget.gadgetbridge.database.PeriodicExporter(4389): 	at android.os.Handler.dispatchMessage(Handler.java:102) ~[na:0.0]
01-13 17:40:12.147 I/nodomain.freeyourgadget.gadgetbridge.database.PeriodicExporter(4389): 	at android.os.Looper.loop(Looper.java:154) ~[na:0.0]
01-13 17:40:12.147 I/nodomain.freeyourgadget.gadgetbridge.database.PeriodicExporter(4389): 	at android.app.ActivityThread.main(ActivityThread.java:6186) ~[na:0.0]
01-13 17:40:12.147 I/nodomain.freeyourgadget.gadgetbridge.database.PeriodicExporter(4389): 	at java.lang.reflect.Method.invoke(Native Method) ~[na:0.0]
01-13 17:40:12.147 I/nodomain.freeyourgadget.gadgetbridge.database.PeriodicExporter(4389): 	at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:889) ~[na:0.0]
01-13 17:40:12.147 I/nodomain.freeyourgadget.gadgetbridge.database.PeriodicExporter(4389): 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:779) ~[na:0.0]

[AndyScherzinger]

@Woundorf like related to the server's dns config:

mCode=HOST_NOT_AVAILABLE

From your stack trace. Beware that with our client 3.14+ we switched ipv4 over ipv6 to ipv6 over ipv4. So your server's dns likely has a ipv6 record that isn't quite right. If the server doesn't support v6 at all then our client falls back to v4. Before v3.14 the client work the other way around.

Hope this helps.

[Woundorf]

The server surely doesn't support IPv6 because it's a home server and my ISP doesn't support IPv6.

Also, I can reach the server directly from the app fine, even at the same time that this fails. It's only this specific use case that I have found to fail, and it fails immediately after pressing the button (i.e. it doesn't appear to have time to receive a DNS response).

[linuxrrze]

I observed the same thing with a IPv6+IPv4 enabled nextcloud server.

[tobiasKaminsky]

@jmue @grote both of you changed the way how DocumentsStorageProvider: openDocument works.

It seems that it is ok to call any DocumentsStoragProvider on main thread.
However, our http library does not allow this.

This is one of the changes: 1fdea37

Previously it would just fire a service to download the file.
Now it handled in thread, and as this can be on UI thread (when calling app is doing this), this can lead to problems.

"Easiest" would probably be to put the whole download thing in a Thread, and once this is finished, we serve the downloaded file.

What do you think?

[grote]

I don't think that Nextcloud should do something. Apps shouldn't do I/O on the UiThread and it seems your HTTP library is even enforcing this. But starting another thread and then doing a blocking wait would not change the situation. The UiThread would still be blocked, but now you need StrictMode to find out about it. IMHO the apps doing I/O on the UiThread should fix that.

If you want to allow these apps to do this, maybe the check in the HTTP library can be turned off or downgraded to a warning?

[jmue]

I think Thorsten is right here. openDocument() must not block the UI. As I don't know of any way to drive the ParcelFileDescriptor asynchronously the calling thread has to be other than the main thread. The service has only covered up the problem in the past. It has to be solved on client side.

[jmue]

Storage Access Framework documentation has following comment in the sample implementation of openDocument().

    // It's OK to do network operations in this method to download the document,
    // as long as you periodically check the CancellationSignal. If you have an
    // extremely large file to transfer from the network, a better solution may
    // be pipes or sockets (see ParcelFileDescriptor for helper methods).

[ChrisAichinger]

I'm affected by this issue as well, is there any update? From reading the discussion I'm not clear on whether this should be a bug report in Nextcloud, in the HTTP library Nextcloud uses, or in Gadgetbridge.

There was a Gitlab issue on Gadgetbridge about this problem as well, but it has been closed as the problem seemed to be with Nextcloud.

If the problem is on the Nextcloud side, is there anything I/we can do to move this forward and fix the regression? If you think this should be better fixed in Gadgetbridge, could you please explain how Gadgetbridge is using the APIs wrongly / what the correct usage pattern would be?

[grote]

This app is doing I/O on the UiThread which is not OK. It needs to do its file operations on another thread.