Reading from rclone mounts soft-reboots the system

Help and Support
1

What is the problem you are having with rclone?

When trying to run rclone from a batch script to mount all my drives to virtual mount points in OpenWRT, some files are read but always end up in Access denied errors, and after a seemingly random amount of time (regardless of read/write activity) the entire system will soft-reboot with several things broken (IPv6 routing breaking, inability to redo PPPoE dialing, etc.) Just while diagnosing to post I had it happen both in the span of 10 minutes and 2 hours, yet on the meantime I was able to even stream a video through Plex coming from OneDrive, but not open several pictures coming from the same source. (Only common denominator seems to be a stack trace from python3 attached in the log files)

rclone is called as a daemon using the posted commands from a service file, then restarting both Plex and Jellyfin containers after mounting is successful, but every time I return from these crashes I have to delete empty folders inside the mount points corresponding to the folders that were accessed before the crash, otherwise several of the mounts would fail.

What is your rclone version (output from rclone version)

rclone v1.57.0
- os/version: openwrt SNAPSHOT (64 bit)
- os/kernel: 5.10.88 (aarch64)
- os/type: linux
- os/arch: arm64
- go/version: go1.17.2
- go/linking: static
- go/tags: none

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

Google Drive, OneDrive and SSH

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

        rclone mount --daemon --syslog --syslog-facility KERN --attr-timeout 8700h --dir-cache-time 8760h --vfs-cache-max-age 8760h --poll-interval 30s --allow-other --vfs-cache-max-size 24G --vfs-cache-poll-interval 20m --vfs-cache-mode writes -vv ToasterDEV-OneDrive:/ /usbstick/rclone/alex/onedrive
        rclone mount --daemon --syslog --syslog-facility KERN --attr-timeout 8700h --dir-cache-time 8760h --vfs-cache-max-age 8760h --poll-interval 30s --allow-other --vfs-cache-max-size 24G --vfs-cache-poll-interval 20m --vfs-cache-mode writes -vv ToasterDEV-GoogleDrive:/ /usbstick/rclone/alex/gdrive
        rclone mount --daemon --syslog --syslog-facility KERN --attr-timeout 8700h --dir-cache-time 8760h --vfs-cache-max-age 8760h --poll-interval 30s --allow-other --vfs-cache-max-size 24G --vfs-cache-poll-interval 20m --vfs-cache-mode writes -vv ToasterDEV-GooglePhotos:/ /usbstick/rclone/alex/gphotos
        rclone mount --daemon --syslog --syslog-facility KERN --attr-timeout 8700h --dir-cache-time 8760h --vfs-cache-max-age 8760h --poll-interval 30s --allow-other --vfs-cache-max-size 24G --vfs-cache-poll-interval 20m --vfs-cache-mode writes -vv Lizita63-OneDrive:/ /usbstick/rclone/liz/onedrive
        rclone mount --daemon --syslog --syslog-facility KERN --attr-timeout 8700h --dir-cache-time 8760h --vfs-cache-max-age 8760h --poll-interval 30s --allow-other --vfs-cache-max-size 24G --vfs-cache-poll-interval 20m --vfs-cache-mode writes -vv Lizita63-GoogleDrive:/ /usbstick/rclone/liz/gdrive
        rclone mount --daemon --syslog --syslog-facility KERN --attr-timeout 8700h --dir-cache-time 8760h --vfs-cache-max-age 8760h --poll-interval 30s --allow-other --vfs-cache-max-size 24G --vfs-cache-poll-interval 20m --vfs-cache-mode writes -vv Lizita63-GooglePhotos:/ /usbstick/rclone/liz/gphotos
        rclone mount --daemon --syslog --syslog-facility KERN --attr-timeout 8700h --dir-cache-time 8760h --vfs-cache-max-age 8760h --poll-interval 30s --allow-other --vfs-cache-max-size 24G --vfs-cache-poll-interval 20m --vfs-cache-mode writes -vv OVERNET:/tmp/mnt/ENTWARE-USB/samba /usbstick/rclone/samba/overnet
        rclone mount --daemon --syslog --syslog-facility KERN --attr-timeout 8700h --dir-cache-time 8760h --vfs-cache-max-age 8760h --poll-interval 30s --allow-other --vfs-cache-max-size 24G --vfs-cache-poll-interval 20m --vfs-cache-mode writes -vv UNDERNET:/tmp/mnt/ENTWARE-USB/samba /usbstick/rclone/samba/undernet

The rclone config contents with secrets removed.

[ToasterDEV-OneDrive]
type = onedrive
region = global
token = REMOVED
drive_id = REMOVED
drive_type = personal

[OVERNET]
type = sftp
host = 192.168.1.2
user = orpheustelos
port = 1025
md5sum_command = md5sum
sha1sum_command = none
pass = REMOVED

[UNDERNET]
type = sftp
host = 192.168.1.3
user = orpheustelos
port = 1025
md5sum_command = md5sum
sha1sum_command = none
pass = REMOVED

[ToasterDEV-GoogleDrive]
type = drive
client_id = REMOVED
client_secret = REMOVED
scope = drive.readonly
token = REMOVED

[ToasterDEV-GooglePhotos]
type = google photos
read_only = true
token = REMOVED
client_id = REMOVED
client_secret = REMOVED

[Lizita63-OneDrive]
type = onedrive
region = global
token = REMOVED
drive_id = REMOVED
drive_type = personal

[Lizita63-GoogleDrive]
type = drive
client_id = REMOVED
client_secret = REMOVED
scope = drive
token = REMOVED
[Lizita63-GooglePhotos]
type = google photos
client_id = REMOVED
client_secret = REMOVED
read_only = true
token = REMOVED

A log from the command with the -vv flag

Log kept unicorning GitHub, so uploading it as a zip file here

2

hello and welcome to the forum,

it is a common problem with running rclone on routers, of running out of memory.

3

Hello there, thanks for the welcome!

I'm not too sure if that's the issue. The router I'm using is a Raspberry Pi 4B with 4GB of RAM and a 64GB mSD card plus an M.2 enclosed 256GB SATA SSD for Docker containers.

The mSD card is pretty much just a scratch disk, over 58GB of space free and available for caching too, so unless I'm hitting a memory leak, I'm not sure if the problem could even be swap space being used.

4
  • what makes you think this is a rclone issue?
  • those logs are huge, can you just post what you think is relevant to show this is a rclone problem?

that is usually a file permissions issue, not a rclone issue.

not sure what that means, that the system reboots on its own and after the reboot IPv6 routing does not work?

with my pi4, booting from ssd, no sd card installed, i have had issues with overheating.
had to setup a cpu fan and even then still gets hot and that is a common pi problem.
tho i use ubuntu server, not openwrt.

i used to run openwrt on a linksys wrt for many years, never had issues with reboots or routing issues.

fwiw, i always thought of openwrt is a very narrow use case as a dedicated router, not a general purpose operating system for docker, plex and so on.

openwrt has a fantastic forum, many experts there who can help figure out why openwrt is randomly rebooting.

5

Mostly that the issue only appears when rclone is run, and given the binary is not available in the entware repositories for OpenWRT, I'm not too sure how likely I am to receive a response over on their forums (Docker and docker-compose on the other hand are available, for example).

If so, the only piece I think may be relevant is the following:
From system.log, a reload happens between line 46508 (where rclone was asked to read from a file) to line 46509, where the kernel starts booting up from scratch, indicated by fstab reloading sda1 and enumerating possible mount points) until service begin getting started around lines 4662*, specifically starting the configured init script for rclone in line 46624, where rclone seems unable to find its config file (normally located and not moved from /root/.config/rclone/rclone.conf). I am not sure if manually setting the location of the config file within the init script would change this situation, as manually calling the init script after the whole system has loaded proves successful.

We then go all the way until line 47754, where a kernel warning starts and outputs a trace until line 47797, which goes as follows:

