What is the problem you are having with rclone?
Completion stats are not written to the specified log file for completed syncs (either fully completed or interrupted via --max-duration).
Weirdly, when using the -vv option to provide the logs for this post, the stats ARE shown in the logfile, even using the same command that produces no logs without -vv.
For context, I have a slow internet connection and I am trying to use rclone to sync my borg backup repository. I want to stop rclone before the nightly backups start and then restart afterwards so I have been tinkering with the --max-duration parameter which is great.
I want to be able to monitor the interactive progress (which I'll do by running rclone in a tmux session), but also capture the post-run stats for reporting. After searching the forum, the --progress and --log-file options seems to be the answer but I am getting odd results.
I'm not sure if this is a bug or intended behaviour but perhaps someone can shed some light on it.
There is a chance the problem exists between chair and keyboard, so apologies if I am simply being dumb.
I have noted the following behaviour during testing.
I tested using my full borg backup folder when using --max-duration (since there is no way I can get a full sync to complete with my current connection), and using a single ~40MB file for the completed/successful (i.e. return code 0) backups.
--progress --log-file <logfile>=> completion stats logged to screen but nothing at all in logfile
Screen:
rclone sync --config /etc/rclone/rclone.conf --progress --log-file rclone.log <source_file> <target>
Transferred: 40.495 MiB / 40.495 MiB, 100%, 1.042 MiB/s, ETA 0s
Transferred: 1 / 1, 100%
Elapsed time: 38.5s
Logfile:
<empty>
--progress --log-file <logfile> --dry-run=> completion stats logged to screen and logfile
Screen:
rclone sync --config /etc/rclone/rclone.conf --progress --log-file rclone.log --dry-run <source_file> <target>
Transferred: 40.485 MiB / 40.485 MiB, 100%, 0 B/s, ETA -
Transferred: 1 / 1, 100%
Elapsed time: 0.0s
Logfile:
2025/05/11 17:01:45 NOTICE: 57: Skipped copy as --dry-run is set (size 40.485Mi)
2025/05/11 17:01:45 NOTICE:
Transferred: 40.485 MiB / 40.485 MiB, 100%, 0 B/s, ETA -
Transferred: 1 / 1, 100%
Elapsed time: 0.0s
--progress --log-file <logfile> --max-duration 10s --cutoff-mode soft=> completion stats logged to screen but not shown in logfile (although there is at least something in it)
Screen:
rclone sync --config /etc/rclone/rclone.conf --progress --log-file rclone.log --max-duration 10s --cutoff-mode soft <source_dir> <target>
Transferred: 329.970 MiB / 219.563 GiB, 0%, 812.116 KiB/s, ETA 3d6h37m
Errors: 1 (fatal error encountered)
Checks: 501 / 501, 100%
Transferred: 4 / 2225, 0%
Elapsed time: 5m54.7s
Logfile:
2025/05/11 17:21:13 ERROR : Encrypted drive 'crypt_box:': max transfer duration reached as set by --max-duration
2025/05/11 17:21:13 ERROR : Cancelling sync due to fatal error: max transfer duration reached as set by --max-duration
2025/05/11 17:21:13 ERROR : Fatal error received - not attempting retries
2025/05/11 17:21:13 NOTICE: Failed to sync: max transfer duration reached as set by --max-duration
--progress --log-file <logfile> --max-duration 10s --cutoff-mode soft --dry-run=> completion stats logged to screen and logfile
Screen:
rclone sync --config /etc/rclone/rclone.conf --progress --log-file rclone.log --max-duration 10s --cutoff-mode soft --dry-run <source_dir> <target>
Transferred: 219.241 GiB / 219.241 GiB, 100%, 0 B/s, ETA -
Checks: 505 / 505, 100%
Transferred: 2221 / 2221, 100%
Elapsed time: 2.6s
Logfile:
<snip>
2025/05/11 17:23:06 NOTICE: borgrepos/server1/data/3/3871: Skipped copy as --dry-run is set (size 100.093Mi)
2025/05/11 17:23:06 NOTICE: borgrepos/server1/data/3/3872: Skipped copy as --dry-run is set (size 100.868Mi)
2025/05/11 17:23:06 NOTICE: borgrepos/server1/data/3/3873: Skipped copy as --dry-run is set (size 100.250Mi)
2025/05/11 17:23:06 NOTICE: borgrepos/server1/data/3/3874: Skipped copy as --dry-run is set (size 273.002Ki)
2025/05/11 17:23:06 NOTICE: borgrepos/server1/data/3/3879: Skipped copy as --dry-run is set (size 840)
2025/05/11 17:23:06 NOTICE: borgrepos/server1/data/3/3881: Skipped copy as --dry-run is set (size 17)
2025/05/11 17:23:06 NOTICE: borgrepos/server2/data/0: Skipped set directory modification time as --dry-run is set
2025/05/11 17:23:06 NOTICE: borgrepos/server1/data/1: Skipped set directory modification time as --dry-run is set
2025/05/11 17:23:06 NOTICE: borgrepos/server1/data/2: Skipped set directory modification time as --dry-run is set
2025/05/11 17:23:06 NOTICE: borgrepos/server1/data/3: Skipped set directory modification time as --dry-run is set
2025/05/11 17:23:06 NOTICE: borgrepos/server1/data: Skipped set directory modification time as --dry-run is set
2025/05/11 17:23:06 NOTICE: borgrepos/server2/data: Skipped set directory modification time as --dry-run is set
2025/05/11 17:23:06 NOTICE: borgrepos/server1: Skipped set directory modification time as --dry-run is set
2025/05/11 17:23:06 NOTICE: borgrepos/server2: Skipped set directory modification time as --dry-run is set
2025/05/11 17:23:06 NOTICE: borgrepos: Skipped set directory modification time as --dry-run is set
2025/05/11 17:23:06 NOTICE:
Transferred: 219.241 GiB / 219.241 GiB, 100%, 0 B/s, ETA -
Checks: 505 / 505, 100%
Transferred: 2221 / 2221, 100%
Elapsed time: 2.6s
Run the command 'rclone version' and share the full output of the command.
rclone v1.69.2
- os/version: raspbian 12.10 (64 bit)
- os/kernel: 6.12.22-v8+ (aarch64)
- os/type: linux
- os/arch: arm64 (ARMv8 compatible)
- go/version: go1.24.2
- go/linking: static
- go/tags: none
Which cloud storage system are you using? (eg Google Drive)
Hetzner
The command you were trying to run (eg rclone copy /tmp remote:tmp)
Multiple examples given above.
The rclone config contents with secrets removed.
[hetzner_box]
type = sftp
host = <hetzner_url>
user = <username>
port = 23
key_file = /etc/rclone/id_rsa
known_hosts_file = /root/.ssh/known_hosts
shell_type = unix
md5sum_command = md5sum
sha1sum_command = sha1sum
[crypt_box]
type = crypt
remote = hetzner_box:borgbackup
password = <password>
password2 = <password>
filename_encoding = base64
A log from the command with the -vv flag
Log shown is a successfully completed single file sync which as shown above produced no log output at all without the -vv parameter.
2025/05/11 17:35:36 DEBUG : rclone: Version "v1.69.2" starting with parameters ["rclone" "sync" "--config" "/etc/rclone/rclone.conf" "--progress" "--log-file" "/var/log/rclone/rclone_sync.log" "-vv" "/borgbackup/borgrepos/server03/data/0/57" "crypt_box:"]
2025/05/11 17:35:36 DEBUG : Creating backend with remote "/borgbackup/borgrepos/server03/data/0/57"
2025/05/11 17:35:36 DEBUG : Using config file from "/etc/rclone/rclone.conf"
2025/05/11 17:35:36 DEBUG : fs cache: renaming child cache item "/borgbackup/borgrepos/server03/data/0/57" to be canonical for parent "/borgbackup/borgrepos/server03/data/0"
2025/05/11 17:35:36 DEBUG : Creating backend with remote "crypt_box:"
2025/05/11 17:35:36 DEBUG : Creating backend with remote "hetzner_box:borgbackup"
2025/05/11 17:35:37 DEBUG : sftp://<hetzner_url>:23/borgbackup: New connection 192.168.30.3:35606->X.X.X.X:23 to "SSH-2.0-OpenSSH_9.6p1 Ubuntu-3ubuntu13.11"
2025/05/11 17:35:37 DEBUG : sftp://<hetzner_url>:23/borgbackup: Shell type "unix" from config
2025/05/11 17:35:37 DEBUG : sftp://<hetzner_url>:23/borgbackup: Relative path resolved to "/home/borgbackup"
2025/05/11 17:35:37 DEBUG : sftp://<hetzner_url>:23/borgbackup: Using root directory "/home/borgbackup"
2025/05/11 17:35:37 DEBUG : 57: Need to transfer - File not found at Destination
2025/05/11 17:36:20 DEBUG : sftp://<hetzner_url>:23/borgbackup: Shell path "/home/borgbackup/OkEjw5LQcDG18rwpN4Y6tmdaJDUrPQKiJ_dQpK5x5uU"
2025/05/11 17:36:20 DEBUG : sftp://<hetzner_url>:23/borgbackup: Running remote command: md5sum /home/borgbackup/OkEjw5LQcDG18rwpN4Y6tmdaJDUrPQKiJ_dQpK5x5uU
2025/05/11 17:36:20 DEBUG : sftp://<hetzner_url>:23/borgbackup: Remote command result: c8a15da51c553ca0efdeb10d50387cd8 /home/borgbackup/OkEjw5LQcDG18rwpN4Y6tmdaJDUrPQKiJ_dQpK5x5uU
2025/05/11 17:36:20 DEBUG : OkEjw5LQcDG18rwpN4Y6tmdaJDUrPQKiJ_dQpK5x5uU: Parsed hash: c8a15da51c553ca0efdeb10d50387cd8
2025/05/11 17:36:20 DEBUG : 57.9beeab1.partial: md5 = c8a15da51c553ca0efdeb10d50387cd8 OK
2025/05/11 17:36:20 DEBUG : 57.9beeab1.partial: renamed to: 57
2025/05/11 17:36:20 INFO : 57: Copied (new)
2025/05/11 17:36:20 INFO :
Transferred: 40.495 MiB / 40.495 MiB, 100%, 968.706 KiB/s, ETA 0s
Transferred: 1 / 1, 100%
Elapsed time: 42.8s
2025/05/11 17:36:20 DEBUG : 14 go routines active
2025/05/11 17:36:20 DEBUG : sftp://<hetzner_url>:23/borgbackup: Closing 1 unused connections