Rclone cache remote gets unmounted and can't be remounted without reboot. How to resolve it?

Help and Support
1

This is my rclone command:

sudo rclone mount --allow-other -vvv --dir-cache-time=168h --log-file=/home/tito/rclone-cache.log --cache-workers=4 --cache-db-path=/home/tito/rclone_cache --cache-tmp-upload-path=/home/tito/rclone_tmp_upload --cache-tmp-wait-time=15m --attr-timeout=1s --rc --cache-info-age=168h --vfs-cache-mode writes gdrivecache: /mnt/gdrivenoenc

For some reason it randomly tends to get unmounted after some minutes/hours.
If I execute the command again it fails to mount the remote and this is what I see in the log:

2018/08/22 22:15:48 DEBUG : Using config file from "/root/.config/rclone/rclone.conf"
2018/08/22 22:15:48 NOTICE: Serving remote control on http://127.0.0.1:5572/
2018/08/22 22:15:48 DEBUG : gdrivecache: wrapped eduaccount_foro1: at root 
2018/08/22 22:15:49 INFO  : gdrivecache: Cache DB path: /home/tito/rclone_cache/gdrivecache.db
2018/08/22 22:15:49 INFO  : gdrivecache: Cache chunk path: /home/tito/rclone_cache/gdrivecache
2018/08/22 22:15:49 INFO  : gdrivecache: Chunk Memory: true
2018/08/22 22:15:49 INFO  : gdrivecache: Chunk Size: 10M
2018/08/22 22:15:49 INFO  : gdrivecache: Chunk Total Size: 64G
2018/08/22 22:15:49 INFO  : gdrivecache: Chunk Clean Interval: 1m0s
2018/08/22 22:15:49 INFO  : gdrivecache: Workers: 4
2018/08/22 22:15:49 INFO  : gdrivecache: File Age: 168h0m0s
2018/08/22 22:15:49 INFO  : gdrivecache: Upload Temp Rest Time: 15m0s
2018/08/22 22:15:49 INFO  : gdrivecache: Upload Temp FS: /home/tito/rclone_tmp_upload
2018/08/22 22:15:49 DEBUG : Adding path "cache/expire" to remote control registry
2018/08/22 22:15:49 DEBUG : Adding path "cache/stats" to remote control registry
2018/08/22 22:15:49 Fatal error: Can not open: /home/tito/gdrivenoenc: open /home/tito/gdrivenoenc: transport endpoint is not connected

How can I fix it? The only way I find out is rebooting the server and running the command again, but obviously that’s not fix really.

PS: I won’t run rclone as sudo anymore as I noticed that it was saving lot of GB’s to my /root/ folder and causing it to be full as my /root/ folder is only 20GB

2

Hmm, not sure… What does it say in the log when it unmounts?

Can you try the latest beta too?

3

You’d have to check if something still has a file / directory opened and you can do a:

fusermount -uz /mountpoint to clear it and check if any rclone is running.

root@gemini:~ ps -ef | grep rclone
felix      603     1  0 11:30 ?        00:00:15 /usr/bin/rclone mount gcrypt: /GD --allow-other --dir-cache-time 72h --buffer-size 1G --vfs-read-chunk-size 64M --vfs-read-chunk-size-limit off --umask 002 --bind 192.168.1.30 --log-level DEBUG --log-file /home/felix/logs/rclone.log

You can check by using lsof as root to see if something has a file open which is preventing the unmount:

root@gemini:~ lsof /mountpoint for rclone

4

Thanks for the replies.

During the last 5 days it didn’t get unmounted so I can’t provide any logs that would show why I couldn’t remount the drive after it gets unmounted.

However, can anyone help me what would be the best way to get the remote remounted in case it gets unmounted for some reason.

Currently I only have the command that I wrote in the OP added to crontab to get the command running 30 seconds after the server has been switched on.

5

I think using systemd works quite well for this. There are some notes on the rclone wiki about this: https://github.com/ncw/rclone/wiki/rclone-fstab-mount-helper-script#systemd

6

I’m not sure the .mount options allow for failure restarting though from what I was checking on.

I do this for mine now, although, I’ve honestly never had it crash:

root@gemini:/etc/systemd/system cat gmedia-rclone.service
[Unit]
Description=RClone Service
PartOf=gmedia.service
RequiresMountsFor=/data

# This uses cmount as it's a built version of rclone from source
# sync_read must be used or files are read out of order
# auto_cache allows for system memory to be used

