Ls on autofs triggered rclone mount hangs the first time

What is the problem you are having with rclone?

  • I use autofs to mount my remotes using rclone
  • When the mounted remote is first accessed using ls, it hangs.
  • After I kill the ls process, everything works as expected

I have a lot of problems with autofs and rclone. I understand the setup is complex, exotic and is complex to troubleshoot. That is why I tried to set up a minimal reproducible example. I will most probably also post about the other issues.
So any help, hint, pointers are much appreciated.

What is your rclone version (output from rclone version)

rclone v1.55.1
- os/type: linux
- os/arch: amd64
- go/version: go1.16.3
- go/linking: static
- go/tags: none

Which cloud storage system are you using?

ftp

reproducible example

prerequisites

  • ubuntu (debian). Here I used Ubuntu 20.04.3 LTS on x86_64
  • you need autofs to be installed (sudo apt install autofs)
  • I use a public ftp server rebex for this minimal reproducible example

files

/etc/auto.master.debug

/- 	/etc/auto.rclone.rebex

/etc/auto.rclone.rebex

/tmp/mnt2/rebex   -fstype=fuse.rclonefsdev,allow-non-empty,allow-other,log-file=/tmp/rclonefs.log,verbose   "::ftp,host=test.rebex.net,user=demo,pass=7l3xYbNT_gPzlsphlwKo11VRU4JUTAuE:"

/usr/local/bin/rclonefsdev

#!/bin/bash
function log() { echo "[$(date --rfc-3339=seconds)]: $0 - $*" 1>&2 ; }
log args="$*"
remote=$1
mountpoint=$2
shift 2

### when the automount runs this script, the mountpoint is already in /proc/mounts with the type="autofs"
### when the mount is effective, its type="fuse.rclone"
is_in_proc_mounts_with_rclone() { grep fuse.rclone  /proc/mounts  | grep -q -P "$1\s";  }

# if already mounted, do nothing, to avoid mount loops
is_in_proc_mounts_with_rclone "$mountpoint" && log "$mountpoint is already mounted, skipping..." && exit 0

USER=
# Process -o parameters, given by automount with the options listed in the autofs map file
rclone_args=
while getopts :o: opts; do
    case $opts in
        o)
            params=${OPTARG//,/ }
            for param in $params; do
                case $param in 
                    rw|ro|dev|suid|exec|auto|nodev|nosuid|noexec|noauto|x-systemd.*)
                        # log ignoring option $param 
                        continue
                        ;;
                    rclone_user*)
                        USER=${param#rclone_user=}
                        ;;
                    *)
                        rclone_args="$rclone_args --$param"
                        ;;
                esac
            done
            ;;

        \?)
            echo "Invalid option: -$OPTARG"
            ;;
    esac
done

rclone_args="$rclone_args $remote $mountpoint"

# # NOTE: do not try "mount --daemon" here, it does not play well with systemd automount, use '&'!
# # NOTE: mount is suid and ignores pre-set PATHs -> specify explicitely

# rclone_cmd="PATH=$PATH rclone mount $rclone_args </dev/null 2>&1 >>$LOGFILE &"
set -x # output all comands
#nohup PATH=$PATH "rclone mount $rclone_args  2>&1 >> $LOGFILE"  &
if [[ ! -z "$USER" ]]; then
    log "running mount under user $USER"
    ls -ld $mountpoint
    ls -l /autofs
    # chown $USER $mountpoint
    # ls -ld $mountpoint
    su $USER -c "rclone mount $rclone_args </dev/null 2>&1 >/dev/null" &
else
    log "running mount using current user" $(id)
    PATH=$PATH rclone mount $rclone_args </dev/null 2>&1 >/dev/null  &
fi
set +x

for i in {1..20}; do 
    log "waiting for mountpoint '$mountpoint' - attempt #$i..."
    is_in_proc_mounts_with_rclone "$mountpoint" && echo "mount '$mountpoint' successful!" && exit 0
    sleep .2
done

log "FAILED"
exit 1

executing it

first terminal

# make sure rclonefsdev is executable
sudo chmod a+rx /usr/local/bin/rclonefsdev
# create mountpoint dir
mkdir /tmp/mnt2/
sudo service autofs stop
sudo automount -fFvd auto.master.debug

second terminal

# first access of the mount point:
ls /tmp/mnt2/rebex/
# --> this hangs forever, even from other terminals, until the process is killed via CTRL+C

# then it works fine
 ls -l /tmp/mnt2/rebex/pub/example/
