search

orgzly-revived / orgzly-android-revived

Outliner for taking notes and managing to-do lists
https://www.orgzlyrevived.com
GNU General Public License v3.0
672 stars 42 forks source link

Cloning Git repo: Operation not permitted #200

Open tinloaf opened 8 months ago

tinloaf commented 8 months ago

Please complete the following information:

Device: Google Pixel 6 running Lineage OS 20
Android Version: Android 13
Orgzly Revived Version: 1.8.18 (installed from F-Droid)

I am trying to clone a git repository containing all my org files. The git access (via SSH) seems to work, it gets to the point where it says "Repository is being cloned" (or similar, my phone is in German, the original message is "Repository wird geklont").

Then, an error message "Operation not permitted" pops up. It offers to copy a stack trace, this is the trace:

java.io.IOException: fc.n: Operation not permitted
    at w5.f.l(GitRepo.java:60)
    at w5.f.n(GitRepo.java:3)
    at w5.f.o(GitRepo.java:18)
    at com.orgzly.android.ui.repo.git.GitRepoActivity$d.c(GitRepoActivity.kt:9)
    at com.orgzly.android.ui.repo.git.GitRepoActivity$d.doInBackground(GitRepoActivity.kt:3)
    at android.os.AsyncTask$3.call(AsyncTask.java:394)
    at java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:305)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1137)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:637)
    at java.lang.Thread.run(Thread.java:1012)
Caused by: fc.n: Operation not permitted
    at ec.h.m(CloneCommand.java:75)
    at w5.f.l(GitRepo.java:39)
    ... 10 more
Caused by: java.io.IOException: Operation not permitted
    at java.io.UnixFileSystem.createFileExclusively0(Native Method)
    at java.io.UnixFileSystem.createFileExclusively(UnixFileSystem.java:317)
    at java.io.File.createTempFile(File.java:2007)
    at ic.d.a(Checkout.java:162)
    at ic.l.g(DirCacheCheckout.java:337)
    at ic.l.d(DirCacheCheckout.java:1)
    at ec.h.n(CloneCommand.java:157)
    at ec.h.m(CloneCommand.java:54)
    ... 11 more

