Avoiding Bisync 'times are equal' conflicts with newer?

Help and Support
21

It could be due to using --recover. From the docs:

In the rare event that a file is synced successfully during a run that later aborts, and then that same file changes AGAIN before the next run, bisync will think it is a sync conflict, and handle it accordingly. (From bisync's perspective, the file has changed on both sides since the last trusted sync, and the files on either side are not currently identical.) Therefore, --recover carries with it a slightly increased chance of having conflicts -- though in practice this is pretty rare, as the conditions required to cause it are quite specific. This risk can be reduced by using bisync's "Graceful Shutdown" mode (triggered by sending SIGINT or Ctrl+C ), when you have the choice, instead of forcing a sudden termination.

When you notice this happening, did the previous run finish successfully? Or did it end in an error that the current run is recovering from? (The example in your log looks like the latter.)

As an experiment, you could try omitting --recover and see if the conflicts still happen.

Another thing to keep in mind is that it is not terribly difficult for an application to change a file's modtime independently of its content (for example, rclone touch does exactly this.) So, while I think other explanations are likelier, it's a possible explanation to keep in mind for the local side (I agree it wouldn't explain the idrive side, if you're sure no other systems are syncing to it.)

This could be a good use case for --conflict-resolve path2, because you have high confidence that the local side should win (especially if the change on the idrive side is likely to be a red herring caused by --recover.)

1 Like
22

More testing without --recover before looking at --conflict-resolve path2 is required but there was a non-conflict error this morning I wanted to flag.

After you linked the excerpt from the docs I learned my service was sending SIGTERM instead of SIGINT, which meant that sometimes rclone was prevented from completing a graceful shutdown. This has now been corrected with KillSignal=SIGINT.

Since removing recover and fixing the kill signal provisionally there seem to be less conflicts, but I will be doing more work on the project over the next few weeks and that will be a better test. The other 'file not found' errors as below occur very regularly.

This morning after a successful bisync I moved a file into my local path while I could see rclone was between scans in the terminal I keep open to monitor it. This was enough to generate a error requiring resync on the next run.

Timeline:

10:31:13 INFO  : Bisync successful
10:34 problem-file.png moved manually
10:35:32 DEBUG : rclone: Version "v1.67.0" starting with parameters...
10:36:15 ERROR : - Path2 file not found in Path1 - ABC/problem-file.png
10:36:15 Bisync aborted. Must run --resync to recover

Sending you a link to the debug log now.

I see in the log after that which I shared before I fixed it with a manual recover Bisync critical error: path1 and path2 are out of sync and ERROR : Bisync critical error: cannot find prior Path1 or Path2 listings. I assume these are as a result of the initial problem.

23

More similar non-conflict errors today triggered just by downloading 2 files and a few minutes later deleting them with Nautilus, there were no interruptions to rclone or any complex file operations. Bisync should be able to tolerate this without requiring --recover, no?

2024/08/29 14:27:50 ERROR : -                   Path2 file not found in Path1               - Education/mod4567/T3 Web Services/Topic 3 - Web Services.pptx
2024/08/29 14:27:50 ERROR : -                   Path2 file not found in Path1               - Education/mod4567/T3 Web Services/quote-ws (1).zip
2024/08/29 14:27:50 DEBUG : Lock file removed: /home/salty/.cache/rclone/bisync/idrive-sync-hasher_..local__home_salty_sync.lck
2024/08/29 14:27:50 ERROR : Bisync critical error: path1 and path2 are out of sync, run --resync to recover
2024/08/29 14:27:50 ERROR : Bisync aborted. Must run --resync to recover.
tail: /home/salty/.config/rclone/rclone.log: file truncated
2024/08/29 14:27:50 DEBUG : Lock file removed: /home/salty/.cache/rclone/bisync/idrive-sync-hasher_..local__home_salty_sync.lck
2024/08/29 14:27:50 ERROR : Bisync critical error: path1 and path2 are out of sync, run --resync to recover
2024/08/29 14:27:50 ERROR : Bisync aborted. Must run --resync to recover.
tail: /home/salty/.config/rclone/rclone.log: file truncated
2024/08/29 14:30:36 DEBUG : rclone: Version "v1.67.0" starting with parameters ["rclone" "bisync" "idrive-sync-hasher:/" "/home/salty/sync/" "--check-access" "--fast-list" "--verbose" "--filter-from=/home/salty/.config/rclone/filters" "--links" "--compare" "size,modtime,checksum" "--log-file=/home/salty/.config/rclone/rclone.log" "--error-on-no-transfer" "--conflict-resolve" "newer" "--resilient" "-vv"]
2024/08/29 14:30:36 DEBUG : Creating backend with remote "idrive-sync-hasher:/"
2024/08/29 14:30:36 DEBUG : Using config file from "/home/salty/.config/rclone/rclone.conf"
2024/08/29 14:30:36 INFO  : Hasher is EXPERIMENTAL!
2024/08/29 14:30:36 DEBUG : Creating backend with remote "idrive-sync-crypt:/"
2024/08/29 14:30:36 DEBUG : Creating backend with remote "idrive-sync:sync"
2024/08/29 14:30:36 DEBUG : Resolving service "s3" region "us-east-1"
2024/08/29 14:30:36 DEBUG : hasher::idrive-sync-hasher:/: Groups by usage: cached [md5], passed [], auto [md5], slow [], supported [md5]
2024/08/29 14:30:36 DEBUG : idrive-sync-crypt~hasher.bolt: Opened for reading in 42.059µs
2024/08/29 14:30:36 DEBUG : Creating backend with remote "/home/salty/sync/"
2024/08/29 14:30:36 DEBUG : local: detected overridden config - adding "{b6816}" suffix to name
2024/08/29 14:30:36 DEBUG : fs cache: renaming cache item "/home/salty/sync/" to be canonical "local{b6816}:/home/salty/sync"
2024/08/29 14:30:36 NOTICE: bisync is IN BETA. Don't use in production!
2024/08/29 14:30:36 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": true,
	"HashType1": 1,
	"HashType2": 1,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": true,
	"DownloadHash": false
}
2024/08/29 14:30:36 DEBUG : Lock file created: /home/salty/.cache/rclone/bisync/idrive-sync-hasher_..local__home_salty_sync.lck
2024/08/29 14:30:36 INFO  : Synching Path1 "idrive-sync-hasher:/" with Path2 "local{b6816}:/home/salty/sync/"
2024/08/29 14:30:36 DEBUG : : updated backup-dir for Path1
2024/08/29 14:30:36 DEBUG : : updated backup-dir for Path2
2024/08/29 14:30:36 DEBUG : Lock file removed: /home/salty/.cache/rclone/bisync/idrive-sync-hasher_..local__home_salty_sync.lck
2024/08/29 14:30:36 ERROR : Bisync critical error: cannot find prior Path1 or Path2 listings, likely due to critical error on prior run 
Tip: here are the filenames we were looking for. Do they exist? 
Path1: /home/salty/.cache/rclone/bisync/idrive-sync-hasher_..local__home_salty_sync.path1.lst
Path2: /home/salty/.cache/rclone/bisync/idrive-sync-hasher_..local__home_salty_sync.path2.lst
Try running this command to inspect the work dir: 
rclone lsl "/home/salty/.cache/rclone/bisync"
2024/08/29 14:30:36 ERROR : Bisync aborted. Error is retryable without --resync due to --resilient mode.
tail: /home/salty/.config/rclone/rclone.log: file truncated
24