[Service]
Type=notify
Environment=RCLONE_CONFIG=/data/rclone/rclone.conf
ExecStart=/usr/bin/rclone mount gcrypt: /data/mounts/rclone \
   --allow-other \
   --dir-cache-time 72h \
   --buffer-size 1G \
   --vfs-read-chunk-size 128M \
   --vfs-read-chunk-size-limit off \
   --umask 002 \
   --bind 192.168.1.30 \
   --log-level INFO \
   --log-file /home/felix/logs/rclone.log
ExecStop=/bin/fusermount -uz /data/mounts/rclone
Restart=on-failure
User=felix
Group=felix

[Install]
WantedBy=gmedia.service

I couldn’t figure out a way run as a different user on the mount command either as I didn’t want to run as root so I left it as a service rather than a mount in systemd.

7

Having a similar issue to @soy_titooo I think. Here is the command that I run when mounting
rclone mount -vvv --allow-other --allow-non-empty gcache: /Users/User1/gcache

and here is the output:
2019/01/11 17:31:53 DEBUG : Google drive root ‘’: Checking for changes on remote
2019/01/11 17:32:06 DEBUG : /: Attr:
2019/01/11 17:32:06 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=
2019/01/11 17:32:08 DEBUG : Cache remote gcache:: starting cleanup
2019/01/11 17:32:36 DEBUG : /: Attr:
2019/01/11 17:32:36 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=
2019/01/11 17:32:37 DEBUG : /: Attr:
2019/01/11 17:32:37 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=

not sure if I can give you anymore information or where I can get the debug file from to share

appreciate the help!

8

Your output looks fine and no errors.

What is the issue?

9

I was finally able to get it to error out here is what I saw:

Last login: Sun Jan 13 20:04:52 on console
Users-Mac-mini:~ User$ rclone mount -vvv --allow-other --allow-non-empty gcache: /Users/User/gcache
2019/01/13 20:06:53 DEBUG : rclone: Version “v1.45” starting with parameters [“rclone” “mount” “-vvv” “–allow-other” “–allow-non-empty” “gcache:” “/Users/User/gcache”]
2019/01/13 20:06:53 DEBUG : Using config file from “/Users/User/.config/rclone/rclone.conf”
2019/01/13 20:06:53 DEBUG : gcache: wrapped gdrive: at root
2019/01/13 20:06:53 ERROR : plex: websocket.Dial ws://127.0.0.1:32400/web/index.html/:/websockets/notifications?X-Plex-Token=user removed: dial tcp 127.0.0.1:32400: connect: connection refused
2019/01/13 20:06:53 INFO : gcache: Cache DB path: /Users/User/Library/Caches/rclone/cache-backend/gcache.db
2019/01/13 20:06:53 INFO : gcache: Cache chunk path: /Users/User/Library/Caches/rclone/cache-backend/gcache
2019/01/13 20:06:53 INFO : gcache: Chunk Memory: false
2019/01/13 20:06:53 INFO : gcache: Chunk Size: 16M
2019/01/13 20:06:53 INFO : gcache: Chunk Total Size: 20G
2019/01/13 20:06:53 INFO : gcache: Chunk Clean Interval: 1m0s
2019/01/13 20:06:53 INFO : gcache: Workers: 6
2019/01/13 20:06:53 INFO : gcache: File Age: 2h0m0s
2019/01/13 20:06:53 DEBUG : Adding path “cache/expire” to remote control registry
2019/01/13 20:06:53 DEBUG : Adding path “cache/stats” to remote control registry
2019/01/13 20:06:53 DEBUG : Adding path “cache/fetch” to remote control registry
2019/01/13 20:06:53 DEBUG : Cache remote gcache:: Mounting on “/Users/User/gcache”
2019/01/13 20:06:54 DEBUG : Cache remote gcache:: subscribing to ChangeNotify
2019/01/13 20:06:54 DEBUG : Adding path “vfs/forget” to remote control registry
2019/01/13 20:06:54 DEBUG : Adding path “vfs/refresh” to remote control registry
2019/01/13 20:06:54 DEBUG : Adding path “vfs/poll-interval” to remote control registry
2019/01/13 20:06:54 DEBUG : : Root:
2019/01/13 20:06:54 DEBUG : : >Root: node=/, err=
2019/01/13 20:06:54 DEBUG : : Statfs:
2019/01/13 20:06:54 DEBUG : : Statfs:
2019/01/13 20:06:54 DEBUG : : Statfs:
2019/01/13 20:06:54 DEBUG : /: Attr:
2019/01/13 20:06:54 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=
2019/01/13 20:07:46 DEBUG : /: Attr:
2019/01/13 20:07:46 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=
2019/01/13 20:07:46 DEBUG : : Statfs:
2019/01/13 20:07:53 DEBUG : Cache remote gcache:: starting cleanup
2019/01/13 20:07:54 DEBUG : pacer: Rate limited, sleeping for 1.43531842s (1 consecutive low level retries)
2019/01/13 20:07:54 DEBUG : pacer: low level retry 1/10 (error Get https://www.googleapis.com/drive/v3/changes/startPageToken?alt=json&prettyPrint=false&supportsTeamDrives=false: net/http: TLS handshake timeout)
2019/01/13 20:07:54 DEBUG : pacer: Rate limited, sleeping for 2.463965096s (2 consecutive low level retries)
2019/01/13 20:07:54 DEBUG : pacer: low level retry 1/10 (error Get https://www.googleapis.com/drive/v3/about?alt=json&fields=storageQuota&prettyPrint=false: net/http: TLS handshake timeout)
2019/01/13 20:08:46 DEBUG : /: Attr:
2019/01/13 20:08:46 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=
2019/01/13 20:08:46 DEBUG : : Statfs:
2019/01/13 20:08:53 DEBUG : Cache remote gcache:: starting cleanup
2019/01/13 20:08:54 DEBUG : pacer: Rate limited, sleeping for 4.057467794s (3 consecutive low level retries)
2019/01/13 20:08:54 DEBUG : pacer: low level retry 2/10 (error Get googleapi link/startPageToken?alt=json&prettyPrint=false&supportsTeamDrives=false: write tcp 192.168.50.199:49465->216.58.192.234:443: write: broken pipe)
2019/01/13 20:08:54 DEBUG : pacer: Rate limited, sleeping for 8.182126391s (4 consecutive low level retries)
2019/01/13 20:08:54 DEBUG : pacer: low level retry 2/10 (error Get google api link?alt=json&fields=storageQuota&prettyPrint=false: write tcp 192.168.50.199:49466->216.58.192.234:443: write: broken pipe)
2019/01/13 20:08:54 DEBUG : pacer: Resetting sleep to minimum 10ms on success
2019/01/13 20:08:58 DEBUG : : >Statfs: stat={Blocks:4294967295 Bfree:4294967295 Bavail:4294967295 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=
2019/01/13 20:08:58 DEBUG : : >Statfs: stat={Blocks:4294967295 Bfree:4294967295 Bavail:4294967295 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=
2019/01/13 20:08:58 DEBUG : : >Statfs: stat={Blocks:4294967295 Bfree:4294967295 Bavail:4294967295 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=
2019/01/13 20:08:58 DEBUG : : >Statfs: stat={Blocks:4294967295 Bfree:4294967295 Bavail:4294967295 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=
2019/01/13 20:08:58 DEBUG : : >Statfs: stat={Blocks:4294967295 Bfree:4294967295 Bavail:4294967295 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=
2019/01/13 20:08:58 DEBUG : rclone: Version “v1.45” finishing with parameters [“rclone” “mount” “-vvv” “–allow-other” “–allow-non-empty” “gcache:” “/Users/User/gcache”]
2019/01/13 20:08:58 INFO : plex: stopped Plex watcher
2019/01/13 20:08:58 DEBUG : Cache remote gcache:: Services stopped
Users-Mac-mini:~ User$

10

Those look all to be network connection errors and items not connecting. Does your network break on the machine?

11

Yes, sometimes I have problems with my VPN which is why I think this error was happening. Now I am having a different problem.

~ User$ rclone mount -vvv --allow-other --allow-non-empty gcache: /Users/User/gcache
2019/02/10 22:17:31 DEBUG : rclone: Version “v1.45” starting with parameters [“rclone” “mount” “-vvv” “–allow-other” “–allow-non-empty” “gcache:” “/Users/User/gcache”]
2019/02/10 22:17:31 DEBUG : Using config file from “/Users/User/.config/rclone/rclone.conf”
2019/02/10 22:17:31 DEBUG : gcache: wrapped gdrive: at root
2019/02/10 22:17:31 ERROR : plex: websocket.Dial ws://127.0.0.1:32400/web/index.html/:/websockets/notifications?X-Plex-Token=: dial tcp 127.0.0.1:32400: connect: connection refused
2019/02/10 22:17:31 INFO : gcache: Cache DB path: /Users/User/Library/Caches/rclone/cache-backend/gcache.db
2019/02/10 22:17:31 INFO : gcache: Cache chunk path: /Users/User/Library/Caches/rclone/cache-backend/gcache
2019/02/10 22:17:31 INFO : gcache: Chunk Memory: false
2019/02/10 22:17:31 INFO : gcache: Chunk Size: 16M
2019/02/10 22:17:31 INFO : gcache: Chunk Total Size: 20G
2019/02/10 22:17:31 INFO : gcache: Chunk Clean Interval: 1m0s
2019/02/10 22:17:31 INFO : gcache: Workers: 6
2019/02/10 22:17:31 INFO : gcache: File Age: 2h0m0s
2019/02/10 22:17:31 DEBUG : Adding path “cache/expire” to remote control registry
2019/02/10 22:17:31 DEBUG : Adding path “cache/stats” to remote control registry
2019/02/10 22:17:31 DEBUG : Adding path “cache/fetch” to remote control registry
2019/02/10 22:17:31 DEBUG : Cache remote gcache:: Mounting on “/Users/User/gcache”
2019/02/10 22:17:31 mount helper error: mount_osxfuse: /Users/User: Permission denied
2019/02/10 22:17:31 Fatal error: failed to mount FUSE fs: mount_osxfusefs: exit status 64
~ User$ rclone mount -vvv --allow-non-empty gcache: /Users/User/gcache
2019/02/10 22:17:47 DEBUG : rclone: Version “v1.45” starting with parameters [“rclone” “mount” “-vvv” “–allow-non-empty” “gcache:” “/Users/User/gcache”]
2019/02/10 22:17:47 DEBUG : Using config file from “/Users/User/.config/rclone/rclone.conf”
2019/02/10 22:17:47 DEBUG : gcache: wrapped gdrive: at root
2019/02/10 22:17:47 ERROR : plex: websocket.Dial ws://127.0.0.1:32400/web/index.html/:/websockets/notifications?X-Plex-Token=: dial tcp 127.0.0.1:32400: connect: connection refused
2019/02/10 22:17:47 INFO : gcache: Cache DB path: /Users/User/Library/Caches/rclone/cache-backend/gcache.db
2019/02/10 22:17:47 INFO : gcache: Cache chunk path: /Users/User/Library/Caches/rclone/cache-backend/gcache
2019/02/10 22:17:47 INFO : gcache: Chunk Memory: false
2019/02/10 22:17:47 INFO : gcache: Chunk Size: 16M
2019/02/10 22:17:47 INFO : gcache: Chunk Total Size: 20G
2019/02/10 22:17:47 INFO : gcache: Chunk Clean Interval: 1m0s
2019/02/10 22:17:47 INFO : gcache: Workers: 6
2019/02/10 22:17:47 INFO : gcache: File Age: 2h0m0s
2019/02/10 22:17:47 DEBUG : Adding path “cache/expire” to remote control registry
2019/02/10 22:17:47 DEBUG : Adding path “cache/stats” to remote control registry
2019/02/10 22:17:47 DEBUG : Adding path “cache/fetch” to remote control registry
2019/02/10 22:17:47 DEBUG : Cache remote gcache:: Mounting on “/Users/User/gcache”
2019/02/10 22:17:47 DEBUG : Cache remote gcache:: subscribing to ChangeNotify
2019/02/10 22:17:47 DEBUG : Adding path “vfs/forget” to remote control registry
2019/02/10 22:17:47 DEBUG : Adding path “vfs/refresh” to remote control registry
2019/02/10 22:17:47 DEBUG : Adding path “vfs/poll-interval” to remote control registry
2019/02/10 22:17:47 DEBUG : : Root:
2019/02/10 22:17:47 DEBUG : : >Root: node=/, err=
2019/02/10 22:17:47 DEBUG : : Statfs:
2019/02/10 22:17:47 DEBUG : : Statfs:
2019/02/10 22:17:47 DEBUG : : Statfs:
2019/02/10 22:17:48 DEBUG : /: Attr:
2019/02/10 22:17:48 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=
2019/02/10 22:18:01 DEBUG : /: Attr:
2019/02/10 22:18:01 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=
2019/02/10 22:18:01 DEBUG : : Statfs:
2019/02/10 22:18:47 DEBUG : Cache remote gcache:: starting cleanup
2019/02/10 22:18:47 DEBUG : pacer: Rate limited, sleeping for 1.504516005s (1 consecutive low level retries)
2019/02/10 22:18:47 DEBUG : pacer: low level retry 1/10 (error Get w w w .googleapis.com/drive/v3/changes/startPageToken?alt=json&prettyPrint=false&supportsTeamDrives=false: Post https:// accounts .google.com/o/oauth2/token: net/http: TLS handshake timeout)
2019/02/10 22:19:01 DEBUG : /: Attr:
2019/02/10 22:19:01 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=
2019/02/10 22:19:01 DEBUG : : Statfs:
2019/02/10 22:19:47 DEBUG : pacer: Rate limited, sleeping for 2.91830731s (2 consecutive low level retries)
2019/02/10 22:19:47 DEBUG : pacer: low level retry 1/10 (error Get https://www.googleapis.com/drive/v3/about?alt=json&fields=storageQuota&prettyPrint=false: Post https://accounts.google.com/o/oauth2/token: write tcp 192.168.50.199:49462->*** write: broken pipe)
2019/02/10 22:19:47 DEBUG : Cache remote gcache:: starting cleanup
2019/02/10 22:19:47 DEBUG : gdrive: Saved new token in config file
2019/02/10 22:19:48 DEBUG : pacer: Resetting sleep to minimum 10ms on success
2019/02/10 22:19:48 DEBUG : : >Statfs: stat={Blocks:4294967295 Bfree:4294967295 Bavail:4294967295 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=
2019/02/10 22:19:48 DEBUG : : >Statfs: stat={Blocks:4294967295 Bfree:4294967295 Bavail:4294967295 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=
2019/02/10 22:19:48 DEBUG : : >Statfs: stat={Blocks:4294967295 Bfree:4294967295 Bavail:4294967295 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=
2019/02/10 22:19:48 DEBUG : : >Statfs: stat={Blocks:4294967295 Bfree:4294967295 Bavail:4294967295 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=
2019/02/10 22:19:48 DEBUG : : >Statfs: stat={Blocks:4294967295 Bfree:4294967295 Bavail:4294967295 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=
2019/02/10 22:19:48 DEBUG : rclone: Version “v1.45” finishing with parameters [“rclone” “mount” “-vvv” “–allow-non-empty” “gcache:” “/Users/User/gcache”]
2019/02/10 22:19:48 INFO : plex: stopped Plex watcher
2019/02/10 22:19:48 DEBUG : Cache remote gcache:: Services stopped

12

Looks like you need to get a new token.

You can use rclone config to refresh it.

13

Plex token or google token?

14

I mean, it looks like your network is dying or something.


2019/02/10 22:18:47 DEBUG : pacer: low level retry 1/10 (error Get w w w .googleapis.com/drive/v3/changes/startPageToken?alt=json&prettyPrint=false&supportsTeamDrives=false: Post https:// accounts .google.com/o/oauth2/token: net/http: TLS handshake timeout)

and plex can’t even connect to itself.

2019/02/10 22:17:47 ERROR : plex: websocket.Dial ws://127.0.0.1:32400/web/index.html/:/websockets/notifications?X-Plex-Token=: dial tcp 127.0.0.1:32400: connect: connection refused

Is Plex running on the same machine?

15

Yes plex is running on the same machine

16

Are you running in a docker or something? Your machine is saying it cannot connect to itself based on those logs and it cannot connect out to the internet.

Firewall?

17

Not running in docker, it’s running fine after I restarted. But it will happen again at some point when I start to watch a movie.

18

So this is still happening, any other logs I can send to take a look at?

19

I’m not sure what else to recommend as your machine basically stops working on the network and that’s well beyond a rclone issue.

If there is another Mac user of rclone, maybe they could suggest something but all the logs you’ve shared point to networking for the process stopping to work.

There isn’t a rclone setting that would fix that.

21

Could that last line be causing an issue?

rclone: Version “v1.45” starting with parameters [“rclone” “mount” “-vvv” “–allow-non-empty” “–cache-db-purge” “gcache:” “/Users/User/gcache”]

2019/03/02 19:19:06 DEBUG : Using config file from “/Users/User/.config/rclone/rclone.conf”

2019/03/02 19:19:06 DEBUG : gcache: wrapped gdrive: at root

2019/03/02 19:19:06 DEBUG : gcache: Purging the DB

2019/03/02 19:19:06 ERROR : plex: websocket.Dial ws://127.0.0.1:32400/web/index.html/:/websockets/notifications?X-Plex-Token=Removed: dial tcp 127.0.0.1:32400: connect: connection refused