Thu Dec 30 02:06:25 2021 kern.warn kernel: [  188.732032] ------------[ cut here ]------------
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  188.736660] deprecated, use hwmon sysfs instead
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  188.741227] WARNING: CPU: 0 PID: 29057 at drivers/firmware/raspberrypi.c:237 get_throttled_show+0x64/0x70
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  188.750785] Modules linked in: qcserial pppoe ppp_async option l2tp_ppp cdc_mbim brcmfmac wireguard usb_wwan sr9700 smsc95xx sierra_net sierra rndis_host qmi_wwan pppox ppp_generic pl2303 libchacha20poly1305 libblake2s iscsi_tcp ipt_REJECT huawei_cdc_ncm ftdi_sio dm9601 chacha_neon ch341 cfg80211 cdc_ncm cdc_ether ax88179_178a asix aqc111 zstd xt_time xt_tcpudp xt_tcpmss xt_statistic xt_state xt_recent xt_quota2 xt_quota xt_pkttype xt_owner xt_nat xt_multiport xt_mark xt_mac xt_limit xt_length xt_hl xt_helper xt_hashlimit xt_geoip xt_ecn xt_dscp xt_conntrack xt_connmark xt_connlimit xt_connbytes xt_comment xt_cgroup xt_addrtype xt_TEE xt_TCPMSS xt_REDIRECT xt_MASQUERADE xt_LOG xt_HL xt_FLOWOFFLOAD xt_DSCP xt_CT xt_CLASSIFY usbserial usbnet usbhid ums_usbat ums_sddr55 ums_sddr09 ums_karma ums_jumpshot ums_isd200 ums_freecom ums_datafab ums_cypress ums_alauda slhc sch_cake rtl8150 r8169 poly1305_neon pegasus nft_reject_ipv6 nft_reject_ipv4 nft_reject_inet nft_reject_bridge nft_reject
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  188.750915]  nft_redir nft_quota nft_objref nft_numgen nft_meta_bridge nft_log nft_limit nft_hash nft_fwd_netdev nft_dup_netdev nft_ct nft_counter nf_tables nf_reject_ipv4 nf_log_ipv4 nf_flow_table nf_dup_netdev nf_dup_ipv6 nf_dup_ipv4 nf_conntrack_netlink nf_conncount macvlan lzo libiscsi_tcp libiscsi libcurve25519_generic libchacha libblake2s_generic iptable_raw iptable_nat iptable_mangle iptable_filter ipt_ECN ip6table_raw ip_tables hid_generic crc_ccitt compat cdc_wdm cdc_acm brcmutil br_netfilter spi_bcm2835 fuse sch_teql sch_sfq sch_red sch_prio sch_pie sch_multiq sch_gred sch_fq sch_dsmark sch_codel em_text em_nbyte em_meta em_cmp act_simple act_police act_pedit act_ipt act_csum cls_bpf act_bpf act_ctinfo sch_tbf sch_ingress sch_htb sch_hfsc em_u32 cls_u32 cls_tcindex cls_route cls_matchall cls_fw cls_flow cls_basic act_skbedit act_mirred act_gact snd_bcm2835(C) hid pwm_bcm2835 evdev i2c_bcm2835 usb_f_acm u_serial usb_f_mass_storage usb_f_hid usb_f_ecm u_ether i2c_dev libcomposite
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  188.837971]  ledtrig_usbport ledtrig_oneshot ledtrig_gpio cryptodev xt_set ip_set_list_set ip_set_hash_netportnet ip_set_hash_netport ip_set_hash_netnet ip_set_hash_netiface ip_set_hash_net ip_set_hash_mac ip_set_hash_ipportnet ip_set_hash_ipportip ip_set_hash_ipport ip_set_hash_ipmark ip_set_hash_ip ip_set_bitmap_port ip_set_bitmap_ipmac ip_set_bitmap_ip ip_set nfnetlink ip6table_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 ip6t_NPT ip6t_rt ip6t_mh ip6t_ipv6header ip6t_hbh ip6t_frag ip6t_eui64 ip6t_ah nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables ip6t_REJECT x_tables nf_reject_ipv6 nfsv4 nfsd nfs nfs_ssc bonding ip6_gre ip_gre gre ifb dummy sit l2tp_netlink l2tp_core udp_tunnel ip6_udp_tunnel ipip ip6_tunnel tunnel6 tunnel4 ip_tunnel rpcsec_gss_krb5 auth_rpcgss oid_registry veth tun snd_rawmidi snd_seq_device snd_pcm_oss snd_pcm_dmaengine snd_mixer_oss snd_hwdep snd_compress snd_pcm snd_timer snd soundcore lockd sunrpc grace isofs hfsplus cdrom cifs
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  188.925537]  dns_resolver dm_mirror dm_region_hash dm_log dm_crypt dm_mod dax nls_utf8 crypto_user algif_skcipher algif_rng algif_hash algif_aead af_alg sha1_generic md5 md4 kpp des_generic libdes cmac authenc arc4 crypto_acompress vfat fat nls_iso8859_1 nls_cp437 dwc2 roles uhci_hcd ohci_platform ohci_hcd ledtrig_transient fsl_mph_dr_of ehci_platform ehci_fsl ehci_hcd gpio_button_hotplug exfat btrfs xor zstd_decompress zstd_compress zlib_inflate zlib_deflate xxhash xor_neon raid6_pq lzo_decompress lzo_compress libcrc32c realtek encrypted_keys trusted tpm
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.061705] CPU: 0 PID: 29057 Comm: python3 Tainted: G         C        5.10.88 #0
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.069266] Hardware name: Raspberry Pi 4 Model B Rev 1.1 (DT)
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.075095] pstate: 80400005 (Nzcv daif +PAN -UAO -TCO BTYPE=--)
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.081101] pc : get_throttled_show+0x64/0x70
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.085455] lr : get_throttled_show+0x64/0x70
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.089803] sp : ffffffc011babc20
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.093110] x29: ffffffc011babc20 x28: ffffff804120b0b0
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.098414] x27: 0000000000400cc0 x26: ffffff804120b0a0
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.103718] x25: 0000000000000000 x24: ffffff80a44e9a00
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.109023] x23: ffffff80402fb010 x22: ffffff8047205000
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.114327] x21: ffffffc0107eb0a0 x20: ffffff80402a6f00
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.119631] x19: ffffff8047205000 x18: 000000000000037c
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.124934] x17: 0000000000000000 x16: 0000000000000000
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.130237] x15: ffffffc010a278d0 x14: 0000000000000a74
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.135541] x13: 000000000000237c x12: ffffffc011bab8f8
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.140844] x11: 000000000004cd70 x10: 000000000004cd10
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.146147] x9 : ffffffc010a7f8d0 x8 : 00000000000053a0
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.151450] x7 : ffffffc010a278d0 x6 : 0000000000000001
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.156753] x5 : ffffff80fb8266b0 x4 : 0000000000000000
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.162057] x3 : 0000000000000027 x2 : 0000000000000027
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.167361] x1 : 0000000000000023 x0 : 0000000000000023
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.172665] Call trace:
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.175115]  get_throttled_show+0x64/0x70
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.179125]  dev_attr_show+0x20/0x5c
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.182697]  sysfs_kf_seq_show+0x88/0x130
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.186700]  kernfs_seq_show+0x2c/0x40
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.190444]  seq_read_iter+0x1bc/0x4a0
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.194186]  kernfs_fop_read_iter+0x150/0x1d0
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.198536]  new_sync_read+0xd4/0x150
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.202193]  vfs_read+0x11c/0x1a0
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.205500]  ksys_read+0x58/0xe0
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.208722]  __arm64_sys_read+0x1c/0x30
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.212554]  do_el0_svc+0xbc/0x140
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.215951]  el0_svc+0x14/0x20
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.219000]  el0_sync_handler+0xa4/0x140
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.222915]  el0_sync+0x164/0x180
Thu Dec 30 02:06:25 2021 kern.warn kernel: [  189.226221] ---[ end trace c9e8e9273e9271cb ]---

The DHCP server restarts a couple more times, then the log cuts off.

system.log.old just includes queries related to file accesses, but coincides with the Access denied issue, as whenever I try to open this particular file, I just receive an error stated as <nil>

Wed Dec 29 23:23:31 2021 kern.debug rclone[1994]: Pictures/My Nintendo Wallpapers/: Lookup: name="December calendar - Xenoblade Chronicles 2"
Wed Dec 29 23:23:31 2021 kern.debug rclone[1994]: Pictures/My Nintendo Wallpapers/: >Lookup: node=Pictures/My Nintendo Wallpapers/December calendar - Xenoblade Chronicles 2/, err=<nil>

The Pi is inside a case with an onboard fan, highest I've got so far has been 68°C, so far no overheating.

