Keep getting conflicts generated on Android device for files modified only on a desktop PC

I used to run with MaxConflicts set to 0 as I remembered having problems with the default setting in the distant past. Recently, I’ve been experimenting with setting it back to the default value, but I’ve experienced strange problems in relation to it.

Basically, what happens is that there are two devices — D4DZUG (Windows) and GCXVKIG (Android). The files in question are edited only on D4DZUG. They are then synced to multiple other devices, including GCXVKIG (Android). No other device does any modifications to the files.

However, the problem is that I keep getting conflicts for some of these files. I’ve used the REST API to check which device generates them, and I found out that it was GCXVKIG (Android). This is what such a conflict file looks like.

{
  "availability": [
    "GCXVKIG",
    "UDPWEVD",
    "7777777",
    "XZZTDIY"
  ],
  "global": {
    "deleted": false,
    "ignored": false,
    "inodeChange": "1970-01-01T01:00:00+01:00",
    "invalid": false,
    "localFlags": 0,
    "modified": "2022-10-06T22:00:38.2488379+02:00",
    "modifiedBy": "GCXVKIG",
    "mustRescan": false,
    "name": "index.sync-conflict-20221006-234632-D4DZUGP.html",
    "noPermissions": true,
    "numBlocks": 43,
    "platform": {
      "unix": null,
      "windows": null,
      "linux": null,
      "darwin": null,
      "freebsd": null,
      "netbsd": null
    },
    "sequence": 879864,
    "size": 5552038,
    "type": "FILE_INFO_TYPE_FILE",
    "version": [
      "GCXVKIG:1665092792"
    ]
  },
  "globalVersions": "{{Version:{[{GCXVKIG 1665092792}]}, Deleted:false, Devices:{GCXVKIG, UDPWEVD, 7777777, XZZTDIY}, Invalid:{}}}",
  "local": {
    "deleted": false,
    "ignored": false,
    "inodeChange": "1970-01-01T01:00:00+01:00",
    "invalid": false,
    "localFlags": 0,
    "modified": "2022-10-06T22:00:38.2488379+02:00",
    "modifiedBy": "GCXVKIG",
    "mustRescan": false,
    "name": "index.sync-conflict-20221006-234632-D4DZUGP.html",
    "noPermissions": true,
    "numBlocks": 43,
    "platform": {
      "unix": null,
      "windows": null,
      "linux": null,
      "darwin": null,
      "freebsd": null,
      "netbsd": null
    },
    "sequence": 2389399,
    "size": 5552038,
    "type": "FILE_INFO_TYPE_FILE",
    "version": [
      "GCXVKIG:1665092792"
    ]
  },
  "mtime": {
    "err": null,
    "value": {
      "real": "0001-01-01T00:00:00Z",
      "virtual": "0001-01-01T00:00:00Z"
    }
  }
}

Have you got any idea what the problem may be about? I assume that Android is likely to be the culprit, as I’ve encountered no such problems with any of my other, Windows devices, and the very same files are synced to all of them too. Is this about the mtime?

Just to reiterate, the conflicts appear even though the Android device doesn’t even touch the files. For example, just today a file that was edited on D4DZUG (Windows) only got multiple conflicts from GCXVKIG (Android) despite the latter being completely idle all that time, literally laying down on the desk doing nothing, with Syncthing running in the background.

Syncthing is v1.22.0 on both devices.

2 Likes

Mtime shouldn’t be able to cause conflicts, as in mod. time only conflicts should not trigger the creation of a conflict file.

How do the files differ? Just the old version of it as a conflict?

Yeah, they’re just the old versions with no changes done to them.

To add more details, I think I enabled conflicts on the Android device maybe 2-3 days ago. Since then, these files seem to be have been generated over and over again. The folder is literally filled with them like below.

