Puller complains about invalid filenames which are long gone

banzai · June 10, 2019, 9:17am

When I started using syncthing with my Home Folder, it contained some files with a colon in the filename. Linux client didn’t have any problems, but the windows client complained about invalid filenames. That’s perfectly fine and I just renamed the files and rescanned the folder.

But although the problematic files are gone now, the windows client still complains about those invalid filenames and says “out of sync” and lists the old filenames in the “out of sync” list.

How can I “clean up” this file list? Is there some cache I can clear somehow?

I can provide a full log if necessary, just don’t want to publish it here…

Both clients are 1.1.4 (upgraded from 1.1.3, which is the first version I ever used).

imsodin · June 10, 2019, 9:32am

This should just work, without you doing anything.

Please start by posting screenshots from both sides to check if there are any oddities there.

banzai · June 10, 2019, 10:00am

This is the windows side:

This is the linux side:

calmh · June 10, 2019, 10:19am

And click on the failed items?

banzai · June 10, 2019, 10:21am

calmh · June 10, 2019, 10:24am

Interesting.

imsodin · June 10, 2019, 11:20am

Could you query the /rest/db/file endpoint for one of those files (https://docs.syncthing.net/rest/db-file-get.html).

banzai · June 10, 2019, 1:22pm

I’m always getting “No such object in the index”. I guess I didn’t get the format right for the URL.

Can you tell me how the parameters file and folder have to be filled?

Is it the local folder or is the folder just relative to the sync-dir? What characters have to be replaced with %XX (I replaced spaces, colon, backslashes, but it didn’t help) Does the folder need a trailing (back)slash?

imsodin · June 10, 2019, 2:13pm

On linux it’s something like this: curl -X POST -H "X-API-Key: abc123" 'http://localhost:8384/rest/db/file?folder=msrcl-kvcnd&file=2005-05-02: Agenten.txt'. Quoting is important.

banzai · June 10, 2019, 2:42pm

Ok, I finally got it (had to replace spaces with %20):

bka@bka-pc:~$ curl -X GET -H "X-API-Key: xxx" 'http://localhost:8384/rest/db/file?folder=msrcl-kvcnd&file=Job\01%20Uni%20KL%20Wissenschaftlicher%20Mitarbeiter\Projekte\Memory\Memos\DevSheets\2005-05-02:%20Agenten.txt'
{
  "availability": [
    {
      "id": "EFZZSVQ-POIBRPK-WEQTLFL-CB6VS4T-MFI4LJF-XVPQMJU-MKZZKX5-PPFVXQT",
      "fromTemporary": false
    }
  ],
  "global": {
    "deleted": true,
    "ignored": false,
    "invalid": false,
    "localFlags": 0,
    "modified": "2006-10-13T22:25:20+02:00",
    "modifiedBy": "EFZZSVQ",
    "mustRescan": false,
    "name": "Job\\01 Uni KL Wissenschaftlicher Mitarbeiter\\Projekte\\Memory\\Memos\\DevSheets\\2005-05-02: Agenten.txt",
    "noPermissions": false,
    "numBlocks": 0,
    "permissions": "0",
    "sequence": 542468,
    "size": 0,
    "type": 0,
    "version": [
      "EFZZSVQ:2"
    ]
  },
  "local": {
    "deleted": true,
    "ignored": false,
    "invalid": false,
    "localFlags": 0,
    "modified": "2006-10-13T22:25:20+02:00",
    "modifiedBy": "Y2UU6DH",
    "mustRescan": false,
    "name": "Job\\01 Uni KL Wissenschaftlicher Mitarbeiter\\Projekte\\Memory\\Memos\\DevSheets\\2005-05-02: Agenten.txt",
    "noPermissions": false,
    "numBlocks": 0,
    "permissions": "0",
    "sequence": 962193,
    "size": 0,
    "type": 0,
    "version": [
      "Y2UU6DH:1"
    ]
  }
}

imsodin · June 10, 2019, 3:32pm

If you can live with this state a little longer, that would be nice. This is clearly a bug (a locally and globally deleted file should never be needed/pulled), but I don’t know yet why/how it happens. So I might have more questions to you to narrow it down. This does not impact the sync, everything else will still be synced like normal, it just shows this incorrect notification about out-of-sync files.

banzai · June 10, 2019, 4:19pm

Sure, I can live with this for the moment, it was just my urge to have things neat and tidy

And I’ll gladly provide what I can to help resolve this issue. Thanks for looking into this.

imsodin · June 10, 2019, 6:00pm

Did you ignore these files at any point? I am asking because that should be the only way how this file could have ended up with that local version and being deleted.

Also an elephant in the room that I missed: Why is that file in the database in the first place? It shouldn’t have been successfully scanned unless windows/golang’s os started to support colons in one way or another at some point.

AudriusButkevicius · June 10, 2019, 6:14pm

Did you scan on linux and then use the db on windows or something like that?

banzai · June 11, 2019, 4:07pm

@Audrius: No, I don’t think so. I installed syncthing on linux (in a docker container) and when this was running and my home dir was scanned, I installed synctrayzor on my PC and connected both instances and shared the folder.

But there’s one specialty: the configuration directory for the docker container is volume-mounted to my home directory (in /.syncthing-config) to have it persisted and be part of the backup. So this config dir was shared to c:\users\bka\h\.syncthing-config. I later added this dir to the ignore patterns and deleted the content from my PC. But I don’t think the windows instance picked anything up from there, the local config dir seems to be …\AppData\Local\syncthing.

@Simon: Yes, I ignored those files at first. I started with

!/SomeDir
*

as ignore patterns. When this was working fine, I switched to ignoring only certain directories.

I honestly have no idea how those files ended up in the database. Those files have not been on the PC before, only on the linux server.

AudriusButkevicius · June 11, 2019, 5:22pm

These files used to be outright dropped at network level when received on windows (perhaps that is no longer the case).

So the only way I can think they landed is

What happens in the logs? I suspect it should complain about these.

imsodin · June 11, 2019, 5:26pm

Complete tinfoil: What if something changed in windows/go’s os package such that there isn’t an error with colons? We never explicitly check for invalid filenames in the scanning stage. Maybe that would be a good idea even if I’d expect it to be redundant, as filesystem calls should result in an error.

AudriusButkevicius · June 11, 2019, 5:33pm

How did the files land there in the first place? Can OP create one of those files? I suspect not.

Is OS running on some funky FS on the latest windows version?

I know that colons are magical characters for creating and accessing resource streams, I know you can create them from command line, but I don’t think they would ever be listed by Walk et al.

Sure, we can add a check.

imsodin · June 12, 2019, 8:58am

Unrelated to the whole windows stuff I found a general bug where file that are deleted locally, such that they “lose” to the global deletion (older mod/deletion time), are still considered needed. This is not an issue generally, as they will just get “pulled”, with the puller just noticing that it’s already gone, but in this case it produces said error. This still leaves the riddle of why the file is there in the first place.
Actually no, looking at how it’s implemented that works as designed. Changing it would be non-trivial and I am not sure whether it is even desired: It’s nice to get the metadata (especially version vector) in sync even if both sides are deletions, in case of future modifications.

banzai · June 12, 2019, 6:49pm

I tried to reproduce this today, and that’s what happened:

On linux I created a file with a colon in a directory which is ignored on the windows side:

[root@frogstar .syncthing-config]# echo "bla" > 'test:file'

Syncthing on linux picked up the file.

On windows I unignored the directory, and after waiting a bit, I queried the DB on windows:

bka@bka-pc:/mnt/c/Windows/System32$ curl -X GET -H "X-API-Key: xxx" 'http://localhost:8384/rest/db/file?folder=msrcl-kvcnd&file=.syncthing-config\test:file'
{
  "availability": [
    {
      "id": "EFZZSVQ-POIBRPK-WEQTLFL-CB6VS4T-MFI4LJF-XVPQMJU-MKZZKX5-PPFVXQT",
      "fromTemporary": false
    }
  ],
  "global": {
    "deleted": false,
    "ignored": false,
    "invalid": false,
    "localFlags": 0,
    "modified": "2019-06-12T20:25:30.271290366+02:00",
    "modifiedBy": "EFZZSVQ",
    "mustRescan": false,
    "name": ".syncthing-config\\test:file",
    "noPermissions": false,
    "numBlocks": 1,
    "permissions": "0644",
    "sequence": 1234849,
    "size": 4,
    "type": 0,
    "version": [
      "EFZZSVQ:1"
    ]
  },
  "local": {
    "deleted": true,
    "ignored": false,
    "invalid": false,
    "localFlags": 0,
    "modified": "2019-06-12T20:25:30.271290366+02:00",
    "modifiedBy": "Y2UU6DH",
    "mustRescan": false,
    "name": ".syncthing-config\\test:file",
    "noPermissions": false,
    "numBlocks": 0,
    "permissions": "0",
    "sequence": 2199918,
    "size": 0,
    "type": 0,
    "version": [
      "Y2UU6DH:1"
    ]
  }
}

I renamed the file on linux:

[root@frogstar .syncthing-config]# mv test\:file test_file

The file now got sync’ed to windows with the new name and again I queried the DB:

bka@bka-pc:/mnt/c/Windows/System32$ curl -X GET -H "X-API-Key: xxx" 'http://localhost:8384/rest/db/file?folder=msrcl-kvcnd&file=.syncthing-config\test:file'
{
  "availability": [
    {
      "id": "EFZZSVQ-POIBRPK-WEQTLFL-CB6VS4T-MFI4LJF-XVPQMJU-MKZZKX5-PPFVXQT",
      "fromTemporary": false
    }
  ],
  "global": {
    "deleted": true,
    "ignored": false,
    "invalid": false,
    "localFlags": 0,
    "modified": "2019-06-12T20:25:30.271290366+02:00",
    "modifiedBy": "EFZZSVQ",
    "mustRescan": false,
    "name": ".syncthing-config\\test:file",
    "noPermissions": false,
    "numBlocks": 0,
    "permissions": "0",
    "sequence": 1248581,
    "size": 0,
    "type": 0,
    "version": [
      "EFZZSVQ:2"
    ]
  },
  "local": {
    "deleted": true,
    "ignored": false,
    "invalid": false,
    "localFlags": 0,
    "modified": "2019-06-12T20:25:30.271290366+02:00",
    "modifiedBy": "Y2UU6DH",
    "mustRescan": false,
    "name": ".syncthing-config\\test:file",
    "noPermissions": false,
    "numBlocks": 0,
    "permissions": "0",
    "sequence": 2199918,
    "size": 0,
    "type": 0,
    "version": [
      "Y2UU6DH:1"
    ]
  }
}

And again the GUI shows one more out-of-sync item named “test:file”.

Do you need something from the logs?