NeoApplications / Neo-Backup

backup manager for android
GNU Affero General Public License v3.0
2.55k stars 126 forks source link

[Bug] Backup fails if some filenames contain two consecutive spaces #288

Closed Jakeler closed 3 years ago

Jakeler commented 3 years ago

Description Backing up the F-Droid store app with data fails if a specific APK file is in the app data.

Steps To Reproduce

  1. Install F-Droid as app
  2. Download this app through the store (does not need to be installed): https://f-droid.org/de/packages/com.simplemobiletools.gallery.pro/
  3. Try to backup F-Droid with data, it fails with the error below

I tried many other apps/APKs and could not find any others that cause this error... but with this gallery app it happens reproducibly.

Logcat

01-19 01:04:01.939 25050 26844 I e       : Backing up: org.fdroid.fdroid [F-Droid]
01-19 01:04:01.940 25050 26736 D OpenGLRenderer: endAllActiveAnimators on 0x7cf82b2100 (RippleDrawable) with handle 0x7cc5a4bd80
01-19 01:04:01.947 25050 25050 W UiThreadStatement: Already on the UI thread, this method should not be called from the main application thread
01-19 01:04:01.985 25050 26844 I e       : Schedule{packageName=org.fdroid.fdroid, appMetaInfo=m.a.a.l.c@9e75e08, appUri=content://com.android.externalstorage.documents/tree/primary%3AOABX/document/primary%3AOABX%2Forg.fdroid.fdroid, storageStats=android.app.usage.StorageStats@859a9a1, packageInfo={true, /data/app/org.fdroid.fdroid-Cegpaojbcu_psX7BMXIFrw==/base.apk, /data/user/0/org.fdroid.fdroid, /data/user_de/0/org.fdroid.fdroid}, backupHistory=[BackupItem{ packageName="org.fdroid.fdroid", packageLabel="F-Droid", backupDate="2021-01-19T01:02:49.347" }]}: Backing up package
01-19 01:04:01.986 25050 26844 I a       : [org.fdroid.fdroid] Backup package apks
01-19 01:04:01.986 25050 26844 D a       : [org.fdroid.fdroid] The app is a normal apk
01-19 01:04:01.986 25050 26844 D a       : [org.fdroid.fdroid] Backing up package (1 apks: base.apk)
01-19 01:04:02.044 25050 26844 I e       : Schedule{packageName=org.fdroid.fdroid, appMetaInfo=m.a.a.l.c@9e75e08, appUri=content://com.android.externalstorage.documents/tree/primary%3AOABX/document/primary%3AOABX%2Forg.fdroid.fdroid, storageStats=android.app.usage.StorageStats@859a9a1, packageInfo={true, /data/app/org.fdroid.fdroid-Cegpaojbcu_psX7BMXIFrw==/base.apk, /data/user/0/org.fdroid.fdroid, /data/user_de/0/org.fdroid.fdroid}, backupHistory=[BackupItem{ packageName="org.fdroid.fdroid", packageLabel="F-Droid", backupDate="2021-01-19T01:02:49.347" }]}: Backing up data
01-19 01:04:02.044 25050 26844 I a       : [org.fdroid.fdroid] Starting data backup
01-19 01:04:02.044 25050 26844 D a       : Running Command: toybox ls -All "/data/user/0/org.fdroid.fdroid"
01-19 01:04:02.070 25050 26844 D a       : Command(s) '[Ljava.lang.String;@a9852b4' ended with 0
01-19 01:04:02.071 25050 26844 D a       : Running Command: toybox ls -All "/data/user/0/org.fdroid.fdroid/app_ACRA-approved"
01-19 01:04:02.096 25050 26844 D a       : Command(s) '[Ljava.lang.String;@7463edd' ended with 0
01-19 01:04:02.096 25050 26844 D a       : Running Command: toybox ls -All "/data/user/0/org.fdroid.fdroid/app_ACRA-unapproved"
01-19 01:04:02.124 25050 26844 D a       : Command(s) '[Ljava.lang.String;@bfe4a52' ended with 0
01-19 01:04:02.124 25050 26844 D a       : Running Command: toybox ls -All "/data/user/0/org.fdroid.fdroid/app_keystore"
01-19 01:04:02.137 25050 26844 D a       : Command(s) '[Ljava.lang.String;@356d123' ended with 0
01-19 01:04:02.137 25050 26844 D a       : Running Command: toybox ls -All "/data/user/0/org.fdroid.fdroid/databases"
01-19 01:04:02.149 25050 26844 D a       : Command(s) '[Ljava.lang.String;@3c1e620' ended with 0
01-19 01:04:02.149 25050 26844 D a       : Running Command: toybox ls -All "/data/user/0/org.fdroid.fdroid/files"
01-19 01:04:02.163 25050 26844 D a       : Command(s) '[Ljava.lang.String;@a6cebd9' ended with 0
01-19 01:04:02.163 25050 26844 D a       : Running Command: toybox ls -All "/data/user/0/org.fdroid.fdroid/files/FDROID"
01-19 01:04:02.177 25050 26844 D a       : Command(s) '[Ljava.lang.String;@312b99e' ended with 0
01-19 01:04:02.179 25050 26844 D a       : Running Command: toybox ls -All "/data/user/0/org.fdroid.fdroid/files/FDROID/REPO"
01-19 01:04:02.209 25050 26844 D a       : Command(s) '[Ljava.lang.String;@1bb5c7f' ended with 0
01-19 01:04:02.210 25050 26844 D a       : Running Command: toybox ls -All "/data/user/0/org.fdroid.fdroid/files/fdroid"
01-19 01:04:02.237 25050 26844 D a       : Command(s) '[Ljava.lang.String;@c2f444c' ended with 0
01-19 01:04:02.238 25050 26844 D a       : Running Command: toybox ls -All "/data/user/0/org.fdroid.fdroid/files/fdroid/repo"
01-19 01:04:02.257 25050 26844 D a       : Command(s) '[Ljava.lang.String;@5b76c95' ended with 0
01-19 01:04:02.258 25050 26844 D a       : Running Command: toybox ls -All "/data/user/0/org.fdroid.fdroid/files/fdroid/repo/icons"
01-19 01:04:02.271 25050 26844 D a       : Command(s) '[Ljava.lang.String;@26cd1aa' ended with 0
01-19 01:04:02.271 25050 26844 D a       : Running Command: toybox ls -All "/data/user/0/org.fdroid.fdroid/shared_prefs"
01-19 01:04:02.284 25050 26844 D a       : Command(s) '[Ljava.lang.String;@3b3419b' ended with 0
01-19 01:04:02.285 25050 26844 I a       : Backing up data got 43 files to backup
01-19 01:04:02.285 25050 26844 I a       : Creating data backup
01-19 01:04:02.298 25050 26844 D a       : Adding app_ACRA-approved to archive (filesize: 0)
01-19 01:04:02.298 25050 26844 D a       : Adding app_ACRA-unapproved to archive (filesize: 0)
01-19 01:04:02.298 25050 26844 D a       : Adding app_keystore to archive (filesize: 0)
01-19 01:04:02.299 25050 26844 D a       : Adding app_keystore/kerplapp.bks to archive (filesize: 2091)
01-19 01:04:02.340 25050 26844 D a       : Adding databases to archive (filesize: 0)
01-19 01:04:02.340 25050 26844 D a       : Adding databases/fdroid to archive (filesize: 8658944)
01-19 01:04:02.999 25050 26844 D a       : Adding databases/fdroid-journal to archive (filesize: 0)
01-19 01:04:03.022 25050 26844 D a       : Adding files to archive (filesize: 0)
01-19 01:04:03.022 25050 26844 D a       : Adding files/Aurora Store-3.2.8.apk to archive (filesize: 4597548)
01-19 01:04:03.409 25050 26844 D a       : Adding files/DAVx-3.3.7-ose.apk to archive (filesize: 9747265)
01-19 01:04:04.195 25050 26844 D a       : Adding files/FDROID to archive (filesize: 0)
01-19 01:04:04.195 25050 26844 D a       : Adding files/Schlichte Galerie Pro - Foto Manager Editor-6.18.0.apk to archive (filesize: 15951095)
01-19 01:04:04.205 25050 26844 D a       : Done compressing. Closing data.tar.gz
01-19 01:04:04.205 25050 26844 E a       : java.io.IOException occurred on data backup: java.io.IOException: Entry 'files/Schlichte Galerie Pro - Foto Manager Editor-6.18.0.apk' closed at '0' before the '15951095' bytes specified in the header were written
01-19 01:04:04.205 25050 26844 E e       : Backup failed due to a: java.io.IOException occurred on data backup: java.io.IOException: Entry 'files/Schlichte Galerie Pro - Foto Manager Editor-6.18.0.apk' closed at '0' before the '15951095' bytes specified in the header were written
127|davinci:/data/data/org.fdroid.fdroid/files # ls -All
-rw------- 1 u0_a247 u0_a247  4597548 2021-01-19 01:02:39.000000000 +0100 Aurora\ Store-3.2.8.apk
drwx------ 3 u0_a247 u0_a247     3488 2021-01-19 00:56:56.797387120 +0100 FDROID
-rw------- 1 u0_a247 u0_a247 15951095 2021-01-19 01:03:29.000000000 +0100 Schlichte\ Galerie\ Pro\ -\ Foto\ Manager\ \ Editor-6.18.0.apk
-rw------- 1 u0_a247 u0_a247 42411711 2021-01-19 00:59:28.000000000 +0100 Tasks.org\ Open-Source-Aufgabenlisten\ und\ Erinneru-11.2.1.apk

I don't see a difference to the other .apk files, but the backup works if I just delete Schlichte\ Galerie\ Pro\ -\ Foto\ Manager\ \ Editor-6.18.0.apk, very strange.

System Information:

machiav3lli commented 3 years ago

This error means that the app is possibly running in the background changing the data while the backup process, please try advanced settings > Stop-Cont. If it doesn't work, then it's probably caused by the privilged plug-in.

Jakeler commented 3 years ago

Stop-Cont or manually killing the app doesn't help unfortunately. I haven't used F-Droid directly before when I encountered this issue the first time and it also does not happen with any other apk so far, even if I just downloaded it and switch to OABX as fast as possible. I dont't have the F-Droid Privileged Extension installed. I noticed something else with a my file manager (Solid Explorer): it fails to delete this file, but works for other files in the app data... it throws a pl.solidexplorer.common.exceptions.SEException, but checking the SELinux context with ls -lAZ shows that it is the same for all files in the directory. A root shell with simple rm does the job though. It has to be some property of this specifc file, but I just can't figure out what exactly.

machiav3lli commented 3 years ago

Oh, then it could be a cyclic symlinking!

Jakeler commented 3 years ago

Nope, it is not a symlink. btw: It handles cyclic symlinks completly fine and stores it just as link without following. I have tried it out and I think symlinks should not cause any issues with the current implementation.

But I have now found the actual issue: It is the filename that contains two consecutive spaces after ... Foto\ Manager\ \! It is easily reproducible, renaming the file makes it work again. Probably an issue with filename escaping? I have also noticed in the error that it doesn't get correctly displayed, in the popup it prints the second backslash and in logcat it omits the second space completely.

hg42 commented 3 years ago

yes, "double spaces" indicates it's probably a quoting issue. The command line is probably split into words and then joined with single spaces. If the display is also wrong, this would indicate it's caused by reading from ls. Could you please show how it is exactly displayed in the popup? (I assume you are aware of spaces being narrower than other characters for proportional fonts, so you compare it with other spaces)

Unfortunately, I currently don't have time to update my development environment to the current version and work with that. But I might find time to have a look at the sources (online, github)...and thinking about the reasons.

btw. I also use Simple Gallery Pro ... but my system language is English (despite I'm German). I now see, the label is Schlichte\ Galerie\ Pro\ -\ Foto\ Manager\ \ Editor while it is 'Schlichte\ Galerie\ Pro\ -\ Foto\ Manager\ &\ Editor' in the F-Droid search, which explains the double space. The '&' seems to be removed by the App developer of Simple Gallery Pro or by some F-Droid procedures. But this doesn't matter, OAandBackupX should be able to use any valid file name.

hg42 commented 3 years ago

in a quick evening session, I updated my project and wrote a test case and I found the file name is read correctly from the line you provided:

// app/src/test/java/ShellHandlerTest.kt

import com.machiav3lli.backup.handler.ShellHandler
import org.junit.Assert
import org.junit.Test

class ShellHandlerTest {
    @Test
    fun test_fromLsOOutput_handlesDoubleSpace() {
        val fileInfo = ShellHandler.FileInfo.fromLsOOutput(
                "-rw------- 1 user0_a247 group0_a247 15951095 2021-01-19 01:03:29.000000000 +0100 Schlichte\\ Galerie\\ Pro\\ -\\ Foto\\ Manager\\ \\ Editor-6.18.0.apk",
                "/data/data/org.fdroid.fdroid/files"
        )
        Assert.assertEquals(fileInfo.filePath, "Schlichte\\ Galerie\\ Pro\\ -\\ Foto\\ Manager\\ \\ Editor-6.18.0.apk")
        Assert.assertEquals(fileInfo.fileSize, 15951095)
        Assert.assertEquals(fileInfo.owner, "user0_a247")
        Assert.assertEquals(fileInfo.group, "group0_a247")
        Assert.assertEquals(fileInfo.fileModTime.time, 1611014609000)
        Assert.assertEquals(fileInfo.fileMode, 0b0_110_000_000)
    }
}

so currently, I don't see what's going on.

btw. I used the latest sources, so you may try the (mostly) corresponding 5.0.1-alpha1

Jakeler commented 3 years ago

Thanks for looking into it @hg42! I have now attached the debugger with a breakpoint at this function. The difference to your test case is that the real input does not contain any backslashes, they get parsed just as spaces. It is already wrong in the token array, more precisely the splitWithoutEmptyValues function causes it. Try these tests:

    @Test
    fun test_fromLsOOutput_handlesDoubleSpace() {
        val fileInfo = ShellHandler.FileInfo.fromLsOOutput(
                "-rw------- 1 user0_a247 group0_a247 15951095 2021-01-19 01:03:29.000000000 +0100 111   333.file",
                "/data/data/org.fdroid.fdroid/files"
        )
        Assert.assertEquals(fileInfo.filePath, "111   333.file")
        Assert.assertEquals(fileInfo.fileSize, 15951095)
        Assert.assertEquals(fileInfo.owner, "user0_a248")
        Assert.assertEquals(fileInfo.group, "group0_a247")
        Assert.assertEquals(fileInfo.fileModTime.time, 1611014609000)
        Assert.assertEquals(fileInfo.fileMode, 0b0_110_000_000)
    }

    @Test
    fun test_splitWithoutEmptyValues_tripleSpace() {
        val tokens = ShellHandler.splitWithoutEmptyValues(
                "-rw------- 1 user0_a247 group0_a247 15951095 2021-01-19 01:03:29.000000000 +0100 111   333.file",
                " ",8)
        val expected = arrayOf(
            "-rw-------",
            "1",
            "user0_a247",
            "group0_a247",
            "15951095",
            "2021-01-19",
            "01:03:29.000000000",
            "+0100",
            "111   333.file",
        )
        Assert.assertArrayEquals(expected, tokens)
    }

Note that I have prepared a file with 3 spaces, but there could be even more spaces, everything is reduced to one... On adb shell this shows up as 111\ \ \ 333.file

The tests fail both:

org.junit.ComparisonFailure: 
Expected :111 333.file
Actual   :111   333.file
<Click to see difference>

arrays first differed at element [8]; 
Expected :111   333.file
Actual   :111 333.file
<Click to see difference>
hg42 commented 3 years ago

sorry, I hadn't time to follow...I didn't and still can't test on a phone.

Some thoughts I had in the mean time:

hg42 commented 3 years ago

ok, that's interesting :-) I created a file with spaces and found that ls handles tty output different from pipe output:

root@RMX1993L1:/ # toybox ls -All /data/data/net.rgruet.android.g3watchdog/files/                                                                              
total 4
drwx------ 5 u0_a221 u0_a221 4096 2020-10-19 05:28:25.513354851 +0200 .Fabric
-rw-r--r-- 1 root    root       0 2021-01-25 18:10:12.763104876 +0100 111\ \ \ file\ with\ \ \ spaces.txt
root@RMX1993L1:/ # toybox ls -All /data/data/net.rgruet.android.g3watchdog/files/ | cat                                                                        
total 4
drwx------ 5 u0_a221 u0_a221 4096 2020-10-19 05:28:25.513354851 +0200 .Fabric
-rw-r--r-- 1 root    root       0 2021-01-25 18:10:12.763104876 +0100 111   file with   spaces.txt

so, everything is as expected, the PR is fine, thanks fro the work!

Jakeler commented 3 years ago

Indeed very interesting, so it is actually caused by toybox. Thanks for the infos! I was wondering that too, spent hours in the debugger yesterday. Figured that it comes from libsu, the output of Shell.su(cmd) is already without backslashes. Digging in that implementation shows that it directly takes a stdout stream without modifying it.

btw: The whole approach with parsing shell output seems very fragile to me, I think there are more possible issues. A unsolved one is #218 where a file contains '. Other characters with special meaning in the shell could cause similar issues. Maybe a custom native module would improve the situation? Or Shizuku looks interesting, but I am not sure if it already has the required APIs.

hg42 commented 3 years ago

well, I know, that several commands behave differently with tty, e.g. colors. In a pipe they explicitly try to create machine readable formats (or better optimized for processing). E.g. a simple ls | cat switches to one file name per line (option -1). There is also an option for escaping: -b escape nongraphic chars which pointed me to this conclusion.

I agree, we should definitely check more of the shell quoting/escaping.