index.sync-conflict-20221006-130052-D4DZUGP~20221006-165121.html
index.sync-conflict-20221006-130052-D4DZUGP~20221006-204655.html
index.sync-conflict-20221006-131550-D4DZUGP~20221006-165121.html
index.sync-conflict-20221006-131550-D4DZUGP~20221006-204656.html
index.sync-conflict-20221006-133051-D4DZUGP~20221006-165121.html
index.sync-conflict-20221006-133051-D4DZUGP~20221006-204655.html
index.sync-conflict-20221006-140052-D4DZUGP~20221006-165121.html
index.sync-conflict-20221006-140052-D4DZUGP~20221006-204655.html
index.sync-conflict-20221006-151559-D4DZUGP~20221006-165121.html
index.sync-conflict-20221006-151559-D4DZUGP~20221006-204655.html
index.sync-conflict-20221006-161549-D4DZUGP~20221006-165121.html
index.sync-conflict-20221006-161549-D4DZUGP~20221006-204655.html
index.sync-conflict-20221006-163049-D4DZUGP~20221006-165121.html
index.sync-conflict-20221006-163049-D4DZUGP~20221006-204655.html
index.sync-conflict-20221006-171552-D4DZUGP~20221006-204656.html
index.sync-conflict-20221006-173052-D4DZUGP~20221006-204656.html
index.sync-conflict-20221006-181554-D4DZUGP~20221006-204656.html
index.sync-conflict-20221006-201551-D4DZUGP~20221006-211922.html
index.sync-conflict-20221006-201551-D4DZUGP~20221006-212149.html
index.sync-conflict-20221006-211553-D4DZUGP~20221006-211922.html

This is just one example, as the same conflicts have appeared for other files (and file types) as well.

Edit:

Something weird is going on here. For testing, I’ve disabled conflicts on GCXVKIG (Android) again, but the conflicted files are still being created, yet this time it’s on D4DZUGP (Windows). Again, the files themselves are edited at D4DZUGP (Windows) only, and GCXVKIG (Android) just receives the files without even opening or touching them.

The filenames contain GCXVKIG now and are like

27de26d1eb814735ab524396c114f549.sync-conflict-20221007-113615-GCXVKIG.md

with the REST API info as below.

{
  "availability": [
    "7777777",
    "UDPWEVD",
    "XZZTDIY",
    "GCXVKIG"
  ],
  "global": {
    "deleted": false,
    "ignored": false,
    "inodeChange": "1970-01-01T01:00:00+01:00",
    "invalid": false,
    "localFlags": 0,
    "modified": "2023-10-07T11:36:17.7088374+02:00",
    "modifiedBy": "D4DZUGP",
    "mustRescan": false,
    "name": "27de26d1eb814735ab524396c114f549.sync-conflict-20221007-113615-GCXVKIG.md",
    "noPermissions": true,
    "numBlocks": 1,
    "platform": {
      "unix": null,
      "windows": null,
      "linux": null,
      "darwin": null,
      "freebsd": null,
      "netbsd": null
    },
    "sequence": 63522,
    "size": 746,
    "type": "FILE_INFO_TYPE_FILE",
    "version": [
      "D4DZUGP:1665135385",
      "UDPWEVD:1665135376"
    ]
  },
  "globalVersions": "{{Version:{[{D4DZUGP 1665135385} {UDPWEVD 1665135376}]}, Deleted:false, Devices:{7777777, UDPWEVD, XZZTDIY, GCXVKIG}, Invalid:{}}}",
  "local": {
    "deleted": false,
    "ignored": false,
    "inodeChange": "1970-01-01T01:00:00+01:00",
    "invalid": false,
    "localFlags": 0,
    "modified": "2023-10-07T11:36:17.7088374+02:00",
    "modifiedBy": "D4DZUGP",
    "mustRescan": false,
    "name": "27de26d1eb814735ab524396c114f549.sync-conflict-20221007-113615-GCXVKIG.md",
    "noPermissions": true,
    "numBlocks": 1,
    "platform": {
      "unix": null,
      "windows": null,
      "linux": null,
      "darwin": null,
      "freebsd": null,
      "netbsd": null
    },
    "sequence": 63522,
    "size": 746,
    "type": "FILE_INFO_TYPE_FILE",
    "version": [
      "D4DZUGP:1665135385",
      "UDPWEVD:1665135376"
    ]
  },
  "mtime": {
    "err": null,
    "value": {
      "real": "0001-01-01T00:00:00Z",
      "virtual": "0001-01-01T00:00:00Z"
    }
  }
}

It seems that I’d have to disable conflicts on both sides to prevent them from being created.

Has anyone else maybe got any idea what the culprit could be that causes Syncthing to treat old file versions as conflicts?

I’m going to disable conflicts on both sides for now, as the situation is getting quite ridiculous with the conflicted copies being created almost constantly (and in addition to that, these files take 5-10 MB each, so with many such copies they also take quite a lot of space, especially on the Android device with its limited storage).

I’m also going to try to reproduce this in a clean environment/folder myself to maybe get a better idea of what exactly is going on.

Edit

I’ve noticed in the Recent changes that the Android device is, in fact, listed as the one that “modified” the files, even though this happened when it was completely idle and not doing anything.

