The log file created with --log-file does not include the current file being processed even at the highest verbosity level. A log entry is made after processing of the file has completed. Logging the file before processing it allows the following scenarios:
User can tail the log to follow current progress instead of only completed progress
User can tell which file may be incomplete/corrupted if rclone is abnormally terminated
Proposed logging additions with new entries prefixed with <new>.
Edit: Apologies. I meant to put this in the Feature category.
As you said, it does appear to be dependent upon the backend. If there is multipart copying being done, each part is logged. However, in the case of local to local copying without segmenting/chunking, no logging is provided until completion of the file. If there was a fixed log statement at the start of a file's processing and not on each chunk/segment uploaded it would cover all scenarios.
Yes you are right these logs are missing. That is because the file bypasses the NeedsTransfer check if it exists in the source and not the destination and it is NeedsTransfer which prints the logs.
It needed fixing twice, once for --track-renames and once without.
based on my testing up above and the source code changes,
i assume, we only need to test when the source is a dir.
the results looks good to me.
i tested using this script.
note: i never used track-renames before, not sure my test is valid.
set -x
source=~/files/source
dest=~/files/dest
function setup {
./rclone delete $source
./rclone delete $dest
# same filename, same content
echo 'same.file' > $source/same.file
echo 'same.file' > $dest/same.file
# same filename, different content
echo 'differ.source' > $source/differ
echo 'differ.dest' > $dest/differ
# different filename, same content to test track-renames
echo 'same.conents' > $source/track.source.file
echo 'same.conents' > $dest/track.dest.file
# test missing files on source and dest
echo 'missing.on.dest' > $source/missing.on.dest
echo 'missing.on.source' > $dest/missing.on.source
}
setup
./rclone sync $source $dest -vv
setup
./rclone sync $source $dest --track-renames -vv
and here is the outputs
./rclone sync /root/files/source /root/files/dest -vv
2023/04/03 11:21:13 DEBUG : rclone: Version "v1.63.0-beta.6933.6178e407e.fix-sync-logs" starting with parameters ["./rclone" "sync" "/root/files/source" "/root/files/dest" "-vv"]
2023/04/03 11:21:13 DEBUG : Creating backend with remote "/root/files/source"
2023/04/03 11:21:13 DEBUG : Using config file from "/root/.config/rclone/rclone.conf"
2023/04/03 11:21:13 DEBUG : Creating backend with remote "/root/files/dest"
2023/04/03 11:21:13 DEBUG : missing.on.dest: Need to transfer - File not found at Destination
2023/04/03 11:21:13 DEBUG : track.source.file: Need to transfer - File not found at Destination
2023/04/03 11:21:13 DEBUG : differ: Sizes differ (src 14 vs dst 12)
2023/04/03 11:21:13 DEBUG : Local file system at /root/files/dest: Waiting for checks to finish
2023/04/03 11:21:13 DEBUG : same.file: Size and modification time the same (differ by 0s, within tolerance 1ns)
2023/04/03 11:21:13 DEBUG : track.source.file: md5 = 69560bcf3a8ea14317b74c4adc7709cb OK
2023/04/03 11:21:13 DEBUG : same.file: Unchanged skipping
2023/04/03 11:21:13 INFO : track.source.file: Copied (new)
2023/04/03 11:21:13 DEBUG : Local file system at /root/files/dest: Waiting for transfers to finish
2023/04/03 11:21:13 DEBUG : missing.on.dest: md5 = a21b4a9ca47717eac8b820fa58dbc239 OK
2023/04/03 11:21:13 INFO : missing.on.dest: Copied (new)
2023/04/03 11:21:13 DEBUG : differ: md5 = aa3e7d3799f0801835eb6ba3248e8867 OK
2023/04/03 11:21:13 INFO : differ: Copied (replaced existing)
2023/04/03 11:21:13 DEBUG : Waiting for deletions to finish
2023/04/03 11:21:13 INFO : missing.on.source: Deleted
2023/04/03 11:21:13 INFO : track.dest.file: Deleted
2023/04/03 11:21:13 INFO :
Transferred: 43 B / 43 B, 100%, 0 B/s, ETA -
Checks: 4 / 4, 100%
Deleted: 2 (files), 0 (dirs)
Transferred: 3 / 3, 100%
Elapsed time: 0.1s
and
2023/04/03 11:21:14 DEBUG : rclone: Version "v1.63.0-beta.6933.6178e407e.fix-sync-logs" starting with parameters ["./rclone" "sync" "/root/files/source" "/root/files/dest" "--track-renames" "-vv"]
2023/04/03 11:21:14 DEBUG : Creating backend with remote "/root/files/source"
2023/04/03 11:21:14 DEBUG : Using config file from "/root/.config/rclone/rclone.conf"
2023/04/03 11:21:14 DEBUG : Creating backend with remote "/root/files/dest"
2023/04/03 11:21:14 INFO : Local file system at /root/files/dest: Making map for --track-renames
2023/04/03 11:21:14 DEBUG : same.file: Size and modification time the same (differ by 0s, within tolerance 1ns)
2023/04/03 11:21:14 DEBUG : same.file: Unchanged skipping
2023/04/03 11:21:14 DEBUG : differ: Sizes differ (src 14 vs dst 12)
2023/04/03 11:21:14 INFO : Local file system at /root/files/dest: Finished making map for --track-renames
2023/04/03 11:21:14 DEBUG : Local file system at /root/files/dest: Waiting for checks to finish
2023/04/03 11:21:14 DEBUG : missing.on.dest: Need to transfer - No matching file found at Destination
2023/04/03 11:21:14 DEBUG : differ: md5 = aa3e7d3799f0801835eb6ba3248e8867 OK
2023/04/03 11:21:14 INFO : differ: Copied (replaced existing)
2023/04/03 11:21:14 DEBUG : Local file system at /root/files/dest: Waiting for renames to finish
2023/04/03 11:21:14 INFO : track.dest.file: Moved (server-side) to: track.source.file
2023/04/03 11:21:14 INFO : track.source.file: Renamed from "track.dest.file"
2023/04/03 11:21:14 DEBUG : Local file system at /root/files/dest: Waiting for transfers to finish
2023/04/03 11:21:14 DEBUG : missing.on.dest: md5 = a21b4a9ca47717eac8b820fa58dbc239 OK
2023/04/03 11:21:14 INFO : missing.on.dest: Copied (new)
2023/04/03 11:21:14 DEBUG : Waiting for deletions to finish
2023/04/03 11:21:14 INFO : missing.on.source: Deleted
2023/04/03 11:21:14 INFO :
Transferred: 43 B / 43 B, 100%, 0 B/s, ETA -
Checks: 5 / 5, 100%
Deleted: 1 (files), 0 (dirs)
Renamed: 1
Transferred: 2 / 2, 100%
Elapsed time: 0.1s
