Writing the same file through DocumentProvider in short succession fails

afflux commented 1 year ago

⚠️ Before posting ⚠️

[X] This is a bug, not a question or an enhancement.
[X] I've searched for similar issues and didn't find a duplicate.
[X] I've written a clear and descriptive title for this issue, not just "Bug" or "Crash".
[X] I agree to follow Nextcloud's Code of Conduct.

Steps to reproduce

Use Seedvault to back up into Nextcloud document provider
Backup fails pretty much immediately

Expected behaviour

Backup should work :-)

Actual behaviour

01-21 11:19:27.280 16389 22235 E BackupCoordinator: java.io.FileNotFoundException: Failed to open document for writing .backup.metadata
01-21 11:19:27.280 16389 22235 E BackupCoordinator:     at android.database.DatabaseUtils.readExceptionWithFileNotFoundExceptionFromParcel(DatabaseUtils.java:151)
01-21 11:19:27.280 16389 22235 E BackupCoordinator:     at android.content.ContentProviderProxy.openAssetFile(ContentProviderNative.java:705)
01-21 11:19:27.280 16389 22235 E BackupCoordinator:     at android.content.ContentResolver.openAssetFileDescriptor(ContentResolver.java:1860)
01-21 11:19:27.280 16389 22235 E BackupCoordinator:     at android.content.ContentResolver.openOutputStream(ContentResolver.java:1562)
01-21 11:19:27.280 16389 22235 E BackupCoordinator:     at com.stevesoltys.seedvault.plugins.saf.DocumentsStorage.getOutputStream(DocumentsStorage.kt:142)
01-21 11:19:27.280 16389 22235 E BackupCoordinator:     at com.stevesoltys.seedvault.plugins.saf.DocumentsProviderStoragePlugin.getOutputStream(DocumentsProviderStoragePlugin.kt:66)

I've debugged this using frida. As you can see here, the first attempt to store .backup.metadata works:

164646 ms  DocumentsStorageProvider.openDocument("a1ebc18cccdbc2d16184bd5292186a1d/4038", "wt", null)
164648 ms     | <= [id=4038, name=.backup.metadata, mime=application/octet-stream, downloaded=false, local=null, remote=/.SeedVaultAndroidBackup/1674294725092/.backup.metadata, parentId=4037, etag=, favourite=false]
164972 ms     | ParcelFileDescriptor.open("file:/storage/emulated/0/Android/media/com.nextcloud.client/nextcloud/USER@HOST/.SeedVaultAndroidBackup/1674294725092/.backup.metadata", 2c000000)
164981 ms     | <= "<instance: android.os.ParcelFileDescriptor>"

But shortly after, the same file is written again, and this fails:

166664 ms  DocumentsStorageProvider.openDocument("a1ebc18cccdbc2d16184bd5292186a1d/4038", "wt", null)
166664 ms     | <= [id=4038, name=.backup.metadata, mime=application/octet-stream, downloaded=false, local=, remote=/.SeedVaultAndroidBackup/1674294725092/.backup.metadata, parentId=4037, etag=350ebf46ff002413caf2914d1fc2e947, favourite=false]
166672 ms     | ParcelFileDescriptor.open("file:/", 2c000000)

Note that local= is just the empty string, which is set, for example, here: https://github.com/nextcloud/android/blob/5836b300a2f15b9ee37894e30ddb84d04a0154ee/app/src/main/java/com/owncloud/android/operations/UploadFileOperation.java#L985-L991

(also here: https://github.com/nextcloud/android/blob/5836b300a2f15b9ee37894e30ddb84d04a0154ee/app/src/main/java/com/owncloud/android/operations/UploadFileOperation.java#L1295-L1309)

I don't get why sometimes there is the empty string and sometimes it's set to null (it's not really documented). But most accessors in OCFile check for empty string. Not the DocumentStorageProvider, though: https://github.com/nextcloud/android/blob/5836b300a2f15b9ee37894e30ddb84d04a0154ee/app/src/main/java/com/owncloud/android/providers/DocumentsStorageProvider.java#L214

Android version

13

Device brand and model

Google Pixel 4

Stock or custom OS?

Custom (explain in "additional information")

Nextcloud android app version

3.23.1

Nextcloud server version

25.0.3

Using a reverse proxy?

Yes

Android logs

nextcloud-logcat.txt

Server error logs

No response

Additional information

LineageOS 20

afflux commented 1 year ago

@grote: git blame pointed to https://github.com/nextcloud/android/commit/44227d828d117585408f101189c81c67a7810d4d - do you think this just needs a check for empty storage path?

ghost commented 1 year ago

@grote: git blame pointed to 44227d8 - do you think this just needs a check for empty storage path?

I notice that when the backup attempt initializes correctly for the first time that I have more success getting everything backed up afterwards

grote commented 1 year ago

@afflux thanks for the in-depth debugging!

do you think this just needs a check for empty storage path?

I only helped with the DocumentsProvider, but don't know the internal of Nextcloud so well. If we need to check for null and empty string, this should probably get added to the place you identified.

This might indeed be one of the ongoing issues with Nextcloud's DocumentsProvider implementation that you've found here.

nextcloud / android