Firstly, just want to note (as the documentation already does) that Graceful Shutdown mode uses "best efforts" to wrap up cleanly before the timer runs out, but there is no guarantee that it will always be able to do so. It can be useful for occasional emergencies, but is not something I'd recommend relying on for normal day-to-day use. If you are constantly terminating bisync before it is finished, I would not be surprised if sooner or later this results in some errors.

The above error is exactly what --recover deals with. Normally, when bisync has a critical error during a run, the "listings" are deleted during the exit process, as they are deemed untrustworthy. Without --recover, a --resync is required on the next run. With --recover, bisync looks to the "backup" listings (from the last successful run) and uses those.

1 Like
25

Comment to keep thread open.

26

Sorry for the delay in coming back to this thread but as the academic year has resumed I am under more pressure with deadlines etc.

I appreciate you have said that rclone makes the best effort to shutdown gracefully but it can not be relied upon, and it seems very reasonable that if conflicts are occurring after I have interrupted rclone that is a likely cause.

That said, now that I am developing more I have had even more time testing rclone bisync, and it is very clear that yes although sometimes after I boot conflicts occur during the first run (and this could almost be described as rarely occurring), I receive an alert for the vast majority of conflicts when I have already been working for considerable time, without my computer automatically sleeping as I normally have this disabled.

As no alerts for rclone were received prior to the conflicts this means that multiple successful runs were complete every 10 minutes or so, ruling out the ungraceful interruption to rclone being the cause, at least in these instances.

My environment is the same during the conflicts, only ever working on one of just two devices that sync, sometimes the other computer has not been on for days like on Sunday, ruling out what I would consider a normal conflict where two computers are trying to sync a modification to the same file.

There are so many conflicts throughout the day that I have to manually correct, after multiple successful syncs, without sleeping, and with only one computer powered on, I expect that my experience of rclone bisync is not that which is intended and something is wrong.

I tested without recover for a few weeks and there were less conflicts but there were very regular errors that required a manual --resync to resolve. I re-added --recover, as manually deleting conflict files seemed easier than manually resyncs. It seems I need --recover to handle these errors without manual intervention but it is causing most of the conflicts. I did not document the non conflict errors at the time but I do not remember noticing each could be explained by ungraceful interruption - I can test and record more non-recover errors if necessary.

  --conflict-loser ConflictLoserAction   Action to take on the loser of a sync conflict (when there is a winner) or on both files (when there is no winner): , num, pathname, delete (default: num)```

  --conflict-resolve string              Automatically resolve conflicts by preferring the version that is: none, path1, path2, newer, older, larger, smaller (default: none) (default "none")```

The best time to test this is when I am developing but I also want to make sure I do not lose any work, so if I add --conflict-resolve path2 and as a precaution conflict-loser idrive-sync-hasher:/conflicts/ will this mean that the conflict files I see now will populate that directory, or will setting path2 as the resolve option mean they are never created in the first place?

Yes, as demonstrated the conflicts I am reporting are locally generated on a single system, and they are not due to my laptop and desktop trying to sync modifications to the same file, though if possible I would like rclone to be able to handle these normal conflicts should they occur by keeping both files. I will settle for always choosing the local file to resolve the issue with locally generated conflicts, but ideally it would work something like this:

# Check for normal conflicts, different file versions,
# modtime & size or hash:
if file1 modtime != file2 modtime...
   append .conflictNum to one of the files and move

# Locally generated/--recover caused conflict between
# two equal versions of the file on a single computer
else
   conflict resolve path2
27

I think what would be really helpful here is to focus on the absolute simplest case -- the one where you are seeing unexpected conflicts even though:

  • Only one machine is in use, and the other has been off for days
  • --recover is not in use
  • Graceful Shutdown is not in use
  • We are certain the previous run finished successfully and the machine has not slept or otherwise interrupted a run since then.

I think it is also useful to back up and consider what exactly a conflict is:

In bisync, a "conflict" is a file that is new or changed on both sides (relative to the prior run) AND is not currently identical on both sides.

In our "simple" scenario here, the two sides are idrive and local. We know why the file is changing on local (because you have edited it during the normal course of working). What we don't know is why the file has changed on idrive (or, more accurately: why bisync thinks the file has changed on idrive, relative to the previous sync.) I think that is the main question we need to solve.

Since idrive is cloud storage, not a machine, nothing should really be changing there unless you have told it to. So the next logical question is whether the file's content is really changing, or whether the change is just an illusion (i.e. the file on idrive is not truly changing, and bisync just thinks it is for some reason.) If the file is really changing, you need to figure out what is causing the change (like possibly some other app that is syncing changes to idrive, or edits made manually in the browser UI). If idrive gives you an event audit log for the file, that could be useful to determine this.

On the other hand, if the change is an illusion, then we need to determine why bisync thinks the file is changing when it is really not. It would help to know what specifically the change is (for example, is idrive reporting a modtime that is newer than the one we expect based on the last sync? If so, is idrive wrong, or is our expectation wrong?) The debug log can help you figure this out, as all changes should show the "old" and "new" values (with "old" being our expectation based on the last run.)

As idrive uses s3, we also need to consider the s3-specific quirks related to modtime. (For example, rule out --use-server-modtime as a possible factor.) If possible, it would be really helpful to confirm whether we can reproduce this bug with a non-s3-based backend, to determine whether the problem is specific to s3 in some way. (For example, I bisync with drive and the only conflicts I ever see are the ones I expect to see.) Likewise, it would be helpful to remove hasher from the equation, if possible -- the goal is to narrow this down to the bare minimum repro case.

The only valid values for --conflict-loser are num, pathname, and delete, so the above example would give you a syntax error. I think maybe you are thinking of --conflict-suffix, but this still only changes the leaf -- it does not move the file to a new directory. If I understand your goal correctly, you could accomplish something similar by using --backup-dir1 and --backup-dir2 in combination with --conflict-loser delete. But to be honest, I think you would be better off doing your testing in a new environment with dummy files, instead of in production with files you care about. I totally get the convenience factor since your existing setup appears to produce the bug easily -- but I think at some point the needs of your production environment will inevitably be at odds with the debugging goal of stripping this down to the fewest possible settings. And, ultimately we do need to find a way to reproduce this outside of your exact existing setup (because if we can't, then we haven't ruled out that something about your setup may be causing it.)

