Union mount high load average with unstable internet

What is the problem you are having with rclone?

We are using a rclone mount of a union (local disk and one remote backend).
If the internet is unstable the mount point get extremely slow and the load average increases a lot.

shouldn't this continue normally using only the local disk? is it a bug?

how can i debug this?

if the internet becomes unstable the mount should work only with the local disk and not crash the system with high load average.

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

rclone v1.57.0

  • os/version: ubuntu 20.04 (64 bit)
  • os/kernel: 5.4.0-97-generic (x86_64)
  • os/type: linux
  • os/arch: amd64
  • go/version: go1.17.2
  • go/linking: static
  • go/tags: none

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

google cloud storage

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

rclone mount union: /union --union-upstreams /local remote:bucket

The rclone config contents with secrets removed.

[remote]
type = google cloud storage
service_account_file = 

[union]
type = union
action_policy = all
create_policy = all
search_policy = ff

A log from the command with the -vv flag

2022/02/11 13:44:35 DEBUG : rclone: Version "v1.57.0" starting with parameters ["rclone" "mount" "union:" "/union" "--union-upstreams" "/local remote:bucket" "-vv"]
2022/02/11 13:44:35 DEBUG : Creating backend with remote "union:"
2022/02/11 13:44:35 DEBUG : Creating backend with remote "/local"
2022/02/11 13:44:35 DEBUG : Creating backend with remote "remote:bucket"
2022/02/11 13:44:35 DEBUG : union root '': actionPolicy = *policy.All, createPolicy = *policy.All, searchPolicy = *policy.FF
2022/02/11 13:44:35 DEBUG : fs cache: renaming cache item "union:" to be canonical "union{f8jJs}:"
2022/02/11 13:44:35 INFO  : union root '': poll-interval is not supported by this remote
2022/02/11 13:44:35 DEBUG : union root '': Mounting on "/union"
2022/02/11 13:44:35 DEBUG : : Root:
2022/02/11 13:44:35 DEBUG : : >Root: node=/, err=<nil>
^C2022/02/11 13:44:39 INFO  : Signal received: interrupt

A union mount continues to work even if a upstreams stops working?

When using a network based file system and the network is not stable, things generally do not work well.

It depends on how the upstream times out and what is actually going on as there's no debug log for the issue, it's tough to guess what may or may not happen.

Generally though, a server will go unresponsive if a network based file system stops responding as it is no different a bad physical disk (not talking raids in my example).

i got right now a high load average (51.88, 48.00, 36.55) and memory usage is ok.

I restarted union mount and everything went back to normal.

bellow the debbug.... is there something more that could I debbug?