Going through the log just now, I'm honestly not too sure where and when is the problem occurring, and given the only common factor is rclone itself, I don't know how would I go about asking for help or troubleshooting in a reliable manner (perhaps by using debug symbols or something of the sort I would be able to get even more verbosity), but as of right now all I can think of is that perhaps attempting to run rclone within a Docker container would isolate the router's OS environment being the primary issue.

Until then, if there's any pointers you could give me as to what else I could try to isolate the root cause, I'd be glad to see is there's any way around this issue.

Cheers!

6

Hi Arturo

Linux (OpenWrt is a Debian Linux derivative) kernel MUST be rock solid. In no event should a user space program make it crash or reboot the system. However, in embedded world this rule does not always work. How could rclone crash an embedded device?

  • by requesting too much RAM/swap due to memory leak (I belive we have ironed out most cases but who knows)
  • by requesting too much RAM/swap for directory/attr cache (we avoid it below)
  • by using flash/SSD so intensively that it uses too much current stressing a weak embedded power supply (I encountered this with my router when I added an external USB modem and started hashing files on SSD - I fixed it by adding an external USB hub with higher price, separate power adapter and device isolation by current)
  • by working with FUSE kernel driver in a pattern that triggers a bug in it causing kernel panic (I'll discuss it later)

Let's look at your command line:

Where could we strip complexity here?
First, let's leave only one rclone mount and comment out the rest.

--daemon asks rclone to run a background copy of itself detached from console, wait a little for successful start and exit to simulate ordinary mount command (useful for using rclone with /etc/fstab). Replace it with just rclone mount ... & without --daemon. This way you can be sure that the mounting process has the console. You will need it when you kill -SIGQUIT to print stack trace in case of deadlocks.

--allow-other - keep it. It avoids permission errors due to non-standard security model of FUSE. Some background: normally if you assign a file with 666 permissions it normally means everyone can read and write it... But FUSE is not "normal" it adds the permission condition of "user id of the process owning the mount". The --allow-other flag drops this condition and returns semantics back to normal. :slight_smile:

--attr-timeout 8700h --dir-cache-time 8760h - remove this. Let's get memory cache out of equation to avoid RAM overflow and swapping.

--vfs-cache-max-age 8760h --poll-interval 30s --vfs-cache-max-size 24G --vfs-cache-poll-interval 20m --vfs-cache-mode writes - remove it all.
Let's get disk cache out of equation to prevent overheating and higher power consumption by flash/SSD cards serving the cache. Instead, use --vfs-cache-mode none.

-vv - keep it. We need a lot of debugging.

--syslog --syslog-facility KERN - keep it. Let's see events from rclone and kernel intermixed to better understand the bug timeline.

Now leave it working for several hours. Run a simple bash script to make some load on the mount, like while true; do touch /mount/file1; sleep 1; rm /mount/file1; sleep 1; done... You got the idea :wink:

Will it crash your system?

7

Let's talk a little bit about the last crasher item, the FUSE. Its main part is a driver in kernel, which receives read/write/mkdir/etc events from the mounted directory via kernel VFS layer and passes further to user-space program (rclone) serving the mount via /dev/fuse control device.
Containers add complexity on this path as FUSE and kernel VFS should additionally remap / parts / in / the / path according to current mount table depending on the container (or host system) the current process belongs to. More complexity triggers more bugs. We eliminated this complexity by eliminating docker.

rclone works with the /dev/fuse device via a library. The core rclone developer has tried three golang fuse libraries so far:

  • billziss/cgo-fuse - rock solid, the only one that works on windows/mac; but the bad thing is it produces non-static rclone and adds dependency on GNU libc.so and the libfuse.so dynamic library, so we don't YET release it for linux or with docker; this is rclone mount on windows/mac or rclone cmount on linux if rclone was built as a shared binary
  • bazil/go-fuse - gives <5% probability of deadlocks in daily stress tests on the main rclone test box; this is rclone mount on linux or in dockerized rclone
  • hanwen/go-fuse - >5% probability of errors in daily stress tests, we don't have enough human resources to iron them out; we provide it as rclone mount2 in static rclone builds for linux/docker

Note: rclone team runs daily stress tests for a number of OS/storage combinations, where OS is Windows/MacOS/Linux, where Linux means Ubuntu latest LTS.
We run ZERO tests on OpenWrt, have NO stability data for this platform.

So now you tried to eliminate most causes above, but if you still experience crashes/restarts
then most probably we have a bug on the path
mount -> kernel VFS -> FUSE driver -> /dev/fuse -> FUSE library -> rclone proper
Then the easiest mitigation you can try is replace rclone mount by rclone mount2.
It's known to be unstable on Ubuntu, but maybe it can help with OpenWrt?

8

Okay, so the script has been running for over a day at this point and I can thankfully report no crashes!

The command I ended up with was the following:

rclone mount --syslog --syslog-facility KERN --poll-interval 30s --allow-other --vfs-cache-mode off -vv ToasterDEV-OneDrive:/ /usbstick/rclone/alex/onedrive

And aside from some I/O errors appearing sporadically, it seems the system was able to both read and write the test file to OneDrive without any issues!

[root@OpenWRT-RPi /]# while true; do touch /usbstick/rclone/alex/onedrive/to
uchtest.txt; sleep 1; rm /usbstick/rclone/alex/onedrive/touchtest.txt; sleep
 1; done
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: close failed: Operation not permitted
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: close failed: Operation not permitted
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: close failed: Operation not permitted
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error
touch: close failed: Operation not permitted
touch: /usbstick/rclone/alex/onedrive/touchtest.txt: I/O error
rm: can't remove '/usbstick/rclone/alex/onedrive/touchtest.txt': I/O error

Mon Jan 17 20:01:37 2022 kern.debug rclone[28444]: &{touchtest.txt (w)}: Flush:
Mon Jan 17 20:01:37 2022 kern.debug rclone[28444]: touchtest.txt: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions
Mon Jan 17 20:01:37 2022 kern.debug rclone[28444]: : Added virtual directory entry vAddFile: "touchtest.txt"
Mon Jan 17 20:01:37 2022 kern.debug rclone[28444]: &{touchtest.txt (w)}: >Flush: err=<nil>
Mon Jan 17 20:01:37 2022 kern.debug rclone[28444]: &{touchtest.txt (w)}: Release:
Mon Jan 17 20:01:37 2022 kern.debug rclone[28444]: touchtest.txt: WriteFileHandle.Release closing
Mon Jan 17 20:01:37 2022 kern.debug rclone[28444]: One drive root '': File to upload is small (0 bytes), uploading instead of streaming
Mon Jan 17 20:01:37 2022 kern.debug rclone[28444]: touchtest.txt: Starting singlepart upload
Mon Jan 17 20:01:38 2022 kern.debug rclone[28444]: touchtest.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
Mon Jan 17 20:01:38 2022 kern.info rclone[28444]: touchtest.txt: Copied (new)
Mon Jan 17 20:01:38 2022 kern.debug rclone[28444]: : Added virtual directory entry vAddFile: "touchtest.txt"
Mon Jan 17 20:01:38 2022 kern.debug rclone[28444]: &{touchtest.txt (w)}: >Release: err=<nil>
Mon Jan 17 20:01:38 2022 kern.debug rclone[28444]: /: Remove: name="touchtest.txt"
Mon Jan 17 20:01:38 2022 kern.debug rclone[28444]: touchtest.txt: Remove:
Mon Jan 17 20:01:38 2022 kern.debug rclone[28444]: : Added virtual directory entry vDel: "touchtest.txt"
Mon Jan 17 20:01:39 2022 kern.debug rclone[28444]: touchtest.txt: >Remove: err=<nil>
Mon Jan 17 20:01:39 2022 kern.debug rclone[28444]: /: >Remove: err=<nil>
Mon Jan 17 20:01:40 2022 kern.debug rclone[28444]: /: Lookup: name="touchtest.txt"
Mon Jan 17 20:01:40 2022 kern.debug rclone[28444]: /: >Lookup: node=<nil>, err=no such file or directory
Mon Jan 17 20:01:40 2022 kern.debug rclone[28444]: /: Lookup: name="touchtest.txt"
Mon Jan 17 20:01:40 2022 kern.debug rclone[28444]: /: >Lookup: node=<nil>, err=no such file or directory
Mon Jan 17 20:01:40 2022 kern.debug rclone[28444]: /: Create: name="touchtest.txt"
Mon Jan 17 20:01:40 2022 kern.debug rclone[28444]: touchtest.txt: Open: flags=O_RDWR|O_CREATE|0x20000
Mon Jan 17 20:01:40 2022 kern.debug rclone[28444]: : Added virtual directory entry vAddFile: "touchtest.txt"
Mon Jan 17 20:01:40 2022 kern.debug rclone[28444]: touchtest.txt: >Open: fd=touchtest.txt (w), err=<nil>
Mon Jan 17 20:01:40 2022 kern.debug rclone[28444]: /: >Create: node=touchtest.txt, handle=&{touchtest.txt (w)}, err=<nil>
Mon Jan 17 20:01:40 2022 kern.debug rclone[28444]: touchtest.txt: Attr:
Mon Jan 17 20:01:40 2022 kern.debug rclone[28444]: touchtest.txt: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Mon Jan 17 20:01:40 2022 kern.debug rclone[28444]: &{touchtest.txt (w)}: Flush:
Mon Jan 17 20:01:40 2022 kern.debug rclone[28444]: touchtest.txt: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions
Mon Jan 17 20:01:40 2022 kern.debug rclone[28444]: : Added virtual directory entry vAddFile: "touchtest.txt"
Mon Jan 17 20:01:40 2022 kern.debug rclone[28444]: &{touchtest.txt (w)}: >Flush: err=<nil>
Mon Jan 17 20:01:40 2022 kern.debug rclone[28444]: &{touchtest.txt (w)}: Release:
Mon Jan 17 20:01:40 2022 kern.debug rclone[28444]: touchtest.txt: WriteFileHandle.Release closing
Mon Jan 17 20:01:40 2022 kern.debug rclone[28444]: One drive root '': File to upload is small (0 bytes), uploading instead of streaming
Mon Jan 17 20:01:40 2022 kern.debug rclone[28444]: touchtest.txt: Starting singlepart upload
Mon Jan 17 20:01:41 2022 kern.debug rclone[28444]: /: Remove: name="touchtest.txt"
Mon Jan 17 20:01:41 2022 kern.debug rclone[28444]: touchtest.txt: Remove:
Mon Jan 17 20:01:41 2022 kern.debug rclone[28444]: : Added virtual directory entry vDel: "touchtest.txt"
Mon Jan 17 20:01:41 2022 kern.debug rclone[28444]: touchtest.txt: >Remove: err=<nil>
Mon Jan 17 20:01:41 2022 kern.debug rclone[28444]: /: >Remove: err=<nil>
Mon Jan 17 20:01:41 2022 kern.debug rclone[28444]: touchtest.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
Mon Jan 17 20:01:41 2022 kern.info rclone[28444]: touchtest.txt: Copied (new)
Mon Jan 17 20:01:41 2022 kern.debug rclone[28444]: : Added virtual directory entry vAddFile: "touchtest.txt"
Mon Jan 17 20:01:41 2022 kern.debug rclone[28444]: &{touchtest.txt (w)}: >Release: err=<nil>
Mon Jan 17 20:01:42 2022 kern.debug rclone[28444]: /: Lookup: name="touchtest.txt"
Mon Jan 17 20:01:42 2022 kern.debug rclone[28444]: /: >Lookup: node=touchtest.txt, err=<nil>
Mon Jan 17 20:01:42 2022 kern.debug rclone[28444]: touchtest.txt: Attr:
Mon Jan 17 20:01:42 2022 kern.debug rclone[28444]: touchtest.txt: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Mon Jan 17 20:01:42 2022 kern.debug rclone[28444]: touchtest.txt: Setattr: a=Setattr [ID=0xab05c Node=0x2a Uid=0 Gid=0 Pid=3145] atime=2022-01-17 20:01:42.129453172 -0600 CST atime=now mtime=2022-01-17 20:01:42.129453172 -0600 CST mtime=now handle=INVALID-0x0
Mon Jan 17 20:01:42 2022 kern.debug rclone[28444]: touchtest.txt: Applied pending mod time 2022-01-17 20:01:42.129453172 -0600 CST OK
Mon Jan 17 20:01:42 2022 kern.debug rclone[28444]: touchtest.txt: >Setattr: err=<nil>
Mon Jan 17 20:01:42 2022 kern.debug rclone[28444]: touchtest.txt: Attr:
Mon Jan 17 20:01:42 2022 kern.debug rclone[28444]: touchtest.txt: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Mon Jan 17 20:01:43 2022 kern.debug rclone[28444]: /: Lookup: name="touchtest.txt"
Mon Jan 17 20:01:43 2022 kern.debug rclone[28444]: /: >Lookup: node=touchtest.txt, err=<nil>
Mon Jan 17 20:01:43 2022 kern.debug rclone[28444]: touchtest.txt: Attr:
Mon Jan 17 20:01:43 2022 kern.debug rclone[28444]: touchtest.txt: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Mon Jan 17 20:01:43 2022 kern.debug rclone[28444]: /: Remove: name="touchtest.txt"
Mon Jan 17 20:01:43 2022 kern.debug rclone[28444]: touchtest.txt: Remove:
Mon Jan 17 20:01:43 2022 kern.debug rclone[28444]: : Added virtual directory entry vDel: "touchtest.txt"
Mon Jan 17 20:01:43 2022 kern.debug rclone[28444]: touchtest.txt: >Remove: err=<nil>
Mon Jan 17 20:01:43 2022 kern.debug rclone[28444]: /: >Remove: err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: ReadDirAll:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >ReadDirAll: item=28, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="AndroidStudio"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=AndroidStudio/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: AndroidStudio/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: AndroidStudio/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="Aplicaciones"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=Aplicaciones/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Aplicaciones/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Aplicaciones/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="AppData"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=AppData/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: AppData/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: AppData/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="AssistantComputerControl"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=AssistantComputerControl/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: AssistantComputerControl/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: AssistantComputerControl/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="CRX"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=CRX/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: CRX/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: CRX/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="Comunicado_RInterinas.pdf"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=Comunicado_RInterinas.pdf, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Comunicado_RInterinas.pdf: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Comunicado_RInterinas.pdf: >Attr: a=valid=1s ino=0 size=143140 mode=-rw-r--r--, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="Contacts"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=Contacts/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Contacts/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Contacts/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="Creative Cloud Files"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=Creative Cloud Files/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Creative Cloud Files/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Creative Cloud Files/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="Desktop"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=Desktop/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Desktop/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Desktop/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="Documents"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=Documents/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Documents/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Documents/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="Downloads"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=Downloads/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Downloads/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Downloads/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="Favorites"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=Favorites/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Favorites/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Favorites/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="JetbrainsProjects"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=JetbrainsProjects/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: JetbrainsProjects/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: JetbrainsProjects/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="Links"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=Links/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Links/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Links/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="Music"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=Music/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Music/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Music/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="OpenVPN"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=OpenVPN/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: OpenVPN/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: OpenVPN/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="Pictures"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=Pictures/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Pictures/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Pictures/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="Saved Games"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=Saved Games/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Saved Games/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Saved Games/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="Searches"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=Searches/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Searches/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Searches/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="TizenStudio"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=TizenStudio/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: TizenStudio/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: TizenStudio/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="Videos"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=Videos/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Videos/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Videos/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="Voice Recorder"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=Voice Recorder/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Voice Recorder/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Voice Recorder/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="Xilinx"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=Xilinx/, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Xilinx/: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: Xilinx/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="id_ed25519"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=id_ed25519, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: id_ed25519: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: id_ed25519: >Attr: a=valid=1s ino=0 size=411 mode=-rw-r--r--, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="pia-token.txt"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=pia-token.txt, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: pia-token.txt: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: pia-token.txt: >Attr: a=valid=1s ino=0 size=322 mode=-rw-r--r--, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="tufdevme.conf"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=tufdevme.conf, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: tufdevme.conf: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: tufdevme.conf: >Attr: a=valid=1s ino=0 size=452 mode=-rw-r--r--, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="touchtest.txt"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=<nil>, err=no such file or directory
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Lookup: name="touchtest.txt"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Lookup: node=<nil>, err=no such file or directory
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: Create: name="touchtest.txt"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: touchtest.txt: Open: flags=O_RDWR|O_CREATE|0x20000
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: : Added virtual directory entry vAddFile: "touchtest.txt"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: touchtest.txt: >Open: fd=touchtest.txt (w), err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: /: >Create: node=touchtest.txt, handle=&{touchtest.txt (w)}, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: touchtest.txt: Attr:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: touchtest.txt: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: &{touchtest.txt (w)}: Flush:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: touchtest.txt: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: : Added virtual directory entry vAddFile: "touchtest.txt"
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: &{touchtest.txt (w)}: >Flush: err=<nil>
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: &{touchtest.txt (w)}: Release:
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: touchtest.txt: WriteFileHandle.Release closing
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: One drive root '': File to upload is small (0 bytes), uploading instead of streaming
Mon Jan 17 20:01:44 2022 kern.debug rclone[28444]: touchtest.txt: Starting singlepart upload
Mon Jan 17 20:01:45 2022 kern.debug rclone[28444]: touchtest.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
Mon Jan 17 20:01:45 2022 kern.info rclone[28444]: touchtest.txt: Copied (new)
Mon Jan 17 20:01:45 2022 kern.debug rclone[28444]: : Added virtual directory entry vAddFile: "touchtest.txt"
Mon Jan 17 20:01:45 2022 kern.debug rclone[28444]: &{touchtest.txt (w)}: >Release: err=<nil>
Mon Jan 17 20:01:45 2022 kern.debug rclone[28444]: touchtest.txt: Attr:
Mon Jan 17 20:01:45 2022 kern.debug rclone[28444]: touchtest.txt: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Mon Jan 17 20:01:45 2022 kern.debug rclone[28444]: /: Remove: name="touchtest.txt"
Mon Jan 17 20:01:45 2022 kern.debug rclone[28444]: touchtest.txt: Remove:
Mon Jan 17 20:01:45 2022 kern.debug rclone[28444]: : Added virtual directory entry vDel: "touchtest.txt"
Mon Jan 17 20:01:46 2022 kern.debug rclone[28444]: touchtest.txt: >Remove: err=<nil>
Mon Jan 17 20:01:46 2022 kern.debug rclone[28444]: /: >Remove: err=<nil>
Mon Jan 17 20:01:47 2022 kern.debug rclone[28444]: /: Lookup: name="touchtest.txt"
Mon Jan 17 20:01:47 2022 kern.debug rclone[28444]: /: >Lookup: node=<nil>, err=no such file or directory
Mon Jan 17 20:01:47 2022 kern.debug rclone[28444]: /: Lookup: name="touchtest.txt"
Mon Jan 17 20:01:47 2022 kern.debug rclone[28444]: /: >Lookup: node=<nil>, err=no such file or directory
Mon Jan 17 20:01:47 2022 kern.debug rclone[28444]: /: Create: name="touchtest.txt"
Mon Jan 17 20:01:47 2022 kern.debug rclone[28444]: touchtest.txt: Open: flags=O_RDWR|O_CREATE|0x20000
Mon Jan 17 20:01:47 2022 kern.debug rclone[28444]: : Added virtual directory entry vAddFile: "touchtest.txt"
Mon Jan 17 20:01:47 2022 kern.debug rclone[28444]: touchtest.txt: >Open: fd=touchtest.txt (w), err=<nil>
Mon Jan 17 20:01:47 2022 kern.debug rclone[28444]: /: >Create: node=touchtest.txt, handle=&{touchtest.txt (w)}, err=<nil>
Mon Jan 17 20:01:47 2022 kern.debug rclone[28444]: touchtest.txt: Attr:
Mon Jan 17 20:01:47 2022 kern.debug rclone[28444]: touchtest.txt: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Mon Jan 17 20:01:47 2022 kern.debug rclone[28444]: &{touchtest.txt (w)}: Flush:
Mon Jan 17 20:01:47 2022 kern.debug rclone[28444]: touchtest.txt: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions
Mon Jan 17 20:01:47 2022 kern.debug rclone[28444]: : Added virtual directory entry vAddFile: "touchtest.txt"
Mon Jan 17 20:01:47 2022 kern.debug rclone[28444]: &{touchtest.txt (w)}: >Flush: err=<nil>
Mon Jan 17 20:01:47 2022 kern.debug rclone[28444]: &{touchtest.txt (w)}: Release:
Mon Jan 17 20:01:47 2022 kern.debug rclone[28444]: touchtest.txt: WriteFileHandle.Release closing
Mon Jan 17 20:01:47 2022 kern.debug rclone[28444]: One drive root '': File to upload is small (0 bytes), uploading instead of streaming
Mon Jan 17 20:01:47 2022 kern.debug rclone[28444]: touchtest.txt: Starting singlepart upload
Mon Jan 17 20:01:48 2022 kern.debug rclone[28444]: touchtest.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
Mon Jan 17 20:01:48 2022 kern.info rclone[28444]: touchtest.txt: Copied (new)
Mon Jan 17 20:01:48 2022 kern.debug rclone[28444]: : Added virtual directory entry vAddFile: "touchtest.txt"
Mon Jan 17 20:01:48 2022 kern.debug rclone[28444]: &{touchtest.txt (w)}: >Release: err=<nil>
Mon Jan 17 20:01:48 2022 kern.debug rclone[28444]: touchtest.txt: Attr:
Mon Jan 17 20:01:48 2022 kern.debug rclone[28444]: touchtest.txt: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Mon Jan 17 20:01:48 2022 kern.debug rclone[28444]: /: Remove: name="touchtest.txt"
Mon Jan 17 20:01:48 2022 kern.debug rclone[28444]: touchtest.txt: Remove:
Mon Jan 17 20:01:48 2022 kern.debug rclone[28444]: : Added virtual directory entry vDel: "touchtest.txt"
Mon Jan 17 20:01:48 2022 kern.debug rclone[28444]: touchtest.txt: >Remove: err=<nil>
Mon Jan 17 20:01:48 2022 kern.debug rclone[28444]: /: >Remove: err=<nil>
Mon Jan 17 20:01:49 2022 kern.debug rclone[28444]: /: Lookup: name="touchtest.txt"
Mon Jan 17 20:01:49 2022 kern.debug rclone[28444]: /: >Lookup: node=<nil>, err=no such file or directory
Mon Jan 17 20:01:49 2022 kern.debug rclone[28444]: /: Lookup: name="touchtest.txt"
Mon Jan 17 20:01:49 2022 kern.debug rclone[28444]: /: >Lookup: node=<nil>, err=no such file or directory
Mon Jan 17 20:01:49 2022 kern.debug rclone[28444]: /: Create: name="touchtest.txt"
Mon Jan 17 20:01:49 2022 kern.debug rclone[28444]: touchtest.txt: Open: flags=O_RDWR|O_CREATE|0x20000
Mon Jan 17 20:01:49 2022 kern.debug rclone[28444]: : Added virtual directory entry vAddFile: "touchtest.txt"
Mon Jan 17 20:01:49 2022 kern.debug rclone[28444]: touchtest.txt: >Open: fd=touchtest.txt (w), err=<nil>
Mon Jan 17 20:01:49 2022 kern.debug rclone[28444]: /: >Create: node=touchtest.txt, handle=&{touchtest.txt (w)}, err=<nil>
Mon Jan 17 20:01:49 2022 kern.debug rclone[28444]: touchtest.txt: Attr:
Mon Jan 17 20:01:49 2022 kern.debug rclone[28444]: touchtest.txt: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Mon Jan 17 20:01:49 2022 kern.debug rclone[28444]: &{touchtest.txt (w)}: Flush:
Mon Jan 17 20:01:49 2022 kern.debug rclone[28444]: touchtest.txt: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions
Mon Jan 17 20:01:49 2022 kern.debug rclone[28444]: : Added virtual directory entry vAddFile: "touchtest.txt"
Mon Jan 17 20:01:49 2022 kern.debug rclone[28444]: &{touchtest.txt (w)}: >Flush: err=<nil>
Mon Jan 17 20:01:49 2022 kern.debug rclone[28444]: &{touchtest.txt (w)}: Release:
Mon Jan 17 20:01:49 2022 kern.debug rclone[28444]: touchtest.txt: WriteFileHandle.Release closing
Mon Jan 17 20:01:49 2022 kern.debug rclone[28444]: One drive root '': File to upload is small (0 bytes), uploading instead of streaming
Mon Jan 17 20:01:49 2022 kern.debug rclone[28444]: touchtest.txt: Starting singlepart upload
Mon Jan 17 20:01:50 2022 kern.debug rclone[28444]: touchtest.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
Mon Jan 17 20:01:50 2022 kern.info rclone[28444]: touchtest.txt: Copied (new)
Mon Jan 17 20:01:50 2022 kern.debug rclone[28444]: : Added virtual directory entry vAddFile: "touchtest.txt"
Mon Jan 17 20:01:50 2022 kern.debug rclone[28444]: &{touchtest.txt (w)}: >Release: err=<nil>
Mon Jan 17 20:01:50 2022 kern.debug rclone[28444]: touchtest.txt: Attr:
Mon Jan 17 20:01:50 2022 kern.debug rclone[28444]: touchtest.txt: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Mon Jan 17 20:01:50 2022 kern.debug rclone[28444]: /: Remove: name="touchtest.txt"
Mon Jan 17 20:01:50 2022 kern.debug rclone[28444]: touchtest.txt: Remove:
Mon Jan 17 20:01:50 2022 kern.debug rclone[28444]: : Added virtual directory entry vDel: "touchtest.txt"

Should I try to mass-mount and attempt normal usage without cache, or is there any other way to diagnose why would caching crash the system?

Thanks for the help!

9

  1. There is something strange about touched file. The rclone log does not indicate any errors (they are <nil>), but the kernel VFS returns I/O error to the process accessing the mount. Based on the access path picture the error most probably bubbled up in between FUSE driver -> /dev/fuse -> FUSE library.
    I'm starting to suspect that the fuse driver in your OpenWrt build is cheesy (unstable) but can't prove.
    Will the error persist if you change the fuse library i.e. run rclone as rclone mount2 .....?

  2. Start loading your mount more than just touch/rm/sleep - run plex, copy movies back'n'forth. Will it crash?

  3. If it runs fine, add back the memory cache --attr-cache --dir-cache. Still fine?

  4. If still fine, add back the disk cache.

  5. At this step you will know the guilty piece (memory and/or disk cache). Keep it disabled. Activate remaining mounts.

10

Unfortunately, it seems like it.

I tried running the command twice, first as mount, then mount2, but the following results were gathered.

When attempting to load the mount harder by rescanning my Plex library, mount was able to work correctly until reaching a particular file, at which point the system tried to read it several times until it stopped hanging. At this point I was able to open pictures and music, but movies were a no go.

Tue Jan 18 00:05:35 2022 kern.debug rclone[32590]: Creating backend with remote "ToasterDEV-OneDrive:/"
Tue Jan 18 00:05:35 2022 kern.debug rclone[32590]: Using config file from "/root/.config/rclone/rclone.conf"
Tue Jan 18 00:05:36 2022 kern.debug rclone[32590]: fs cache: renaming cache item "ToasterDEV-OneDrive:/" to be canonical "ToasterDEV-OneDrive:"
Tue Jan 18 00:05:36 2022 kern.info rclone[32590]: One drive root '': poll-interval is not supported by this remote
Tue Jan 18 00:05:36 2022 kern.notice rclone[32590]: One drive root '': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
Tue Jan 18 00:05:36 2022 kern.debug rclone[32590]: One drive root '': Mounting on "/usbstick/rclone/alex/onedrive"
Tue Jan 18 00:05:36 2022 kern.debug rclone[32590]: : Root:
Tue Jan 18 00:05:36 2022 kern.debug rclone[32590]: : >Root: node=/, err=<nil>
Tue Jan 18 00:06:02 2022 kern.debug rclone[32590]: /: Lookup: name="Videos"
Tue Jan 18 00:06:02 2022 kern.debug rclone[32590]: /: >Lookup: node=Videos/, err=<nil>
Tue Jan 18 00:06:02 2022 kern.debug rclone[32590]: Videos/: Attr:
Tue Jan 18 00:06:02 2022 kern.debug rclone[32590]: Videos/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Tue Jan 18 00:06:02 2022 kern.debug rclone[32590]: Videos/: Lookup: name="Series"
Tue Jan 18 00:06:03 2022 kern.debug rclone[32590]: Videos/: >Lookup: node=Videos/Series/, err=<nil>
Tue Jan 18 00:06:03 2022 kern.debug rclone[32590]: Videos/Series/: Attr:
Tue Jan 18 00:06:03 2022 kern.debug rclone[32590]: Videos/Series/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Tue Jan 18 00:06:03 2022 daemon.err dockerd[25143]: time="2022-01-18T00:06:03.220601737-06:00" level=info msg="starting signal loop" namespace=moby path=/tmp/run/docker/containerd/daemon/io.containerd.runtime.v2.task/moby/f8ce99c177723f3ef4053e99247595ccad5f29ffddd008d4270744c3fdade0cc pid=585
Tue Jan 18 00:06:07 2022 kern.debug rclone[32590]: Videos/Movies/: Lookup: name=".grab"
Tue Jan 18 00:06:08 2022 kern.debug rclone[32590]: Videos/Movies/: >Lookup: node=<nil>, err=no such file or directory
Tue Jan 18 00:06:08 2022 kern.debug rclone[32590]: Music/: Lookup: name=".grab"
Tue Jan 18 00:06:09 2022 kern.debug rclone[32590]: Music/: >Lookup: node=<nil>, err=no such file or directory
Tue Jan 18 00:06:09 2022 kern.debug rclone[32590]: Videos/Pictures/: Lookup: name=".grab"
Tue Jan 18 00:06:09 2022 kern.debug rclone[32590]: Videos/Pictures/: >Lookup: node=<nil>, err=no such file or directory
Tue Jan 18 00:06:09 2022 kern.debug rclone[32590]: Videos/Series/: Lookup: name=".grab"
Tue Jan 18 00:06:09 2022 kern.debug rclone[32590]: Videos/Series/: >Lookup: node=<nil>, err=no such file or directory
Tue Jan 18 00:06:27 2022 kern.debug rclone[32590]: Videos/Movies/: Lookup: name=".grab"
Tue Jan 18 00:06:27 2022 kern.debug rclone[32590]: Videos/Movies/: >Lookup: node=<nil>, err=no such file or directory
Tue Jan 18 00:06:27 2022 kern.debug rclone[32590]: Music/: Lookup: name=".grab"
Tue Jan 18 00:06:27 2022 kern.debug rclone[32590]: Music/: >Lookup: node=<nil>, err=no such file or directory
Tue Jan 18 00:06:27 2022 kern.debug rclone[32590]: Videos/Pictures/: Lookup: name=".grab"
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png: ChunkedReader.Read at 0 length 16384 chunkOffset 0 chunkSize 134217728
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: &{Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png (r)}: >Read: read=16384, err=<nil>
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: &{Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png (r)}: Flush:
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: &{Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png (r)}: >Flush: err=<nil>
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: &{Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png (r)}: Release:
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png: ReadFileHandle.Release closing
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png: Open: flags=OpenReadOnly+0x20000
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png: Open: flags=O_RDONLY|0x20000
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png: >Open: fd=Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png (r), err=<nil>
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: &{Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png (r)}: >Release: err=<nil>
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png: >Open: fh=&{Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png (r)}, err=<nil>
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: &{Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png (r)}: Read: len=16384, offset=0
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png: ChunkedReader.openRange at 0 length 134217728
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: &{Videos/Movies/Blue Movie (Fuck).mp4 (r)}: Read: len=131072, offset=555155456
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: &{Videos/Movies/Blue Movie (Fuck).mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: &{Videos/Movies/Blue Movie (Fuck).mp4 (r)}: Read: len=131072, offset=555286528
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: &{Videos/Movies/Blue Movie (Fuck).mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 00:59:53 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png: ChunkedReader.Read at 0 length 16384 chunkOffset 0 chunkSize 134217728
Tue Jan 18 00:44:24 2022 kern.err rclone[32590]: Videos/Movies/In A Better World.nfo: ReadFileHandle.Read error: low level retry 3/10: stream error: stream ID 4355; CANCEL
Tue Jan 18 00:44:24 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.nfo: ReadFileHandle.seek from 0 to 0
Tue Jan 18 00:44:24 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.nfo: ChunkedReader.RangeSeek from -1 to 0 length -1
Tue Jan 18 00:44:24 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.nfo: ChunkedReader.openRange at 0 length 134217728
Tue Jan 18 00:44:25 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.nfo: ChunkedReader.Read at 0 length 4096 chunkOffset 0 chunkSize 134217728
Tue Jan 18 00:45:04 2022 kern.err rclone[32590]: Videos/Movies/In A Better World.nfo: ReadFileHandle.Read error: low level retry 4/10: stream error: stream ID 4357; CANCEL
Tue Jan 18 00:45:04 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.nfo: ReadFileHandle.seek from 0 to 0
Tue Jan 18 00:45:04 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.nfo: ChunkedReader.RangeSeek from -1 to 0 length -1
Tue Jan 18 00:45:04 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.nfo: ChunkedReader.openRange at 0 length 134217728
Tue Jan 18 00:45:04 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.nfo: ChunkedReader.Read at 0 length 4096 chunkOffset 0 chunkSize 134217728
Tue Jan 18 00:45:44 2022 kern.err rclone[32590]: Videos/Movies/In A Better World.nfo: ReadFileHandle.Read error: low level retry 5/10: stream error: stream ID 4359; CANCEL
Tue Jan 18 00:45:44 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.nfo: ReadFileHandle.seek from 0 to 0
Tue Jan 18 00:45:44 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.nfo: ChunkedReader.RangeSeek from -1 to 0 length -1
Tue Jan 18 00:45:44 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.nfo: ChunkedReader.openRange at 0 length 134217728
Tue Jan 18 00:45:45 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.nfo: ChunkedReader.Read at 0 length 4096 chunkOffset 0 chunkSize 134217728
Tue Jan 18 00:47:45 2022 kern.err rclone[32590]: Videos/Movies/In A Better World.nfo: ReadFileHandle.Read error: low level retry 8/10: stream error: stream ID 4365; CANCEL
Tue Jan 18 00:48:25 2022 kern.err rclone[32590]: Videos/Movies/In A Better World.nfo: ReadFileHandle.Read error: low level retry 9/10: stream error: stream ID 4367; CANCEL
Tue Jan 18 00:48:25 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.nfo: ReadFileHandle.seek from 0 to 0
Tue Jan 18 00:48:25 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.nfo: ChunkedReader.RangeSeek from -1 to 0 length -1
Tue Jan 18 00:48:25 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.nfo: ChunkedReader.openRange at 0 length 134217728
Tue Jan 18 00:48:25 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.nfo: ChunkedReader.Read at 0 length 4096 chunkOffset 0 chunkSize 134217728
Tue Jan 18 00:49:05 2022 kern.err rclone[32590]: Videos/Movies/In A Better World.nfo: ReadFileHandle.Read error: low level retry 10/10: stream error: stream ID 4369; CANCEL
Tue Jan 18 00:49:05 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.nfo: ReadFileHandle.seek from 0 to 0
Tue Jan 18 00:49:05 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.nfo: ChunkedReader.RangeSeek from -1 to 0 length -1
Tue Jan 18 00:49:05 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.nfo: ChunkedReader.openRange at 0 length 134217728
Tue Jan 18 00:49:05 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.nfo: ChunkedReader.Read at 0 length 4096 chunkOffset 0 chunkSize 134217728
Tue Jan 18 00:49:19 2022 authpriv.info dropbear[11441]: TCP forward failed: Error listening: Address in use
Tue Jan 18 00:49:19 2022 daemon.err dockerd[25143]: time="2022-01-18T00:49:19.913361497-06:00" level=info msg="starting signal loop" namespace=moby path=/tmp/run/docker/containerd/daemon/io.containerd.runtime.v2.task/moby/b875467fbc911ed5b866b30edb3b1b23825a71284fc1e490ce5e0c495dc0a032 pid=11473
Tue Jan 18 00:49:24 2022 daemon.err dockerd[25143]: time="2022-01-18T00:49:24.630886813-06:00" level=error msg="copy shim log" error="read /proc/self/fd/37: file already closed"
Tue Jan 18 00:49:45 2022 kern.err rclone[32590]: Videos/Movies/In A Better World.nfo: ReadFileHandle.Read error: stream error: stream ID 4371; CANCEL
Tue Jan 18 00:49:45 2022 kern.debug rclone[32590]: &{Videos/Movies/In A Better World.nfo (r)}: >Read: read=0, err=stream error: stream ID 4371; CANCEL
Tue Jan 18 00:49:45 2022 kern.debug rclone[32590]: &{Videos/Movies/In A Better World.nfo (r)}: Flush:
Tue Jan 18 00:49:45 2022 kern.debug rclone[32590]: &{Videos/Movies/In A Better World.nfo (r)}: >Flush: err=<nil>
Tue Jan 18 00:49:45 2022 kern.debug rclone[32590]: &{Videos/Movies/In A Better World.nfo (r)}: Release:
Tue Jan 18 00:49:45 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.nfo: ReadFileHandle.Release closing
Tue Jan 18 00:49:45 2022 kern.debug rclone[32590]: &{Videos/Movies/In A Better World.nfo (r)}: >Release: err=<nil>
Tue Jan 18 00:49:45 2022 kern.debug rclone[32590]: Videos/Movies/: Lookup: name="In A Better World.mp4"
Tue Jan 18 00:49:45 2022 kern.debug rclone[32590]: Videos/Movies: Re-reading directory (15m30.876259778s old)
Tue Jan 18 00:49:46 2022 kern.debug rclone[32590]: Videos/Movies/: >Lookup: node=Videos/Movies/In A Better World.mp4, err=<nil>
Tue Jan 18 00:49:46 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.mp4: Attr:
Tue Jan 18 00:49:46 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.mp4: >Attr: a=valid=1s ino=0 size=2340881408 mode=-rw-r--r--, err=<nil>
Tue Jan 18 00:49:46 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.mp4: Open: flags=OpenReadOnly+0x20000
Tue Jan 18 00:49:46 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.mp4: Open: flags=O_RDONLY|0x20000
Tue Jan 18 00:49:46 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.mp4: >Open: fd=Videos/Movies/In A Better World.mp4 (r), err=<nil>
Tue Jan 18 00:49:46 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.mp4: >Open: fh=&{Videos/Movies/In A Better World.mp4 (r)}, err=<nil>
Tue Jan 18 00:49:46 2022 kern.debug rclone[32590]: &{Videos/Movies/In A Better World.mp4 (r)}: Read: len=131072, offset=0
Tue Jan 18 00:49:46 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.mp4: ChunkedReader.openRange at 0 length 134217728
Tue Jan 18 00:49:47 2022 kern.debug rclone[32590]: Videos/Movies/In A Better World.mp4: ChunkedReader.Read at 0 length 4096 chunkOffset 0 chunkSize 134217728
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png: ChunkedReader.Read at 0 length 16384 chunkOffset 0 chunkSize 134217728
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: &{Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png (r)}: >Read: read=16384, err=<nil>
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: &{Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png (r)}: Flush:
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: &{Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png (r)}: >Flush: err=<nil>
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: &{Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png (r)}: Release:
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png: ReadFileHandle.Release closing
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png: Open: flags=OpenReadOnly+0x20000
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png: Open: flags=O_RDONLY|0x20000
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png: >Open: fd=Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png (r), err=<nil>
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: &{Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png (r)}: >Release: err=<nil>
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png: >Open: fh=&{Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png (r)}, err=<nil>
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: &{Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png (r)}: Read: len=16384, offset=0
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png: ChunkedReader.openRange at 0 length 134217728
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: &{Videos/Movies/Blue Movie (Fuck).mp4 (r)}: Read: len=131072, offset=555155456
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: &{Videos/Movies/Blue Movie (Fuck).mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: &{Videos/Movies/Blue Movie (Fuck).mp4 (r)}: Read: len=131072, offset=555286528
Tue Jan 18 00:59:52 2022 kern.debug rclone[32590]: &{Videos/Movies/Blue Movie (Fuck).mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 00:59:53 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png: ChunkedReader.Read at 0 length 16384 chunkOffset 0 chunkSize 134217728
Tue Jan 18 00:59:53 2022 kern.debug rclone[32590]: &{Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png (r)}: Release:
Tue Jan 18 00:59:53 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png: ReadFileHandle.Release closing
Tue Jan 18 00:59:53 2022 kern.debug rclone[32590]: &{Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png (r)}: >Release: err=<nil>
Tue Jan 18 00:59:53 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png: Attr:
Tue Jan 18 00:59:53 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Hero Images/Paper Mario The Thousand Year Door.png: >Attr: a=valid=1s ino=0 size=771340 mode=-rw-r--r--, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=366149632
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=366280704
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Videos/Movies/Children of Men.mp4: ChunkedReader.Read at 382136320 length 1048576 chunkOffset 137822208 chunkSize 268435456
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=366411776
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=366542848
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=366673920
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=366804992
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=366936064
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=367067136
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=367198208
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=367329280
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Videos/Movies/Children of Men.mp4: ChunkedReader.Read at 383184896 length 1048576 chunkOffset 137822208 chunkSize 268435456
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=367460352
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=367591424
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=367722496
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=367853568
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=367984640
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=368115712
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=368246784
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=368377856
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Videos/Movies/Children of Men.mp4: ChunkedReader.Read at 384233472 length 1048576 chunkOffset 137822208 chunkSize 268435456
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=368508928
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=368640000
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=368771072
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=368902144
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=369033216
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=369164288
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=369295360
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=369426432
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Videos/Movies/Children of Men.mp4: ChunkedReader.Read at 385282048 length 1048576 chunkOffset 137822208 chunkSize 268435456
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=369557504
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=369688576
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=369819648
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=369950720
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=370081792
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=370212864
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=370343936
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=370475008
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Videos/Movies/Children of Men.mp4: ChunkedReader.Read at 386330624 length 1048576 chunkOffset 137822208 chunkSize 268435456
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Music/Xenoblade/Xenoblade Original Soundtrack/Disc 1/1-04 Manami Kiyota - Daily Life.flac (r)}: >Release: err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Music/Xenoblade/Xenoblade Original Soundtrack/Disc 3/3-11 ACE+ - One Who Gets in Our Way.flac (r)}: Flush:
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Music/Xenoblade/: Attr:
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Music/Xenoblade/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Music/Xenoblade/: Lookup: name="Xenoblade Original Soundtrack"
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Music/Xenoblade/: >Lookup: node=Music/Xenoblade/Xenoblade Original Soundtrack/, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Music/Xenoblade/Xenoblade Original Soundtrack/: Attr:
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Music/Xenoblade/Xenoblade Original Soundtrack/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Music/Xenoblade/Xenoblade Original Soundtrack/: >Lookup: node=Music/Xenoblade/Xenoblade Original Soundtrack/Disc 3/, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Music/Xenoblade/Xenoblade Original Soundtrack/Disc 3/: Attr:
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Music/Xenoblade/Xenoblade Original Soundtrack/Disc 3/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Logos/: Lookup: name="Persona 4 Arena Ultimax.png"
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Logos/: >Lookup: node=Pictures/Steam Grid Images/Logos/Persona 4 Arena Ultimax.png, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Logos/Persona 4 Arena Ultimax.png: Attr:
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Pictures/Steam Grid Images/Logos/Persona 4 Arena Ultimax.png: >Attr: a=valid=1s ino=0 size=1649435 mode=-rw-r--r--, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Music/Xenoblade/Xenoblade Original Soundtrack/Disc 3/: Lookup: name="3-11 ACE+ - One Who Gets in Our Way.flac"
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Music/Xenoblade/Xenoblade Original Soundtrack/Disc 3/: >Lookup: node=Music/Xenoblade/Xenoblade Original Soundtrack/Disc 3/3-11 ACE+ - One Who Gets in Our Way.flac, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Music/Xenoblade/Xenoblade Original Soundtrack/Disc 3/3-11 ACE+ - One Who Gets in Our Way.flac: Attr:
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: Read: len=131072, offset=370606080
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: &{Videos/Movies/Children of Men.mp4 (r)}: >Read: read=131072, err=<nil>
Tue Jan 18 01:06:50 2022 kern.debug rclone[32590]: Videos/Movies/Promare.mkv: ChunkedReader.Read at 1061445632 length 1048576 chunkOffset 1057255424 chunkSize 134217728

mount2 gave similar results, though it actually ended up crashing the whole system again, in spite of having no caching.

root@OpenWRT-RPi /70# rclone mount2 --syslog --syslog-facility KERN --poll-interval 30s --allow-other --vfs-cache-mode off -vv ToasterDEV-OneDrive://usbstick/rclone/alex/onedrive
client_loop: send disconnect: Connection reset

[process exited with code 255]

Tue Jan 18 04:22:56 2022 kern.debug rclone[1598]: fh=0x40017a32f0(Music/Xenoblade/Xenoblade Original Soundtrack/Disc 1/1-06 Manami Kiyota - Thoughts to a Friend.flac): Read: off=24838144
Tue Jan 18 04:22:56 2022 kern.debug rclone[1598]: fh=0x40017a32f0(Music/Xenoblade/Xenoblade Original Soundtrack/Disc 1/1-06 Manami Kiyota - Thoughts to a Friend.flac): >Read: n=131072, off=24838144, errno=errno 0
Tue Jan 18 04:22:56 2022 kern.debug rclone[1598]: fh=0x40017a32f0(Music/Xenoblade/Xenoblade Original Soundtrack/Disc 1/1-06 Manami Kiyota - Thoughts to a Friend.flac): Read: off=24969216
Tue Jan 18 04:22:56 2022 kern.debug rclone[1598]: fh=0x40017a32f0(Music/Xenoblade/Xenoblade Original Soundtrack/Disc 1/1-06 Manami Kiyota - Thoughts to a Friend.flac): >Read: n=131072, off=24969216, errno=errno 0
Tue Jan 18 04:22:56 2022 kern.debug rclone[1598]: fh=0x4001a7bf08(Music/Xenoblade/Xenoblade Original Soundtrack/Disc 1/1-08 ACE+ - Crisis.flac): Read: off=851968
Tue Jan 18 04:22:56 2022 kern.debug rclone[1598]: fh=0x4001a7bf08(Music/Xenoblade/Xenoblade Original Soundtrack/Disc 1/1-08 ACE+ - Crisis.flac): >Read: n=131072, off=851968, errno=errno 0
Tue Jan 18 04:22:56 2022 kern.debug rclone[1598]: fh=0x40017a32f0(Music/Xenoblade/Xenoblade Original Soundtrack/Disc 1/1-06 Manami Kiyota - Thoughts to a Friend.flac): Read: off=25100288
Tue Jan 18 04:22:56 2022 kern.debug rclone[1598]: fh=0x40017a32f0(Music/Xenoblade/Xenoblade Original Soundtrack/Disc 1/1-06 Manami Kiyota - Thoughts to a Friend.flac): >Read: n=30784, off=25100288, errno=errno 0
Tue Jan 18 04:22:56 2022 kern.debug rclone[1598]: Music/Xenoblade/Xenoblade Original Soundtrack/Disc 1/1-08 ACE+ - Crisis.flac: ChunkedReader.Read at 5238784 length 1048576 chunkOffset 0 chunkSize 134217728
Tue Jan 18 04:22:56 2022 kern.debug rclone[1598]: fh=0x4001a7bf08(Music/Xenoblade/Xenoblade Original Soundtrack/Disc 1/1-08 ACE+ - Crisis.flac): Read: off=983040
Tue Jan 18 04:22:56 2022 kern.debug rclone[1598]: fh=0x4001a7bf08(Music/Xenoblade/Xenoblade Original Soundtrack/Disc 1/1-08 ACE+ - Crisis.flac): >Read: n=131072, off=983040, errno=errno 0
client_loop: send disconnect: Connection reset

[process exited with code 255]
11

Then it's something between fuse kernel driver, go fuse library and linux kernel patched by OpenWrt. Even just reporting such a bug would require one to know the kernel, the OpenWrt and RPi.

There are funnier ways to kill your precious life time but If you really want to continue tackling this you'd better find others to form the community.
@Animosity022 @asdffdsa Do you think that experiments with rclone on now popular Raspberry Pi with OpenWrt/Ubuntu/Raspbian may deserve a dedicated forum topic to help people organize?

In this particular case, maybe trying Ubuntu for RPi would be an easier shortcut?

12

Sure, I don't see why not.

Personally, running rclone on OpenWrt/RPi seems crazy to me as I'd just buy a cheap server or find a better solution

13

no, but you can create a new off-topic for it.
--- as a test, pizero version 1, with raspbian, i ran a rclone mount and used it as a streaming server for a week, never a glitch. now i have a couple of pizero version 2, and all the better.
--- currently, i use a pi4, booting from external usb ssd, running ubuntu server, using emby media server, never a glitch.
tho i needed to add a cpu heatsink+fan.

fwiw, for many years i ran openwrt on a linksys wrt, ran great as a router, but never thought to push it as a general purpose os.
now, i just recycle old computers as routers, cheap servers and so on.
given that openwrt has a great support forum, just behind the rclone forum, might post there.