Mergerfs local and google crypt mount randomly disconnects

Help and Support
1

What is the problem you are having with rclone?

I have a crypt remote from google drive and a local path in a mergerfs pool mounted from a single bash script.

I use the pool as a library path in Plex.

It works most of the time, but occasionally the mounts disappear. I have a Scheduled Task every 10 mins that runs the mount.sh and basically looks for a file and remounts if it is not there.

I would like to figure out why it's dropping, instead of running this bandaid script but I can't find anything in the logs for rclone, and I haven't found a way to log mergerfs.

What is your rclone version (output from rclone version)

rclone v1.52.3

Which OS you are using and how many bits (eg Windows 7, 64 bit)

synololgy ds1019- bit

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)

rclone --config $CONFIG mount $REMOTE $MOUNTPT  \
                --allow-other \
                --dir-cache-time 1000h \
                --log-level INFO \
                --log-file $LOGGDRIVE \
                --poll-interval 15s \
                --umask 002 \
                --user-agent animosityapp \
                --rc \
                --rc-addr :5572 \
                --vfs-read-chunk-size 32M \
                --file-perms 0775 &

mergerfs $LOCAL:$MOUNTPT $POOL \
     -o defaults,fsname=encrypted_pool,allow_other \
     -o moveonenospc=true,category.create=ff,func.getattr=newest &

The rclone config contents with secrets removed.

[gdrive]
type = drive
client_id = ***************
client_secret = ***************
scope = drive
root_folder_id = ***************
token = ***************

[gcrypt]
type = crypt
remote = gdrive:crypt
filename_encryption = standard
directory_name_encryption = true
password = ***************
password2 = ***************

A log from the command with the -vv flag

I used --log-level INFO
this is the only error

2020/08/30 04:48:37 NOTICE: Serving remote control on http://[::]:5572/
2020/08/30 04:53:47 Failed to start remote control: start server failed: listen tcp :5572: bind: address already in use
2020/08/30 04:54:25 Failed to start remote control: start server failed: listen tcp :5572: bind: address already in use
2020/08/30 04:55:16 NOTICE: Serving remote control on http://[::]:5572/
2020/08/30 07:06:41 NOTICE: Serving remote control on http://[::]:5572/
2

That log means you already have an rclone running an --rc

There can be only one on a given port.

You can set the port with --rc-addr localhost:12345

Or it might mean a previous rclone is still running.

3

thanks for the info. I don't use the --rc, i guess it was part of the script I reference when I set this up. but is this related to the mount dropping?

4

From the log you posted, there isn't anything rclone related that seems to be any issue at all.

I'm not as familiar with the Synology. How are you starting it and stopping it? It looks like something is killing rclone I'd imagine if you are seeing it stopped.

When you say disconnected, you log and there is no rclone running anymore?

5

It's a bash script, running as a Task in the Task Scheduler. I don't usually need to unmount, but if I do I just run fusermount -uz.

The script checks for the points in /proc/mounts and also for mountcheck files in the paths (gcrypt and mergerfs pool).

If mounted, but the files aren't there it will unmount and mount again. If both are there for each mount, it doesn't do anything. I have this set to run every 10 mins.

if [[ -f "$MOUNTPT/$CHECKFILE" ]] && [[ -f "$POOL/$CHECKFILE" ]]
then
    echo "$(date "+%d.%m.%Y %T") INFO: $REMOTE and $POOL are already mounted, exiting"
    echo "$(date "+%d.%m.%Y %T") INFO: ------- done, exiting --------------- "
    exit 0
else
    echo "$(date "+%d.%m.%Y %T") INFO: mountcheck failed "
    if grep "$MOUNTPT" /proc/mounts
    then
        echo "$(date "+%d.%m.%Y %T") INFO: $REMOTE is mounted incorrectly, unmounting..."
        fusermount -uz $MOUNTPT
    fi
    echo "$(date "+%d.%m.%Y %T") INFO: mounting..."
    rclone --config $CONFIG mount $REMOTE $MOUNTPT  \
...

I notice the mount dissappears when I am watching something from the pool in Plex. Other than that, this seems to work for me. Just would be cool to figure out why it's dropping.

Thanks for taking a look.

6

If you run the mount in debug log and store a log file:

-vv --log-file /tmp/rclone.log

If rclone is crashing or stopping, you'd see something in there.

If something else is killing rclone, you would not see though though.

I run a Linux OS so I use systemd and it's a bit easier to track.

7

thank you, think this is just want i was looking for. I will add it and keep my eye on it for a while.

I had --log-level: INFO before, didn't realize i could swap that for -vv and still log to a file.

Yes, how I miss system :frowning: but Synology's DSM distro doesn't support it. I use my Intel NUC running Ubuntu 20.04 when I want more flexibility.

8

So, I've added -vv and noticed the mount dropped again tonight. Here is what I found in the logs:

I don't think this is related, it's about 8 hours before the drive discounts. Just mentioning it in case:

