Upload speed reported incorrectly

19wolf · January 9, 2023, 3:49am

What is the problem you are having with rclone?

After several hours of uploading at a fairly consistent 4MiB/s (~30mbps), logs show upload speed consistently at 71.214 KiB/s (~0.5mbps)

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

rclone v1.62.0-beta.6672.98fa93f6d

os/version: slackware 15.0+ (64 bit)
os/kernel: 5.19.17-Unraid (x86_64)
os/type: linux
os/arch: amd64
go/version: go1.19.4
go/linking: static
go/tags: none

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

Google Drive

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

RUNLEVEL=3
RCLONE_LOG_FILE=/var/log/rclone.log
RCLONE_TRANSFERS=6
RCLONE_STATS_ONE_LINE=true
RCLONE_DRIVE_STOP_ON_UPLOAD_LIMIT=true
RCLONE_STATS_LOG_LEVEL=NOTICE
PWD=/usr/local/emhttp
RCLONE_NO_TRAVERSE=true
RCLONE_FAST_LIST=true
RCLONE_CHECKSUM=true
RCLONE_VERBOSE=1
RCLONE_MAX_DURATION=24h
RCLONE_CHECKERS=12
INIT_VERSION=sysvinit-2.99
SHLVL=10
BOOT_IMAGE=/bzimage
RCLONE_STATS=20m
RCLONE_ORDER_BY=modtime,desc
CONSOLE=/dev/console
PATH=.:/usr/local/sbin:/usr/sbin:/sbin:/usr/local/bin:/usr/bin:/bin
PREVLEVEL=N
OLDPWD=/usr/local/emhttp
_=/usr/sbin/rcloneorig

