When trying to use rclone's Docker container to mount a OneDrive share using either the Web GUI or rclone rc mount/mount, the system returns fusermount: exit status 1 and error 500 as a response, even after delegating the proper rights to the container.
Run the command 'rclone version' and share the full output of the command.
I am able to ls -la within the assigned mount point /data/alex/onedrive and see the contents of the cloud drive, but trying to read the linked folder from outside the container reports it as empty. From inside container
/data/alex/onedrive # ls -la
total 145
drwxr-xr-x 1 root root 0 Jan 9 19:26 .
drwxr-xr-x 5 root root 3488 Jan 9 03:05 ..
drwxr-xr-x 1 root root 0 Jul 12 21:23 AndroidStudio
drwxr-xr-x 1 root root 0 Jan 9 08:10 Aplicaciones
drwxr-xr-x 1 root root 0 May 22 2021 AppData
drwxr-xr-x 1 root root 0 Nov 6 2020 AssistantComputerControl
drwxr-xr-x 1 root root 0 Jan 6 10:32 CRX
-rw-r--r-- 1 root root 143140 Aug 20 2020 Comunicado_RInterinas.pdf
drwxr-xr-x 1 root root 0 Nov 8 00:05 Contacts
drwxr-xr-x 1 root root 0 Jul 12 21:19 Creative Cloud Files
drwxr-xr-x 1 root root 0 Jan 7 11:40 Desktop
drwxr-xr-x 1 root root 0 Jan 9 08:14 Documents
drwxr-xr-x 1 root root 0 Jan 9 03:11 Downloads
drwxr-xr-x 1 root root 0 Nov 8 00:15 Favorites
drwxr-xr-x 1 root root 0 Sep 14 2020 JetbrainsProjects
drwxr-xr-x 1 root root 0 Nov 8 05:49 Links
drwxr-xr-x 1 root root 0 Jan 7 11:32 Music
drwxr-xr-x 1 root root 0 Jan 7 11:31 OpenVPN
drwxr-xr-x 1 root root 0 Dec 22 09:11 Pictures
drwxr-xr-x 1 root root 0 Jul 22 17:59 Saved Games
drwxr-xr-x 1 root root 0 Jan 7 11:32 Searches
drwxr-xr-x 1 root root 0 Jul 7 2020 TizenStudio
drwxr-xr-x 1 root root 0 Jan 7 11:37 Videos
drwxr-xr-x 1 root root 0 May 14 2019 Voice Recorder
drwxr-xr-x 1 root root 0 Dec 23 2020 Xilinx
-rw-r--r-- 1 root root 411 Jun 26 2021 id_ed25519
-rw-r--r-- 1 root root 322 Jun 27 2021 pia-token.txt
-rw-r--r-- 1 root root 452 May 24 2020 tufdevme.conf
From outside container
[root@OpenWRT-RPi /usbstick/rclone/alex/onedrive]# ls -la
drwxr-xr-x 2 root root 3488 Jan 9 13:25 ./
drwxr-xr-x 5 root root 3488 Dec 29 22:59 ../
So far no logs have been generated inside the /logs folder, but trying to unmount the previous command with fusermount -u /data/alex/onedrive, then remounting with the debugging to kernel flag, reports the following:
Assuming the hosts' folder is the left mapping, the right mapping corresponds to the folder inside the container, at least if I'm understanding Docker's documentation correctly. At least for the non-FUSE volumes, I'm able to confirm that read/write operations perform successfully on both the containers' /rclone/config and /logs folder, though I'm still not sure why no log file is being generated in spite of me being able to use rclone listremotes on both directories that are mapped to the same location.
It does, but it tends to crash the kernel within a seemingly random amount of time. The previous post I made was about that issue, in fact.
I just tried again using first the plain command and then adding -vfs-cache-mode writes since it wouldn't mount without that command, but the mount never succeeded. I'll attach the output of my steps below.
[root@OpenWRT-RPi /]# docker exec -it servicehub-rclone-1 sh
/data # mount ToasterDEV-OneDrive: /data/mount
mount: bad address 'ToasterDEV-OneDrive'
/data # rclone mount ToasterDEV-OneDrive: /data/mount
2022/01/13 04:07:12 Fatal error: Directory already mounted, use --allow-non-empty to mount anyway: /data/mount
/data # fusermount -u /data/mount
/data # ls /data/ount
ls: /data/ount: No such file or directory
/data # ls /data/mount
/data # rclone mount ToasterDEV-OneDrive: /data/mount
2022/01/13 04:07:33 NOTICE: One drive root '': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
^C2022/01/13 04:08:00 ERROR : /data/mount: Unmounted rclone mount
/data # rclone mount --vfs-cache-mode writes -vv ToasterDEV-OneDrive: /data/mount
2022/01/13 04:08:31 DEBUG : rclone: Version "v1.57.0" starting with parameters ["rclone" "mount" "--vfs-cache-mode" "writes" "-vv" "ToasterDEV-OneDrive:" "/data/mount"]
2022/01/13 04:08:31 DEBUG : Creating backend with remote "ToasterDEV-OneDrive:"
2022/01/13 04:08:31 DEBUG : Using config file from "/config/rclone/rclone.conf"
2022/01/13 04:08:31 INFO : One drive root '': poll-interval is not supported by this remote
2022/01/13 04:08:31 DEBUG : vfs cache: root is "/root/.cache/rclone"
2022/01/13 04:08:31 DEBUG : vfs cache: data root is "/root/.cache/rclone/vfs/ToasterDEV-OneDrive"
2022/01/13 04:08:31 DEBUG : vfs cache: metadata root is "/root/.cache/rclone/vfsMeta/ToasterDEV-OneDrive"
2022/01/13 04:08:31 DEBUG : Creating backend with remote "/root/.cache/rclone/vfs/ToasterDEV-OneDrive/"
2022/01/13 04:08:31 DEBUG : Creating backend with remote "/root/.cache/rclone/vfsMeta/ToasterDEV-OneDrive/"
2022/01/13 04:08:31 DEBUG : One drive root '': Mounting on "/data/mount"
2022/01/13 04:08:31 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2022/01/13 04:08:31 DEBUG : : Root:
2022/01/13 04:08:31 DEBUG : : >Root: node=/, err=<nil>
2022/01/13 04:09:31 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2022/01/13 04:10:31 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2022/01/13 04:11:31 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
^C2022/01/13 04:12:10 INFO : Signal received: interrupt
2022/01/13 04:12:10 DEBUG : vfs cache: cleaner exiting
2022/01/13 04:12:10 ERROR : /data/mount: Unmounted rclone mount
2022/01/13 04:12:10 INFO : Exiting...
/data #
What a coincidence! I came across those posts while researching before making this post. I've tried both setting rshared and shared then rebuilding the container stack, but for some reason regardless of which one I use they end up showing this error message and failing to mount:
/data # rclone mount --vfs-cache-mode writes -vv ToasterDEV-OneDrive: /data/mount
2022/01/13 04:19:52 DEBUG : rclone: Version "v1.57.0" starting with parameters ["rclone" "mount" "--vfs-cache-mode" "writes" "-vv" "ToasterDEV-OneDrive:" "/data/mount"]
2022/01/13 04:19:52 DEBUG : Creating backend with remote "ToasterDEV-OneDrive:"
2022/01/13 04:19:52 DEBUG : Using config file from "/config/rclone/rclone.conf"
2022/01/13 04:19:53 INFO : One drive root '': poll-interval is not supported by this remote
2022/01/13 04:19:53 DEBUG : vfs cache: root is "/root/.cache/rclone"
2022/01/13 04:19:53 DEBUG : vfs cache: data root is "/root/.cache/rclone/vfs/ToasterDEV-OneDrive"
2022/01/13 04:19:53 DEBUG : vfs cache: metadata root is "/root/.cache/rclone/vfsMeta/ToasterDEV-OneDrive"
2022/01/13 04:19:53 DEBUG : Creating backend with remote "/root/.cache/rclone/vfs/ToasterDEV-OneDrive/"
2022/01/13 04:19:53 DEBUG : Creating backend with remote "/root/.cache/rclone/vfsMeta/ToasterDEV-OneDrive/"
2022/01/13 04:19:53 DEBUG : One drive root '': Mounting on "/data/mount"
2022/01/13 04:19:53 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2022/01/13 04:19:53 DEBUG : : Root:
2022/01/13 04:19:53 DEBUG : : >Root: node=/, err=<nil>
2022/01/13 04:20:53 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
That error nil in particular only appears when the mount gets stuck, but for some reason if I am to restart the container without altering the declared settings in the compose file, the mount will sometimes succeed but only within the container; the outside mount will still appear as empty.
Thanks for the help!
Edit: Just tried refreshing the token to see if it'd make a difference, but so far no dice.
In no case on earth should kernel let a user-space process or even a fuse mount crash it. If you experience kernel crashes, blame kernel or drivers. I suggest you find out your kernel version (uname -a), and applied patches (see release notes) esp. fuse/vfs driver tweaks. Is docker considered stable on openwrt? Dig openwrt forums and stackoverflow for similar problems.
In fact error nil means "no error" that is according to your log rclone ran smoothly. Let's dig further why it got stuck later on.
First, look at the system log (preferably the one containing kernel messages as you encountered kernel crashes above), typically /var/log/syslog or /var/log/messages or output of the dmesg command or something specific to your embedded platform.
Next, let's snapshot the state of rclone threads while it's stuck. Make sure the rclone standard output goes to a console i.e. remove the --daemon flag from the mount command line and rerun. Use ps -efa | grep rclone to find out the rclone pid. Send it the stack trace signal kill -QUIT <PID> and paste its output below together with rclone and kernel logs.
My kernel version is Linux OpenWRT-RPi 5.10.88 #0 SMP Mon Dec 27 16:32:02 2021 aarch64 GNU/Linux, running on build 3.5.331/r18436 from this community build, but so far I haven't been able to find anything regarding FUSE/bind mounts on either the forum thread or the changelog. Docker is within the release package repositories, so I believe it is stable, too.
Okay, that's reassuring.
Sure, thanks for the help!
From the stack trace
/data # rclone mount --vfs-cache-mode writes -vv ToasterDEV-OneDrive:/ /data
/mount
2022/01/14 05:45:55 DEBUG : rclone: Version "v1.57.0" starting with parameters ["rclone" "mount" "--vfs-cache-mode" "writes" "-vv" "ToasterDEV-OneDrive:/" "/data/mount"]
2022/01/14 05:45:55 DEBUG : Creating backend with remote "ToasterDEV-OneDrive:/"
2022/01/14 05:45:55 DEBUG : Using config file from "/config/rclone/rclone.conf"
2022/01/14 05:45:55 DEBUG : fs cache: renaming cache item "ToasterDEV-OneDrive:/" to be canonical "ToasterDEV-OneDrive:"
2022/01/14 05:45:55 INFO : One drive root '': poll-interval is not supported by this remote
2022/01/14 05:45:55 DEBUG : vfs cache: root is "/root/.cache/rclone"
2022/01/14 05:45:55 DEBUG : vfs cache: data root is "/root/.cache/rclone/vfs/ToasterDEV-OneDrive"
2022/01/14 05:45:55 DEBUG : vfs cache: metadata root is "/root/.cache/rclone/vfsMeta/ToasterDEV-OneDrive"
2022/01/14 05:45:55 DEBUG : Creating backend with remote "/root/.cache/rclone/vfs/ToasterDEV-OneDrive/"
2022/01/14 05:45:55 DEBUG : Creating backend with remote "/root/.cache/rclone/vfsMeta/ToasterDEV-OneDrive/"
2022/01/14 05:45:55 DEBUG : One drive root '': Mounting on "/data/mount"
2022/01/14 05:45:55 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2022/01/14 05:45:55 DEBUG : : Root:
2022/01/14 05:45:55 DEBUG : : >Root: node=/, err=<nil>
SIGQUIT: quit
PC=0x7f4cc m=0 sigcode=0
goroutine 0 [idle]:
runtime.futex()
/usr/local/go/src/runtime/sys_linux_arm64.s:565 +0x1c
runtime.futexsleep(0x27e8530, 0x0, 0xffffffffffffffff)
/usr/local/go/src/runtime/os_linux.go:44 +0x38
runtime.notesleep(0x27e8530)
/usr/local/go/src/runtime/lock_futex.go:160 +0x98
runtime.mPark()
/usr/local/go/src/runtime/proc.go:1441 +0x28
runtime.stopm()
/usr/local/go/src/runtime/proc.go:2408 +0x80
runtime.startlockedm(0x4000450d00)
/usr/local/go/src/runtime/proc.go:2631 +0x6c
runtime.schedule()
/usr/local/go/src/runtime/proc.go:3402 +0x6c
runtime.park_m(0x40004691e0)
/usr/local/go/src/runtime/proc.go:3516 +0x188
runtime.mcall()
/usr/local/go/src/runtime/asm_arm64.s:179 +0x54
goroutine 1 [select]:
github.com/rclone/rclone/cmd/mountlib.(*MountPoint).Wait(0x40005bec60)
/go/src/github.com/rclone/rclone/cmd/mountlib/mount.go:290 +0x214
github.com/rclone/rclone/cmd/mountlib.NewMountCommand.func1(0x4000219400, {0x400045f9f0, 0x2, 0x5})
/go/src/github.com/rclone/rclone/cmd/mountlib/mount.go:181 +0x2ec
github.com/spf13/cobra.(*Command).execute(0x4000219400, {0x400045f9a0, 0x5, 0x5})
/go/pkg/mod/github.com/spf13/cobra@v1.2.1/command.go:860 +0x650
github.com/spf13/cobra.(*Command).ExecuteC(0x27c8b40)
/go/pkg/mod/github.com/spf13/cobra@v1.2.1/command.go:974 +0x424
github.com/spf13/cobra.(*Command).Execute(...)
/go/pkg/mod/github.com/spf13/cobra@v1.2.1/command.go:902
github.com/rclone/rclone/cmd.Main()
/go/src/github.com/rclone/rclone/cmd/cmd.go:555 +0x9c
main.main()
/go/src/github.com/rclone/rclone/rclone.go:14 +0x20
goroutine 18 [select]:
go.opencensus.io/stats/view.(*worker).start(0x4000130d00)
/go/pkg/mod/go.opencensus.io@v0.23.0/stats/view/worker.go:276 +0x98
created by go.opencensus.io/stats/view.init.0
/go/pkg/mod/go.opencensus.io@v0.23.0/stats/view/worker.go:34 +0x80
goroutine 25 [chan receive]:
github.com/rclone/rclone/lib/oauthutil.(*Renew).renewOnExpiry(0x4000462d80)
/go/src/github.com/rclone/rclone/lib/oauthutil/renew.go:39 +0x48
created by github.com/rclone/rclone/lib/oauthutil.NewRenew
/go/src/github.com/rclone/rclone/lib/oauthutil/renew.go:28 +0xb0
goroutine 51 [syscall]:
os/signal.signal_recv()
/usr/local/go/src/runtime/sigqueue.go:169 +0x108
os/signal.loop()
/usr/local/go/src/os/signal/signal_unix.go:24 +0x20
created by os/signal.Notify.func1.1
/usr/local/go/src/os/signal/signal.go:151 +0x38
goroutine 46 [select]:
github.com/rclone/rclone/vfs/vfscache.(*Cache).cleaner(0x40007f1a40, {0x1a9f990, 0x40007cc140})
/go/src/github.com/rclone/rclone/vfs/vfscache/cache.go:784 +0x128
created by github.com/rclone/rclone/vfs/vfscache.New
/go/src/github.com/rclone/rclone/vfs/vfscache/cache.go:143 +0x660
goroutine 49 [syscall]:
syscall.Syscall(0x3f, 0xa, 0x4000a80000, 0x21000)
/usr/local/go/src/syscall/asm_linux_arm64.s:9 +0x10
syscall.read(0xa, {0x4000a80000, 0x21000, 0x21000})
/usr/local/go/src/syscall/zsyscall_linux_arm64.go:687 +0x58
syscall.Read(...)
/usr/local/go/src/syscall/syscall_unix.go:189
bazil.org/fuse.(*Conn).ReadRequest(0x40009b3a40)
/go/pkg/mod/bazil.org/fuse@v0.0.0-20200524192727-fb710f7dfd05/fuse.go:580 +0x10c
bazil.org/fuse/fs.(*Server).Serve(0x40009b50a0, {0x1a68c00, 0x40009d6870})
/go/pkg/mod/bazil.org/fuse@v0.0.0-20200524192727-fb710f7dfd05/fs/serve.go:501 +0x45c
github.com/rclone/rclone/cmd/mount.mount.func2(0x40009d6870, 0x40009b3a40, 0x40009b3e60)
/go/src/github.com/rclone/rclone/cmd/mount/mount.go:100 +0x3c
created by github.com/rclone/rclone/cmd/mount.mount
/go/src/github.com/rclone/rclone/cmd/mount/mount.go:99 +0x408
goroutine 65 [chan receive]:
github.com/rclone/rclone/lib/atexit.Register.func1.1()
/go/src/github.com/rclone/rclone/lib/atexit/atexit.go:45 +0x3c
created by github.com/rclone/rclone/lib/atexit.Register.func1
/go/src/github.com/rclone/rclone/lib/atexit/atexit.go:44 +0xb0
r0 0x27e8530
r1 0x80
r2 0x0
r3 0x0
r4 0x0
r5 0x0
r6 0x9
r7 0x1
r8 0x62
r9 0x4000b100bf
r10 0x1000
r11 0x1a38f6c
r12 0x7
r13 0x0
r14 0x0
r15 0x0
r16 0x7
r17 0x2801180
r18 0x0
r19 0x7f967db000
r20 0x7fd0113e90
r21 0x27e83e0
r22 0x4000002000
r23 0xa76c6eed39128e56
r24 0x4000731298
r25 0x4b74955f6ceaff70
r26 0x17af1b8
r27 0x27b2cd8
r28 0x27e7cc0
r29 0x7fd0113f28
lr 0x43588
sp 0x7fd0113f30
pc 0x7f4cc
fault 0x0
/data #
From the system log
[root@OpenWRT-RPi /]# logread -f
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 available DHCP range: 192.168.1.100 -- 192.168.1.249
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 DHCPDISCOVER(br-lan) 10:27:f5:bc:3c:a4
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 tags: lan, known, br-lan
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 DHCPOFFER(br-lan) 192.168.1.14 10:27:f5:bc:3c:a4
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 requested options: 1:netmask, 3:router, 28:broadcast, 6:dns-server
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 bootfile name: pxelinux.0
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 server name: router
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 next server: 192.168.1.1
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 sent size: 1 option: 53 message-type 2
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 sent size: 4 option: 54 server-identifier 192.168.1.1
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 sent size: 4 option: 51 lease-time 12h
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 sent size: 4 option: 58 T1 6h
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 sent size: 4 option: 59 T2 10h30m
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 sent size: 4 option: 1 netmask 255.255.255.0
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 sent size: 4 option: 28 broadcast 192.168.1.255
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 sent size: 4 option: 3 router 192.168.1.1
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 sent size: 4 option: 6 dns-server 192.168.1.1
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 sent size: 20 option:209 70:78:65:6c:69:6e:75:78:2e:63:66:67:2f:64...
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 available DHCP range: 192.168.1.100 -- 192.168.1.249
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 client provides name: EP10
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 DHCPREQUEST(br-lan) 192.168.1.14 10:27:f5:bc:3c:a4
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 tags: lan, known, br-lan
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 DHCPACK(br-lan) 192.168.1.14 10:27:f5:bc:3c:a4 BedroomTVPlug
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 requested options: 1:netmask, 3:router, 28:broadcast, 6:dns-server
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 bootfile name: pxelinux.0
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 server name: router
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 next server: 192.168.1.1
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 sent size: 1 option: 53 message-type 5
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 sent size: 4 option: 54 server-identifier 192.168.1.1
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 sent size: 4 option: 51 lease-time 12h
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 sent size: 4 option: 58 T1 6h
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 sent size: 4 option: 59 T2 10h30m
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 sent size: 4 option: 1 netmask 255.255.255.0
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 sent size: 4 option: 28 broadcast 192.168.1.255
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 sent size: 4 option: 3 router 192.168.1.1
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 sent size: 4 option: 6 dns-server 192.168.1.1
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1620787192 sent size: 20 option:209 70:78:65:6c:69:6e:75:78:2e:63:66:67:2f:64...
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 available DHCP range: 192.168.1.100 -- 192.168.1.249
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 DHCPDISCOVER(br-lan) 10:27:f5:bc:3c:a4
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 tags: lan, known, br-lan
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 DHCPOFFER(br-lan) 192.168.1.14 10:27:f5:bc:3c:a4
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 requested options: 1:netmask, 3:router, 28:broadcast, 6:dns-server
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 bootfile name: pxelinux.0
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 server name: router
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 next server: 192.168.1.1
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 sent size: 1 option: 53 message-type 2
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 sent size: 4 option: 54 server-identifier 192.168.1.1
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 sent size: 4 option: 51 lease-time 12h
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 sent size: 4 option: 58 T1 6h
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 sent size: 4 option: 59 T2 10h30m
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 sent size: 4 option: 1 netmask 255.255.255.0
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 sent size: 4 option: 28 broadcast 192.168.1.255
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 sent size: 4 option: 3 router 192.168.1.1
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 sent size: 4 option: 6 dns-server 192.168.1.1
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 sent size: 20 option:209 70:78:65:6c:69:6e:75:78:2e:63:66:67:2f:64...
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 available DHCP range: 192.168.1.100 -- 192.168.1.249
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 client provides name: EP10
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 DHCPREQUEST(br-lan) 192.168.1.14 10:27:f5:bc:3c:a4
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 tags: lan, known, br-lan
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 DHCPACK(br-lan) 192.168.1.14 10:27:f5:bc:3c:a4 BedroomTVPlug
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 requested options: 1:netmask, 3:router, 28:broadcast, 6:dns-server
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 bootfile name: pxelinux.0
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 server name: router
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 next server: 192.168.1.1
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 sent size: 1 option: 53 message-type 5
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 sent size: 4 option: 54 server-identifier 192.168.1.1
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 sent size: 4 option: 51 lease-time 12h
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 sent size: 4 option: 58 T1 6h
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 sent size: 4 option: 59 T2 10h30m
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 sent size: 4 option: 1 netmask 255.255.255.0
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 sent size: 4 option: 28 broadcast 192.168.1.255
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 sent size: 4 option: 3 router 192.168.1.1
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 sent size: 4 option: 6 dns-server 192.168.1.1
Thu Jan 13 23:46:28 2022 daemon.info dnsmasq-dhcp[7080]: 1191334786 sent size: 20 option:209 70:78:65:6c:69:6e:75:78:2e:63:66:67:2f:64...
Thu Jan 13 23:46:29 2022 kern.warn kernel: [ 2569.750494] [banIP-0.7.10, src/DROP] IN=pppoe-wan OUT= MAC= SRC=141.98.10.63 DST=189.163.49.242 LEN=40 TOS=0x00 PREC=0x00 TTL=240 ID=54321 PROTO=TCP SPT=44841 DPT=22 WINDOW=65535 RES=0x00 SYN URGP=0
Thu Jan 13 23:46:45 2022 kern.warn kernel: [ 2585.592150] [banIP-0.7.10, src/DROP] IN=pppoe-wan OUT= MAC= SRC=185.73.126.190 DST=189.163.49.242 LEN=40 TOS=0x00 PREC=0x00 TTL=244 ID=33430 PROTO=TCP SPT=56040 DPT=21686 WINDOW=1024 RES=0x00 SYN URGP=0
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 available DHCP range: 192.168.1.100 -- 192.168.1.249
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 DHCPDISCOVER(br-lan) 10:27:f5:bc:30:9e
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 tags: lan, known, br-lan
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 DHCPOFFER(br-lan) 192.168.1.15 10:27:f5:bc:30:9e
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 requested options: 1:netmask, 3:router, 28:broadcast, 6:dns-server
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 bootfile name: pxelinux.0
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 server name: router
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 next server: 192.168.1.1
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 sent size: 1 option: 53 message-type 2
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 sent size: 4 option: 54 server-identifier 192.168.1.1
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 sent size: 4 option: 51 lease-time 12h
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 sent size: 4 option: 58 T1 6h
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 sent size: 4 option: 59 T2 10h30m
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 sent size: 4 option: 1 netmask 255.255.255.0
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 sent size: 4 option: 28 broadcast 192.168.1.255
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 sent size: 4 option: 3 router 192.168.1.1
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 sent size: 4 option: 6 dns-server 192.168.1.1
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 sent size: 20 option:209 70:78:65:6c:69:6e:75:78:2e:63:66:67:2f:64...
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 available DHCP range: 192.168.1.100 -- 192.168.1.249
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 client provides name: EP10
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 DHCPREQUEST(br-lan) 192.168.1.15 10:27:f5:bc:30:9e
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 tags: lan, known, br-lan
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 DHCPACK(br-lan) 192.168.1.15 10:27:f5:bc:30:9e BedroomLamp
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 requested options: 1:netmask, 3:router, 28:broadcast, 6:dns-server
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 bootfile name: pxelinux.0
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 server name: router
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 next server: 192.168.1.1
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 sent size: 1 option: 53 message-type 5
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 sent size: 4 option: 54 server-identifier 192.168.1.1
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 sent size: 4 option: 51 lease-time 12h
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 sent size: 4 option: 58 T1 6h
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 sent size: 4 option: 59 T2 10h30m
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 sent size: 4 option: 1 netmask 255.255.255.0
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 sent size: 4 option: 28 broadcast 192.168.1.255
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 sent size: 4 option: 3 router 192.168.1.1
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 sent size: 4 option: 6 dns-server 192.168.1.1
Thu Jan 13 23:46:49 2022 daemon.info dnsmasq-dhcp[7080]: 968727913 sent size: 20 option:209 70:78:65:6c:69:6e:75:78:2e:63:66:67:2f:64...
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 available DHCP range: 192.168.1.100 -- 192.168.1.249
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 DHCPDISCOVER(br-lan) 10:27:f5:bc:30:9e
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 tags: lan, known, br-lan
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 DHCPOFFER(br-lan) 192.168.1.15 10:27:f5:bc:30:9e
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 requested options: 1:netmask, 3:router, 28:broadcast, 6:dns-server
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 bootfile name: pxelinux.0
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 server name: router
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 next server: 192.168.1.1
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 sent size: 1 option: 53 message-type 2
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 sent size: 4 option: 54 server-identifier 192.168.1.1
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 sent size: 4 option: 51 lease-time 12h
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 sent size: 4 option: 58 T1 6h
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 sent size: 4 option: 59 T2 10h30m
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 sent size: 4 option: 1 netmask 255.255.255.0
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 sent size: 4 option: 28 broadcast 192.168.1.255
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 sent size: 4 option: 3 router 192.168.1.1
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 sent size: 4 option: 6 dns-server 192.168.1.1
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 sent size: 20 option:209 70:78:65:6c:69:6e:75:78:2e:63:66:67:2f:64...
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 available DHCP range: 192.168.1.100 -- 192.168.1.249
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 client provides name: EP10
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 DHCPREQUEST(br-lan) 192.168.1.15 10:27:f5:bc:30:9e
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 tags: lan, known, br-lan
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 DHCPACK(br-lan) 192.168.1.15 10:27:f5:bc:30:9e BedroomLamp
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 requested options: 1:netmask, 3:router, 28:broadcast, 6:dns-server
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 bootfile name: pxelinux.0
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 server name: router
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 next server: 192.168.1.1
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 sent size: 1 option: 53 message-type 5
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 sent size: 4 option: 54 server-identifier 192.168.1.1
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 sent size: 4 option: 51 lease-time 12h
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 sent size: 4 option: 58 T1 6h
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 sent size: 4 option: 59 T2 10h30m
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 sent size: 4 option: 1 netmask 255.255.255.0
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 sent size: 4 option: 28 broadcast 192.168.1.255
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 sent size: 4 option: 3 router 192.168.1.1
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 sent size: 4 option: 6 dns-server 192.168.1.1
Thu Jan 13 23:46:50 2022 daemon.info dnsmasq-dhcp[7080]: 1463462490 sent size: 20 option:209 70:78:65:6c:69:6e:75:78:2e:63:66:67:2f:64...
Thu Jan 13 23:46:52 2022 daemon.err dockerd[23431]: time="2022-01-13T23:46:52.088314315-06:00" level=info msg="starting signal loop" namespace=moby path=/tmp/run/docker/containerd/daemon/io.containerd.runtime.v2.task/moby/6485c3695eaef51b05385f38eb546b5d5873de779a57f94556d5c89a6d5e06d1 pid=22124
Thu Jan 13 23:46:58 2022 daemon.err dockerd[23431]: time="2022-01-13T23:46:58.136133237-06:00" level=error msg="copy shim log" error="read /proc/self/fd/27: file already closed"
Thu Jan 13 23:47:08 2022 daemon.info dnsmasq-dhcp[7080]: 1709434359 available DHCP range: 192.168.1.100 -- 192.168.1.249
Thu Jan 13 23:47:08 2022 daemon.info dnsmasq-dhcp[7080]: 1709434359 DHCPDISCOVER(br-lan) 10:27:f5:bc:3c:a4
Thu Jan 13 23:47:08 2022 daemon.info dnsmasq-dhcp[7080]: 1709434359 tags: lan, known, br-lan
Thu Jan 13 23:47:08 2022 daemon.info dnsmasq-dhcp[7080]: 1709434359 DHCPOFFER(br-lan) 192.168.1.14 10:27:f5:bc:3c:a4
Thu Jan 13 23:47:08 2022 daemon.info dnsmasq-dhcp[7080]: 1709434359 requested options: 1:netmask, 3:router, 28:broadcast, 6:dns-server
Thu Jan 13 23:47:08 2022 daemon.info dnsmasq-dhcp[7080]: 1709434359 bootfile name: pxelinux.0
Thu Jan 13 23:47:08 2022 daemon.info dnsmasq-dhcp[7080]: 1709434359 server name: router
Thu Jan 13 23:47:08 2022 daemon.info dnsmasq-dhcp[7080]: 1709434359 next server: 192.168.1.1
Thu Jan 13 23:47:08 2022 daemon.info dnsmasq-dhcp[7080]: 1709434359 sent size: 1 option: 53 message-type 2
Thu Jan 13 23:47:08 2022 daemon.info dnsmasq-dhcp[7080]: 1709434359 sent size: 4 option: 54 server-identifier 192.168.1.1
Thu Jan 13 23:47:08 2022 daemon.info dnsmasq-dhcp[7080]: 1709434359 sent size: 4 option: 51 lease-time 12h
Thu Jan 13 23:47:08 2022 daemon.info dnsmasq-dhcp[7080]: 1709434359 sent size: 4 option: 58 T1 6h
Thu Jan 13 23:47:08 2022 daemon.info dnsmasq-dhcp[7080]: 1709434359 sent size: 4 option: 59 T2 10h30m
Thu Jan 13 23:47:08 2022 daemon.info dnsmasq-dhcp[7080]: 1709434359 sent size: 4 option: 1 netmask 255.255.255.0
Oddly nothing came up on the system log this time.
If there's anything else you need please tell me so.
I can see a thread waiting on the OAauth token renewal and threads busy with VFS cache sweeping. I have seen a similar pattern once with another storage provider. In that case the problem was that they did not update my OAuth token and a number of VFS threads was blocked waiting for the new one.
Let's check whether your OneDrive auth is healthy, in isolation from complex VFS/mount stuff.
While your mount is sitting there blocked, enter your container again from another console and do something very simple that will still require OneDrive auth:
docker exec -it servicehub-rclone-1 sh
# rclone lsd ToasterDEV-OneDrive: -vv
We need a mount to reproduce the issue, investigate it and isolate the broken piece.
Let's try to do a "simpler" kind of mount from inside the container:
1. Mount a local directory in the container
This isolates us from network issues between rclone in container and a remote storage provider:
docker exec -it servicehub-rclone-1 sh
# rclone version
# mkdir /test1
# rclone mount /test1 /data/mount -vv --log-file /test1.log
and from another console
docker exec -it servicehub-rclone-1 sh
# touch /test1/hello1
# ls /data/mount/hello1
2. Mount the remote storage but to a "simpler" directory inside the container
"Simpler" is the one that is not exported from container to outside host and so NOT handled specially by the kernel - this partially isolates us from peculiarities creeping between fuse kernel driver, custom openwrt kernel and docker daemon:
docker exec -it servicehub-rclone-1 sh
# rclone version
# mkdir /test2
# rclone mount ToasterDEV-OneDrive: /test2 -vv --log-file /test2.log
and from another console
docker exec -it servicehub-rclone-1 sh
# ls /test2
3. Both simplifications together
docker exec -it servicehub-rclone-1 sh
# rclone version
# mkdir /test3a
# mkdir /test4b
# rclone mount /test3a /test3b -vv --log-file /test3.log
and from another console
docker exec -it servicehub-rclone-1 sh
# touch /test3a/hello3
# ls /test3b
root@OpenWRT-RPi /74# docker exec -it servicehub-rclone-1 sh
/data # touch /test3a/hello3
/data # ls /test3b
ls: /test3b: No such file or directory
/data #
/data # cat /test3.log
2022/01/14 08:42:53 DEBUG : rclone: Version "v1.57.0" starting with parameters ["rclone" "mount" "/test3a" "/test3b" "-vv" "--log-file" "/test3.log"]
2022/01/14 08:42:53 DEBUG : Creating backend with remote "/test3a"
2022/01/14 08:42:53 DEBUG : Using config file from "/config/rclone/rclone.conf"
2022/01/14 08:42:53 INFO : Local file system at /test3a: poll-interval is not supported by this remote
2022/01/14 08:42:53 DEBUG : Local file system at /test3a: Mounting on "/test3b"
2022/01/14 08:42:53 Fatal error: failed to mount FUSE fs: mountpoint does not exist: /test3b
It seems all internal mount points worked except for the last one, though if I'm understanding the command syntax correctly, perhaps /test4b should be /test3b.
If so, I reran the test with the following output and results:
[root@OpenWRT-RPi /]# docker exec -it servicehub-rclone-1 sh
/data # mkdir /test3b
/data # rclone mount /test3a /test3b -vv --log-file /test4.log
root@OpenWRT-RPi /74# docker exec -it servicehub-rclone-1 sh
/data # touch /test3a/hello3
/data # ls /test3b
hello3
/data #
/data # cat /test4.log
2022/01/14 08:52:38 DEBUG : rclone: Version "v1.57.0" starting with parameters ["rclone" "mount" "/test3a" "/test3b" "-vv" "--log-file" "/test4.log"]
2022/01/14 08:52:38 DEBUG : Creating backend with remote "/test3a"
2022/01/14 08:52:38 DEBUG : Using config file from "/config/rclone/rclone.conf"
2022/01/14 08:52:38 INFO : Local file system at /test3a: poll-interval is not supported by this remote
2022/01/14 08:52:38 DEBUG : Local file system at /test3a: Mounting on "/test3b"
2022/01/14 08:52:38 DEBUG : : Root:
2022/01/14 08:52:38 DEBUG : : >Root: node=/, err=<nil>
2022/01/14 08:53:06 DEBUG : /: Attr:
2022/01/14 08:53:06 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2022/01/14 08:53:06 DEBUG : /: ReadDirAll:
2022/01/14 08:53:06 DEBUG : /: >ReadDirAll: item=3, err=<nil>
2022/01/14 08:53:06 DEBUG : /: Lookup: name="hello3"
2022/01/14 08:53:06 DEBUG : /: >Lookup: node=hello3, err=<nil>
2022/01/14 08:53:06 DEBUG : hello3: Attr:
2022/01/14 08:53:06 DEBUG : hello3: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
/data #
And it seems the mount was a success.
Would the issue then be the Docker implementation itself?
rclone in container CAN mount to a directory ISOLATED in the container
rclone in container CANNOT mount to a directory EXPORTED outside of the container via shared mechanism
Conclusion: something is wrong between docker and kernel w.r.t. exporting (back-propagating) THE kind of filesystem where ACTUALLY belongs the /data/mount directory.
Now remember that containers are in fact just remappings of resource pieces (filesystems, network devices etc) between groups of processes. Let's follow back the Ariadne thread to the origins of the /data/mount directory. Where did your docker container mapped it from? Did it or its parent fall under any --volume flag of the container?
If yes, let's see where did this --volume flag pull it from.
If NO, then it belongs with the container's / filesystem (which is a kind of overlay2 filesystem used by docker to merge image layers together) and your openwrt kernel has problems serving exported mount points there.
I guess NO is the answer. In that case you'd better report back to the OpenWRT build maintainer something like "the overlay2 filesystem driver in your build sucks, namely blah blah".
In the same time you can try to mitigate. Use docker's directory remapping facilities in such a way that /data/mount comes from a healthier filesystem driver. Run your rclone docker container like
docker run ... ... --volume /usbstick/rclone/alex:/test5 ... -it rclone/rclone:latest sh
Omit the shared flag for now.
Now /test5 in container is just remapped (they use to call it "bind-mount") to /usbstick/rclone/alex on host which is most probably a normal FAT32 or EXT3 filesystem without overlays.
Can you run rclone in the container and mount remote storage under /test5?
mkdir /test5/mount
rclone mount YourRemote: /test5/mount ...
If NO, let's pause a little.
if YES, make a step further and rerun container with a flag allowing to back-propagate mounts from inside the container back to the host:
docker run ... ... --volume /usbstick/rclone/alex:/test5:rshared ... -it rclone/rclone:latest sh
In an ideal world this would make the rclone mount appear on host as /usrstick/rclone/alex/mount