Systemd Shows Failed To Mount Some Backends

Help and Support
1

What is the problem you are having with rclone?

When I mount some of my HTTP backend they just go to background automatically. But some of them aren't. They just stay at the terminal. if I press "Ctrl+C" they just umount but for the background backends, I've to enter umount command to unmount.
The problem I'm facing is systemd service detects the background mounts as failed & restart the service. My log files are full with "Fatal error: Directory already mounted, use --allow-non-empty to mount anyway: /home/plex/SamFTP/English" only for the backends that are straight going to the background. But I've put the same command for both of them.
Note: I use those two for Plex & everything is working there it's just systemd goes crazy & my log files are filling up.

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

rclone v1.57.0

  • os/version: ubuntu 20.04 (64 bit)
  • os/kernel: 5.4.0-91-generic (x86_64)
  • os/type: linux
  • os/arch: amd64
  • go/version: go1.17.2
  • go/linking: static
  • go/tags: none

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

http

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

Here is a backend systemd service that DON'T go to background & systemd detects as active (running)

[Unit]
Description=RClone Documentary
After=network-online.target
Wants=network-online.target

[Service]
Type=notify
User=plex
Group=plex
ExecStart=/usr/bin/rclone mount Documentary: /home/plex/SamFTP/WebSeries/Documentary --allow-other --dir-cache-time 24h --log-file=/home/plex/Logs/Documentary.txt --poll-interval 10s --umask 002 --cache-dir=/home/plex/cache --vfs-cache-mode full --vfs-cache-max-size 50G --vfs-cache-max-age 720h --vfs-cache-poll-interval 5m --vfs-read-ahead 2G
ExecStop=/usr/bin/fusermount -uz /home/plex/SamFTP/WebSeries/Documentary
RestartSec=3
Restart=on-failure
KillMode=none

[Install]
WantedBy=multi-user.target

Here is a backend systemd service that GO to background & systemd detects as failed (Result: timeout)

● RafidrcloneEnglish.service - RClone English
     Loaded: loaded (/etc/systemd/system/RafidrcloneEnglish.service; enabled; vendor preset: enabled)
     Active: failed (Result: timeout) since Thu 2022-01-13 01:07:24 +06; 16min ago
   Main PID: 644
      Tasks: 12 (limit: 4399)
     Memory: 202.8M
     CGroup: /system.slice/RafidrcloneEnglish.service
             └─644 /usr/bin/rclone mount English: /home/plex/SamFTP/English --allow-other --dir-cache-time 24h --log-file=/home/plex/Logs/RcloneSamEnglish.txt --poll-interval 10s --umask 002 --cache-dir=/home/plex/cache --vfs-cache-mode full --vfs-cache-max-size 50G --vfs-cache-max-age 720h --vfs-cache-poll-interval 5m --vfs-read-ahead 2G

Jan 13 01:05:54 RAFIDsLabincMediaServer systemd[1]: Starting RClone English...
Jan 13 01:07:24 RAFIDsLabincMediaServer systemd[1]: RafidrcloneEnglish.service: start operation timed out. Terminating.
Jan 13 01:07:24 RAFIDsLabincMediaServer systemd[1]: RafidrcloneEnglish.service: Failed with result 'timeout'.
Jan 13 01:07:24 RAFIDsLabincMediaServer systemd[1]: Failed to start RClone English.
Jan 13 01:11:28 RAFIDsLabincMediaServer systemd[1]: RafidrcloneEnglish.service: Got notification message from PID 644, but reception only permitted for main PID which is currently not known
Jan 13 01:11:28 RAFIDsLabincMediaServer systemd[1]: RafidrcloneEnglish.service: Got notification message from PID 644, but reception only permitted for main PID which is currently not known
Jan 13 01:16:28 RAFIDsLabincMediaServer systemd[1]: RafidrcloneEnglish.service: Got notification message from PID 644, but reception only permitted for main PID which is currently not known
Jan 13 01:21:28 RAFIDsLabincMediaServer systemd[1]: RafidrcloneEnglish.service: Got notification message from PID 644, but reception only permitted for main PID which is currently not known

The rclone config contents with secrets removed.

For Documentary Backend that's working fine in systemd:

[Documentary]
type = http
url = http://172.16.50.8/SAM-FTP/Documentary/