I did give the app all permissions it requested, but I notice there is no 'access files' permission (again sorry, it's German, but the relevant point is that below 'Nicht zugelassen' / 'Not granted' it says 'Alle Berechtigungen zugelassen' / 'All permissions granted').

Note that when setting up the git repo in orgzly-revived, I did click the 'Browse' button and (from the file browser that opened) created a new directory, and selected that newly created directory. I dimly seem to remember that Android apps by default have permissions on directories created from the same App. But that also does not seem to solve the problem.

amberin commented 8 months ago

Thank you very much for your report! It looks like the Git library tries to create a temp file during cloning, and gets this permission issue. I have never seen this problem before.

I will see if I can reproduce this on a virtual device with your characteristics.

amberin commented 8 months ago

Oh and it's normal that you don't see any storage permission among the app's regular permissions. The permission that you were prompted about is of a different kind.

tinloaf commented 8 months ago

Thanks for your quick reply. Please let me know if I can help in any way. I'm not an an Android dev, but I can e.g. use adb logcat.

tinloaf commented 6 months ago

Just a quick update: I updated my phone to Lineage OS 21 / Android 14, the issue remains.

amberin commented 6 months ago

@tinloaf I wish I could test on a virtual device with Lineage, but it requires building the OS image locally, and I don't have the storage space required. This means I cannot reproduce the error.

Version 1.8.22 targets Android 13, which might make a difference permission-wise. Have you tried it? Edit: Sorry, it's not yet available from F-Droid.

tinloaf commented 5 months ago

@amberin Ah, I wasn't aware that LOS did not provide prebuilt images for virtual devices. :-/

I just got 1.8.22 from F-Droid and the error is still the same.

tinloaf commented 3 months ago

(Sorry for the very long comment. I tried including all possibly relevant backtraces which I could find…)

I tried today to get to the bottom of this (even though I'm really not a Android dev…). I cloned the repo, built a debug build, pushed it to my phone and reproduced the problem while watching adb logcat. I find Android logs always very noisy, but I think I might have found something suspicious.

When the cloning crashes, there are lots of log messages by StorageManager and MediaProvider. I assume these are components that somehow abstract the filesystem layer?

Shortly before the cloning crashes, this is logged:

08-01 23:39:01.369  3662  3857 W MediaProvider: isAppCloneUserPair for user 0: false
08-01 23:39:01.390  3662 15284 W MediaProvider: isAppCloneUserPair for user 0: false
08-01 23:39:01.408  3662  5038 I MediaProvider: Deleted 1 0 0 0 0 0 0 items on external_primary due to com.orgzlyrevived
08-01 23:39:01.413  3662  4983 W MediaProvider: isAppCloneUserPair for user 0: false
08-01 23:39:01.421  3662  3857 I MediaProvider: Deleted 1 0 0 0 0 0 0 items on external_primary due to com.orgzlyrevived
08-01 23:39:01.438  3662  5038 W MediaProvider: isAppCloneUserPair for user 0: false
08-01 23:39:01.442  3662  3726 E StorageManager: Failed to open /storage/emulated/0/org-git/.git/HEAD.lock to set project id.: No such file or directory
08-01 23:39:01.443  3662  3898 I MediaProvider: Deleted 1 0 0 0 0 0 0 items on external_primary due to com.orgzlyrevived
08-01 23:39:01.445  3662  3726 W MediaProvider: Failed to update quota type for /storage/emulated/0/org-git/.git/HEAD.lock
08-01 23:39:01.445  3662  3726 W MediaProvider: java.io.IOException: Failed to update quota type for /storage/emulated/0/org-git/.git/HEAD.lock
08-01 23:39:01.445  3662  3726 W MediaProvider:     at android.os.storage.StorageManager.updateExternalStorageFileQuotaType(StorageManager.java:2589)
08-01 23:39:01.445  3662  3726 W MediaProvider:     at com.android.providers.media.MediaProvider.updateQuotaTypeForFileInternal(MediaProvider.java:960)
08-01 23:39:01.445  3662  3726 W MediaProvider:     at com.android.providers.media.MediaProvider.updateQuotaTypeForUri(MediaProvider.java:935)
08-01 23:39:01.445  3662  3726 W MediaProvider:     at com.android.providers.media.MediaProvider$5.lambda$onInsert$0(MediaProvider.java:994)
08-01 23:39:01.445  3662  3726 W MediaProvider:     at com.android.providers.media.MediaProvider$5.$r8$lambda$4KU7YPdO1inr9tOLVzprJ5YcfCE(MediaProvider.java:0)
08-01 23:39:01.445  3662  3726 W MediaProvider:     at com.android.providers.media.MediaProvider$5$$ExternalSyntheticLambda2.run(R8$$SyntheticClass:0)
08-01 23:39:01.445  3662  3726 W MediaProvider:     at android.os.Handler.handleCallback(Handler.java:959)
08-01 23:39:01.445  3662  3726 W MediaProvider:     at android.os.Handler.dispatchMessage(Handler.java:100)
08-01 23:39:01.445  3662  3726 W MediaProvider:     at android.os.Looper.loopOnce(Looper.java:232)
08-01 23:39:01.445  3662  3726 W MediaProvider:     at android.os.Looper.loop(Looper.java:317)
08-01 23:39:01.445  3662  3726 W MediaProvider:     at android.os.HandlerThread.run(HandlerThread.java:68)

Shortly after that:

08-01 23:39:01.449  3662  3857 W MediaProvider: Database update failed while renaming /storage/emulated/0/org-git/.git/config.lock
08-01 23:39:01.449  3662  3857 W MediaProvider: android.database.sqlite.SQLiteConstraintException: UNIQUE constraint failed: files._data (code 2067 SQLITE_CONSTRAINT_UNIQUE)
08-01 23:39:01.449  3662  3857 W MediaProvider:     at android.database.sqlite.SQLiteConnection.nativeExecuteForChangedRowCount(Native Method)
08-01 23:39:01.449  3662  3857 W MediaProvider:     at android.database.sqlite.SQLiteConnection.executeForChangedRowCount(SQLiteConnection.java:923)
08-01 23:39:01.449  3662  3857 W MediaProvider:     at android.database.sqlite.SQLiteSession.executeForChangedRowCount(SQLiteSession.java:780)
08-01 23:39:01.449  3662  3857 W MediaProvider:     at android.database.sqlite.SQLiteStatement.executeUpdateDelete(SQLiteStatement.java:67)
08-01 23:39:01.449  3662  3857 W MediaProvider:     at com.android.providers.media.util.DatabaseUtils.executeUpdateDelete(DatabaseUtils.java:499)
08-01 23:39:01.449  3662  3857 W MediaProvider:     at com.android.providers.media.util.SQLiteQueryBuilder.update(SQLiteQueryBuilder.java:697)
08-01 23:39:01.449  3662  3857 W MediaProvider:     at com.android.providers.media.util.SQLiteQueryBuilder.lambda$update$2(SQLiteQueryBuilder.java:619)
08-01 23:39:01.449  3662  3857 W MediaProvider:     at com.android.providers.media.util.SQLiteQueryBuilder.$r8$lambda$V5i8aaD8hBMOL_-PCdDrUiXRenE(SQLiteQueryBuilder.java:0)
08-01 23:39:01.449  3662  3857 W MediaProvider:     at com.android.providers.media.util.SQLiteQueryBuilder$$ExternalSyntheticLambda2.apply(R8$$SyntheticClass:0)
08-01 23:39:01.449  3662  3857 W MediaProvider:     at com.android.providers.media.DatabaseHelper.runWithTransaction(DatabaseHelper.java:885)
08-01 23:39:01.449  3662  3857 W MediaProvider:     at com.android.providers.media.util.SQLiteQueryBuilder.update(SQLiteQueryBuilder.java:618)
08-01 23:39:01.449  3662  3857 W MediaProvider:     at com.android.providers.media.MediaProvider.updateDatabaseForFuseRename(MediaProvider.java:3009)
08-01 23:39:01.449  3662  3857 W MediaProvider:     at com.android.providers.media.MediaProvider.updateDatabaseForFuseRename(MediaProvider.java:2976)
08-01 23:39:01.449  3662  3857 W MediaProvider:     at com.android.providers.media.MediaProvider.updateDatabaseForFuseRename(MediaProvider.java:2970)
08-01 23:39:01.449  3662  3857 W MediaProvider:     at com.android.providers.media.MediaProvider.renameFileForFuse(MediaProvider.java:3332)
08-01 23:39:01.449  3662  3857 W MediaProvider:     at com.android.providers.media.MediaProvider.renameFileUncheckedForFuse(MediaProvider.java:3312)
08-01 23:39:01.449  3662  3857 W MediaProvider:     at com.android.providers.media.MediaProvider.renameUncheckedForFuse(MediaProvider.java:3399)
08-01 23:39:01.449  3662  3857 W MediaProvider:     at com.android.providers.media.MediaProvider.renameForFuse(MediaProvider.java:3447)
08-01 23:39:01.450  3662  3857 I MediaProvider: Retrying database update after deleting conflicting entry

It looks like it tries to do the database operation again:

08-01 23:39:01.450  3662  3857 I MediaProvider: Retrying database update after deleting conflicting entry

I don't see another error for config.lock, so maybe the retry is successfull?

However, after that, another file causes trouble:

08-01 23:39:01.625  3662  3726 E StorageManager: Failed to open /storage/emulated/0/org-git/roam/._20201118190756-emacs.org3018103407467291914.tmp to set project id.: No such file or directory
08-01 23:39:01.625  3662  3726 W MediaProvider: Failed to update quota type for /storage/emulated/0/org-git/roam/._20201118190756-emacs.org3018103407467291914.tmp
08-01 23:39:01.625  3662  3726 W MediaProvider: java.io.IOException: Failed to update quota type for /storage/emulated/0/org-git/roam/._20201118190756-emacs.org3018103407467291914.tmp
08-01 23:39:01.625  3662  3726 W MediaProvider:     at android.os.storage.StorageManager.updateExternalStorageFileQuotaType(StorageManager.java:2589)
08-01 23:39:01.625  3662  3726 W MediaProvider:     at com.android.providers.media.MediaProvider.updateQuotaTypeForFileInternal(MediaProvider.java:960)
08-01 23:39:01.625  3662  3726 W MediaProvider:     at com.android.providers.media.MediaProvider.updateQuotaTypeForUri(MediaProvider.java:935)
08-01 23:39:01.625  3662  3726 W MediaProvider:     at com.android.providers.media.MediaProvider$5.lambda$onInsert$0(MediaProvider.java:994)
08-01 23:39:01.625  3662  3726 W MediaProvider:     at com.android.providers.media.MediaProvider$5.$r8$lambda$4KU7YPdO1inr9tOLVzprJ5YcfCE(MediaProvider.java:0)
08-01 23:39:01.625  3662  3726 W MediaProvider:     at com.android.providers.media.MediaProvider$5$$ExternalSyntheticLambda2.run(R8$$SyntheticClass:0)
08-01 23:39:01.625  3662  3726 W MediaProvider:     at android.os.Handler.handleCallback(Handler.java:959)
08-01 23:39:01.625  3662  3726 W MediaProvider:     at android.os.Handler.dispatchMessage(Handler.java:100)
08-01 23:39:01.625  3662  3726 W MediaProvider:     at android.os.Looper.loopOnce(Looper.java:232)
08-01 23:39:01.625  3662  3726 W MediaProvider:     at android.os.Looper.loop(Looper.java:317)
08-01 23:39:01.625  3662  3726 W MediaProvider:     at android.os.HandlerThread.run(HandlerThread.java:68)

That's the last backtrace I can see that mentions a file. After that, there's the backtrace which I also see in the toast, and which probably is not very useful:

08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity: Error during repo cloning:
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity: java.io.IOException: org.eclipse.jgit.api.errors.JGitInternalException: Operation not permitted
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    at com.orgzly.android.repos.GitRepo.cloneRepo(GitRepo.java:166)
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    at com.orgzly.android.repos.GitRepo.ensureRepositoryExists(GitRepo.java:103)
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    at com.orgzly.android.repos.GitRepo.ensureRepositoryExists(GitRepo.java:93)
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    at com.orgzly.android.ui.repo.git.GitRepoActivity$RepoCloneTask.doInBackground(GitRepoActivity.kt:491)
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    at com.orgzly.android.ui.repo.git.GitRepoActivity$RepoCloneTask.doInBackground(GitRepoActivity.kt:480)
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    at android.os.AsyncTask$3.call(AsyncTask.java:394)
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    at java.util.concurrent.FutureTask.run(FutureTask.java:264)
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:305)
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    at java.lang.Thread.run(Thread.java:1012)
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity: Caused by: org.eclipse.jgit.api.errors.JGitInternalException: Operation not permitted
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    at org.eclipse.jgit.api.CloneCommand.call(CloneCommand.java:215)
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    at com.orgzly.android.repos.GitRepo.cloneRepo(GitRepo.java:157)
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    ... 10 more
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity: Caused by: java.io.IOException: Operation not permitted
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    at java.io.UnixFileSystem.createFileExclusively0(Native Method)
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    at java.io.UnixFileSystem.createFileExclusively(UnixFileSystem.java:349)
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    at java.io.File.createTempFile(File.java:2007)
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    at org.eclipse.jgit.dircache.Checkout.checkout(Checkout.java:193)
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    at org.eclipse.jgit.dircache.DirCacheCheckout.doCheckout(DirCacheCheckout.java:562)
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    at org.eclipse.jgit.dircache.DirCacheCheckout.checkout(DirCacheCheckout.java:465)
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    at org.eclipse.jgit.api.CloneCommand.checkout(CloneCommand.java:385)
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    at org.eclipse.jgit.api.CloneCommand.call(CloneCommand.java:212)
08-01 23:39:03.656 15880 15880 E com.orgzly.android.ui.repo.git.GitRepoActivity:    ... 11 more
08-01 23:39:03.657  1371  4653 D CoreBackPreview: Window{8720919 u0 com.orgzlyrevived/com.orgzly.android.ui.repo.git.GitRepoActivity}: Setting back callback OnBackInvokedCallbackInfo{mCallback=android.window.IOnBackInvokedCallback$Stub$Proxy@707ab78, mPriority=0, mIsAnimationCallback=false}

However, after that there's something that looks interesting:

08-01 23:39:03.662   545   557 W gralloc4: Unable to set buffer name VRI[GitRepoActivity]#20(BLAST Consumer)20: File name too long
08-01 23:39:03.663   545   557 W gralloc4: Unable to set buffer name VRI[GitRepoActivity]#20(BLAST Consumer)20: File name too long
08-01 23:39:03.664   545   557 W gralloc4: Unable to set buffer name VRI[GitRepoActivity]#20(BLAST Consumer)20: File name too long
08-01 23:39:03.664   545   557 W gralloc4: Unable to set buffer name VRI[GitRepoActivity]#20(BLAST Consumer)20: File name too long

I don't know what gralloc4 is, but the message contains GitRepoActivity and File name too long. Could that be the problem? The file name in the backtrace above seems to be extended with a timestamp (or similar), a .tmp, etc. But I assume that this is not under orgzly's control, but rather under jgit control, right?

amberin commented 3 months ago

gralloc4 is graphics-rendering code, and GitRepoActivity is the screen where you are, where a progress spinner is shown. So I'm afraid that the "file name too long" message is probably not about the git repo files. But I'm not 100% sure.

Do you have some sort of filesystem encryption enabled which might make your new folder exist in an encrypted filesystem? Because that could theoretically affect the maximum allowed file name length. (I'm not aware of such an encryption feature, but I don't know LineageOS.)

tinloaf commented 3 months ago

No, I only have the usual Android full-disk encryption enabled, but that should not be specific to LineageOS. :(