total 404
-rw-r--r-- 1 root root 19156 Feb 16  2007 imap-console-client.png
-rw-r--r-- 1 root root 36672 Mar 19  2007 KeyGenerator.png
-rw-r--r-- 1 root root 24029 Mar 19  2007 KeyGeneratorSmall.png
-rw-r--r-- 1 root root 16471 Feb 16  2007 mail-editor.png
-rw-r--r-- 1 root root 35414 Feb 16  2007 mail-send-winforms.png
-rw-r--r-- 1 root root 49011 Feb 16  2007 mime-explorer.png
-rw-r--r-- 1 root root 58024 Mar 19  2007 pocketftp.png
-rw-r--r-- 1 root root 20197 Mar 19  2007 pocketftpSmall.png
-rw-r--r-- 1 root root 20472 Feb 16  2007 pop3-browser.png
-rw-r--r-- 1 root root 11205 Feb 16  2007 pop3-console-client.png
-rw-r--r-- 1 root root   407 Mar 23  2007 readme.txt
-rw-r--r-- 1 root root 11546 Mar 19  2007 ResumableTransfer.png
-rw-r--r-- 1 root root  2635 Mar 19  2007 winceclient.png
-rw-r--r-- 1 root root  6146 Mar 19  2007 winceclientSmall.png
-rw-r--r-- 1 root root 80000 Mar 19  2007 WinFormClient.png
-rw-r--r-- 1 root root 17911 Mar 19  2007 WinFormClientSmall.png

logs

from automount

mount(generic): calling mount -t fuse.rclonefsdev -o allow-non-empty,allow-other,log-file=/tmp/rclonefs.log,verbose :ftp,host=test.rebex.net,user=demo,pass=7l3xYbNT_gPzlsphlwKo11VRU4JUTAuE: /tmp/mnt2/rebex
>> [2021-10-01 12:58:11+02:00]: /usr/local/bin/rclonefsdev - args=:ftp,host=test.rebex.net,user=demo,pass=7l3xYbNT_gPzlsphlwKo11VRU4JUTAuE: /tmp/mnt2/rebex -o rw,allow-non-empty,allow-other,log-file=/tmp/rclonefs.log,verbose,dev,suid
>> + [[ ! -z '' ]]
>> ++ id
>> + log 'running mount using current user' 'uid=0(root)' 'gid=0(root)' 'groups=0(root)'
>> ++ date --rfc-3339=seconds
>> + echo '[2021-10-01 12:58:11+02:00]: /usr/local/bin/rclonefsdev - running mount using current user uid=0(root) gid=0(root) groups=0(root)'
>> [2021-10-01 12:58:11+02:00]: /usr/local/bin/rclonefsdev - running mount using current user uid=0(root) gid=0(root) groups=0(root)
>> + set +x
>> + PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
>> + rclone mount --allow-non-empty --allow-other --log-file=/tmp/rclonefs.log --verbose :ftp,host=test.rebex.net,user=demo,pass=7l3xYbNT_gPzlsphlwKo11VRU4JUTAuE: /tmp/mnt2/rebex
>> [2021-10-01 12:58:11+02:00]: /usr/local/bin/rclonefsdev - waiting for mountpoint '/tmp/mnt2/rebex' - attempt #1...
>> [2021-10-01 12:58:11+02:00]: /usr/local/bin/rclonefsdev - waiting for mountpoint '/tmp/mnt2/rebex' - attempt #2...
>> [2021-10-01 12:58:11+02:00]: /usr/local/bin/rclonefsdev - waiting for mountpoint '/tmp/mnt2/rebex' - attempt #3...
>> mount '/tmp/mnt2/rebex' successful!

from rclone

2021/10/01 12:58:11 NOTICE: Config file "/root/.config/rclone/rclone.conf" not found - using defaults
2021/10/01 12:58:11 INFO : ftp://test.rebex.net:21: poll-interval is not supported by this remote

simple mounts using rclone mount

This works fine: the first ls does not hang:

rclone mount -v ":ftp,host=test.rebex.net,user=demo,pass=7l3xYbNT_gPzlsphlwKo11VRU4JUTAuE:" /tmp/mnt2/

# from other terminal: does not hang
ls -l /tmp/mnt2/pub/example/

hi,

not sure that it matters but in file /etc/auto.rclone.rebex, the connection string starts with two colons, i think it should be a single colon.
::ftp

Hi, thanks, but it needs to start with 2 ::, one is "eaten" by automount.
If you look at the automount log, the actual rclone command line is:

rclone mount --allow-non-empty --allow-other --log-file=/tmp/rclonefs.log --verbose :ftp,host=test.rebex.net,user=demo,pass=7l3xYbNT_gPzlsphlwKo11VRU4JUTAuE: /tmp/mnt2/rebex

yes, i did notice that the actual command looked ok and that the second ls command does work.

can you post the debug log, that shows what happens when running the first failed ls as compared to the second successful ls

the rclone debug log for the first failed ls:

2021/10/01 16:09:42 NOTICE: Config file "/root/.config/rclone/rclone.conf" not found - using defaults
2021/10/01 16:09:42 INFO  : ftp://test.rebex.net:21: poll-interval is not supported by this remote

not that the subsequent ls does not trigger any additional log

So my guess is that the rclone mount is working alright, but that there's some bad interaction between automount and the rclonefsdev script.

I'll just note that @ivandeex is fixing this at the moment in

So I recommend subscribing to that issue

1 Like

this fixes my issue !

1 Like

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