For English Backend that's not working fine in systemd:

[English]
type = http
url = http://172.16.50.7/SAM-FTP-2/English%20Movies/

A log from the command with the -vv flag

Both of them produce an empty result. At first run with -vv both of them go to the background but after manually unmounting & rerun for both of them shows no log in the terminal. They are just blank but they don't go to the background.

plex@RAFIDsLabincMediaServer:~/Scripts$ rclone mount English: /home/plex/SamFTP/English --allow-other --dir-cache-time 24h --log-file=/home/plex/Logs/RcloneSamEnglish.txt --poll-interval 10s --umask 002 --cache-dir=/home/plex/cache --vfs-cache-mode full --vfs-cache-max-size 50G --vfs-cache-max-age 720h --vfs-cache-poll-interval 5m --vfs-read-ahead 2G -vv



rclone mount Documentary: /home/plex/SamFTP/WebSeries/Documentary --allow-other --dir-cache-time 24h --log-file=/home/plex/Logs/Documentary.txt --poll-interval 10s --umask 002 --cache-dir=/home/plex/cache --vfs-cache-mode full --vfs-cache-max-size 50G --vfs-cache-max-age 720h --vfs-cache-poll-interval 5m --vfs-read-ahead 2G -vv
2

If the logs have:

That means there are contents in the location you are trying to mount to.

Make sure it's empty before you mount.

Pick one service file.
Change the log level to DEBUG
Reload systemd
Start the service
Share the journalctl output and the full debug log file if it fails.

Sounds like it's already got stuff there so you see it retrying over and over until it exits from failures.

3

journalctl output:

plex@RAFIDsLabincMediaServer:~/Logs$ sudo journalctl -u RcloneSamEnglish.service
-- Logs begin at Mon 2022-01-10 13:54:18 +06, end at Thu 2022-01-13 13:05:08 +06. --
-- No entries --

systemctl status:

● RafidrcloneEnglish.service - RClone English
     Loaded: loaded (/etc/systemd/system/RafidrcloneEnglish.service; enabled; vendor preset: enabled)
     Active: activating (start) since Thu 2022-01-13 12:57:15 +06; 66ms ago
   Main PID: 8197 (rclone)
      Tasks: 15 (limit: 4399)
     Memory: 190.1M
     CGroup: /system.slice/RafidrcloneEnglish.service
             ├─5939 /usr/bin/rclone mount English: /home/plex/SamFTP/English --allow-other --dir-cache-time 24h --log-file=/home/plex/Logs/RcloneSamEnglishTEST.txt --log-level DEBUG --poll-interval 10s --umask 002 --cache-dir=/home/plex/cache --vfs-cache-mode full --vfs-cache-max-size 50G --vfs-cache-max-age 720h --vfs-cache-poll-interval 5m --vfs-read-ahead 2G
             └─8197 /usr/bin/rclone mount English: /home/plex/SamFTP/English --allow-other --dir-cache-time 24h --log-file=/home/plex/Logs/RcloneSamEnglishTEST.txt --log-level DEBUG --poll-interval 10s --umask 002 --cache-dir=/home/plex/cache --vfs-cache-mode full --vfs-cache-max-size 50G --vfs-cache-max-age 720h --vfs-cache-poll-interval 5m --vfs-read-ahead 2G

Jan 13 12:57:15 RAFIDsLabincMediaServer systemd[1]: Stopped RClone English.
Jan 13 12:57:15 RAFIDsLabincMediaServer systemd[1]: RafidrcloneEnglish.service: Found left-over process 5939 (rclone) in control group while starting unit. Ignoring.
Jan 13 12:57:15 RAFIDsLabincMediaServer systemd[1]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
Jan 13 12:57:15 RAFIDsLabincMediaServer systemd[1]: Starting RClone English...
Jan 13 12:57:15 RAFIDsLabincMediaServer systemd[1]: RafidrcloneEnglish.service: Main process exited, code=exited, status=1/FAILURE
Jan 13 12:57:15 RAFIDsLabincMediaServer systemd[1]: RafidrcloneEnglish.service: Failed with result 'exit-code'.
Jan 13 12:57:15 RAFIDsLabincMediaServer systemd[1]: Failed to start RClone English.

Debug file output:

