What is the problem you are having with rclone?
Even when all data is cached including metadata, rclone still makes HTTP requests.
What is your rclone version (output from rclone version)
v1.56.0
Which OS you are using and how many bits (eg Windows 7, 64 bit)
Ubuntu 20.04.2 LTS 64 bit
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)
go run $app_folder/rclone.go mount 'vfstoremote:' $mount_folder \
--log-file $log_file --log-level DEBUG --dump requests \
--no-check-dest --no-traverse --no-check-certificate --tpslimit 8 --fast-list \
--fs-cache-expire-duration 180m --fs-cache-expire-interval 180m \
--read-only --no-checksum --no-modtime --allow-other --umask 000 \
--multi-thread-streams 4 \
--attr-timeout 8760h \
--dir-cache-time 8760h \
--poll-interval 0 \
--vfs-cache-max-age 8760h \
--buffer-size 2048M \
--vfs-cache-mode full \
--vfs-cache-max-age 8760h \
--vfs-cache-max-size 6144G \
--vfs-read-chunk-size 256K \
--vfs-read-chunk-size-limit 256K \
--vfs-cache-poll-interval 1m
The rclone config contents with secrets removed.
[bc]
type = drive
service_account_file = ~/.config/rclone/xxx.json
team_drive = xxxxx
root_folder_id =
chunk_size = 256K
server_side_across_configs = true
[cmri]
type = drive
service_account_file = ~/.config/rclone/xxx.json
team_drive = xxxxx
root_folder_id =
chunk_size = 256K
server_side_across_configs = true
[fmri]
type = drive
service_account_file = ~/.config/rclone/xxx.json
team_drive = xxxxx
root_folder_id =
chunk_size = 256K
server_side_across_configs = true
[mri]
type = drive
service_account_file = ~/.config/rclone/xxx.json
team_drive = xxxxx
root_folder_id =
chunk_size = 256K
server_side_across_configs = true
[mrv]
type = drive
service_account_file = ~/.config/rclone/xxx.json
team_drive = xxxxx
root_folder_id =
chunk_size = 256K
server_side_across_configs = true
[chunkerbc]
type = chunker
remote = bc:chunks
chunk_size = 1G
name_format = *.###.rclone_chunk
[chunkercmri]
type = chunker
remote = cmri:chunks
chunk_size = 1G
name_format = *.###.rclone_chunk
[chunkerfmri]
type = chunker
remote = fmri:chunks
chunk_size = 1G
name_format = *.###.rclone_chunk
[chunkermra]
type = chunker
remote = mra:chunks
chunk_size = 1G
name_format = *.###.rclone_chunk
[chunkermrv]
type = chunker
remote = mrv:chunks
chunk_size = 1G
name_format = *.###.rclone_chunk
[vfstoremote]
type = union
upstreams = chunkerbc: chunkercmri: chunkerfmri: chunkermra: chunkermrv:
search_policy = all
action_policy = all
create_policy = all
A log from the command with the -vv flag
2021/08/09 12:19:05 INFO : Starting transaction limiter: max 8 transactions/s with burst 1
2021/08/09 12:19:05 DEBUG : rclone: Version "v1.56.0-DEV" starting with parameters ["/tmp/go-build2981075869/b001/exe/rclone" "mount" "vfstoremote:" "/mnt/storage/cache" "--log-file" "/home/rclone/app/logs/rclone_cache.log" "--log-level" "DEBUG" "--dump" "requests" "--no-check-dest" "--no-traverse" "--no-check-certificate" "--tpslimit" "8" "--fast-list" "--fs-cache-expire-duration" "180m" "--fs-cache-expire-interval" "180m" "--read-only" "--no-checksum" "--no-modtime" "--allow-other" "--umask" "000" "--multi-thread-streams" "4" "--attr-timeout" "8760h" "--dir-cache-time" "8760h" "--poll-interval" "0" "--vfs-cache-max-age" "8760h" "--buffer-size" "2048M" "--vfs-cache-mode" "full" "--vfs-cache-max-age" "8760h" "--vfs-cache-max-size" "6144G" "--vfs-read-chunk-size" "256K" "--vfs-read-chunk-size-limit" "256K" "--vfs-cache-poll-interval" "1m"]
2021/08/09 12:19:05 DEBUG : Creating backend with remote "vfstoremote:"
2021/08/09 12:19:05 DEBUG : Using config file from "/home/rclone/.config/rclone/rclone.conf"
2021/08/09 12:19:05 DEBUG : Creating backend with remote "chunkermra:"
2021/08/09 12:19:05 DEBUG : Creating backend with remote "chunkerbc:"
2021/08/09 12:19:05 DEBUG : Creating backend with remote "chunkercmri:"
2021/08/09 12:19:05 DEBUG : Creating backend with remote "chunkermrv:"
2021/08/09 12:19:05 DEBUG : Creating backend with remote "chunkerfmri:"
2021/08/09 12:19:05 DEBUG : Creating backend with remote "cmri:chunks"
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : Creating backend with remote "mra:chunks"
2021/08/09 12:19:05 DEBUG : Creating backend with remote "bc:chunks"
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : Creating backend with remote "fmri:chunks"
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : Creating backend with remote "mrv:chunks"
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:05 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : Reset feature "ListR"
2021/08/09 12:19:20 DEBUG : union root '': actionPolicy = *policy.All, createPolicy = *policy.All, searchPolicy = *policy.All
2021/08/09 12:19:20 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/vfstoremote"
2021/08/09 12:19:20 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/vfstoremote"
2021/08/09 12:19:20 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/vfstoremote"
2021/08/09 12:19:21 DEBUG : union root '': Mounting on "/mnt/storage/cache"
2021/08/09 12:19:21 DEBUG : : Root:
2021/08/09 12:19:21 DEBUG : : >Root: node=/, err=<nil>
2021/08/09 12:19:24 DEBUG : /: Attr:
2021/08/09 12:19:24 DEBUG : /: >Attr: attr=valid=8760h0m0s ino=0 size=0 mode=drwxrwxrwx, err=<nil>
2021/08/09 12:19:24 DEBUG : /: ReadDirAll:
[.....]
2021/08/09 12:52:27 DEBUG : 12043.diacom: vfs cache: setting modification time to 2021-07-25 14:26:42.363 +0000 UTC
2021/08/09 12:52:27 DEBUG : 12043.diacom(0xc02198ce80): >close: err=<nil>
2021/08/09 12:52:27 DEBUG : &{12043.diacom (rw)}: >Release: err=<nil>
2021/08/09 12:52:27 DEBUG : &{12044.diacom (rw)}: Read: len=16384, offset=0
2021/08/09 12:52:27 DEBUG : 12044.diacom(0xc0241fe3c0): _readAt: size=16384, off=0
2021/08/09 12:52:27 DEBUG : 12044.diacom(0xc0241fe3c0): openPending:
2021/08/09 12:52:27 DEBUG : 12044.diacom: vfs cache: truncate to size=4069582409
2021/08/09 12:52:27 DEBUG : : Added virtual directory entry vAddFile: "12044.diacom"
2021/08/09 12:52:27 DEBUG : 12044.diacom(0xc0241fe3c0): >openPending: err=<nil>
2021/08/09 12:52:27 DEBUG : vfs cache: looking for range={Pos:0 Size:16384} in [{Pos:0 Size:98304}] - present true
2021/08/09 12:52:27 DEBUG : 12044.diacom: ChunkedReader.RangeSeek from -1 to 98304 length -1
2021/08/09 12:52:27 DEBUG : 12044.diacom: ChunkedReader.Read at -1 length 4096 chunkOffset 98304 chunkSize 262144
2021/08/09 12:52:27 DEBUG : 12044.diacom: ChunkedReader.openRange at 98304 length 262144
2021/08/09 12:52:27 DEBUG : 12044.diacom(0xc0241fe3c0): >_readAt: n=16384, err=<nil>
2021/08/09 12:52:27 DEBUG : &{12044.diacom (rw)}: >Read: read=16384, err=<nil>
2021/08/09 12:52:27 DEBUG : &{12044.diacom (rw)}: Flush:
2021/08/09 12:52:27 DEBUG : 12044.diacom(0xc0241fe3c0): RWFileHandle.Flush
2021/08/09 12:52:27 DEBUG : &{12044.diacom (rw)}: >Flush: err=<nil>
2021/08/09 12:52:27 DEBUG : &{12044.diacom (rw)}: Release:
2021/08/09 12:52:27 DEBUG : 12044.diacom(0xc0241fe3c0): RWFileHandle.Release
2021/08/09 12:52:27 DEBUG : 12044.diacom(0xc0241fe3c0): close:
2021/08/09 12:52:27 DEBUG : /: Lookup: name="12045.diacom"
2021/08/09 12:52:27 DEBUG : /: >Lookup: node=12045.diacom, err=<nil>
2021/08/09 12:52:27 DEBUG : 12045.diacom: Attr:
2021/08/09 12:52:27 DEBUG : 12045.diacom: >Attr: a=valid=8760h0m0s ino=0 size=4069582406 mode=-rw-rw-rw-, err=<nil>
2021/08/09 12:52:27 DEBUG : 12045.diacom: Open: flags=OpenReadOnly
2021/08/09 12:52:27 DEBUG : 12045.diacom: Open: flags=O_RDONLY
2021/08/09 12:52:27 DEBUG : 12045.diacom: newRWFileHandle:
2021/08/09 12:52:27 DEBUG : 12045.diacom: >newRWFileHandle: err=<nil>
2021/08/09 12:52:27 DEBUG : 12045.diacom: >Open: fd=12045.diacom (rw), err=<nil>
2021/08/09 12:52:27 DEBUG : 12045.diacom: >Open: fh=&{12045.diacom (rw)}, err=<nil>
2021/08/09 12:52:27 DEBUG : XXXXX DEBUG HTTP: https://www.googleapis.com/drive/v3/files/xxxxxx?alt=media
2021/08/09 12:52:27 DEBUG : XXXXX START TRACE XXXXX
2021/08/09 12:52:27 DEBUG : 1> /home/rclone/app/rclone/fs/fshttp/http.go#270
2021/08/09 12:52:27 DEBUG : 2> /home/rclone/go/pkg/mod/golang.org/x/oauth2@v0.0.0-20210413134643-5e61552d6c78/transport.go#55
2021/08/09 12:52:27 DEBUG : 3> /home/rclone/app/go/src/net/http/client.go#251
2021/08/09 12:52:27 DEBUG : 4> /home/rclone/app/go/src/net/http/client.go#175
2021/08/09 12:52:27 DEBUG : 5> /home/rclone/app/go/src/net/http/client.go#717
2021/08/09 12:52:27 DEBUG : 6> /home/rclone/app/go/src/net/http/client.go#585
2021/08/09 12:52:27 DEBUG : 7> /home/rclone/app/rclone/backend/drive/drive.go#3444
2021/08/09 12:52:27 DEBUG : 8> /home/rclone/app/rclone/fs/pacer.go#88
2021/08/09 12:52:27 DEBUG : 9> /home/rclone/app/rclone/lib/pacer/pacer.go#197
2021/08/09 12:52:27 DEBUG : 10> /home/rclone/app/rclone/lib/pacer/pacer.go#216
2021/08/09 12:52:27 DEBUG : 11> /home/rclone/app/rclone/backend/drive/drive.go#3443
2021/08/09 12:52:27 DEBUG : 12> /home/rclone/app/rclone/backend/drive/drive.go#3509
2021/08/09 12:52:27 DEBUG : 13> /home/rclone/app/rclone/backend/drive/drive.go#3552
2021/08/09 12:52:27 DEBUG : 14> /home/rclone/app/rclone/backend/chunker/chunker.go#2244
2021/08/09 12:52:27 DEBUG : 15> /home/rclone/app/rclone/backend/chunker/chunker.go#2210
2021/08/09 12:52:27 DEBUG : 16> /home/rclone/app/rclone/backend/chunker/chunker.go#2184
2021/08/09 12:52:27 DEBUG : 17> /home/rclone/app/rclone/fs/chunkedreader/chunkedreader.go#224
2021/08/09 12:52:27 DEBUG : 18> /home/rclone/app/rclone/fs/chunkedreader/chunkedreader.go#91
2021/08/09 12:52:27 DEBUG : 19> /home/rclone/app/rclone/lib/readers/readfill.go#14
2021/08/09 12:52:27 DEBUG : 20> /home/rclone/app/rclone/fs/asyncreader/asyncreader.go#351
2021/08/09 12:52:27 DEBUG : 21> /home/rclone/app/rclone/fs/asyncreader/asyncreader.go#95
2021/08/09 12:52:27 DEBUG : 22> /home/rclone/app/go/src/runtime/asm_amd64.s#1371
2021/08/09 12:52:27 DEBUG : XXXXX END TRACE XXXXX
Changes made to source:
./vfs/vfscache/item.go:
func (item *Item) _checkObject(o fs.Object) error {
[...]
if item.info.Fingerprint != "" {
// no need to check fingerprint
} else {
remoteFingerprint := fs.Fingerprint(context.TODO(), o, false)
fs.Debugf(item.name, "vfs cache: checking remote fingerprint %q against cached fingerprint %q", remoteFingerprint, item.info.Fingerprint)
item.info.Fingerprint = remoteFingerprint
}
./backend/drive/drive.go:
func (f *Fs) ChangeNotify(ctx context.Context, notifyFunc func(string, fs.EntryType), pollIntervalChan <-chan time.Duration) {
return // no need for change notify
}
In the above logs I've included the function caller trace. I don't understand what is causing HTTP requests to be made on each file open. The meta data and the data being requested is already cached.
3> /home/rclone/app/go/src/net/http/client.go#251
4> /home/rclone/app/go/src/net/http/client.go#175
5> /home/rclone/app/go/src/net/http/client.go#717
6> /home/rclone/app/go/src/net/http/client.go#585
7> /home/rclone/app/rclone/backend/drive/drive.go#3444: httpResponse > res, err = o.fs.client.Do(req)
8> /home/rclone/app/rclone/fs/pacer.go#88: pacerInvoker > retry, err = f()
9> /home/rclone/app/rclone/lib/pacer/pacer.go#197: call > retry, err = p.invoker(i, retries, fn)
10> /home/rclone/app/rclone/lib/pacer/pacer.go#216: Call > return p.call(fn, retries)
11> /home/rclone/app/rclone/backend/drive/drive.go#3443: httpResponse > err = o.fs.pacer.Call(func() (bool, error) {
12> /home/rclone/app/rclone/backend/drive/drive.go#3509: open > _, res, err := o.httpResponse(ctx, url, "GET", options)
13> /home/rclone/app/rclone/backend/drive/drive.go#3552: Open > return o.baseObject.open(ctx, o.url, options...)
14> /home/rclone/app/rclone/backend/chunker/chunker.go#2244: nextChunk > reader, err := chunk.Open(r.ctx, options...)
15> /home/rclone/app/rclone/backend/chunker/chunker.go#2210: newLinearReader > offset, err = r.nextChunk(offset)
16> /home/rclone/app/rclone/backend/chunker/chunker.go#2184: Open > return o.newLinearReader(ctx, offset, limit, openOptions)
17> /home/rclone/app/rclone/fs/chunkedreader/chunkedreader.go#224: openRange > rc, err = cr.o.Open(cr.ctx, &fs.HashesOption{Hashes: hash.Set(hash.None)}, &fs.RangeOption{Start: offset, End: offset + length - 1})
18> /home/rclone/app/rclone/fs/chunkedreader/chunkedreader.go#91: Read > err = cr.openRange()
19> /home/rclone/app/rclone/lib/readers/readfill.go#14: ReadFill > nn, err = r.Read(buf[n:])
20> /home/rclone/app/rclone/fs/asyncreader/asyncreader.go#351: read > n, b.err = readers.ReadFill(rd, b.buf)
21> /home/rclone/app/rclone/fs/asyncreader/asyncreader.go#95: init > err := b.read(a.in)
22> /home/rclone/app/go/src/runtime/asm_amd64.s#1371
Can you please tell me why this is happening or what the HTTP requests purpose is?