Bisync missed syncing changed file - no error, no warning

[vtcifer]

Thanks for the feedback. Some comments:

@nielash

This is a longstanding Known Issue with Bisync which I plan to fix in the near future Essentially, this change slipped by undetected because it met all 3 of the following criteria:

1. The change occurred while a bisync run was running. (The one from 2023/08/18 12:53:01 to 12:56:14 in your logs.)
2. That bisync run made other changes to the same side where the undetected change occurred.
3. The change was a modification of an existing file, not a create/delete/rename.

I'm not sure I consider 4 months a longstanding issue, and tbh, I did search through the list here and reviewed your post to see if had mentioned this kind of behavior before my post. Without the further context you've provided in this reply I'm not sure how one would have known that this could be the outcome of that particular design. I'm also not convinced this is the situation here. I got my docker container back up (this also means I can run with -vv), and turned off the automatic bisync. If I run my regular bisync job with --dryrun, it STILL doesn't catch it as needing syncing, even though I can tell in the 2 path listings it is the only file that is different. So bisync should still be seeing it as differing, unless I'm misunderstanding somthing.

$ /usr/local/bin/rclone bisync gdrive:lichswarm /data/lichswarm --workdir /cache -vv --filter-from /filter-from-list.txt --dry-run
2023/08/23 10:00:42 DEBUG : rclone: Version "v1.63.1" starting with parameters ["/usr/local/bin/rclone" "bisync" "gdrive:lichswarm" "/data/lichswarm" "--workdir" "/cache" "-vvvvvv" "--filter-from" "/filter-from-list.txt" "--dry-run"]
2023/08/23 10:00:42 DEBUG : Creating backend with remote "gdrive:lichswarm"
2023/08/23 10:00:42 DEBUG : Using config file from "/config/rclone/rclone.conf"
2023/08/23 10:00:42 DEBUG : Google drive root 'lichswarm': 'root_folder_id = 0AHrsqdoJKZRaUk9PVA' - save this in the config to speed up startup
2023/08/23 10:00:42 DEBUG : Creating backend with remote "/data/lichswarm"
2023/08/23 10:00:42 NOTICE: bisync is EXPERIMENTAL. Don't use in production!
2023/08/23 10:00:42 INFO  : Synching Path1 "gdrive:lichswarm/" with Path2 "/data/lichswarm/"
2023/08/23 10:00:42 INFO  : Path1 checking for diffs
2023/08/23 10:00:42 DEBUG : .rubocop.yml: Excluded
2023/08/23 10:00:42 DEBUG : .gitignore: Excluded
2023/08/23 10:00:42 DEBUG : .ruby-version: Excluded
2023/08/23 10:00:42 DEBUG : .github: Excluded
2023/08/23 10:00:42 DEBUG : logs: Excluded
2023/08/23 10:00:42 DEBUG : temp: Excluded
2023/08/23 10:00:42 DEBUG : .gitattributes: Excluded
2023/08/23 10:00:42 DEBUG : .git: Excluded
2023/08/23 10:00:43 DEBUG : data/lich.db3: Excluded
2023/08/23 10:00:43 DEBUG : data/alias.db3: Excluded
2023/08/23 10:00:44 DEBUG : scripts/.rubocop.yml: Excluded
2023/08/23 10:00:44 DEBUG : scripts/.git: Excluded
2023/08/23 10:00:44 DEBUG : scripts/.travis.yml: Excluded
2023/08/23 10:00:44 DEBUG : scripts/.gitignore: Excluded
2023/08/23 10:00:44 DEBUG : scripts/.github: Excluded
2023/08/23 10:00:44 DEBUG : scripts/.gitattributes: Excluded
2023/08/23 10:00:44 DEBUG : scripts/profiles/Samples: Excluded
2023/08/23 10:01:04 INFO  : Path2 checking for diffs
2023/08/23 10:01:04 DEBUG : temp: Excluded
2023/08/23 10:01:04 DEBUG : logs: Excluded
2023/08/23 10:01:42 NOTICE:
Transferred:              0 B / 0 B, -, 0 B/s, ETA -
Elapsed time:       1m0.5s

2023/08/23 10:01:53 INFO  : No changes found
2023/08/23 10:01:53 INFO  : Updating listings
2023/08/23 10:01:55 INFO  : Bisync successful
2023/08/23 10:01:55 NOTICE:
Transferred:              0 B / 0 B, -, 0 B/s, ETA -
Elapsed time:      1m13.1s


# clear out beyond ms precision time
$ sed -E -i 's/[01234567890]{8}\+0000/\+0000/' gdrive_lichswarm..data_lichswarm.path1.lst-dry gdrive_lichswarm..data_lichswarm.path2.lst-dry
# sort by filename column
$ sort -bdk6 gdrive_lichswarm..data_lichswarm.path1.lst-dry > sortedpath1
$ sort -bdk6 gdrive_lichswarm..data_lichswarm.path2.lst-dry > sortedpath2

$ diff sortedpath1 sortedpath2
1c1
< # bisync listing v1 from 2023-08-23T10:00:44.4+0000
---
> # bisync listing v1 from 2023-08-23T10:01:15.4+0000
422c422
< -      872 md5:4df788ff588fac9b722be903eda1c903 - 2023-08-18T16:53:10.0+0000 "scripts/custom/delay-script.lic"
---
> -      873 md5:979893b68c3ca5a827cbc3364781b88e - 2023-08-18T15:56:03.5+0000 "scripts/custom/delay-script.lic"

@nielash

• Schedule your bisync runs less frequently -- you mentioned you're currently running it every 1 minute. If you changed it to every 10 minutes, the odds of this happening would decrease by approximately 10x. (FWIW, I run mine every 3 hours, and manually as needed.)

Honestly not really viable in my case. This is a kludgy workaround to the fact there's no real google drive support on linux, nor in rclone support for daemon like running of bisync with file watches to catch changes on a local path and queue updates to the remote paths.
I'm pretty sure at least for google drive rclone gets event notifications when a file changes (I tried using mount earlier but ran into other problems, but I did see in the logs that rclone got notified of changes of files on drive, and that seemed to be how it manages invalidating the local cache file, so that when it tries to be accessed in the future its forced to retrieve the remote copy.)