https://upload.rafid.cf/RcloneSamEnglishhTEST.txt
https://drive.google.com/file/d/1y7GjzDQ7Bnvxh0o6bTK6EEi1-HwVsYWs/view?usp=sharing
https://drive.rafid.cf/0:/tmp/RcloneSamEnglishhTEST.txt
https://drive.rafid.cf/0:/tmp/RcloneSamEnglishhTEST.zip

Same file just uploaded in 4 different forms. File size is more than 5M

4

On the log you shared, the mount is already running when systemd tries to start it.

2022/01/13 12:56:59 DEBUG : : Statfs: 
2022/01/13 12:56:59 DEBUG : : >Statfs: stat={Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>
2022/01/13 12:56:59 DEBUG : rclone: Version "v1.57.0" starting with parameters ["/usr/bin/rclone" "mount" "English:" "/home/plex/SamFTP/English" "--allow-other" "--dir-cache-time" "24h" "--log-file=/home/plex/Logs/RcloneSamEnglishTEST.txt" "--log-level" "DEBUG" "--poll-interval" "10s" "--umask" "002" "--cache-dir=/home/plex/cache" "--vfs-cache-mode" "full" "--vfs-cache-max-size" "50G" "--vfs-cache-max-age" "720h" "--vfs-cache-poll-interval" "5m" "--vfs-read-ahead" "2G"]
2022/01/13 12:56:59 DEBUG : Creating backend with remote "English:"
2022/01/13 12:56:59 DEBUG : Using config file from "/home/plex/.config/rclone/rclone.conf"
2022/01/13 12:56:59 Fatal error: Directory already mounted, use --allow-non-empty to mount anyway: /home/plex/SamFTP/English
2022/01/13 12:57:00 DEBUG : : Statfs:

You need to ensure everything is stopped, no rclone processes are running and start it up with systemd.

I'd blank out the log once you validate everything is stopped.

5

That's the problem I'm saying. It shows the directory is already mounted & that's correct too. Plex working fine. The main problem is systemd. It thinks the process failed & again try to mount.
In my research I found out something interesting:

  1. If I restart my server systemd go crazy, It thinks the process failed & again try to mount. But it's mounted already.
  2. If I manually type "sudo systemctl stop service-name.service" & then again type "sudo systemctl start service-name.service" then systemd shows the process is running fine.
  3. Sometimes issuing "sudo systemctl stop service-name.service" never unmount the directory. I can still see the files, then I've to type "umount /MyDirectory/Where/ItsMounted" then it unmounts. But sometimes systemd successfully stop it & unmount.

I never said it's not mounted. It's mounted & working fine on Plex but systemd shows failed & restart the service. Because of this now I've to remove the following lines on the service file to stop systemd from restarting the service:

RestartSec=3
Restart=on-failure
6

That most likely means you have another service starting early, writing files to your mounted location, which hits the empty issue so you'd have to identify what's writing there.

Unknown as you've only shared logs that show a problem. I can't see your screen or what you type so you share logs and detail what you've tested.

Well, sure. You can't umount a file system that's in use on Linux. If you try to, it'll never unmount. You have to stop all IO/processes on the mount first before you want to unmount it.

Utilities like lsof as root can you what is running against a mount and fuser as well.

Those lines make things worse. The way systemd works is if you can't stop a service after a period of time, it kills the service which leaves the mount in a non working state.

For mounts, you have to stop all IO/processes and then unmount.
When you boot, you want to make sure your dependencies are configured properly so they don't start until after your mount is there if you are writing data to your rclone mounts.

7

Just curious, I use the following script to check whether the directory is empty or not. My ISP has an HTTP server from where I fetch my contents through Rclone & they change the HTTP directory link often. So I use this script to check every 10 minutes. Can this cause the problem ?

#!/bin/sh
FILE=""
DIR="$1"
# init
# look for empty dira
if [ -d "$DIR" ]
then
	if [ "$(ls -A $DIR)" ]; then
     echo "$DIR is NOT Empty Everything Is Fine"
	else
    curl --data chat_id="123456789" --data-urlencode "text=Attention <b>$DIR</b> Is EMPTY" "https://api.telegram.org/BotToken/sendMessage?parse_mode=HTML"
	fi
else
	curl --data chat_id="123456789" --data-urlencode "text=Attention <b>$DIR</b> NOT FOUND" "https://api.telegram.org/BotToken/sendMessage?parse_mode=HTML"
fi
8

Here is another thing I like to report. I use rclone & mount many directories. Backend is same HTTP & service file is same too. Only some of them causing this issue. But others shows running & working fine. Systemd shows them running too.

9

You could have 1 mount or 1000 mounts. If scripts/applications/etc are writing to a mount, it'll have a problem mounting and stopping.

If you check the mount that has the problem, look in the mount location and see if you can figure out what is writing there.

Until you can diagnose that item, there's not much systemd can do as it'll continue to fail and restart until it errors out.

I use proper requires in my services to make sure anything that needs my mounts does not start and is the service for them is required.

So plex as an example has an override for:

After=rclone.service
Requires=rclone.service

As an example so if rclone stops, plex stops based on the requirements.

10

I've checked but found nothing is writing on that directory. After removing RestartSec=3 Restart=on-failure from service file If I do "systemctl status Service-Name.service" it shows this:

● RafidrcloneAnimationSeries.service - RClone Animation Series
     Loaded: loaded (/etc/systemd/system/RafidrcloneAnimationSeries.service; enabled; vendor preset: enabled)
     Active: failed (Result: timeout) since Thu 2022-01-13 12:45:00 +06; 8h ago
   Main PID: 642
      Tasks: 12 (limit: 4399)
     Memory: 71.0M
     CGroup: /system.slice/RafidrcloneAnimationSeries.service
             └─642 /usr/bin/rclone mount AnimationSeries: /home/plex/SamFTP/AnimationSeries --allow-other --dir-cache-time 24h --log-file=/home/plex/Logs/RcloneSamAnimationSeries.txt --poll-interval 10s --umask 002 --cache-dir=/home/plex/cache --vfs-cache-mode full --vfs-cache-max-size 50G --vfs-cache-max-age 720h --vfs-cache-poll-interval 5m --vfs-read-ahead 2G

Jan 13 20:15:20 RAFIDsLabincMediaServer systemd[1]: RafidrcloneAnimationSeries.service: Got notification message from PID 642, but reception only permitted for main PID which is currently not known
Jan 13 20:20:20 RAFIDsLabincMediaServer systemd[1]: RafidrcloneAnimationSeries.service: Got notification message from PID 642, but reception only permitted for main PID which is currently not known
Jan 13 20:25:20 RAFIDsLabincMediaServer systemd[1]: RafidrcloneAnimationSeries.service: Got notification message from PID 642, but reception only permitted for main PID which is currently not known
Jan 13 20:30:20 RAFIDsLabincMediaServer systemd[1]: RafidrcloneAnimationSeries.service: Got notification message from PID 642, but reception only permitted for main PID which is currently not known
Jan 13 20:35:20 RAFIDsLabincMediaServer systemd[1]: RafidrcloneAnimationSeries.service: Got notification message from PID 642, but reception only permitted for main PID which is currently not known
Jan 13 20:40:20 RAFIDsLabincMediaServer systemd[1]: RafidrcloneAnimationSeries.service: Got notification message from PID 642, but reception only permitted for main PID which is currently not known
Jan 13 20:45:20 RAFIDsLabincMediaServer systemd[1]: RafidrcloneAnimationSeries.service: Got notification message from PID 642, but reception only permitted for main PID which is currently not known
Jan 13 20:50:20 RAFIDsLabincMediaServer systemd[1]: RafidrcloneAnimationSeries.service: Got notification message from PID 642, but reception only permitted for main PID which is currently not known
Jan 13 20:55:20 RAFIDsLabincMediaServer systemd[1]: RafidrcloneAnimationSeries.service: Got notification message from PID 642, but reception only permitted for main PID which is currently not known
Jan 13 21:00:20 RAFIDsLabincMediaServer systemd[1]: RafidrcloneAnimationSeries.service: Got notification message from PID 642, but reception only permitted for main PID which is currently not known

Again the directory is mounted & everything is working fine !!

11

I can't see your service file.

You need to start from a quiet system.
Make sure no rclone is running.
Pick one item.
Test that item.

Share all the required information about that service.

  • the service file
  • the journalctl output
  • the ps -ef | grep rclone on the system
  • the debug log for the service
12

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