2020/09/08 16:19:48 DEBUG : Google drive root 'crypt': Checking for changes on remote
2020/09/08 16:20:03 DEBUG : Google drive root 'crypt': Checking for changes on remote
2020/09/08 16:20:15 DEBUG : /: Attr:
2020/09/08 16:20:15 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2020/09/08 16:20:18 DEBUG : Google drive root 'crypt': Checking for changes on remote
2020/09/08 16:20:33 DEBUG : Google drive root 'crypt': Checking for changes on remote

At some point, it had to get a new token (didn't know it did that, that's pretty cool)...

2020/09/08 16:21:03 DEBUG : gdrive: Loaded invalid token from config file - ignoring
2020/09/08 16:21:03 DEBUG : Keeping previous permissions for config file: -rw-rw----
2020/09/08 16:21:03 DEBUG : gdrive: Saved new token in config file
2020/09/08 16:21:18 DEBUG : Google drive root 'crypt': Checking for changes on remote
2020/09/08 16:21:33 DEBUG : Google drive root 'crypt': Checking for changes on remote
2020/09/08 16:21:48 DEBUG : Google drive root 'crypt': Checking for changes on remote

Looks like it stopped working at 2020/09/08 16:29:33, but no error shown. The rest of the log is from me manually running the mount script to remount the drive:


2020/09/08 16:29:18 DEBUG : Google drive root 'crypt': Checking for changes on remote
2020/09/08 16:29:33 DEBUG : Google drive root 'crypt': Checking for changes on remote
2020/09/09 00:02:27 DEBUG : rclone: Version "v1.52.3" starting with parameters ["rclone" "--config" "/volume1/GD/config/rclone.conf" "mount" "gcrypt:" "/volume1/GD/gcrypt" "--allow-other" "--dir-cache-time" "1000h" "-vv" "--log-file" "/volume1/GD/logs/mount-gdrive.log" "--poll-interval" "15s" "--umask" "002" "--user-agent" "animosityapp" "--rc" "--rc-addr" ":5572" "--vfs-read-chunk-size" "32M" "--file-perms" "0775"]
2020/09/09 00:02:27 NOTICE: Serving remote control on http://[::]:5572/
2020/09/09 00:02:27 DEBUG : Using config file from "/volume1/GD/config/rclone.conf"
2020/09/09 00:02:28 DEBUG : Encrypted drive 'gcrypt:': Mounting on "/volume1/GD/gcrypt"
2020/09/09 00:02:28 DEBUG : Adding path "vfs/forget" to remote control registry
2020/09/09 00:02:28 DEBUG : Adding path "vfs/refresh" to remote control registry
2020/09/09 00:02:28 DEBUG : Adding path "vfs/poll-interval" to remote control registry
2020/09/09 00:02:28 DEBUG : : Root:
2020/09/09 00:02:28 DEBUG : : >Root: node=/, err=<nil>
2020/09/09 00:02:29 DEBUG : /: Lookup: name="mountcheck"
2020/09/09 00:02:29 DEBUG : /: >Lookup: node=mountcheck, err=<nil>
2020/09/09 00:02:29 DEBUG : mountcheck: Attr:
2020/09/09 00:02:29 DEBUG : mountcheck: >Attr: a=valid=1s ino=0 size=0 mode=-rwxrwxr-x, err=<nil>
2020/09/09 00:02:29 DEBUG : /: Attr:
2020/09/09 00:02:29 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2020/09/09 00:02:31 DEBUG : /: Attr:
2020/09/09 00:02:31 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2020/09/09 00:02:31 DEBUG : /: Lookup: name="mountcheck"
2020/09/09 00:02:31 DEBUG : /: >Lookup: node=mountcheck, err=<nil>
2020/09/09 00:02:31 DEBUG : mountcheck: Attr:
2020/09/09 00:02:31 DEBUG : mountcheck: >Attr: a=valid=1s ino=0 size=0 mode=-rwxrwxr-x, err=<nil>
2020/09/09 00:02:43 DEBUG : Google drive root 'crypt': Checking for changes on remote

I did try uploading a file with a separate rcllone command while it was mounted, but I don't think it was at the same time the mount dropped.

I also got an API ban, but again, that was about 8 hours later.

9

If there is nothing in the rclone, that usually points to something else killing the rclone process as nothing is logged in rclone. On the Linux side, that's systemd, I'm not sure what to advise to check on your setup though as I'm not familiar with how the Synology works.

You mean you hit an upload or download quota? You really don't get banned from Google unless you have content that infringes against their ToS.

10

It was an upload limit, I thought that was considered a 24 hour ban?

2020/09/07 15:53:02 ERROR : Clue.The.Movie.1985.MULTi.COMPLETE.BLURAY/BDMV/JAR/88890.jar: Failed to copy: googleapi: Error 403: User rate limit exceeded., userRateLimitExceeded
11

Nope, that's not a ban as that's just hitting the quota limit for the day.

12

I wondered, since it usually doesn't last 24 hours when this happens.

I'm gonna mark this solved, thank you for your help and sharing the knowledge :smiley:

13

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