The only “modification” that I can think of is the known issue of Android and moving timestamps, as the folders are located on the internal storage with its FAT filesystem, but timestamp changes alone shouldn’t create conflicts, so I’m kind of out of ideas why this happens.

1 Like

The situation is much worse than I suspected. It appears that literally every change, rename, or deletion on the desktop triggers Android to either create a conflict, or worse, to actually “undelete” the renamed/deleted files. For example, if I rename a file several times in a row on the desktop, then a moment later the old copies of the file are back. The same is true for deletions as well.

The Web GUI lists the Android device as the one, which “modifies” the files. For testing purposes, I’ve changed almost all folders on Android to Receive Only. Sure enough, all changes done on the desktop result in “locally changed items” on Android. I can’t do proper testing with debug logs right now due to work, but I’m personally suspecting https://github.com/syncthing/syncthing-android/commit/5817ed4e073fee4c1ea5aef560d64051002a5def as the potential culprit, since all other recent commits done to the app have been rather minor, with this one being the only major change in behaviour (and the device in question is affected due to running Android 12). Unless, of course, a change in Syncthing proper has triggered this behaviour, but I haven’t experienced the issue between Windows devices, so I kind of doubt it. I believe thus whole thing must be something very recent, as I had never seen anything similar before, and I’ve been syncing more or less the same folders to Android for quite a long time.

On the one hand, as a person who helped find the fix for that, my mind also immediately jumped to it.

On the other hand: the affected code path ONLY triggers on “delete” events. So if you’re seeing it happen on file changes, I don’t see how this codepath could even be involved.

Could this be due to the fact that Syncthing technically doesn’t modify the original files? Even if it’s a change, it still creates a temporary copy first, and then replaces the original file with it. From the Android point of view, this could still be interpreted as a deletion, couldn’t it?

Just to reiterate, modifying files results in conflicted copies. Renaming or deleting files results in Android undeleting them a moment later. Of course, this only is true when doing all that on another device and syncing the changes to Android, not the other way around.

I have managed to reproduce the file undelete behaviour. I can’t really provide the exact steps though, as it doesn’t seem consistent, but what I did was to basically put two PDF files in a synced folder and then keep making copies and renaming the files on the Windows device. The Android device kept undeleting the files that have been either renamed to something else or completely deleted on Windows.

I’m uploading the two logs with db,model enabled below. Please have a look at them when you’ve got some free time.

I’m not an expert when it comes to debug logs, but these lines look suspicious to me.

[HIMFB] DEBUG: sendreceive/wnzi9-9inwy@0x4001480800 Deleting file 1 - Copy.pdf
[HIMFB] DEBUG: sendreceive/wnzi9-9inwy@0x4001480800 new error for 1 - Copy.pdf: delete file: file modified but not rescanned; will try again later

Also, is InodeChangeTime:1970-01-01 01:00:00 +0100 CET normal?

Yes, but there may be some suboptimal handling of it. I don’t see it causing conflicts on its own, but the behavior when updating just xattrs for example isn’t correct. I got caught up on another thing, but I have a PR coming up soonish.

Maybe try this? Fix MediaStore deleting files during case-only renames · Catfriend1/syncthing-android@7072a36 · GitHub

We don’t do the delete on the content resolver at all since a few releases, so that should’t change anything.

Just for the record, I’ve downgraded to v1.21.0 everywhere, as the issue had become literally unbearable, so I’m no longer experiencing the problem at the moment (and I’ve also been able to re-enable conflicts on all devices). I will be waiting eagerly for the proper fix :slightly_smiling_face:.

1 Like

I’ve got some bad news. I’ve just upgraded to v1.22.1 everywhere, and right after doing so, Syncthing began to create the conflicted copies again. This is unrelated to the app, because I’m currently running a self-compiled binary from the command line. The problem must be something that was added in between v1.21.0 and v1.22.0, as there are no conflicted copies when using v1.21.0.

As previously, the conflicted copies themselves are just older versions of the same files. The files themselves are changed only on the PC side while the conflicts are created on Android despite not modifying anything there.

Edit 1

I can reproduce at will when I edit the file on my desktop PC manually. The Android side immediately creates a conflict when the file gets synced there.

Edit 2

I think the debug logs from https://forum.syncthing.net/t/keep-getting-conflicts-generated-on-android-device-for-files-modified-only-on-a-desktop-pc/19060/8 are still relevant, as the situation is basically the same right now. I can provide more logs if needed.

Both the logging and the behavior is different, so new logs showing the issue would be preferable.

For some reason I couldn’t get the conflicts at will after restarting Syncthing with the -logfile option added, but I left it running overnight, and here is the log (with db,model enabled).

