Mount - too high iowait

Suspected Bug
1

What is the problem you are having with rclone?

Getting too high cpu iowait when using rclone mount. It is eating my 6 core cpu and sometimes the load goes to 20+.

top - 13:38:25 up 46 min,  2 users,  load average: 10.18, 8.87, 9.05
Tasks: 193 total,   1 running, 192 sleeping,   0 stopped,   0 zombie
%Cpu(s):  6.8 us,  3.7 sy,  0.0 ni, 26.8 id, 61.8 wa,  0.0 hi,  0.9 si,  0.0 st
MiB Mem :  24045.9 total,   1602.2 free,   5446.6 used,  16997.1 buff/cache
MiB Swap:   5120.0 total,   5097.9 free,     22.1 used.  18337.3 avail Mem 

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND                                                  
    913 root      20   0 4448312 643396   9252 S  29.9   2.6  13:09.50 rclone

Run the command 'rclone version' and share the full output of the command.

rclone v1.57.0-DEV
- os/version: ubuntu 20.04 (64 bit)
- os/kernel: 5.11.0-44-generic (x86_64)
- os/type: linux
- os/arch: amd64
- go/version: go1.17.2
- go/linking: dynamic
- go/tags: cmount

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

Google Drive

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

/usr/bin/rclone cmount gd: /gd \
--allow-other \
--dir-cache-time 5000h \
--log-file /var/log/rclone.log \
--log-level NOTICE \
--poll-interval 10s \
--umask 002 \
--user-agent <deleted> \
--rc \
--rc-addr 127.0.0.1:5572 \
--rc-no-auth \
--drive-pacer-min-sleep 10ms \
--drive-pacer-burst 200 \
--vfs-cache-mode full \
--vfs-cache-max-size 200G \
--vfs-cache-max-age 5000h \
--vfs-read-ahead 100M \
--drive-chunk-size 128M \
-o big_writes -o auto_cache

I am basically using his configuration.
I switched from the regular mount variant(bazil/fuse one) to cmount because troubleshooting.

The rclone config contents with secrets removed.

Paste config here

A log from the command with the -vv flag

The issue usually happens while huge read/write workload like Sonarr importing file, but not always, I am not sure.

2022/01/06 13:52:26 DEBUG : /其他/2015/A Touch of Green (2015) [tvdbid=301485]/Season 01/A Touch of Green (2015) S01E29 [NF WEBDL-1080p][8bit][x264][EAC3 2.0][ZH]-Ao.mkv: >Write: n=8192
2022/01/06 13:52:26 DEBUG : /其他/2015/A Touch of Green (2015) [tvdbid=301485]/Season 01/A Touch of Green (2015) S01E29 [NF WEBDL-1080p][8bit][x264][EAC3 2.0][ZH]-Ao.mkv: Write: ofst=1315643392, fh=0x0
2022/01/06 13:52:26 DEBUG : 其他/2015/A Touch of Green (2015) [tvdbid=301485]/Season 01/A Touch of Green (2015) S01E29 [NF WEBDL-1080p][8bit][x264][EAC3 2.0][ZH]-Ao.mkv(0xc003676380): _writeAt: size=8192, off=1315643392
2022/01/06 13:52:26 DEBUG : 其他/2015/A Touch of Green (2015) [tvdbid=301485]/Season 01/A Touch of Green (2015) S01E29 [NF WEBDL-1080p][8bit][x264][EAC3 2.0][ZH]-Ao.mkv(0xc003676380): >_writeAt: n=8192, err=<nil>
2022/01/06 13:52:26 DEBUG : /其他/2015/A Touch of Green (2015) [tvdbid=301485]/Season 01/A Touch of Green (2015) S01E29 [NF WEBDL-1080p][8bit][x264][EAC3 2.0][ZH]-Ao.mkv: >Write: n=8192
2022/01/06 13:52:26 DEBUG : /其他/2015/A Touch of Green (2015) [tvdbid=301485]/Season 01/A Touch of Green (2015) S01E29 [NF WEBDL-1080p][8bit][x264][EAC3 2.0][ZH]-Ao.mkv: Write: ofst=1315651584, fh=0x0
2022/01/06 13:52:26 DEBUG : 其他/2015/A Touch of Green (2015) [tvdbid=301485]/Season 01/A Touch of Green (2015) S01E29 [NF WEBDL-1080p][8bit][x264][EAC3 2.0][ZH]-Ao.mkv(0xc003676380): _writeAt: size=8192, off=1315651584
2022/01/06 13:52:26 DEBUG : 其他/2015/A Touch of Green (2015) [tvdbid=301485]/Season 01/A Touch of Green (2015) S01E29 [NF WEBDL-1080p][8bit][x264][EAC3 2.0][ZH]-Ao.mkv(0xc003676380): >_writeAt: n=8192, err=<nil>
2022/01/06 13:52:26 DEBUG : /其他/2015/A Touch of Green (2015) [tvdbid=301485]/Season 01/A Touch of Green (2015) S01E29 [NF WEBDL-1080p][8bit][x264][EAC3 2.0][ZH]-Ao.mkv: >Write: n=8192
2

That's how cloud mount works. It's slower than disk so you get IOWait.

Is there a reason you are using a DEV build and cmount?

There's only a small snippet of a log, not a full debug log so hard to guess what's going on.

3

I also noticed that the cpu load average starts increase to about 17 after a few minutes i command copy(it was around 5-10). And if i stop copy, iowait does not go lower, perhaps the upload process is still active?

4

Unknown as I can't see your computer and there aren't any logs to lock at.

I'd guess yes.

5

As an example, I run a copy overnight and my time is almost all IOWait as it's moving files:

image
image1445×333 32.6 KB

Which makes sense since you are uploading files to a remote on the internet and it's technically trying to compare it to local storage which is normally rates in "ms" response time and we're taking a lot longer to upload to a cloud remote hence IOWait.

It's normal.

6

I have patch service_account_file_path · wloot/rclone@299a95f · GitHub over 1.57 tag, but i don't think it related to the issues.

7

I'm trying direct_io mount flag, the situation seems to have improved somehow, I will test more.

8

I'm stepping out as I'm not debugging a custom build. If you want to use a stable version, I'll assist.

Direct IO just masks the issue as it removes some of the OS caching so you get slower response time but better IOWait numbers which makes it look like it's working. IOWait isn't a bad thing as your server has things buffered up and they are uploading. You are chasing a ghost now.

9

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