Slow boot when running rclone systemd service

Help and Support
1

What is the problem you are having with rclone?

I use rclone with both my work computer and personal computer in order to synchronize my Google Drive. I do this by using a systemd service on both machines. It works fine except for one issue: boot times on both machines are extremely slow (about 3 minutes). Help diagnosing this issue as well as possible solutions would be greatly appreciated (more so if instructions are extra clear, as I am not very experienced).

Here are some more details:

  • Both machines are similar: Ubuntu 22.03, 16GiB memory, Intel Core i7 with 512GB of disk capacity.

  • The Google Drive is about 25GB

Here are some more symptoms:

  • When I disable the systemd service, boot time becomes again normal on both machines.

  • When I turn off WiFi before rebooting, boot time becomes normal. I turn on WiFi after reboot, but Files app is nonresponsive for a few minutes. When it becomes responsive again everything works as normal.

  • From the output of systemd-analyze you would not thing there is a problem; it returns:

Startup finished in 5.283s (kernel) + 5.790s (userspace) = 11.074s 
graphical.target reached after 5.740s in userspace

Finally, here is a copy of my systemd service file:

[Unit]
Description=rclone-GDrive
AssertPathIsDirectory=/home/monQuee/rclone-GDrive
Wants=network-online.target
After=network-online.target


[Service]
User=monQuee
Group=monQuee
Type=notify
ExecStart=/usr/bin/rclone  \
        --config=/home/monQuee/.config/rclone/rclone.conf \
        --vfs-cache-mode full \
	--vfs-cache-max-size 250G mount GDrive: /home/monQuee/rclone-GDrive
ExecStop=/bin/fusermount -u /home/monQuee/rclone-GDrive
Restart=always
RestartSec=10

[Install]
WantedBy=default.target

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

Same on both machines:

rclone v1.65.1
- os/version: ubuntu 22.04 (64 bit)
- os/kernel: 6.5.0-14-generic (x86_64)
- os/type: linux
- os/arch: amd64
- go/version: go1.21.5
- 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)

Does not apply

Please run 'rclone config redacted' and share the full output. If you get command not found, please make sure to update rclone.

On one machine I have:

[GDrive]
type = drive
client_id = XXX
client_secret = XXX
scope = drive
use_trash = false
metadata_permissions = read,write
metadata_labels = read,write
token = XXX
team_drive =

On the other I have:

[GDrive]
type = drive
client_id = XXX
client_secret = XXX
scope = drive
token = XXX
team_drive =

A log from the command that you were trying to run with the -vv flag

Does not apply
2

Try to add --vfs-fast-fingerprint flag to your mount command:

ExecStart=/usr/bin/rclone  \
	mount GDrive: /home/monQuee/rclone-GDrive \
	--config=/home/monQuee/.config/rclone/rclone.conf \
	--vfs-cache-mode full \
	--vfs-cache-max-size 250G \
	--vfs-fast-fingerprint

It will shorten time needed to validate existing cache by faster fingerprinting

1 Like
3

Thanks for this suggestion, but this did not have any noticeable effect.

A few more comments:

  • Your suggested systemd file returned an error; my guess is that --vfs-fast-fingerprint wants an input (ran into a similar issue before; see my first reply here). However, vfs-fast-fingerprint=true works. The updated systemd file is below.

  • After editing the systemd file, I ran:

systemctl stop rclone-GDrive.service
systemctl disable rclone-GDrive.service
systemctl daemon-reload
systemctl enable rclone-GDrive.service
systemctl start rclone-GDrive.service

  • Running systemctl status rclone-GDrive.service says the service is active with no apparent issues.

  • New systemd file:

[Unit]
Description=rclone-GDrive
AssertPathIsDirectory=/home/monQuee/rclone-GDrive
Wants=network-online.target
After=network-online.target


[Service]
User=monQuee
Group=monQuee
Type=notify
ExecStart=/usr/bin/rclone  \
        --config=/home/monQuee/.config/rclone/rclone.conf \
        --vfs-cache-mode full \
	--vfs-cache-max-size 250G \
	--vfs-fast-fingerprint=true \
	mount GDrive: /home/monQuee/rclone-GDrive
ExecStop=/bin/fusermount -u /home/monQuee/rclone-GDrive
Restart=always
RestartSec=10

[Install]
WantedBy=default.target
4

This is weird.... I use it too and --vfs-fast-fingerprint is enough.
Are you sure that /usr/bin/rclone is the latest version?

This is excessive:)

It is enough to run:

sudo systemctl daemon-reload
sudo systemctl restart rclone-GDrive.service
2 Likes
5

I think so: at least /usr/bin/rclone version returns rclone v1.65.1. Running the systemd file with just --vfs-fast-fingerprint gives an error after systemctl restart rclone-GDrive.service; namely Fatal error: unknown command "GDrive:" for "rclone" (which is why I thought that --vfs-fast-fingerprint eats mount as an input and then doesn't know what to do with GDrive:).

On the slow boot issue: I noticed another weird behavior. It seems like turning the machine off and then immediately back on while the rclone systemd service is active does not cause a slow boot. It is only when the machine is off for a while that the slow boot comes back (I first noticed this when turning the machine on in the morning).

6

Might be one of this issues that are never resolved as are not serious enough to justify spending long time investigating. 3 minutes delay when you start machine in the morning is not really show stopper.

Maybe one day you will have eureka and find out what it was:)

1 Like
7

It's generally in the log file as to the reason why.

Full mode requires checking the check against the remote and depending on the number of files in the cache, it can take some time to start.

That's the main reason we request a log file as it is generally easy to figure out.

1 Like
8

Thanks for this reply; it hadn't occurred to me that I could obtain a log file even when running from systemd service. I attach a portion of the log.
rclone-slowboot.txt (1.4 MB)
It is full of things that look like this:

2024/01/27 11:07:20 DEBUG : .Trash-1000/info/: Attr: 
2024/01/27 11:07:20 DEBUG : .Trash-1000/info/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2024/01/27 11:07:20 DEBUG : .Trash-1000/info/: Lookup: name="monquee qint - F2021.trashinfo"
2024/01/27 11:07:20 DEBUG : .Trash-1000/info/: >Lookup: node=.Trash-1000/info/monquee qint - F2021.trashinfo, err=<nil>
2024/01/27 11:07:20 DEBUG : .Trash-1000/info/monquee qint - F2021.trashinfo: Attr: 
2024/01/27 11:07:20 DEBUG : .Trash-1000/info/monquee qint - F2021.trashinfo: >Attr: a=valid=1s ino=0 size=116 mode=-rw-r--r--, err=<nil>
2024/01/27 11:07:20 DEBUG : .Trash-1000/info/monquee qint - F2021.trashinfo: Open: flags=OpenReadOnly
2024/01/27 11:07:20 DEBUG : .Trash-1000/info/monquee qint - F2021.trashinfo: Open: flags=O_RDONLY
2024/01/27 11:07:20 DEBUG : .Trash-1000/info/monquee qint - F2021.trashinfo: newRWFileHandle: 
2024/01/27 11:07:20 DEBUG : .Trash-1000/info/monquee qint - F2021.trashinfo: >newRWFileHandle: err=<nil>
2024/01/27 11:07:20 DEBUG : .Trash-1000/info/monquee qint - F2021.trashinfo: >Open: fd=.Trash-1000/info/monquee qint - F2021.trashinfo (rw), err=<nil>
2024/01/27 11:07:20 DEBUG : .Trash-1000/info/monquee qint - F2021.trashinfo: >Open: fh=&{.Trash-1000/info/monquee qint - F2021.trashinfo (rw)}, err=<nil>

Of course, I am guessing that Trash is the issue. Any ideas what specifically could be going wrong, and how to fix them?

9

Looks like a normal startup:

2024/01/27 11:06:55 DEBUG : rclone: Version "v1.65.1" starting with parameters ["/usr/bin/rclone" "--config=/home/monquee/.config/rclone/rclone.conf" "--vfs-cache-mode" "full" "--vfs-cache-max-size" "250G" "--vfs-fast-fingerprint=true" "--log-file=/home/monquee/rclone-log.txt" "--log-level" "DEBUG" "mount" "GDrive:" "/home/monquee/rclone-GDrive"]
2024/01/27 11:06:55 DEBUG : Creating backend with remote "GDrive:"
2024/01/27 11:06:55 DEBUG : Using config file from "/home/monquee/.config/rclone/rclone.conf"
2024/01/27 11:06:55 DEBUG : GDrive: Loaded invalid token from config file - ignoring
2024/01/27 11:06:56 DEBUG : Saving config "token" in section "GDrive" of the config file
2024/01/27 11:06:56 DEBUG : Keeping previous permissions for config file: -rw-rw----
2024/01/27 11:06:56 DEBUG : GDrive: Saved new token in config file
2024/01/27 11:06:56 DEBUG : Google drive root '': 'root_folder_id = 0ADTqzZHzAjaRUk9PVA' - save this in the config to speed up startup
2024/01/27 11:06:56 DEBUG : vfs cache: root is "/home/monquee/.cache/rclone"
2024/01/27 11:06:56 DEBUG : vfs cache: data root is "/home/monquee/.cache/rclone/vfs/GDrive"
2024/01/27 11:06:56 DEBUG : vfs cache: metadata root is "/home/monquee/.cache/rclone/vfsMeta/GDrive"
2024/01/27 11:06:56 DEBUG : Creating backend with remote "/home/monquee/.cache/rclone/vfs/GDrive/"
2024/01/27 11:06:56 DEBUG : fs cache: renaming cache item "/home/monquee/.cache/rclone/vfs/GDrive/" to be canonical "/home/monquee/.cache/rclone/vfs/GDrive"
2024/01/27 11:06:56 DEBUG : Creating backend with remote "/home/monquee/.cache/rclone/vfsMeta/GDrive/"
2024/01/27 11:06:56 DEBUG : fs cache: renaming cache item "/home/monquee/.cache/rclone/vfsMeta/GDrive/" to be canonical "/home/monquee/.cache/rclone/vfsMeta/GDrive"
2024/01/27 11:06:56 DEBUG : removing 2 level 2 directories
2024/01/27 11:06:56 INFO  : Math/pluspts: Removing directory
2024/01/27 11:06:56 INFO  : .Trash-1000/info: Removing directory
2024/01/27 11:06:56 DEBUG : removing 2 level 1 directories
2024/01/27 11:06:56 INFO  : Math: Removing directory
2024/01/27 11:06:56 INFO  : .Trash-1000: Removing directory
2024/01/27 11:06:56 DEBUG : removing 2 level 2 directories
2024/01/27 11:06:56 INFO  : Math/pluspts: Removing directory
2024/01/27 11:06:56 INFO  : .Trash-1000/info: Removing directory
2024/01/27 11:06:56 DEBUG : removing 2 level 1 directories
2024/01/27 11:06:56 INFO  : Math: Removing directory
2024/01/27 11:06:56 INFO  : .Trash-1000: Removing directory
2024/01/27 11:06:56 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2024/01/27 11:06:56 DEBUG : Google drive root '': Mounting on "/home/monquee/rclone-GDrive"
2024/01/27 11:06:56 DEBUG : : Root:

That's a few seconds. What is the concern?

10

It is not good idea to put Thrash on rclone mount - I would disable it.

11

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