That's an interesting idea. To rephrase it, I think what you're suggesting (correct me if I'm wrong) is a new option that usually acts like --conflict-resolve newer when possible, but falls back to --conflict-resolve path2 as a tie-breaker when a winner cannot be determined by looking at modtime. I think this is worth considering -- feel free to submit a Feature Request for it on GitHub, if you would like.

1 Like
28

I want to carry out testing but it has to wait until I have time. Could a mod please extend how long the thread will stay open without me having to bump it?

29

Sorry it has taken me so long to come back to this. I am determined to resolve using rclone bisync for desktop sync and when I have I am very interested in using bisync: status GUI and notifications · Issue #7474 · rclone/rclone · GitHub instead of relying on my bash script and notify-send.

Recent errors (Bisync: Failed to read metadata: operation error S3: HeadObject & error reading hash from underlying) prompted me to purge the remote and for now I will only use the sync remote for my local code on my desktop, and for at least the next few weeks I have rclone disabled on my laptop. The smaller size and quicker runs should make it easier to find and address any issue. Ultimately even if I should migrate a lot of old personal documents I do not really need ready access to from bisync to a mount with rclone browser, I would like to sync more than code.

This sounds promising but as per the docs --use-server-modtime should probably be used with update and rclone tells me bisync does not support it. I tried without it in case it was not required with bisync for some reason but I cancelled it on the second run when as the docs warn it was copying and replacing all existing files on the remote.

Can you please make available a version that supports this, and if so can I just edit the command or is a purge and/or --resync required? I noticed when I tried just removing --use-server-modtime it started copying some files that should have already been uploaded to the remote so I purged and started over.

Also with hasher removed and --compare defaulting to size and modtime this is the command currently running in my script:

rclone bisync "idrive-sync-crypt:/" "/home/salty/sync/" --check-access --fast-list --filter-from=/home/salty/.config/rclone/filters --links --error-on-no-transfer --conflict-resolve newer --resilient -vv

When running with --update and --use-server-modtime I am unsure whether any --compare flags are required for local and server side checks, like to prevent bisync using normal modtime in addition to the server's, or so it will or will not not use size in combination with other checks?

This reads like checksum could this be useful for local side only comparisons but we did add the hasher so I guess that should be left out for now:

If --compare includes checksum and both remotes support checksums but have no hash types in common with each other, checksums will be considered only for comparisons within the same side (to determine what has changed since the prior sync), but not for comparisons against the opposite side. If one side supports checksums and the other does not, checksums will only be considered on the side that supports them.

I will confirm these before reporting any conflicts. I am curious though, are you personally using bisync only on a machine that is rarely off, or do you manually stop it or perhaps confirm a bisync successful before any shutdown?

I am trying to balance troubleshooting using the files in the remote normally, which seems to be the best way to trigger the issue! I should be able to keep doing this, only flagging conflicts that occur for the simplest case.

Until today I have exclusively used IDrive for rclone bisync though I just setup a new separate bucket and remote for a mount with rclone browser. I do not use their own desktop app or any other software to access IDrive, and I never make any changes using the Web UI other than during a purge, not least because everything is encrypted. It follows the likelihood is that the files are not really changing on IDrive - bisync just thinks they are.

I have versioning enabled in case it is something rclone can make use of, but I do not see any file history on the web app. I will see if there is some other way.

If this was something readily available it would make it easier to work and test for the issue at the same time but really the idea is a workaround for experiencing so many conflicts in the first place and resolving that will negate this.

Yes. As above this would be a way to manage the issue of conflicts occurring when I think they should not, as under normal circumstances it should be very rare the modtime is the exact same. I would still be uneasy of always deferring to a particular path especially as the current issue is that these conflicts are actually frequent!

30

I had not made any changes to my local since before I purged the remote when I last posted, and it has been running fine every few minutes my Desktop is on confirming no changes. Today I opened a project in Cursor and before long a critical error was generated.

I still have no re-enabled rclone on my laptop so only my desktop us attempting to sync to IDrive.

In terms of the timeline at some point not long before this part of the log I openend the IDE and I left it idle with Caffeine enabled, as the norm, to prevent sleep. I assume this is just part of the IDE maintenance but as that point I still had not made any changes to my local but on my return I had a notification that there were some rclone transfers and deletions - although no errors yet:

Deletion sample:

2025/01/05 12:43:06 DEBUG : 2024-12-11 14:29:59.996772 +0000 UTC: Modification times differ by 598h4m35.792157888s: 2024-12-11 14:29:59.996772 +0000 UTC, 2025-01-05 12:34:35.788929888 +0000 UTC
2025/01/05 12:43:06 DEBUG : code/mod1234/Lab4/Part2/target/classes/Main.astra: (old: 2024-12-11 14:29:59.996772 +0000 UTC current: 2025-01-05 12:34:35.788929888 +0000 UTC)
2025/01/05 12:43:06 INFO  : - Path2             File changed: time (newer)                  - code/mod1234/Lab4/Part2/target/classes/Main.astra
2025/01/05 12:43:06 INFO  : - Path2             File was deleted                            - code/mod1234/Lab4/Part2/target/classes/Main.astra.conflict1
2025/01/05 12:43:06 INFO  : - Path2             File was deleted                            - code/mod1234/Lab4/Part2/target/classes/Main.class
2025/01/05 12:43:06 INFO  : - Path2             File was deleted                            - code/mod1234/Lab4/Part2/target/classes/Main.class.conflict1
2025/01/05 12:43:06 INFO  : - Path2             File was deleted                            - code/mod1234/Lab4/Part2/target/classes/VacBot$1.class
2025/01/05 12:43:06 INFO  : - Path2             File was deleted                            - code/mod1234/Lab4/Part2/target/classes/VacBot$10.class
2025/01/05 12:43:06 INFO  : - Path2             File was deleted                            - code/mod1234/Lab4/Part2/target/classes/VacBot$11.class
2025/01/05 12:43:06 INFO  : - Path2             File was deleted                            - code/mod1234/Lab4/Part2/target/classes/VacBot$12.class
2025/01/05 12:43:06 INFO  : - Path2             File was deleted                            - code/mod1234/Lab4/Part2/target/classes/VacBot$12.class.conflict1

Copies:

2025/01/05 12:43:21 DEBUG : winner: copy to src: 
{
	"Src": "local{b6816}:/home/salty/sync/",
	"Dst": "idrive-sync-crypt:/",
	"Name": "code/mod1234/Lab4/Part2/target/classes/VacBot.astra",
	"AltName": "",
	"Size": 8791,
	"Modtime": "2025-01-05T12:34:35.788929888Z",
	"Hash": "",
	"Flags": "-",
	"Sigil": 42,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": true,
	"IsSrc": true,
	"IsDst": false,
	"Origin": "sync"
}
2025/01/05 12:43:21 DEBUG : winner: copy to dst: 
{
	"Src": "local{b6816}:/home/salty/sync/",
	"Dst": "idrive-sync-crypt:/",
	"Name": "code/mod1234/Lab4/Part2/target/classes/VacBot.astra",
	"AltName": "",
	"Size": 8791,
	"Modtime": "2025-01-05T12:34:35.788929888Z",
	"Hash": "",
	"Flags": "-",
	"Sigil": 42,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": true,
	"IsSrc": true,
	"IsDst": false,
	"Origin": "sync"
}
2025/01/05 12:43:21 DEBUG : winner: copy to src: 
{
	"Src": "local{b6816}:/home/salty/sync/",
	"Dst": "idrive-sync-crypt:/",
	"Name": "code/mod1234/Lab4/Part2/target/classes/Main.astra",
	"AltName": "",
	"Size": 536,
	"Modtime": "2025-01-05T12:34:35.788929888Z",
	"Hash": "",
	"Flags": "-",
	"Sigil": 42,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": true,
	"IsSrc": true,
	"IsDst": false,
	"Origin": "sync"
}
2025/01/05 12:43:21 DEBUG : winner: copy to dst: 
{
	"Src": "local{b6816}:/home/salty/sync/",
	"Dst": "idrive-sync-crypt:/",
	"Name": "code/mod1234/Lab4/Part2/target/classes/Main.astra",
	"AltName": "",
	"Size": 536,
	"Modtime": "2025-01-05T12:34:35.788929888Z",
	"Hash": "",
	"Flags": "-",
	"Sigil": 42,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": true,
	"IsSrc": true,
	"IsDst": false,
	"Origin": "sync"
}

2025/01/05 12:43:21 INFO  : Bisync successful
2025/01/05 12:43:21 INFO  : 
Transferred:   	    9.202 KiB / 9.202 KiB, 100%, 4.601 KiB/s, ETA 0s
Checks:             71890 / 71890, 100%
Deleted:              122 (files), 0 (dirs), 148.421 KiB (freed)
Transferred:            2 / 2, 100%
Elapsed time:     10m14.0s

No more transfers or deletions and 2 more bisync successful runs occur, the last before the error ending at 12:58:28.

2025/01/05 12:58:29 DEBUG : rclone: Version "v1.68.2" starting with parameters ["rclone" "bisync" "idrive-sync-crypt:/" "/home/salty/sync/" "--check-access" "--fast-list" "--filter-from=/home/salty/.config/rclone/filters" "--links" "--log-file=/home/salty/.config/rclone/logs/idrive-sync-crypt/rclone.log" "--error-on-no-transfer" "--conflict-resolve" "newer" "--resilient" "-vv"]

From my logs I can see that appimagelauncherd integrated a new version of Cursor at 13:00:52 and then at 13:01:16 I make my first intentional change to any files in my local using the command mvn, which pom.xml is configured to automate: <defaultGoal>clean compile dependency:copy-dependencies astra:deploy</defaultGoal>

All mentions of the 2 error related files:

2025/01/05 12:59:10 DEBUG : code/mod1234/Lab4/Part2/target/classes/VacBot.astra: both path1 and path2
2025/01/05 12:59:10 DEBUG : code/mod1234/Lab4/Part2/target/classes/VacBot.astra: is Object
2025/01/05 12:59:10 DEBUG : code/mod1234/Lab4/Part2/target/classes/Main.astra: both path1 and path2
2025/01/05 12:59:10 DEBUG : code/mod1234/Lab4/Part2/target/classes/Main.astra: is Object

2025/01/05 13:05:52 DEBUG : 2025-01-05 12:34:35.788929888 +0000 UTC: Modification times differ by 23m48.404017743s: 2025-01-05 12:34:35.788929888 +0000 UTC, 2025-01-05 12:58:24.192947631 +0000 UTC
2025/01/05 13:05:52 DEBUG : code/mod1234/Lab4/Part2/target/classes/Main.astra: (old: 2025-01-05 12:34:35.788929888 +0000 UTC current: 2025-01-05 12:58:24.192947631 +0000 UTC)
2025/01/05 13:05:52 INFO  : - Path2             File changed: time (newer)                  - code/mod1234/Lab4/Part2/target/classes/Main.astra
2025/01/05 13:05:52 DEBUG : 2025-01-05 12:34:35.788929888 +0000 UTC: Modification times differ by 23m48.404017743s: 2025-01-05 12:34:35.788929888 +0000 UTC, 2025-01-05 12:58:24.192947631 +0000 UTC
2025/01/05 13:05:52 DEBUG : code/mod1234/Lab4/Part2/target/classes/VacBot.astra: (old: 2025-01-05 12:34:35.788929888 +0000 UTC current: 2025-01-05 12:58:24.192947631 +0000 UTC)
2025/01/05 13:05:52 INFO  : - Path2             File changed: time (newer)                  - code/mod1234/Lab4/Part2/target/classes/VacBot.astra

2025/01/05 13:05:52 INFO  : Path2:    2 changes:    0 new,    2 modified,    0 deleted
2025/01/05 13:05:52 INFO  : (Modified:    2 newer,    0 older)
2025/01/05 13:05:52 INFO  : Checking access health
2025/01/05 13:05:52 INFO  : Found 1 matching "RCLONE_TEST" files on both paths
2025/01/05 13:05:52 INFO  : Applying changes
2025/01/05 13:05:52 INFO  : - Path2             Queue copy to Path1                         - idrive-sync-crypt:/code/mod1234/Lab4/Part2/target/classes/Main.astra
2025/01/05 13:05:52 INFO  : - Path2             Queue copy to Path1                         - idrive-sync-crypt:/code/mod1234/Lab4/Part2/target/classes/VacBot.astra
2025/01/05 13:05:52 INFO  : - Path2             Do queued copies to                         - Path1
2025/01/05 13:05:52 DEBUG : : updated backup-dir for Path1

2025/01/05 13:05:53 DEBUG : Encrypted drive 'idrive-sync-crypt:/': Waiting for checks to finish
2025/01/05 13:05:53 DEBUG : code/mod1234/Lab4/Part2/target/classes/Main.astra: Modification times differ by -26m42.055684772s: 2025-01-05 13:01:17.84461466 +0000 GMT, 2025-01-05 12:34:35.788929888 +0000 GMT
2025/01/05 13:05:53 DEBUG : code/mod1234/Lab4/Part2/target/classes/VacBot.astra: Modification times differ by -26m42.055684772s: 2025-01-05 13:01:17.84461466 +0000 GMT, 2025-01-05 12:34:35.788929888 +0000 GMT
2025/01/05 13:05:53 DEBUG : writing result: 
{
	"Src": "local{b6816}:/home/salty/sync/",
	"Dst": "idrive-sync-crypt:/",
	"Name": "code/mod1234/Lab4/Part2/target/classes/Main.astra",
	"AltName": "",
	"Size": 536,
	"Modtime": "2025-01-05T13:01:17.84461466Z",
	"Hash": "",
	"Flags": "-",
	"Sigil": 42,
	"Err": null,
	"Winner": {
		"Obj": {},
		"Side": "src",
		"Err": null
	},
	"IsWinner": true,
	"IsSrc": true,
	"IsDst": false,
	"Origin": "sync"
}
2025/01/05 13:05:53 DEBUG : writing result: 
{
	"Src": "local{b6816}:/home/salty/sync/",
	"Dst": "idrive-sync-crypt:/",
	"Name": "code/mod1234/Lab4/Part2/target/classes/Main.astra",
	"AltName": "",
	"Size": 536,
	"Modtime": "2025-01-05T12:34:35.788929888Z",
	"Hash": "",
	"Flags": "-",
	"Sigil": 42,
	"Err": null,
	"Winner": {
		"Obj": {},
		"Side": "src",
		"Err": null
	},
	"IsWinner": false,
	"IsSrc": false,
	"IsDst": true,
	"Origin": "sync"
}
2025/01/05 13:05:53 DEBUG : writing result: 
{
	"Src": "local{b6816}:/home/salty/sync/",
	"Dst": "idrive-sync-crypt:/",
	"Name": "code/mod1234/Lab4/Part2/target/classes/VacBot.astra",
	"AltName": "",
	"Size": 8791,
	"Modtime": "2025-01-05T13:01:17.84461466Z",
	"Hash": "",
	"Flags": "-",
	"Sigil": 42,
	"Err": null,
	"Winner": {
		"Obj": {},
		"Side": "src",
		"Err": null
	},
	"IsWinner": true,
	"IsSrc": true,
	"IsDst": false,
	"Origin": "sync"
}
2025/01/05 13:05:53 DEBUG : writing result: 
{
	"Src": "local{b6816}:/home/salty/sync/",
	"Dst": "idrive-sync-crypt:/",
	"Name": "code/mod1234/Lab4/Part2/target/classes/VacBot.astra",
	"AltName": "",
	"Size": 8791,
	"Modtime": "2025-01-05T12:34:35.788929888Z",
	"Hash": "",
	"Flags": "-",
	"Sigil": 42,
	"Err": null,
	"Winner": {
		"Obj": {},
		"Side": "src",
		"Err": null
	},
	"IsWinner": false,
	"IsSrc": false,
	"IsDst": true,
	"Origin": "sync"
}
2025/01/05 13:05:53 DEBUG : Encrypted drive 'idrive-sync-crypt:/': Waiting for transfers to finish
2025/01/05 13:05:53 DEBUG : code/mod1234/Lab4/Part2/target/classes/Main.astra: Computing md5 hash of encrypted source
2025/01/05 13:05:53 DEBUG : code/mod1234/Lab4/Part2/target/classes/VacBot.astra: Computing md5 hash of encrypted source
2025/01/05 13:05:53 DEBUG : code/mod1234/Lab4/Part2/target/classes/Main.astra: md5 = 23083bab660164dc43bffbf91255db2c OK
2025/01/05 13:05:53 INFO  : code/mod1234/Lab4/Part2/target/classes/Main.astra: Copied (replaced existing)
2025/01/05 13:05:53 DEBUG : code/mod1234/Lab4/Part2/target/classes/VacBot.astra: md5 = ffe21717e6fe23e99b65fd2112d2dd56 OK
2025/01/05 13:05:53 INFO  : code/mod1234/Lab4/Part2/target/classes/VacBot.astra: Copied (replaced existing)
2025/01/05 13:05:53 DEBUG : Waiting for deletions to finish
2025/01/05 13:05:53 DEBUG : failed to marshal input: json: unsupported type: operations.LoggerFn
2025/01/05 13:05:53 DEBUG : logger: 

2025/01/05 13:05:53 DEBUG : result: 
{
	"Src": "code",
	"Dst": "",
	"Name": "code",
	"AltName": "",
	"Size": -1,
	"Modtime": "2024-11-19T17:09:41.840496Z",
	"Hash": "",
	"Flags": "d",
	"Sigil": 61,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": true,
	"IsSrc": true,
	"IsDst": false,
	"Origin": "sync"
}
2025/01/05 13:05:53 DEBUG : result: 
{
	"Src": "code",
	"Dst": "",
	"Name": "code",
	"AltName": "",
	"Size": -1,
	"Modtime": "2000-01-01T00:00:00Z",
	"Hash": "",
	"Flags": "d",
	"Sigil": 61,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": false,
	"IsSrc": false,
	"IsDst": true,
	"Origin": "sync"
}
2025/01/05 13:05:53 DEBUG : result: 
{
	"Src": "code/mod1234",
	"Dst": "",
	"Name": "code/mod1234",
	"AltName": "",
	"Size": -1,
	"Modtime": "2024-12-10T18:50:11.136536Z",
	"Hash": "",
	"Flags": "d",
	"Sigil": 61,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": true,
	"IsSrc": true,
	"IsDst": false,
	"Origin": "sync"
}
2025/01/05 13:05:53 DEBUG : result: 
{
	"Src": "code/mod1234",
	"Dst": "",
	"Name": "code/mod1234",
	"AltName": "",
	"Size": -1,
	"Modtime": "2000-01-01T00:00:00Z",
	"Hash": "",
	"Flags": "d",
	"Sigil": 61,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": false,
	"IsSrc": false,
	"IsDst": true,
	"Origin": "sync"
}
2025/01/05 13:05:53 DEBUG : result: 
{
	"Src": "code/mod1234/Lab4",
	"Dst": "",
	"Name": "code/mod1234/Lab4",
	"AltName": "",
	"Size": -1,
	"Modtime": "2024-10-30T21:15:09.232355Z",
	"Hash": "",
	"Flags": "d",
	"Sigil": 61,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": true,
	"IsSrc": true,
	"IsDst": false,
	"Origin": "sync"
}
2025/01/05 13:05:53 DEBUG : result: 
{
	"Src": "code/mod1234/Lab4",
	"Dst": "",
	"Name": "code/mod1234/Lab4",
	"AltName": "",
	"Size": -1,
	"Modtime": "2000-01-01T00:00:00Z",
	"Hash": "",
	"Flags": "d",
	"Sigil": 61,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": false,
	"IsSrc": false,
	"IsDst": true,
	"Origin": "sync"
}
2025/01/05 13:05:53 DEBUG : result: 
{
	"Src": "code/mod1234/Lab4/Part2",
	"Dst": "",
	"Name": "code/mod1234/Lab4/Part2",
	"AltName": "",
	"Size": -1,
	"Modtime": "2025-01-05T13:01:17.84061476Z",
	"Hash": "",
	"Flags": "d",
	"Sigil": 61,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": true,
	"IsSrc": true,
	"IsDst": false,
	"Origin": "sync"
}
2025/01/05 13:05:53 DEBUG : result: 
{
	"Src": "code/mod1234/Lab4/Part2",
	"Dst": "",
	"Name": "code/mod1234/Lab4/Part2",
	"AltName": "",
	"Size": -1,
	"Modtime": "2000-01-01T00:00:00Z",
	"Hash": "",
	"Flags": "d",
	"Sigil": 61,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": false,
	"IsSrc": false,
	"IsDst": true,
	"Origin": "sync"
}
2025/01/05 13:05:53 DEBUG : result: 
{
	"Src": "code/mod1234/Lab4/Part2/target",
	"Dst": "",
	"Name": "code/mod1234/Lab4/Part2/target",
	"AltName": "",
	"Size": -1,
	"Modtime": "2025-01-05T13:01:19.600571384Z",
	"Hash": "",
	"Flags": "d",
	"Sigil": 61,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": true,
	"IsSrc": true,
	"IsDst": false,
	"Origin": "sync"
}
2025/01/05 13:05:53 DEBUG : result: 
{
	"Src": "code/mod1234/Lab4/Part2/target",
	"Dst": "",
	"Name": "code/mod1234/Lab4/Part2/target",
	"AltName": "",
	"Size": -1,
	"Modtime": "2000-01-01T00:00:00Z",
	"Hash": "",
	"Flags": "d",
	"Sigil": 61,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": false,
	"IsSrc": false,
	"IsDst": true,
	"Origin": "sync"
}
2025/01/05 13:05:53 DEBUG : result: 
{
	"Src": "code/mod1234/Lab4/Part2/target/classes",
	"Dst": "",
	"Name": "code/mod1234/Lab4/Part2/target/classes",
	"AltName": "",
	"Size": -1,
	"Modtime": "2025-01-05T13:01:19.052584889Z",
	"Hash": "",
	"Flags": "d",
	"Sigil": 61,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": true,
	"IsSrc": true,
	"IsDst": false,
	"Origin": "sync"
}
2025/01/05 13:05:53 DEBUG : result: 
{
	"Src": "code/mod1234/Lab4/Part2/target/classes",
	"Dst": "",
	"Name": "code/mod1234/Lab4/Part2/target/classes",
	"AltName": "",
	"Size": -1,
	"Modtime": "2000-01-01T00:00:00Z",
	"Hash": "",
	"Flags": "d",
	"Sigil": 61,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": false,
	"IsSrc": false,
	"IsDst": true,
	"Origin": "sync"
}
2025/01/05 13:05:53 DEBUG : result: 
{
	"Src": "local{b6816}:/home/salty/sync/",
	"Dst": "idrive-sync-crypt:/",
	"Name": "code/mod1234/Lab4/Part2/target/classes/Main.astra",
	"AltName": "",
	"Size": 536,
	"Modtime": "2025-01-05T13:01:17.84461466Z",
	"Hash": "",
	"Flags": "-",
	"Sigil": 42,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": true,
	"IsSrc": true,
	"IsDst": false,
	"Origin": "sync"
}
2025/01/05 13:05:53 DEBUG : result: 
{
	"Src": "local{b6816}:/home/salty/sync/",
	"Dst": "idrive-sync-crypt:/",
	"Name": "code/mod1234/Lab4/Part2/target/classes/Main.astra",
	"AltName": "",
	"Size": 536,
	"Modtime": "2025-01-05T12:34:35.788929888Z",
	"Hash": "",
	"Flags": "-",
	"Sigil": 42,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": false,
	"IsSrc": false,
	"IsDst": true,
	"Origin": "sync"
}
2025/01/05 13:05:53 DEBUG : result: 
{
	"Src": "local{b6816}:/home/salty/sync/",
	"Dst": "idrive-sync-crypt:/",
	"Name": "code/mod1234/Lab4/Part2/target/classes/VacBot.astra",
	"AltName": "",
	"Size": 8791,
	"Modtime": "2025-01-05T13:01:17.84461466Z",
	"Hash": "",
	"Flags": "-",
	"Sigil": 42,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": true,
	"IsSrc": true,
	"IsDst": false,
	"Origin": "sync"
}
2025/01/05 13:05:53 DEBUG : result: 
{
	"Src": "local{b6816}:/home/salty/sync/",
	"Dst": "idrive-sync-crypt:/",
	"Name": "code/mod1234/Lab4/Part2/target/classes/VacBot.astra",
	"AltName": "",
	"Size": 8791,
	"Modtime": "2025-01-05T12:34:35.788929888Z",
	"Hash": "",
	"Flags": "-",
	"Sigil": 42,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": false,
	"IsSrc": false,
	"IsDst": true,
	"Origin": "sync"
}
2025/01/05 13:05:53 DEBUG : Got 16 results for copy2to1
2025/01/05 13:05:53 DEBUG : d       -1   2024-11-19 17:09:41.840496 +0000 UTC "code"
2025/01/05 13:05:53 DEBUG : d       -1   2000-01-01 00:00:00 +0000 UTC "code"
2025/01/05 13:05:53 DEBUG : d       -1   2024-12-10 18:50:11.136536 +0000 UTC "code/mod1234"
2025/01/05 13:05:53 DEBUG : d       -1   2000-01-01 00:00:00 +0000 UTC "code/mod1234"
2025/01/05 13:05:53 DEBUG : d       -1   2024-10-30 21:15:09.232355 +0000 UTC "code/mod1234/Lab4"
2025/01/05 13:05:53 DEBUG : d       -1   2000-01-01 00:00:00 +0000 UTC "code/mod1234/Lab4"
2025/01/05 13:05:53 DEBUG : d       -1   2025-01-05 13:01:17.84061476 +0000 UTC "code/mod1234/Lab4/Part2"
2025/01/05 13:05:53 DEBUG : d       -1   2000-01-01 00:00:00 +0000 UTC "code/mod1234/Lab4/Part2"
2025/01/05 13:05:53 DEBUG : d       -1   2025-01-05 13:01:19.600571384 +0000 UTC "code/mod1234/Lab4/Part2/target"
2025/01/05 13:05:53 DEBUG : d       -1   2000-01-01 00:00:00 +0000 UTC "code/mod1234/Lab4/Part2/target"
2025/01/05 13:05:53 DEBUG : d       -1   2025-01-05 13:01:19.052584889 +0000 UTC "code/mod1234/Lab4/Part2/target/classes"
2025/01/05 13:05:53 DEBUG : d       -1   2000-01-01 00:00:00 +0000 UTC "code/mod1234/Lab4/Part2/target/classes"
2025/01/05 13:05:53 DEBUG : -      536   2025-01-05 13:01:17.84461466 +0000 UTC "code/mod1234/Lab4/Part2/target/classes/Main.astra"
2025/01/05 13:05:53 DEBUG : -      536   2025-01-05 12:34:35.788929888 +0000 UTC "code/mod1234/Lab4/Part2/target/classes/Main.astra"
2025/01/05 13:05:53 DEBUG : -     8791   2025-01-05 13:01:17.84461466 +0000 UTC "code/mod1234/Lab4/Part2/target/classes/VacBot.astra"
2025/01/05 13:05:53 DEBUG : -     8791   2025-01-05 12:34:35.788929888 +0000 UTC "code/mod1234/Lab4/Part2/target/classes/VacBot.astra"
2025/01/05 13:05:53 DEBUG : syncing empty dirs
2025/01/05 13:05:53 INFO  : Updating listings
2025/01/05 13:05:53 DEBUG : updating 2to1
2025/01/05 13:05:53 DEBUG : results: 
[
	{
		"Src": "code",
		"Dst": "",
		"Name": "code",
		"AltName": "",
		"Size": -1,
		"Modtime": "2024-11-19T17:09:41.840496Z",
		"Hash": "",
		"Flags": "d",
		"Sigil": 61,
		"Err": null,
		"Winner": {
			"Obj": null,
			"Side": "src",
			"Err": null
		},
		"IsWinner": true,
		"IsSrc": true,
		"IsDst": false,
		"Origin": "sync"
	},
	{
		"Src": "code",
		"Dst": "",
		"Name": "code",
		"AltName": "",
		"Size": -1,
		"Modtime": "2000-01-01T00:00:00Z",
		"Hash": "",
		"Flags": "d",
		"Sigil": 61,
		"Err": null,
		"Winner": {
			"Obj": null,
			"Side": "src",
			"Err": null
		},
		"IsWinner": false,
		"IsSrc": false,
		"IsDst": true,
		"Origin": "sync"
	},
	{
		"Src": "code/mod1234",
		"Dst": "",
		"Name": "code/mod1234",
		"AltName": "",
		"Size": -1,
		"Modtime": "2024-12-10T18:50:11.136536Z",
		"Hash": "",
		"Flags": "d",
		"Sigil": 61,
		"Err": null,
		"Winner": {
			"Obj": null,
			"Side": "src",
			"Err": null
		},
		"IsWinner": true,
		"IsSrc": true,
		"IsDst": false,
		"Origin": "sync"
	},
	{
		"Src": "code/mod1234",
		"Dst": "",
		"Name": "code/mod1234",
		"AltName": "",
		"Size": -1,
		"Modtime": "2000-01-01T00:00:00Z",
		"Hash": "",
		"Flags": "d",
		"Sigil": 61,
		"Err": null,
		"Winner": {
			"Obj": null,
			"Side": "src",
			"Err": null
		},
		"IsWinner": false,
		"IsSrc": false,
		"IsDst": true,
		"Origin": "sync"
	},
	{
		"Src": "code/mod1234/Lab4",
		"Dst": "",
		"Name": "code/mod1234/Lab4",
		"AltName": "",
		"Size": -1,
		"Modtime": "2024-10-30T21:15:09.232355Z",
		"Hash": "",
		"Flags": "d",
		"Sigil": 61,
		"Err": null,
		"Winner": {
			"Obj": null,
			"Side": "src",
			"Err": null
		},
		"IsWinner": true,
		"IsSrc": true,
		"IsDst": false,
		"Origin": "sync"
	},
	{
		"Src": "code/mod1234/Lab4",
		"Dst": "",
		"Name": "code/mod1234/Lab4",
		"AltName": "",
		"Size": -1,
		"Modtime": "2000-01-01T00:00:00Z",
		"Hash": "",
		"Flags": "d",
		"Sigil": 61,
		"Err": null,
		"Winner": {
			"Obj": null,
			"Side": "src",
			"Err": null
		},
		"IsWinner": false,
		"IsSrc": false,
		"IsDst": true,
		"Origin": "sync"
	},
	{
		"Src": "code/mod1234/Lab4/Part2",
		"Dst": "",
		"Name": "code/mod1234/Lab4/Part2",
		"AltName": "",
		"Size": -1,
		"Modtime": "2025-01-05T13:01:17.84061476Z",
		"Hash": "",
		"Flags": "d",
		"Sigil": 61,
		"Err": null,
		"Winner": {
			"Obj": null,
			"Side": "src",
			"Err": null
		},
		"IsWinner": true,
		"IsSrc": true,
		"IsDst": false,
		"Origin": "sync"
	},
	{
		"Src": "code/mod1234/Lab4/Part2",
		"Dst": "",
		"Name": "code/mod1234/Lab4/Part2",
		"AltName": "",
		"Size": -1,
		"Modtime": "2000-01-01T00:00:00Z",
		"Hash": "",
		"Flags": "d",
		"Sigil": 61,
		"Err": null,
		"Winner": {
			"Obj": null,
			"Side": "src",
			"Err": null
		},
		"IsWinner": false,
		"IsSrc": false,
		"IsDst": true,
		"Origin": "sync"
	},
	{
		"Src": "code/mod1234/Lab4/Part2/target",
		"Dst": "",
		"Name": "code/mod1234/Lab4/Part2/target",
		"AltName": "",
		"Size": -1,
		"Modtime": "2025-01-05T13:01:19.600571384Z",
		"Hash": "",
		"Flags": "d",
		"Sigil": 61,
		"Err": null,
		"Winner": {
			"Obj": null,
			"Side": "src",
			"Err": null
		},
		"IsWinner": true,
		"IsSrc": true,
		"IsDst": false,
		"Origin": "sync"
	},
	{
		"Src": "code/mod1234/Lab4/Part2/target",
		"Dst": "",
		"Name": "code/mod1234/Lab4/Part2/target",
		"AltName": "",
		"Size": -1,
		"Modtime": "2000-01-01T00:00:00Z",
		"Hash": "",
		"Flags": "d",
		"Sigil": 61,
		"Err": null,
		"Winner": {
			"Obj": null,
			"Side": "src",
			"Err": null
		},
		"IsWinner": false,
		"IsSrc": false,
		"IsDst": true,
		"Origin": "sync"
	},
	{
		"Src": "code/mod1234/Lab4/Part2/target/classes",
		"Dst": "",
		"Name": "code/mod1234/Lab4/Part2/target/classes",
		"AltName": "",
		"Size": -1,
		"Modtime": "2025-01-05T13:01:19.052584889Z",
		"Hash": "",
		"Flags": "d",
		"Sigil": 61,
		"Err": null,
		"Winner": {
			"Obj": null,
			"Side": "src",
			"Err": null
		},
		"IsWinner": true,
		"IsSrc": true,
		"IsDst": false,
		"Origin": "sync"
	},
	{
		"Src": "code/mod1234/Lab4/Part2/target/classes",
		"Dst": "",
		"Name": "code/mod1234/Lab4/Part2/target/classes",
		"AltName": "",
		"Size": -1,
		"Modtime": "2000-01-01T00:00:00Z",
		"Hash": "",
		"Flags": "d",
		"Sigil": 61,
		"Err": null,
		"Winner": {
			"Obj": null,
			"Side": "src",
			"Err": null
		},
		"IsWinner": false,
		"IsSrc": false,
		"IsDst": true,
		"Origin": "sync"
	},
	{
		"Src": "local{b6816}:/home/salty/sync/",
		"Dst": "idrive-sync-crypt:/",
		"Name": "code/mod1234/Lab4/Part2/target/classes/Main.astra",
		"AltName": "",
		"Size": 536,
		"Modtime": "2025-01-05T13:01:17.84461466Z",
		"Hash": "",
		"Flags": "-",
		"Sigil": 42,
		"Err": null,
		"Winner": {
			"Obj": null,
			"Side": "src",
			"Err": null
		},
		"IsWinner": true,
		"IsSrc": true,
		"IsDst": false,
		"Origin": "sync"
	},
	{
		"Src": "local{b6816}:/home/salty/sync/",
		"Dst": "idrive-sync-crypt:/",
		"Name": "code/mod1234/Lab4/Part2/target/classes/Main.astra",
		"AltName": "",
		"Size": 536,
		"Modtime": "2025-01-05T12:34:35.788929888Z",
		"Hash": "",
		"Flags": "-",
		"Sigil": 42,
		"Err": null,
		"Winner": {
			"Obj": null,
			"Side": "src",
			"Err": null
		},
		"IsWinner": false,
		"IsSrc": false,
		"IsDst": true,
		"Origin": "sync"
	},
	{
		"Src": "local{b6816}:/home/salty/sync/",
		"Dst": "idrive-sync-crypt:/",
		"Name": "code/mod1234/Lab4/Part2/target/classes/VacBot.astra",
		"AltName": "",
		"Size": 8791,
		"Modtime": "2025-01-05T13:01:17.84461466Z",
		"Hash": "",
		"Flags": "-",
		"Sigil": 42,
		"Err": null,
		"Winner": {
			"Obj": null,
			"Side": "src",
			"Err": null
		},
		"IsWinner": true,
		"IsSrc": true,
		"IsDst": false,
		"Origin": "sync"
	},
	{
		"Src": "local{b6816}:/home/salty/sync/",
		"Dst": "idrive-sync-crypt:/",
		"Name": "code/mod1234/Lab4/Part2/target/classes/VacBot.astra",
		"AltName": "",
		"Size": 8791,
		"Modtime": "2025-01-05T12:34:35.788929888Z",
		"Hash": "",
		"Flags": "-",
		"Sigil": 42,
		"Err": null,
		"Winner": {
			"Obj": null,
			"Side": "src",
			"Err": null
		},
		"IsWinner": false,
		"IsSrc": false,
		"IsDst": true,
		"Origin": "sync"
	}
]
2025/01/05 13:05:53 DEBUG : queue: 
{
	"code/mod1234/Lab4/Part2/target/classes/Main.astra": null,
	"code/mod1234/Lab4/Part2/target/classes/VacBot.astra": null
}
2025/01/05 13:05:54 DEBUG : winner: copy to src: 
{
	"Src": "local{b6816}:/home/salty/sync/",
	"Dst": "idrive-sync-crypt:/",
	"Name": "code/mod1234/Lab4/Part2/target/classes/Main.astra",
	"AltName": "",
	"Size": 536,
	"Modtime": "2025-01-05T13:01:17.84461466Z",
	"Hash": "",
	"Flags": "-",
	"Sigil": 42,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": true,
	"IsSrc": true,
	"IsDst": false,
	"Origin": "sync"
}
2025/01/05 13:05:54 DEBUG : winner: copy to dst: 
{
	"Src": "local{b6816}:/home/salty/sync/",
	"Dst": "idrive-sync-crypt:/",
	"Name": "code/mod1234/Lab4/Part2/target/classes/Main.astra",
	"AltName": "",
	"Size": 536,
	"Modtime": "2025-01-05T13:01:17.84461466Z",
	"Hash": "",
	"Flags": "-",
	"Sigil": 42,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": true,
	"IsSrc": true,
	"IsDst": false,
	"Origin": "sync"
}
2025/01/05 13:05:54 DEBUG : winner: copy to src: 
{
	"Src": "local{b6816}:/home/salty/sync/",
	"Dst": "idrive-sync-crypt:/",
	"Name": "code/mod1234/Lab4/Part2/target/classes/VacBot.astra",
	"AltName": "",
	"Size": 8791,
	"Modtime": "2025-01-05T13:01:17.84461466Z",
	"Hash": "",
	"Flags": "-",
	"Sigil": 42,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": true,
	"IsSrc": true,
	"IsDst": false,
	"Origin": "sync"
}
2025/01/05 13:05:54 DEBUG : winner: copy to dst: 
{
	"Src": "local{b6816}:/home/salty/sync/",
	"Dst": "idrive-sync-crypt:/",
	"Name": "code/mod1234/Lab4/Part2/target/classes/VacBot.astra",
	"AltName": "",
	"Size": 8791,
	"Modtime": "2025-01-05T13:01:17.84461466Z",
	"Hash": "",
	"Flags": "-",
	"Sigil": 42,
	"Err": null,
	"Winner": {
		"Obj": null,
		"Side": "src",
		"Err": null
	},
	"IsWinner": true,
	"IsSrc": true,
	"IsDst": false,
	"Origin": "sync"
}
2025/01/05 13:05:54 DEBUG : decision: copied to src: code/mod1234/Lab4/Part2/target/classes/Main.astra
2025/01/05 13:05:54 DEBUG : decision: copied to src: code/mod1234/Lab4/Part2/target/classes/VacBot.astra
2025/01/05 13:05:54 DEBUG : decision: copied to dst: code/mod1234/Lab4/Part2/target/classes/Main.astra
2025/01/05 13:05:54 DEBUG : decision: copied to dst: code/mod1234/Lab4/Part2/target/classes/VacBot.astra
2025/01/05 13:05:54 INFO  : Validating listings for Path1 "idrive-sync-crypt:/" vs Path2 "local{b6816}:/home/salty/sync/"

2025/01/05 13:05:54 DEBUG : 2025-01-05 13:01:17.84461466 +0000 UTC: Modification times differ by -2m53.651667029s: 2025-01-05 13:01:17.84461466 +0000 UTC, 2025-01-05 12:58:24.192947631 +0000 UTC
2025/01/05 13:05:54 ERROR : -                   Modtime not equal in listing. Path1: 2025-01-05 13:01:17.84461466 +0000 UTC, Path2: 2025-01-05 12:58:24.192947631 +0000 UTC - code/mod1234/Lab4/Part2/target/classes/Main.astra
2025/01/05 13:05:54 DEBUG : 2025-01-05 13:01:17.84461466 +0000 UTC: Modification times differ by -2m53.651667029s: 2025-01-05 13:01:17.84461466 +0000 UTC, 2025-01-05 12:58:24.192947631 +0000 UTC
2025/01/05 13:05:54 ERROR : -                   Modtime not equal in listing. Path1: 2025-01-05 13:01:17.84461466 +0000 UTC, Path2: 2025-01-05 12:58:24.192947631 +0000 UTC - code/mod1234/Lab4/Part2/target/classes/VacBot.astra

2025/01/05 13:05:54 DEBUG : Lock file removed: /home/salty/.cache/rclone/bisync/idrive-sync-crypt_..local__home_salty_sync.lck
2025/01/05 13:05:54 ERROR : Bisync critical error: path1 and path2 are out of sync, run --resync to recover
2025/01/05 13:05:54 ERROR : Bisync aborted. Must run --resync to recover.

Now looping on:

2025/01/05 13:05:55 DEBUG : Lock file created: /home/salty/.cache/rclone/bisync/idrive-sync-crypt_..local__home_salty_sync.lck
2025/01/05 13:05:55 INFO  : Synching Path1 "idrive-sync-crypt:/" with Path2 "local{b6816}:/home/salty/sync/"
2025/01/05 13:05:55 DEBUG : : updated backup-dir for Path1
2025/01/05 13:05:55 DEBUG : : updated backup-dir for Path2
2025/01/05 13:05:55 DEBUG : Lock file removed: /home/salty/.cache/rclone/bisync/idrive-sync-crypt_..local__home_salty_sync.lck
2025/01/05 13:05:55 ERROR : Bisync critical error: cannot find prior Path1 or Path2 listings, likely due to critical error on prior run 
Tip: here are the filenames we were looking for. Do they exist? 
Path1: /home/salty/.cache/rclone/bisync/idrive-sync-crypt_..local__home_salty_sync.path1.lst
Path2: /home/salty/.cache/rclone/bisync/idrive-sync-crypt_..local__home_salty_sync.path2.lst
Try running this command to inspect the work dir: 
rclone lsl "/home/salty/.cache/rclone/bisync"
2025/01/05 13:05:55 ERROR : Bisync aborted. Error is retryable without --resync due to --resilient mode.

Maybe this is Maven specific. Re-syncing now after updating filters to include:

- /code/**/*.class
- /code/**/target/

Update: Seemed okay for awhile after resync, same conditions as earlier, system has not slept or been powered off, last bisync before this successful and then just now:

2025/01/05 19:24:16 DEBUG : 2025-01-05 19:11:00.751682264 +0000 UTC: modification time the same (differ by 0s, within tolerance 1ns)
2025/01/05 19:24:16 ERROR : -                   Size not equal in listing. Path1: 8850, Path2: 8790 - code/mod1234/Lab4/Part2/src/main/astra/VacBot.astra
2025/01/05 19:24:16 DEBUG : 2025-01-05 19:20:39.269011504 +0000 UTC: Modification times differ by -7m0.182441511s: 2025-01-05 19:20:39.269011504 +0000 UTC, 2025-01-05 19:13:39.086569993 +0000 UTC
2025/01/05 19:24:16 ERROR : -                   Modtime not equal in listing. Path1: 2025-01-05 19:20:39.269011504 +0000 UTC, Path2: 2025-01-05 19:13:39.086569993 +0000 UTC - code/mod1234/Lab4/Part2/src/main/astra/VacBot.astra

Difficult to test for the conflict issue when not using recover means these critical errors require manual intervention to resolve. What can I try here?

31

@nielash can you please come back to me on this? I am not able to progress testing due to the different errors as described with or without --recover.

32

Hi @saltysyncs sorry for the delayed response. I meant to respond to this and then got very sidetracked with other things.

After staring at this for a few hours now, I think I may see the bug. Can you test this version and see if it fixes it for you?

https://beta.rclone.org/branch/test-saltysyncs/v1.70.0-beta.8570.2341934d8.test-saltysyncs/

Source: GitHub - rclone/rclone at test-saltysyncs

(This isn't the "real" fix, but should at least tell us if we've found the bug.)

33

Just wondering if you were able to test this? Someone on GitHub had the same issue and said this fixed it for them.

34

Sorry for delay, will test today. Without recover, right?

35

Yes. Thank you!

36

Resyncing the last few hours. I know we would like to confirm this for the release in a few days, just need a little bit more time to test.

1 Like
37

So far so good but let's see if we can't cause an error with more development tomorrow :upside_down_face:

1 Like
38

The only problem I have experienced so far is when I forgot to disable sleep and resumed to soon afterwards see go errors. Rebooting resolved this and no issues on subsequent syncs.

1 Like
39

That is encouraging! Thanks!

40

Still working fine here on the test version, thank you for all of your work on this, it makes a huge difference to be able to use bisync without having to deal with very regular errors. I knew it could work this well! :slightly_smiling_face:

You mentioned it is not the real fix but it sure seems like it! Should I upgrade to 1.69.1 or is there something else I can test first?

Happy to test anything that will help but after that I would like to work towards syncing between my two machines again, using the hasher for speed, and testing again with --recover. I know you said that it could be responsible for the conflicts but I wonder if there is any way the issue you resolved was a factor? Is there any logical order to re-enable those perhaps testing for a few days each?