Syncany has started to delete all files that have not been recently modified

[elijh]

Syncany has started to delete all the files and folders in my file tree that have not been recently modified. This is quite alarming!

The deleted files still show up in the past history, so I will attempt to restore them.

[elijh]

I am using syncany 0.4.7.alpha on Ubuntu Wily 15.10.

[elijh]

For what it is worth, everything went to hell on Nov 10th.

[pimotte]

This is bad.

Can you provide us with logs? (~/.config/syncany/logs/* and .syncany/logs/* in your repo) If you don't want to post them publicly on the internet, e-mail them to the core team at team@syncany.org

[pimotte]

Have you made any changes to Syncany or the environment of any kind? Anything involving time/timezones?

[elijh]

All the missing files are marked as deleted on Nov 10 in sy ls -r -deleted. I can't think of anything particular about that day. I will email the logs.

[elijh]

If I try to restore any file, I get this:

sy restore bdab5b44a7
Error: Cannot find type of message. Invalid XML: 
       Refer to help page using '--help'.

The repo log has:

5-12-15 13:21:51.974 | CommandLineClie | main           | SEVE : Command org.syncany.cli.RestoreCommand@2f7300c2 FAILED. 
java.lang.Exception: Cannot find type of message. Invalid XML: 
        at org.syncany.operations.daemon.messages.api.XmlMessageFactory.getMessageType(XmlMessageFactory.java:108)
        at org.syncany.operations.daemon.messages.api.XmlMessageFactory.toMessage(XmlMessageFactory.java:85)
        at org.syncany.operations.daemon.messages.api.XmlMessageFactory.toResponse(XmlMessageFactory.java:65)
        at org.syncany.cli.CommandLineClient.handleRestResponse(CommandLineClient.java:457)
        at org.syncany.cli.CommandLineClient.sendToRest(CommandLineClient.java:441)
        at org.syncany.cli.CommandLineClient.runCommand(CommandLineClient.java:374)
        at org.syncany.cli.CommandLineClient.start(CommandLineClient.java:198)
        at org.syncany.Syncany.main(Syncany.java:52)

[elijh]

Is there an "oh shit" command that I can run on the server-side repository to restore all files?

[elijh]

I created a new local sync folder that uses the local storage plugin instead of what I was using before (ssh).

In other words, something like this:

cd ~
mkdir local-storage-repo
cd local-storage-repo
rsync -rav username@previous.remote.server:~/path/to/storage/ .
cd ~
mkdir sync-dir
cd sync-dir
sy connect

And then I specified local as the storage plugin and ~/local-storage-repo as the backend storage. So far so good, but now I get different errors:

cd sync-dir
sy ls -q -f Documents/Writing/notes.txt
15-11-10 12:51:37 D - rw-rw-r-- --a- 324 bebb4019a7102b29db22f09e5aea672e7cf8c555 2bb567ec43e716af64d33760d44f28c9b21d58dd 2 Documents/Writing/notes.txt

If I try to restore the file:

sy restore -t /tmp/notes.txt 2bb567ec43e716af64d33760d44f28c9b21d58dd
Could not restore file. No file by that ID or version found, or file ID prefix matches more than one file.

It appears to only have the deletion revision stored, and not the initial content::

sy ls -q -f --versions Documents/Writing/notes.txt
15-11-10 12:51:37 D - rw-rw-r-- --a- 324 bebb4019a7102b29db22f09e5aea672e7cf8c555 2bb567ec43e716af64d33760d44f28c9b21d58dd 2 Documents/Writing/notes.txt

That is incorrect, yes? There is no revision number "1".

Ahhh... Help?!

[pimotte]

This is another bug in Syncany. I have verified your behavior, but I have also verified that the data in this scenario is still there. In any case, make sure that you keep a copy of your repo data, and I will try to fix this bug. I have created #534 to seperate the restore issue from the issue you encountered in the first place.

I will give that priority to allow you to recover your files. I hope you did not save any data in there for which you didn't have a backup? (These kinds of bugs are why we are in alpha. We simply have not done enough testing to encounter all of these issues.)

[pimotte]

PR #535 fixes the restore issue you are having (ie. #534, not the original issue)

If you are able and willing to compile your own code, feel free to grab that branch and try it out. I will merge it later, in which case it will kick off a development build and you could use that one instead at that point.

Edit: It looks like the build is broken for an unrelated reason. Merging the PR might take some time.

[pimotte]

The logs you sent only seem to go back to november 30th, at least the daemon logs in home. (I'm trying to find out if we rotate those automatically, and if yes what we should set differently).

November 10th is just a couple of days past the last release, the shows a failed status and ls command on the command line, because of malformatted xml. Could it be you upgraded Syncany without restarting the daemon, if that causes communication between a new client and an old daemon that would be an odd circumstance.

[elijh]

On 12/06/2015 04:14 AM, Pim Otte wrote:

PR #535 #535 fixes the restore
issue you are having.

Amazing! That is working. Thank you so much.

I have about 21k files to recover, at about 20 seconds per file, so I
think it is going to take about 5 days to finish. I can live with that!

-elijah

[elijh]

On 12/06/2015 09:43 AM, Pim Otte wrote: The logs you sent only seem to go back to november 30th, at least the daemon logs in home. (I'm trying to find out if we rotate those automatically, and if yes what we should set differently).

Hmm.. The logs I emailed included everything in the logs directories.

November 10th is just a couple of days past the last release, the shows a failed status and ls command on the command line, because of malformatted xml. Could it be you upgraded Syncany without restarting the daemon, if that causes communication between a new client and an old daemon that would be an odd circumstance.

I have the syncany repo synchronized to two clients. One of those computers probably upgraded before the other. Perhaps that was also a factor?

…

-elijah

[pimotte]

So they contained all the logs from both clients?

[pimotte]

Due to @cuonic 's logs, I suspect that the issue lies in a filesystem comparison, where the full path is used for the one and a relative path is used for the other (relative to the repo root).

[binwiederhier]

@cuonic @elijh Pim and I have been investigating your logs. Unfortunately, we were not able to narrow the cause down more, yet. We have a hypothesis, but that's about it. Here we go

1. the filesystem is unresponsive/unavailable for a few seconds 2. client A marks them as deleted and does "up" 3. client B downloads the changes and does some other change 4. client A downloads B's changes and thereby manifests the deletion

This wild guess seems plausible, because I have been experiencing something similar in one of my repositories. Every once in a while, the database will show two new entries for each file. One DELETED entry and one ADDED entry. This is what it looks like for me (this is from issue #467):

Notice the 20min gap between the DELETED and the ADDED entries! If anything else is done during that time by another client, the change is manifested.

Again, this is a wild guess.

@cuonic Do you have any more of your logs? The excerpt you provided was not enough. Search for DeleteFileSystemAction, that's actually the instruction to delete a file

[liamjack]

@binwiederhier Sadly I don't, I wiped the configuration to try another setup and haven't been able to reproduce this error yet.

[travnick]

Same issue here, syncany removed most of my files to sync. Where to send logs?

Is there any way to tell syncany - restore repository to "this" version, instead of restoring every single file?

--edit:
I have 14567 deleted files, one file tooks 1 munute to restore = 10 days!!!

this line tooks so much time (Intel(R) Core(TM) i7-4790K CPU @ 4.00GHz)

//RestoreOperation.java

//Find file history
FileHistoryId restoreFileHistoryId = findFileHistoryId();

--edit2:

//FileHistorySqlDao.java:143

ResultSet resultSet = preparedStatement.executeQuery()

trying now to speed up this code somehow ... any help?

--edit3:
speed up: now it tooks only 1,5 sec to restore one file, but still 6 hours ...

//RestoreCommand.java

private FileHistoryId findFileHistoryId() {
        String id = options.getFileHistoryId().toString();
        if (id.length() > 10) {
            return FileHistoryId.parseFileId(id);
        }
        else {
            return localDatabase.expandFileHistoryId(options.getFileHistoryId());
        }
}

--edit4:
Another ugly hack: process all file ids within RestoreCommand to reduce initialization time. Tooks about 20 - 7000 ms per file

//RestoreCommand.java

    @Override
    public int execute(String[] operationArgs) throws Exception {
        String uglyHardcodedPathToIds = "my_path.txt";

        RestoreOperationOptions operationOptions = parseOptions(operationArgs);
        RestoreOperation restoteOperation = new RestoreOperation(config, operationOptions);


        List<String> lines = Files.readAllLines(Paths.get(uglyHardcodedPathToIds), StandardCharsets.UTF_8);

        int all_lines = lines.size();
        int currnet_line = 0;
        for (String line : lines) {
            ++currnet_line;

            long startTime = System.currentTimeMillis();

            out.println("Restoring " + line + " (" + currnet_line + " of " + all_lines + ")");
            operationOptions.setFileHistoryId(FileHistoryId.parseFileId(line));

            restoteOperation.setOptions(operationOptions);
            RestoreOperationResult operationResult = restoteOperation.execute();

            printResults(operationResult);

            long stopTime = System.currentTimeMillis();
            long elapsedTime = stopTime - startTime;
            out.println("elapsedTime: " + elapsedTime);
        }

        return 0;       
    }

--edit5:
with this fix 10865 files were restored in 53 minutes 22 seconds, so it's about 0.3s per file, instead of 1.5s. Maybe my hack should become "quick restore"?