The file in question is youtube/index.html. I’ve skimmed through the log myself, and I may of course be wrong here, but these kind of entries look suspicious to me.

[OW324] 2022/11/03 06:46:49.615165 folder_sendrecv.go:1673: DEBUG: receiveonly/j2kgm-h9kws@0x4000a42c00 closing youtube/index.html
[OW324] 2022/11/03 06:46:49.616207 folder_sendrecv.go:1911: DEBUG: receiveonly/j2kgm-h9kws@0x4000a42c00 new error for youtube/index.html: finishing: checking existing file: file modified but not rescanned; will try again later
[OW324] 2022/11/03 06:46:49.658270 folder_sendrecv.go:1673: DEBUG: receiveonly/j2kgm-h9kws@0x4000a42c00 closing youtube/index.html
[OW324] 2022/11/03 06:46:49.658668 folder_sendrecv.go:1911: DEBUG: receiveonly/j2kgm-h9kws@0x4000a42c00 new error for youtube/index.html: finishing: checking existing file: file modified but not rescanned; will try again later
[OW324] 2022/11/03 06:46:49.696189 folder_sendrecv.go:1673: DEBUG: receiveonly/j2kgm-h9kws@0x4000a42c00 closing youtube/index.html
[OW324] 2022/11/03 06:46:49.696603 folder_sendrecv.go:1911: DEBUG: receiveonly/j2kgm-h9kws@0x4000a42c00 new error for youtube/index.html: finishing: checking existing file: file modified but not rescanned; will try again later
[OW324] 2022/11/03 06:46:49.854562 transactions.go:649: DEBUG: new global for "youtube/index.html" after update: {{Version:{[{D4DZUGP 1667448501} {UDPWEVD 1667383324} {44CRNGM 1640458805}]}, Deleted:false, Devices:{D4DZUGP, 7777777}, Invalid:{}}, {Version:{[{D4DZUGP 1667425231} {UDPWEVD 1667383324} {44CRNGM 1640458805}]}, Deleted:false, Devices:{XZZTDIY}, Invalid:{}}, {Version:{[{D4DZUGP 1667373272} {UDPWEVD 1667383324} {44CRNGM 1640458805}]}, Deleted:false, Devices:{UDPWEVD}, Invalid:{}}}
[OW324] 2022/11/03 06:46:49.854756 transactions.go:775: DEBUG: local need delete; folder="j2kgm-h9kws", name="youtube/index.html"
[OW324] 2022/11/03 06:46:49.854947 lowlevel.go:260: DEBUG: adding sequence; folder="j2kgm-h9kws" sequence=13151 youtube/index.html
[OW324] 2022/11/03 06:46:49.856049 folder_sendrecv.go:194: DEBUG: receiveonly/j2kgm-h9kws@0x4000a42c00 changed 1 on try 1
[OW324] 2022/11/03 06:46:49.860997 folder_sendrecv.go:1824: DEBUG: receiveonly/j2kgm-h9kws@0x4000a42c00 scheduling scan after pulling for youtube/index.sync-conflict-20221103-064649-D4DZUGP.html

The situation overall looks like this. All other folders had been paused on purpose to remove noise from the log.

Has anyone got any ideas what the problem may be about? :worried:

I can provide more/other debug logs if needed. Currently, I’ve downgraded to v1.21.0 again, as Syncthing is basically unusable in this state. I’m suspecting the problem is still related to the ownership/extended attributes sync feature (which I don’t actually use), but nevertheless something must be responsible for creating these conflicts. The problem goes away completely as soon as I downgrade to the older version though.

Could be the inode change time check, which is new. If the underlying FS doesn’t support it, like FAT, it probably returns the mtime instead, which is fine. If the underlying FS is a lie and the mtime/inode-change-time fluctuates, as might be the case on Android, weird things will happen. Maybe we should disable that code on Android. You, as a self-compiler, might try to add a if runtimeos.IsAndroid { return time.Time{} } at the top of (basicFileInfo)InodeChangeTime() in fs/basicfs_fileinfo_linuxish.go.

Done! Let’s see what happens. Does it matter that modTimeWindowS is already set to 2 by default on Android, or is the “inode change time check” completely unrelated?

Entirely unrelated, though quite possibly it should be disabled when the mod time window != 0 for similar reasons.

The code change seems to have fixed the problem (although I’m still going to wait till tomorrow to be 100% sure). Do you think that checking for modTimeWindowS would be enough (as it’s automatically used in Android on FAT anyway) or rather should the check be done for Android and modTimeWindowS independently?