Bisync missed syncing changed file - no error, no warning

vtcifer · August 22, 2023, 6:15pm

What is the problem you are having with rclone?

I've been running bisync via a cronjob @ 1/min to keep a local drive (glusterfs backing for a docker swarm) and a google drive in sync. It's worked fine for the most part, within the confines of the known limitations. Today I discovered however that there's been a file that has not been synced for 4 days, even though other files were synced during that time. I was tweaking my filter lists so needing to run with --resync, and that's how I found it. There was no error

Run the command 'rclone version' and share the full output of the command.

docker run --entrypoint "/usr/local/bin/rclone" -it --rm vtcifer/bisyncd:latest version
rclone v1.63.1
- os/version: alpine 3.18.2 (64 bit)
- os/kernel: 6.1.21-v8+ (aarch64)
- os/type: linux
- os/arch: arm64 (ARMv8 compatible)
- go/version: go1.20.6
- go/linking: static
- go/tags: none

Which cloud storage system are you using? (eg Google Drive)

Googld Drive

The command you were trying to run (eg `rclone copy /tmp remote:tmp`)

bisync gdrive:lichswarm /data/lichswarm 
--workdir /cache 
--verbose 
--filter-from /filter-from-list.txt 
--log-file /logs/bisyncd/bisyncd.log

The rclone config contents with secrets removed.

[gdrive]
type = drive
client_id = [redacted]
client_secret = [redacted]
scope = drive
token = {"access_token":"[redacted]","token_type":"Bearer","refresh_token":"[redacted]","expiry":"2023-08-22T11:59:49.148858517-04:00"}
team_drive =

A log from the command with the `-vv` flag

I don't have a -vv I usually just run with -v. I've taken down the docker container that was running my sync process unfortunately so I'm a bit limited on what I can grab at this point.

This is my filter list:

# ignore all git repos files
- .git/**
# ignore all github specific files
- .github/**

# don't sync lich logs or debug logs
- logs/**
- temp/**
# don't sync samples
- scripts/profiles/Samples/**
# don't sync sqlite3 db or journal files, can cause issues
- data/*.db3
- data/*.db3-journal

# ignore dot files
- .*

Here's a screenshot of the file version history from my google drive:

Last modified / file details from the local system:

$ ll delay-script.lic
-rw-r--r-- 1 pi pi 873 Aug 18 11:56 delay-script.lic

Last modified / file details from a windows box (syncing using official google drive software) via WSL:

┌──(user㉿host)-[/mnt/g/My Drive/lichswarm/scripts/custom]
└─$ ll delay-script.lic
-rwxrwxrwx 0 user user 872 Aug 18 12:53 delay-script.lic

log of last successful sync:

2023/08/18 11:57:01 NOTICE: bisync is EXPERIMENTAL. Don't use in production!
2023/08/18 11:57:03 INFO  : Synching Path1 "gdrive:lichswarm/" with Path2 "/data/lichswarm/"
2023/08/18 11:57:03 INFO  : Path1 checking for diffs
2023/08/18 11:57:25 INFO  : - Path1    File is newer                       - scripts/custom/delay-script.lic
2023/08/18 11:57:25 INFO  : Path1:    1 changes:    0 new,    1 newer,    0 older,    0 deleted
2023/08/18 11:57:25 INFO  : Path2 checking for diffs
2023/08/18 11:57:51 INFO  : Applying changes
2023/08/18 11:57:51 INFO  : - Path1    Queue copy to Path2                 - /data/lichswarm/scripts/custom/delay-script.lic
2023/08/18 11:57:51 INFO  : - Path1    Do queued copies to                 - Path2
2023/08/18 11:57:52 INFO  : scripts/custom/delay-script.lic: Copied (replaced existing)
2023/08/18 11:57:52 INFO  : Updating listings
2023/08/18 11:58:02 INFO  :
Transferred:            873 B / 873 B, 100%, 96 B/s, ETA 0s
Checks:                 1 / 1, 100%
Transferred:            1 / 1, 100%
Elapsed time:       1m1.6s

2023/08/18 11:58:24 INFO  : Validating listings for Path1 "gdrive:lichswarm/" vs Path2 "/data/lichswarm/"
2023/08/18 11:58:25 INFO  : Bisync successful
2023/08/18 11:58:25 INFO  :
Transferred:            873 B / 873 B, 100%, 19 B/s, ETA 0s
Checks:                 1 / 1, 100%
Transferred:            1 / 1, 100%
Elapsed time:      1m24.7s

next couple calls to bisync not picking up on that file changing, but picking up others

2023/08/18 12:53:01 NOTICE: bisync is EXPERIMENTAL. Don't use in production!
2023/08/18 12:53:01 INFO  : Synching Path1 "gdrive:lichswarm/" with Path2 "/data/lichswarm/"
2023/08/18 12:53:01 INFO  : Path1 checking for diffs
2023/08/18 12:53:23 INFO  : - Path1    File is newer                       - scripts/custom/watchdog.lic
2023/08/18 12:53:23 INFO  : Path1:    1 changes:    0 new,    1 newer,    0 older,    0 deleted
2023/08/18 12:53:23 INFO  : Path2 checking for diffs
2023/08/18 12:53:58 INFO  : - Path2    File is newer                       - echo_log_room.txt
2023/08/18 12:53:58 INFO  : Path2:    1 changes:    0 new,    1 newer,    0 older,    0 deleted
2023/08/18 12:53:58 INFO  : Applying changes
2023/08/18 12:53:58 INFO  : - Path1    Queue copy to Path2                 - /data/lichswarm/scripts/custom/watchdog.lic
2023/08/18 12:53:58 INFO  : - Path2    Queue copy to Path1                 - gdrive:lichswarm/echo_log_room.txt
2023/08/18 12:53:58 INFO  : - Path2    Do queued copies to                 - Path1
2023/08/18 12:53:59 INFO  : echo_log_room.txt: Copied (replaced existing)
2023/08/18 12:53:59 INFO  : - Path1    Do queued copies to                 - Path2
2023/08/18 12:54:01 INFO  :
Transferred:        2.691 KiB / 4.931 KiB, 55%, 1.345 KiB/s, ETA 1s
Checks:                 2 / 2, 100%
Transferred:            1 / 2, 50%
Elapsed time:       1m0.6s
Transferring:
 *                   scripts/custom/watchdog.lic:  0% /2.239Ki, 0/s, -

2023/08/18 12:54:01 INFO  : scripts/custom/watchdog.lic: Copied (replaced existing)
2023/08/18 12:54:01 INFO  : Updating listings
2023/08/18 12:55:01 INFO  :
Transferred:        4.931 KiB / 4.931 KiB, 100%, 17 B/s, ETA 0s
Checks:                 2 / 2, 100%
Transferred:            2 / 2, 100%
Elapsed time:       2m0.6s

2023/08/18 12:56:01 INFO  :
Transferred:        4.931 KiB / 4.931 KiB, 100%, 17 B/s, ETA 0s
Checks:                 2 / 2, 100%
Transferred:            2 / 2, 100%
Elapsed time:       3m0.6s

2023/08/18 12:56:14 INFO  : Validating listings for Path1 "gdrive:lichswarm/" vs Path2 "/data/lichswarm/"
2023/08/18 12:56:14 INFO  : Bisync successful
2023/08/18 12:56:15 INFO  :
Transferred:        4.931 KiB / 4.931 KiB, 100%, 17 B/s, ETA 0s
Checks:                 2 / 2, 100%
Transferred:            2 / 2, 100%
Elapsed time:      3m14.1s

2023/08/18 12:57:00 NOTICE: bisync is EXPERIMENTAL. Don't use in production!
2023/08/18 12:57:01 INFO  : Synching Path1 "gdrive:lichswarm/" with Path2 "/data/lichswarm/"
2023/08/18 12:57:01 INFO  : Path1 checking for diffs
2023/08/18 12:57:22 INFO  : Path2 checking for diffs
2023/08/18 12:57:54 INFO  : - Path2    File is newer                       - echo_log_room.txt
2023/08/18 12:57:54 INFO  : Path2:    1 changes:    0 new,    1 newer,    0 older,    0 deleted
2023/08/18 12:57:54 INFO  : Applying changes
2023/08/18 12:57:54 INFO  : - Path2    Queue copy to Path1                 - gdrive:lichswarm/echo_log_room.txt
2023/08/18 12:57:54 INFO  : - Path2    Do queued copies to                 - Path1
2023/08/18 12:57:56 INFO  : echo_log_room.txt: Copied (replaced existing)
2023/08/18 12:57:56 INFO  : Updating listings
2023/08/18 12:58:00 INFO  :
Transferred:        5.711 KiB / 5.711 KiB, 100%, 1.142 KiB/s, ETA 0s
Checks:                 1 / 1, 100%
Transferred:            1 / 1, 100%
Elapsed time:       1m0.6s

2023/08/18 12:58:18 INFO  : Validating listings for Path1 "gdrive:lichswarm/" vs Path2 "/data/lichswarm/"
2023/08/18 12:58:18 INFO  : Bisync successful
2023/08/18 12:58:18 INFO  :
Transferred:        5.711 KiB / 5.711 KiB, 100%, 232 B/s, ETA 0s
Checks:                 1 / 1, 100%
Transferred:            1 / 1, 100%
Elapsed time:      1m18.1s

Output of trying to resync, where I caught the fact that this file wasn't synced.

$ docker run \
  --rm \
  --name bisyncd \
  --init \
  --volume /mnt/gfs/lich/.config/rclone:/config/rclone \
  --volume /mnt/gfs/lich/.cache:/cache \
  --volume /mnt/gfs/lich/data:/data \
  --volume /mnt/gfs/lich/swarm/drs/utils/hooks/bisyncd/filter-from-list.txt:/filter-from-list.txt \
  --volume /mnt/gfs/lich/swarm/drs/utils/hooks/bisyncd/crontabs:/crontabs \
  --volume /mnt/gfs/lich/logs/bisyncd:/logs \
  --user $(id -u):$(id -g) \
  --env-file /mnt/gfs/lich/swarm/drs/utils/hooks/bisyncd/env.list \
  --stop-timeout 90 \
      rclone/rclone bisync gdrive:lichswarm /data/lichswarm \
        --workdir /cache \
        --verbose \
        --filter-from /filter-from-list.txt \
        --resync \
        --dry-run
2023/08/22 14:06:43 NOTICE: bisync is EXPERIMENTAL. Don't use in production!
2023/08/22 14:06:43 INFO  : Synching Path1 "gdrive:lichswarm/" with Path2 "/data/lichswarm/"
2023/08/22 14:06:43 INFO  : Copying unique Path2 files to Path1
2023/08/22 14:07:43 NOTICE:
Transferred:              0 B / 0 B, -, 0 B/s, ETA -
Elapsed time:       1m1.4s

2023/08/22 14:08:01 INFO  : Resynching Path1 to Path2
2023/08/22 14:08:03 NOTICE: scripts/custom/delay-script.lic: Skipped copy as --dry-run is set (size 872)
2023/08/22 14:08:03 NOTICE: data/DRF/Vivid: Skipped remove directory as --dry-run is set
2023/08/22 14:08:03 NOTICE: data/DRF/Viscous: Skipped remove directory as --dry-run is set
2023/08/22 14:08:03 NOTICE: data/DRF/Vengeful: Skipped remove directory as --dry-run is set
2023/08/22 14:08:03 INFO  : Resync updating listings
2023/08/22 14:08:43 NOTICE:
Transferred:            872 B / 872 B, 100%, 11 B/s, ETA 0s
Checks:               748 / 748, 100%
Deleted:                0 (files), 3 (dirs)
Transferred:            1 / 1, 100%
Elapsed time:       2m1.4s

2023/08/22 14:09:00 INFO  : Bisync successful
2023/08/22 14:09:00 NOTICE:
Transferred:            872 B / 872 B, 100%, 3 B/s, ETA 0s
Checks:               748 / 748, 100%
Deleted:                0 (files), 3 (dirs)
Transferred:            1 / 1, 100%
Elapsed time:      2m18.4s

grep of logs from 18th-21st + today

$ grep -Fie "delay" bisyncd.log.20230818 bisyncd.log.20230819 bisyncd.log.20230820 bisyncd.log.20230821 bisyncd.log
bisyncd.log.20230818:2023/08/18 11:42:23 INFO  : - Path1    File is new                         - scripts/custom/delay-script.lic
bisyncd.log.20230818:2023/08/18 11:42:55 INFO  : - Path1    Queue copy to Path2                 - /data/lichswarm/scripts/custom/delay-script.lic
bisyncd.log.20230818:2023/08/18 11:42:56 INFO  : scripts/custom/delay-script.lic: Copied (new)
bisyncd.log.20230818:2023/08/18 11:46:23 INFO  : - Path1    File is newer                       - scripts/custom/delay-script.lic
bisyncd.log.20230818:2023/08/18 11:46:58 INFO  : - Path1    Queue copy to Path2                 - /data/lichswarm/scripts/custom/delay-script.lic
bisyncd.log.20230818:2023/08/18 11:47:00 INFO  : scripts/custom/delay-script.lic: Copied (replaced existing)
bisyncd.log.20230818:2023/08/18 11:48:22 INFO  : - Path1    File is newer                       - scripts/custom/delay-script.lic
bisyncd.log.20230818:2023/08/18 11:48:54 INFO  : - Path1    Queue copy to Path2                 - /data/lichswarm/scripts/custom/delay-script.lic
bisyncd.log.20230818:2023/08/18 11:48:56 INFO  : scripts/custom/delay-script.lic: Copied (replaced existing)
bisyncd.log.20230818:2023/08/18 11:52:34 INFO  : - Path1    File is newer                       - scripts/custom/delay-script.lic
bisyncd.log.20230818:2023/08/18 11:53:06 INFO  : - Path1    Queue copy to Path2                 - /data/lichswarm/scripts/custom/delay-script.lic
bisyncd.log.20230818:2023/08/18 11:53:08 INFO  : scripts/custom/delay-script.lic: Copied (replaced existing)
bisyncd.log.20230818:2023/08/18 11:57:25 INFO  : - Path1    File is newer                       - scripts/custom/delay-script.lic
bisyncd.log.20230818:2023/08/18 11:57:51 INFO  : - Path1    Queue copy to Path2                 - /data/lichswarm/scripts/custom/delay-script.lic
bisyncd.log.20230818:2023/08/18 11:57:52 INFO  : scripts/custom/delay-script.lic: Copied (replaced existing)

nielash · August 23, 2023, 4:47am

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:

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.)
That bisync run made other changes to the same side where the undetected change occurred.
The change was a modification of an existing file, not a create/delete/rename.

Lacking any 1 of these 3 would have prevented this (which is likely why you haven't encountered this more often). Had it not been for #2, Bisync would have re-used the initial listing snapshot for that Path instead of taking a new one at the end, and the change would therefore have been discovered on the next sync. And had it not been for #3, Bisync would have returned a critical error as a result of failing the --check-sync (still not ideal, but at least then you would have known about it.)

The reason that --check-sync didn't catch this is because it (currently) only compares filenames, not modtime, size, or hash. It can detect whether a file from one Path is missing on the other, but not whether both Paths have different versions of a file. (To be clear: I'm talking only about the --check-sync feature -- other parts of Bisync (such as the deltas) do indeed compare modtime.)

The reason that a --resync caught this while normal bisync runs did not is because normal bisync runs compare to the prior listing of the same side, while --resync compares to the current listing of the opposite side.

Until this is properly addressed in a future release, here are a few things I'd recommend:

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.)
Use --check-sync=false, as --check-sync is not foolproof anyway (as we've discussed) and without it, your bisyncs will be faster and less likely to end in a critical error.
Supplement this with a periodic independent integrity check, and corrective sync if diffs are found. This is documented in detail here, along with example commands. (This is especially important if using --check-sync=false.)

P.S. I fixed a bunch of other bisync bugs recently (but not this one yet) and added a few new features -- currently scheduled for v1.64. If you're interested in trying them early, they are available in the latest beta. Feedback is welcome

vtcifer · August 23, 2023, 10:32am

Thanks for the feedback. Some comments:

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"

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.)

nielash · August 23, 2023, 12:47pm

I agree, and upon rereading I think the way I worded that was confusing -- my apologies. What I meant is that the bug is very old (as old as Bisync itself), even if it was only discovered recently. I completely agree that it's not well-documented at the moment. (To be clear: I didn't design Bisync or write the original documentation -- I am merely attempting to pick up this unfinished project where the original creator left off, so that these kinds of problems can finally get fixed.)

I think so -- allow me to elaborate.

As you've noted, the file on Path1 has 16:53, and the file on Path2 has 15:56.

In the --dry-run example that you posted here, I think what you expect Bisync to say is this:

16:53 does not equal 15:56, therefore there is a problem here and something needs to be synced to correct it.

But instead, what Bisync actually says is this:

At the end of the prior run, Path1 had 16:53. At present, Path1 still has 16:53. Therefore, there have been no changes on Path1.
At the end of the prior run, Path2 had 15:56. At present, Path2 still has 15:56. Therefore, there have been no changes on Path2.
Since there have been no changes on either Path1 or Path2, I am done here. There is no problem and nothing needs to be synced.

In other words, it is comparing to the prior listing of the same side, not the current listing of the opposite side. This design is not itself the problem. The problem is that prior listing of Path1 is wrong. It should still be 15:56. The bug is that 16:53 was allowed to sneak in undetected on the prior run, between the first and second snapshots. Essentially, Bisync now thinks it has already synced a change that it actually should not know about yet.

If you want to test my theory, you can manually edit that line in path1.lst to match path2.lst, then try the bisync run again, and see if it suddenly notices that it needs syncing.

I hear you. I agree that Bisync has problems right now -- that's why I'm trying to fix them. I think they are solvable, and we're not too far away from a future where one can safely run Bisync every minute without these kinds of issues.

You are right. This is ChangeNotifier and it is supported in mount for a few backends. Unfortunately, local is not one of them yet, so that is the main obstacle preventing this from being possible at the moment for drive<--->local. There is a ticket open for it here and I very much hope it gets implemented at some point.

vtcifer · August 23, 2023, 7:59pm

nielash:

I think so -- allow me to elaborate.

As you've noted, the file on Path1 has 16:53, and the file on Path2 has 15:56.

In the --dry-run example that you posted here, I think what you expect Bisync to say is this:

16:53 does not equal 15:56, therefore there is a problem here and something needs to be synced to correct it.

But instead, what Bisync actually says is this:

At the end of the prior run, Path1 had 16:53. At present, Path1 still has 16:53. Therefore, there have been no changes on Path1.

At the end of the prior run, Path2 had 15:56. At present, Path2 still has 15:56. Therefore, there have been no changes on Path2.

Since there have been no changes on either Path1 or Path2, I am done here. There is no problem and nothing needs to be synced.

In other words, it is comparing to the prior listing of the same side, not the current listing of the opposite side. This design is not itself the problem. The problem is that prior listing of Path1 is wrong. It should still be 15:56. The bug is that 16:53 was allowed to sneak in undetected on the prior run, between the first and second snapshots. Essentially, Bisync now thinks it has already synced a change that it actually should not know about yet.

If you want to test my theory, you can manually edit that line in path1.lst to match path2.lst, then try the bisync run again, and see if it suddenly notices that it needs syncing.

Thanks! That bridges the gap in my understanding.

I have tried using the beta release with some of the recommended setting linked earlier, but seems like there is a weird issue with the --drive-pacer-min-sleep flag:

1b3c54613afd:~$ rclone bisync gdrive:lichswarm /data/lichswarm -MPcv --workdir /cache --check-access --max-delete=10 --filter-from /filter-from-list.txt --check-sync=false --no-cleanup --ignore-listing-checksum --disable ListR --checkers=16 --drive-pacer-min-sleep=10ms --create-e
mpty-src-dirs --resilient --dry-run
2023/08/23 19:55:31 NOTICE: bisync is EXPERIMENTAL. Don't use in production!
2023-08-23 19:55:31 INFO  : Synching Path1 "gdrive{qOqdu}:lichswarm/" with Path2 "/data/lichswarm/"
2023-08-23 19:55:31 ERROR : Bisync critical error: cannot find prior Path1 or Path2 listings, likely due to critical error on prior run
2023-08-23 19:55:31 ERROR : Bisync aborted. Error is retryable without --resync due to --resilient mode.
Transferred:              0 B / 0 B, -, 0 B/s, ETA -


1b3c54613afd:~$ rclone bisync gdrive:lichswarm /data/lichswarm -MPcv --workdir /cache --check-access --max-delete=10 --filter-from /filter-from-list.txt --check-sync=false --no-cleanup --ignore-listing-checksum --disable ListR --checkers=16  --create-empty-src-dirs --resilient --
dry-run
2023/08/23 19:55:39 NOTICE: bisync is EXPERIMENTAL. Don't use in production!
2023-08-23 19:55:39 INFO  : Synching Path1 "gdrive:lichswarm/" with Path2 "/data/lichswarm/"
2023-08-23 19:55:39 INFO  : Path1 checking for diffs
2023-08-23 19:55:57 INFO  : Path2 checking for diffs
2023-08-23 19:56:12 INFO  : - Path2    File is newer                       - data
2023-08-23 19:56:12 INFO  : Path2:    1 changes:    0 new,    1 newer,    0 older,    0 deleted
2023-08-23 19:56:12 INFO  : Checking access health
2023-08-23 19:56:12 ERROR : Access test failed: Path1 count 0, Path2 count 0 - RCLONE_TEST
2023-08-23 19:56:12 ERROR : Bisync critical error: check file check failed
2023-08-23 19:56:12 ERROR : Bisync aborted. Error is retryable without --resync due to --resilient mode.
Transferred:              0 B / 0 B, -, 0 B/s, ETA -
Elapsed time:        33.0s

1b3c54613afd:~$ rclone version
rclone v1.64.0-beta.7267.984470456
- os/version: alpine 3.18.3 (64 bit)
- os/kernel: 6.1.21-v8+ (aarch64)
- os/type: linux
- os/arch: arm64 (ARMv8 compatible)
- go/version: go1.21.0
- go/linking: static
- go/tags: none

nielash · August 23, 2023, 11:05pm

vtcifer:

2023-08-23 19:55:31 INFO  : Synching Path1 "gdrive{qOqdu}:lichswarm/" with Path2 "/data/lichswarm/"
2023-08-23 19:55:31 ERROR : Bisync critical error: cannot find prior Path1 or Path2 listings, likely due to critical error on prior run

This one is happening because --drive-pacer-min-sleep is a backend-specific flag, which is adding {qOqdu} to the name of your gdrive remote (because Rclone detects an overridden config). Bisync is therefore looking for a listing file named gdrive{qOqdu}_lichswarm..data_lichswarm.path1.lst and not finding it because it's actually named gdrive_lichswarm..data_lichswarm.path1.lst (without the {qOqdu}).

To fix this, you can either:

Run a --resync (which will regenerate the listing files with the {qOqdu} it wants)
Use the pacer_min_sleep config parameter instead of the --drive-pacer-min-sleep command flag. (This should remove the {qOqdu} since you are no longer overriding the config.)

Or as a third option, you could manually rename your existing .lst files to include the {qOqdu}, then try again.

More info in the new beta docs.

vtcifer:

2023-08-23 19:56:12 INFO  : Checking access health
2023-08-23 19:56:12 ERROR : Access test failed: Path1 count 0, Path2 count 0 - RCLONE_TEST
2023-08-23 19:56:12 ERROR : Bisync critical error: check file check failed

This one is happening because you included --check-access but Bisync can't find your RCLONE_TEST check-files. Do they exist?

asdffdsa · August 23, 2023, 11:19pm

perhaps a fourth option is to add the flag to the remote.
gdrive,drive_pacer_min_sleep=10ms:lichswarm

system · September 22, 2023, 11:19pm

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.