Fetching profile over HTTP from http://localhost:5572/debug/pprof/heap
Saved profile in /root/pprof/pprof.rclone.alloc_objects.alloc_space.inuse_objects.inuse_space.003.pb.gz
File: rclone
Type: inuse_space
Time: Feb 16, 2022 at 2:36pm (-03)
Showing nodes accounting for 1843.87MB, 98.65% of 1869.11MB total
Dropped 126 nodes (cum <= 9.35MB)
      flat  flat%   sum%        cum   cum%
  317.04MB 16.96% 16.96%   317.04MB 16.96%  encoding/json.(*decodeState).literalStore
  208.54MB 11.16% 28.12%   208.54MB 11.16%  github.com/rclone/rclone/vfs.newFile
  125.02MB  6.69% 34.81%   125.02MB  6.69%  github.com/rclone/rclone/vfs.newDir
  113.51MB  6.07% 40.88%   113.51MB  6.07%  path.Join
  101.51MB  5.43% 46.31%   163.01MB  8.72%  github.com/rclone/rclone/backend/local.(*Fs).newObject
   95.51MB  5.11% 51.42%   122.51MB  6.55%  github.com/rclone/rclone/backend/googlecloudstorage.(*Fs).newObjectWithInfo
   82.83MB  4.43% 55.85%   338.88MB 18.13%  github.com/rclone/rclone/vfs.(*Dir)._readDirFromEntries
   82.01MB  4.39% 60.24%    91.51MB  4.90%  github.com/rclone/rclone/fs/hash.(*MultiHasher).Sums
      76MB  4.07% 64.31%       76MB  4.07%  github.com/rclone/rclone/backend/union.(*Fs).wrapEntries
   74.02MB  3.96% 68.27%   101.52MB  5.43%  github.com/rclone/rclone/vfs/vfscache.newItem
   67.51MB  3.61% 71.88%    73.51MB  3.93%  github.com/rclone/rclone/fs/hash.StreamTypes
   61.50MB  3.29% 75.17%    61.50MB  3.29%  strings.(*Builder).grow (inline)
      59MB  3.16% 78.33%       59MB  3.16%  github.com/rclone/rclone/backend/union/upstream.(*Fs).WrapObject (inline)
      52MB  2.78% 81.11%       52MB  2.78%  encoding/hex.EncodeToString (inline)
      51MB  2.73% 83.84%       51MB  2.73%  github.com/rclone/rclone/fs.NewDir (inline)
   47.93MB  2.56% 86.40%    47.93MB  2.56%  github.com/rclone/rclone/vfs.(*Dir).addObject
   44.98MB  2.41% 88.81%    44.98MB  2.41%  bazil.org/fuse.allocMessage
      34MB  1.82% 90.63%   126.51MB  6.77%  github.com/rclone/rclone/backend/googlecloudstorage.(*Fs).Put
   29.50MB  1.58% 92.21%       87MB  4.65%  github.com/rclone/rclone/backend/union.(*Fs).mergeDirEntries
   27.50MB  1.47% 93.68%    27.50MB  1.47%  sync.NewCond (inline)
      24MB  1.28% 94.96%    55.74MB  2.98%  github.com/rclone/rclone/vfs.newRWFileHandle
   16.50MB  0.88% 95.84%    16.50MB  0.88%  github.com/rclone/rclone/backend/union/upstream.(*Fs).WrapDirectory (inline)
      16MB  0.86% 96.70%       16MB  0.86%  google.golang.org/api/internal/gensupport.NewMediaBuffer (inline)
       9MB  0.48% 97.18%    27.50MB  1.47%  github.com/rclone/rclone/backend/union.(*Fs).put
    7.50MB   0.4% 97.58%    52.48MB  2.81%  bazil.org/fuse.(*Conn).ReadRequest
    6.91MB  0.37% 97.95%   108.42MB  5.80%  github.com/rclone/rclone/vfs/vfscache.(*Cache)._get
    6.50MB  0.35% 98.30%   220.27MB 11.78%  github.com/rclone/rclone/cmd/mount.(*Dir).Create
    5.50MB  0.29% 98.59%   430.88MB 23.05%  github.com/rclone/rclone/cmd/mount.(*Dir).Lookup
    0.53MB 0.028% 98.62%    95.23MB  5.10%  github.com/rclone/rclone/cmd/mount.(*FileHandle).Read
    0.50MB 0.027% 98.65%   800.92MB 42.85%  bazil.org/fuse/fs.(*Server).handleRequest
         0     0% 98.65%    44.98MB  2.41%  bazil.org/fuse.getMessage (inline)
         0     0% 98.65%    52.48MB  2.81%  bazil.org/fuse/fs.(*Server).Serve
         0     0% 98.65%   801.42MB 42.88%  bazil.org/fuse/fs.(*Server).Serve.func1
         0     0% 98.65%   801.42MB 42.88%  bazil.org/fuse/fs.(*Server).serve
         0     0% 98.65%   317.04MB 16.96%  encoding/json.(*Decoder).Decode
         0     0% 98.65%   250.03MB 13.38%  encoding/json.(*decodeState).array
         0     0% 98.65%   317.04MB 16.96%  encoding/json.(*decodeState).object
         0     0% 98.65%   317.04MB 16.96%  encoding/json.(*decodeState).unmarshal
         0     0% 98.65%   317.04MB 16.96%  encoding/json.(*decodeState).value
         0     0% 98.65%   390.54MB 20.89%  github.com/rclone/rclone/backend/googlecloudstorage.(*Fs).List
         0     0% 98.65%   140.51MB  7.52%  github.com/rclone/rclone/backend/googlecloudstorage.(*Fs).itemToDirEntry
         0     0% 98.65%   390.54MB 20.89%  github.com/rclone/rclone/backend/googlecloudstorage.(*Fs).list
         0     0% 98.65%   250.03MB 13.38%  github.com/rclone/rclone/backend/googlecloudstorage.(*Fs).list.func1
         0     0% 98.65%   390.54MB 20.89%  github.com/rclone/rclone/backend/googlecloudstorage.(*Fs).listDir
         0     0% 98.65%   140.51MB  7.52%  github.com/rclone/rclone/backend/googlecloudstorage.(*Fs).listDir.func1
         0     0% 98.65%    92.51MB  4.95%  github.com/rclone/rclone/backend/googlecloudstorage.(*Object).Update
         0     0% 98.65%    83.01MB  4.44%  github.com/rclone/rclone/backend/googlecloudstorage.(*Object).Update.func1
         0     0% 98.65%    36.50MB  1.95%  github.com/rclone/rclone/backend/googlecloudstorage.(*Object).setMetaData
         0     0% 98.65%   236.02MB 12.63%  github.com/rclone/rclone/backend/local.(*Fs).List
         0     0% 98.65%   143.52MB  7.68%  github.com/rclone/rclone/backend/local.(*Fs).Put
         0     0% 98.65%    92.51MB  4.95%  github.com/rclone/rclone/backend/local.(*Fs).cleanRemote
         0     0% 98.65%    61.50MB  3.29%  github.com/rclone/rclone/backend/local.(*Fs).localPath
         0     0% 98.65%   110.51MB  5.91%  github.com/rclone/rclone/backend/local.(*Fs).newObjectWithInfo
         0     0% 98.65%    73.51MB  3.93%  github.com/rclone/rclone/backend/local.(*Object).Hash
         0     0% 98.65%    91.51MB  4.90%  github.com/rclone/rclone/backend/local.(*Object).Update
         0     0% 98.65%       87MB  4.65%  github.com/rclone/rclone/backend/union.(*Fs).List
         0     0% 98.65%   684.06MB 36.60%  github.com/rclone/rclone/backend/union.(*Fs).List.func1
         0     0% 98.65%    27.50MB  1.47%  github.com/rclone/rclone/backend/union.(*Fs).Put
         0     0% 98.65%   288.03MB 15.41%  github.com/rclone/rclone/backend/union.(*Fs).put.func1
         0     0% 98.65%   972.60MB 52.04%  github.com/rclone/rclone/backend/union.multithread.func1
         0     0% 98.65%   270.03MB 14.45%  github.com/rclone/rclone/backend/union/upstream.(*Fs).Put
         0     0% 98.65%    57.50MB  3.08%  github.com/rclone/rclone/backend/union/upstream.(*Fs).WrapEntry
         0     0% 98.65%    44.91MB  2.40%  github.com/rclone/rclone/cmd/mount.(*File).Open
         0     0% 98.65%    52.48MB  2.81%  github.com/rclone/rclone/cmd/mount.mount.func2
         0     0% 98.65%    79.51MB  4.25%  github.com/rclone/rclone/fs.Fingerprint
         0     0% 98.65%   333.04MB 17.82%  github.com/rclone/rclone/fs.pacerInvoker
         0     0% 98.65%       87MB  4.65%  github.com/rclone/rclone/fs/list.DirSorted
         0     0% 98.65%    27.50MB  1.47%  github.com/rclone/rclone/fs/operations.Copy
         0     0% 98.65%   250.03MB 13.38%  github.com/rclone/rclone/lib/pacer.(*Pacer).Call
         0     0% 98.65%    83.01MB  4.44%  github.com/rclone/rclone/lib/pacer.(*Pacer).CallNoRetry (inline)
         0     0% 98.65%   333.04MB 17.82%  github.com/rclone/rclone/lib/pacer.(*Pacer).call
         0     0% 98.65%    74.01MB  3.96%  github.com/rclone/rclone/vfs.(*Dir).Create
         0     0% 98.65%   425.38MB 22.76%  github.com/rclone/rclone/vfs.(*Dir).Stat
         0     0% 98.65%   425.88MB 22.79%  github.com/rclone/rclone/vfs.(*Dir)._readDir
         0     0% 98.65%   425.38MB 22.76%  github.com/rclone/rclone/vfs.(*Dir).stat
         0     0% 98.65%   184.66MB  9.88%  github.com/rclone/rclone/vfs.(*File).Open
         0     0% 98.65%    20.50MB  1.10%  github.com/rclone/rclone/vfs.(*File).Path
         0     0% 98.65%    55.74MB  2.98%  github.com/rclone/rclone/vfs.(*File).openRW
         0     0% 98.65%    94.70MB  5.07%  github.com/rclone/rclone/vfs.(*RWFileHandle).ReadAt
         0     0% 98.65%    29.24MB  1.56%  github.com/rclone/rclone/vfs.(*RWFileHandle).Truncate
         0     0% 98.65%    94.70MB  5.07%  github.com/rclone/rclone/vfs.(*RWFileHandle)._readAt
         0     0% 98.65%   123.44MB  6.60%  github.com/rclone/rclone/vfs.(*RWFileHandle).openPending
         0     0% 98.65%   108.42MB  5.80%  github.com/rclone/rclone/vfs/vfscache.(*Cache).Exists
         0     0% 98.65%   108.42MB  5.80%  github.com/rclone/rclone/vfs/vfscache.(*Cache).get
         0     0% 98.65%    30.50MB  1.63%  github.com/rclone/rclone/vfs/vfscache.(*Item).Close.func2
         0     0% 98.65%    77.01MB  4.12%  github.com/rclone/rclone/vfs/vfscache.(*Item).Open
         0     0% 98.65%    77.01MB  4.12%  github.com/rclone/rclone/vfs/vfscache.(*Item)._checkObject
         0     0% 98.65%    30.50MB  1.63%  github.com/rclone/rclone/vfs/vfscache.(*Item)._store
         0     0% 98.65%    77.01MB  4.12%  github.com/rclone/rclone/vfs/vfscache.(*Item).open
         0     0% 98.65%    30.50MB  1.63%  github.com/rclone/rclone/vfs/vfscache.(*Item).store
         0     0% 98.65%    30.50MB  1.63%  github.com/rclone/rclone/vfs/vfscache/writeback.(*WriteBack).upload
         0     0% 98.65%   317.04MB 16.96%  google.golang.org/api/internal/gensupport.DecodeResponse (inline)
         0     0% 98.65%       16MB  0.86%  google.golang.org/api/internal/gensupport.NewInfoFromMedia
         0     0% 98.65%       16MB  0.86%  google.golang.org/api/internal/gensupport.PrepareUpload
         0     0% 98.65%    67.01MB  3.59%  google.golang.org/api/storage/v1.(*ObjectsInsertCall).Do
         0     0% 98.65%       16MB  0.86%  google.golang.org/api/storage/v1.(*ObjectsInsertCall).Media
         0     0% 98.65%   250.03MB 13.38%  google.golang.org/api/storage/v1.(*ObjectsListCall).Do
         0     0% 98.65%    61.50MB  3.29%  path/filepath.Join (inline)
         0     0% 98.65%    61.50MB  3.29%  path/filepath.join
         0     0% 98.65%    61.50MB  3.29%  strings.(*Builder).Grow (inline)
         0     0% 98.65%    61.50MB  3.29%  strings.Join
         0     0% 98.65%    44.98MB  2.41%  sync.(*Pool).Get

Go routines:
go_routines.txt (39.9 KB)

also did commands:
30-second CPU profile: go tool pprof http://localhost:5572/debug/pprof/profile
5-second execution trace: wget http://localhost:5572/debug/pprof/trace?seconds=5

I can share if needed...

changed --dir-cache-time to 12h but same problem....

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