rcloneorig --config /boot/config/plugins/rclone/.rclone.conf sync /mnt/user/Media/Television/ GoogleDrive:Media/Television/ --exclude Downloads/** --min-age=30d --min-size=50m --modify-window=1m --track-renames

The rclone config contents with secrets removed.

[GoogleDrive]
type = drive
client_id = 32777-snip-pne.apps.googleusercontent.com
client_secret = 
scope = drive
root_folder_id = 2hsK2-snip-BgiH23
token = {"access_token":"","token_type":"Bearer","refresh_token":"","expiry":"2023-01-08T23:15:07.21596893-05:00"}
team_drive =

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

This is running from cron; I don't have -vv enabled unfortunately.

2023/01/08 09:00:45 NOTICE:           0 B / 0 B, -, 0 B/s, ETA - (chk#83/10107)
2023/01/08 09:20:45 NOTICE:           0 B / 0 B, -, 0 B/s, ETA - (chk#122/10146)
2023/01/08 09:40:45 NOTICE:           0 B / 0 B, -, 0 B/s, ETA - (chk#144/10168)
2023/01/08 10:00:45 NOTICE:           0 B / 0 B, -, 0 B/s, ETA - (chk#205/10229)
2023/01/08 10:20:45 NOTICE:           0 B / 0 B, -, 0 B/s, ETA - (chk#346/10370)
2023/01/08 10:40:45 NOTICE:           0 B / 0 B, -, 0 B/s, ETA - (chk#546/10570)
2023/01/08 11:00:45 NOTICE:           0 B / 0 B, -, 0 B/s, ETA - (chk#696/10720)
2023/01/08 11:20:45 NOTICE:           0 B / 0 B, -, 0 B/s, ETA - (chk#802/10826)
2023/01/08 11:40:45 NOTICE:           0 B / 0 B, -, 0 B/s, ETA - (chk#860/10884)
2023/01/08 12:00:45 NOTICE:           0 B / 0 B, -, 0 B/s, ETA - (chk#1065/11089)
2023/01/08 12:20:45 NOTICE:   890.309 MiB / 2.383 GiB, 36%, 3.356 MiB/s, ETA 7m41s (chk#1174/11198)
2023/01/08 12:40:45 NOTICE:     3.700 GiB / 3.700 GiB, 100%, 71.214 KiB/s, ETA 0s (chk#1228/11252)
2023/01/08 13:00:45 NOTICE:     4.243 GiB / 4.412 GiB, 96%, 71.214 KiB/s, ETA 41m24s (chk#1350/11348)
2023/01/08 13:20:45 NOTICE:     8.844 GiB / 22.503 GiB, 39%, 71.214 KiB/s, ETA 2d7h51m48s (xfr#12/20, chk#1393/11348)
2023/01/08 13:40:45 NOTICE:    13.087 GiB / 109.077 GiB, 12%, 71.214 KiB/s, ETA 2w2d8h36m26s (xfr#16/58, chk#1472/11348)
2023/01/08 14:00:45 NOTICE:    15.707 GiB / 233.934 GiB, 7%, 71.214 KiB/s, ETA 5w2d4h33m52s (xfr#16/115, chk#1578/11348)
2023/01/08 14:20:45 NOTICE:    19.576 GiB / 369.409 GiB, 5%, 71.214 KiB/s, ETA 8w3d14h50m24s (xfr#17/170, chk#1699/11348)
2023/01/08 14:40:45 NOTICE:    24.178 GiB / 508.032 GiB, 5%, 71.214 KiB/s, ETA 11w5d10h59m34s (xfr#17/211, chk#1846/11348)
2023/01/08 15:00:45 NOTICE:    28.686 GiB / 611.116 GiB, 5%, 71.214 KiB/s, ETA 14w1d6h10m21s (xfr#18/270, chk#1903/11348)
2023/01/08 15:20:45 NOTICE:    33.230 GiB / 696.712 GiB, 5%, 71.214 KiB/s, ETA 16w1d1h40m54s (xfr#18/316, chk#1998/11348)
2023/01/08 15:40:45 NOTICE:    37.828 GiB / 823.128 GiB, 5%, 71.214 KiB/s, ETA 19w19h55m26s (xfr#20/353, chk#2112/11348)
2023/01/08 16:00:45 NOTICE:    42.425 GiB / 942.768 GiB, 5%, 71.214 KiB/s, ETA 21w6d10h27m19s (xfr#21/428, chk#2184/11348)
2023/01/08 16:20:45 NOTICE:    46.756 GiB / 1.031 TiB, 4%, 71.214 KiB/s, ETA 24w3d23h33s (xfr#21/534, chk#2239/11348)
2023/01/08 16:40:45 NOTICE:    51.135 GiB / 1.121 TiB, 4%, 71.214 KiB/s, ETA 26w4d22h34m34s (xfr#21/625, chk#2320/11348)
2023/01/08 17:00:45 NOTICE:    55.671 GiB / 1.264 TiB, 4%, 71.214 KiB/s, ETA 30w1d2h3m40s (xfr#21/711, chk#2390/11348)
2023/01/08 17:20:45 NOTICE:    60.222 GiB / 1.369 TiB, 4%, 71.214 KiB/s, ETA 32w4d13h58m27s (xfr#21/817, chk#2502/11348)
2023/01/08 17:40:45 NOTICE:    64.791 GiB / 1.440 TiB, 4%, 71.214 KiB/s, ETA 34w2d4h39m36s (xfr#25/879, chk#2580/11348)
2023/01/08 18:00:45 NOTICE:    69.230 GiB / 1.505 TiB, 4%, 71.214 KiB/s, ETA 35w5d18h49m8s (xfr#27/903, chk#2676/11348)
2023/01/08 18:20:45 NOTICE:    73.705 GiB / 1.610 TiB, 4%, 71.214 KiB/s, ETA 38w2d10h11m18s (xfr#29/961, chk#2756/11348)
2023/01/08 18:40:45 NOTICE:    78.303 GiB / 1.661 TiB, 5%, 71.214 KiB/s, ETA 39w3d10h16m53s (xfr#32/994, chk#2829/11348)
2023/01/08 19:00:45 NOTICE:    82.916 GiB / 1.764 TiB, 5%, 71.214 KiB/s, ETA 41w6d16h35m (xfr#39/1038, chk#2884/11348)
2023/01/08 19:20:45 NOTICE:    87.506 GiB / 1.897 TiB, 5%, 71.214 KiB/s, ETA 45w1d4h45m20s (xfr#39/1079, chk#2980/11348)
2023/01/08 19:40:45 NOTICE:    92.064 GiB / 1.973 TiB, 5%, 71.214 KiB/s, ETA 46w6d16h7m48s (xfr#39/1104, chk#3066/11348)
2023/01/08 20:00:45 NOTICE:    96.370 GiB / 2.076 TiB, 5%, 71.214 KiB/s, ETA 49w2d22h25m56s (xfr#40/1300, chk#3149/11348)
2023/01/08 20:20:45 NOTICE:   100.896 GiB / 2.175 TiB, 5%, 71.214 KiB/s, ETA 51w5d9h24m17s (xfr#44/1357, chk#3242/11348)
2023/01/08 20:40:45 NOTICE:   105.228 GiB / 2.295 TiB, 4%, 71.214 KiB/s, ETA 1y2w3d12h48m24s (xfr#46/1413, chk#3360/11348)
2023/01/08 21:00:45 NOTICE:   109.612 GiB / 2.414 TiB, 4%, 71.214 KiB/s, ETA 1y5w2d15h34m43s (xfr#50/1485, chk#3501/11348)
2023/01/08 21:20:45 NOTICE:   113.944 GiB / 2.536 TiB, 4%, 71.214 KiB/s, ETA 1y8w2d2h37m20s (xfr#54/1547, chk#3608/11348)
2023/01/08 21:40:45 NOTICE:   118.428 GiB / 2.669 TiB, 4%, 71.214 KiB/s, ETA 1y11w3d14h41m41s (xfr#57/1609, chk#3712/11348)
2023/01/08 22:00:45 NOTICE:   122.952 GiB / 2.807 TiB, 4%, 71.214 KiB/s, ETA 1y14w5d21h22m36s (xfr#58/1721, chk#3894/11348)
2023/01/08 22:20:45 NOTICE:   127.509 GiB / 2.921 TiB, 4%, 71.214 KiB/s, ETA 1y17w4d56m (xfr#59/1804, chk#3964/11348)

ncw · January 9, 2023, 8:42am

19wolf:

2023/01/08 12:20:45 NOTICE:   890.309 MiB / 2.383 GiB, 36%, 3.356 MiB/s, ETA 7m41s (chk#1174/11198)
2023/01/08 12:40:45 NOTICE:     3.700 GiB / 3.700 GiB, 100%, 71.214 KiB/s, ETA 0s (chk#1228/11252)

Looks like everything was working well at this point, then it ground to a halt.

I suggest you add -vv to see why. Its probably google drive rate limiting of some kind.

19wolf · January 9, 2023, 9:45pm

The thing is, the speed is wrong, it's not actually running that slowly. If you look at the data transferred on each line, it's about 5GiB every 20 minutes, which is about 4MiB/s.

ncw · January 10, 2023, 10:33am

I see what you mean now. That does look odd!

Can you try removing this and see what the full stats say?

Also running with -vv might be useful to see if anything funny is going on.

19wolf · January 11, 2023, 3:13am

Seems like it was just a one-off issue the new log looks fine (aside from the hundreds of debug lines telling me every. single. file. that wasn't synced)

ncw · January 11, 2023, 7:56am

Puzzling! So is this a bug with the one line stats only?

system · February 10, 2023, 7:57am

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