Abnormal Memory Consumption in rclone After Upgrading to AWS Go SDK v2 While Mounting Ceph S3

Suspected Bug
1

What is the problem you are having with rclone?

Mounting Ceph S3 using rclone, memory consumption becomes abnormal after continuously writing files for a short period.

Using top to monitor, the RES memory usage keeps increasing. After writing around 200,000 files of 512KB each, the RES grows to 4.2GB. Even after calling rc vfs/forget and rc core/gc, the reduction in memory usage is insignificant.

In comparison, with rclone version 1.67 under the same workload of writing 200,000 similar files, the RES memory usage is only 900MB.

:thinking: I suspect this is related to the upgrade to AWS Go SDK v2, as we upgraded the SDK version after rclone 1.67. ( I also tried versions 1.69.3 and 1.70.2, and they are both affected.)

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

[root@lbr-rclone ~]# rclone version
rclone v1.70.3

  • os/version: almalinux 9.5 (64 bit)
  • os/kernel: 5.14.0-503.23.2.el9_5.x86_64 (x86_64)
  • os/type: linux
  • os/arch: amd64
  • go/version: go1.24.4
  • go/linking: static
  • go/tags: none

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

ceph S3 （RGW）

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

/usr/bin/rclone mount zos:lbr-rclone-test /mnt/rc --vfs-cache-mode full --cache-dir /cache --log-file /var/log/rc.log --log-level info --uid 1000 --gid 1000 --allow-other --rc --rc-addr=127.0.0.1:5572

The rclone config contents with secrets removed.

[zos]
type = s3
provider = Ceph
access_key_id = akak
secret_access_key = sksk
endpoint = http://xxx.xxx.xxx.xxx

A log from the command with the -vv flag

nothing interesting threre...

pmap

pmap `pidof rclone`
5124: /usr/bin/rclone mount zos:lbr-rclone-test /mnt/rc --vfs-cache-mode full --cache-dir /cache --log-file /var/log/rc.log --log-level info --uid 1000 --gid 1000 --allow-other --rc --rc-addr=127.0.0.1:5572
0000000000400000 30416K r-x-- rclone
00000000021b4000 33552K r---- rclone
0000000004278000 2172K rw--- rclone
0000000004497000 332K rw--- [ anon ]
000000c000000000 5062656K rw--- [ anon ]
000000c135000000 49152K ----- [ anon ]
00007f846299f000 61404K rw--- [ anon ]
00007f846659f000 27708K rw--- [ anon ]
00007f84680b4000 18668K rw--- [ anon ]
00007f84692f9000 12060K rw--- [ anon ]
00007f8469ec1000 7956K rw--- [ anon ]
00007f846a68d000 5772K rw--- [ anon ]
00007f846ac3a000 3524K rw--- [ anon ]
00007f846afac000 2692K rw--- [ anon ]
00007f846b252000 1800K rw--- [ anon ]
00007f846b418000 1088K rw--- [ anon ]
00007f846b530000 6788K rw--- [ anon ]
00007f846bbd1000 1024K rw--- [ anon ]
00007f846bcd1000 68K rw--- [ anon ]
00007f846bce2000 1144K rw--- [ anon ]
00007f846be00000 30720K rw--- [ anon ]
00007f846dc00000 904K rw--- [ anon ]
00007f846dce2000 263680K ----- [ anon ]
00007f847de62000 12K rw--- [ anon ]
00007f847de65000 524276K ----- [ anon ]
00007f849de62000 12K rw--- [ anon ]
00007f849de65000 293556K ----- [ anon ]
00007f84afd12000 4K rw--- [ anon ]
00007f84afd13000 36692K ----- [ anon ]
00007f84b20e8000 4K rw--- [ anon ]
00007f84b20e9000 4580K ----- [ anon ]
00007f84b2562000 4K rw--- [ anon ]
00007f84b2563000 508K ----- [ anon ]
00007f84b25e2000 384K rw--- [ anon ]
00007ffe31437000 132K rw--- [ stack ]
00007ffe315eb000 16K r---- [ anon ]
00007ffe315ef000 8K r-x-- [ anon ]
ffffffffff600000 4K --x-- [ anon ]
total 6485472K
2

another run with v1.70.3

pprof

[root@lbr-rclone ~]# go tool pprof -text http://127.0.0.1:5572/debug/pprof/heap 
Fetching profile over HTTP from http://127.0.0.1:5572/debug/pprof/heap
Saved profile in /root/pprof/pprof.rclone.alloc_objects.alloc_space.inuse_objects.inuse_space.037.pb.gz
File: rclone
Build ID: 57fa23e95d54f99d7018b5a529ebbe8aabe184cd
Type: inuse_space
Time: Jul 11, 2025 at 9:51pm (CST)
Showing nodes accounting for 1508.80MB, 91.63% of 1646.70MB total
Dropped 200 nodes (cum <= 8.23MB)
      flat  flat%   sum%        cum   cum%
  188.58MB 11.45% 11.45%   196.58MB 11.94%  net/textproto.readMIMEHeader
  146.01MB  8.87% 20.32%   146.01MB  8.87%  context.WithValue
   95.50MB  5.80% 26.12%    95.50MB  5.80%  github.com/aws/smithy-go/middleware.withStackValue
   90.52MB  5.50% 31.62%   113.52MB  6.89%  github.com/rclone/rclone/vfs/vfscache.newItem
   87.52MB  5.32% 36.93%    87.52MB  5.32%  net/http.Header.Clone (inline)
   83.02MB  5.04% 41.97%    83.02MB  5.04%  strings.(*Builder).grow
   66.01MB  4.01% 45.98%    68.51MB  4.16%  github.com/aws/aws-sdk-go-v2/service/s3.awsRestxml_deserializeOpHttpBindingsHeadObjectOutput
   56.01MB  3.40% 49.38%    56.01MB  3.40%  github.com/rclone/rclone/backend/s3.s3MetadataToMap
   55.52MB  3.37% 52.75%   447.09MB 27.15%  github.com/aws/aws-sdk-go-v2/service/s3.(*awsRestxml_deserializeOpHeadObject).HandleDeserialize
   54.51MB  3.31% 56.06%    54.51MB  3.31%  github.com/aws/smithy-go/middleware.Metadata.Clone (inline)
   49.52MB  3.01% 59.07%   159.04MB  9.66%  net/http.(*Request).Clone
   43.01MB  2.61% 61.68%    43.01MB  2.61%  github.com/aws/smithy-go/middleware.(*Metadata).Set (inline)
   41.51MB  2.52% 64.20%    50.01MB  3.04%  github.com/aws/smithy-go.(*Properties).Set (inline)
      29MB  1.76% 65.97%  1032.15MB 62.68%  github.com/rclone/rclone/backend/s3.(*Object).headObject
   28.50MB  1.73% 67.70%    28.50MB  1.73%  github.com/aws/smithy-go/transport/http.JoinPath (inline)
      24MB  1.46% 69.15%   100.51MB  6.10%  github.com/aws/smithy-go/transport/http.withMetrics
   23.50MB  1.43% 70.58%    23.50MB  1.43%  strings.(*Builder).WriteString (partial-inline)
      22MB  1.34% 71.92%       22MB  1.34%  net/http.cloneURL (inline)
      22MB  1.34% 73.25%       22MB  1.34%  context.(*cancelCtx).Done
      21MB  1.28% 74.53%   218.08MB 13.24%  net/http.ReadResponse
   20.50MB  1.25% 75.77%    20.50MB  1.25%  github.com/rclone/rclone/vfs.newFile
      19MB  1.15% 76.93%       19MB  1.15%  encoding/json.(*decodeState).literalStore
      18MB  1.09% 78.02%       18MB  1.09%  github.com/aws/smithy-go/transport/http.newHTTPMetrics
      18MB  1.09% 79.11%       18MB  1.09%  path.Join
   17.50MB  1.06% 80.18%    17.50MB  1.06%  strings.(*Builder).Write
   17.02MB  1.03% 81.21%    17.02MB  1.03%  io.copyBuffer
   16.50MB  1.00% 82.21%  1052.28MB 63.90%  github.com/rclone/rclone/backend/s3.(*Fs).Put
   16.42MB     1% 83.21%   129.94MB  7.89%  github.com/rclone/rclone/vfs/vfscache.(*Cache)._get
      16MB  0.97% 84.18%       16MB  0.97%  github.com/rclone/rclone/lib/bucket.Join (inline)
      15MB  0.91% 85.09%       23MB  1.40%  github.com/aws/aws-sdk-go-v2/service/s3.withOperationMetrics
      14MB  0.85% 85.94%       14MB  0.85%  github.com/aws/aws-sdk-go-v2/internal/auth/smithy.(*CredentialsProviderAdapter).GetIdentity
   10.50MB  0.64% 86.58%    10.50MB  0.64%  encoding/hex.EncodeToString (inline)
      10MB  0.61% 87.19%       10MB  0.61%  context.withCancel (inline)
    9.07MB  0.55% 87.74%     9.07MB  0.55%  github.com/rclone/rclone/vfs.(*Dir).addObject
       9MB  0.55% 88.29%    24.50MB  1.49%  net/http/httptrace.WithClientTrace
    8.50MB  0.52% 88.80%     8.50MB  0.52%  github.com/aws/smithy-go.(*Properties).lazyInit (inline)
    6.50MB  0.39% 89.20%   613.62MB 37.26%  github.com/aws/aws-sdk-go-v2/aws/retry.(*Attempt).HandleFinalize
    5.50MB  0.33% 89.53%    17.50MB  1.06%  github.com/aws/aws-sdk-go-v2/aws/retry.setRetryMetadata (inline)
    4.50MB  0.27% 89.80%       18MB  1.09%  github.com/aws/aws-sdk-go-v2/service/s3/internal/customizations.SetBucket (inline)
       4MB  0.24% 90.05%       16MB  0.97%  github.com/aws/aws-sdk-go-v2/aws/middleware.SetServiceID (inline)
    3.50MB  0.21% 90.26%   271.05MB 16.46%  github.com/aws/smithy-go/transport/http.ClientHandler.Handle
       3MB  0.18% 90.44%       22MB  1.34%  github.com/aws/aws-sdk-go-v2/aws/signer/v4.SetPayloadHash (inline)
       3MB  0.18% 90.62%    53.01MB  3.22%  github.com/aws/smithy-go/transport/http.SetSigV4SigningName (partial-inline)
       3MB  0.18% 90.81%    76.08MB  4.62%  github.com/rclone/rclone/cmd/mount.(*Dir).Create
    2.50MB  0.15% 90.96%    18.50MB  1.12%  github.com/aws/aws-sdk-go-v2/aws/middleware.setOperationName (inline)
       2MB  0.12% 91.08%     8.83MB  0.54%  bazil.org/fuse.(*Conn).ReadRequest
       2MB  0.12% 91.20%       16MB  0.97%  github.com/aws/smithy-go/middleware.WithOperationName (inline)
       2MB  0.12% 91.32%    15.50MB  0.94%  github.com/aws/smithy-go/middleware.WithServiceID (inline)
    1.50MB 0.091% 91.41%    44.51MB  2.70%  github.com/aws/aws-sdk-go-v2/aws/middleware.setResponseAt (inline)
       1MB 0.061% 91.47%   190.62MB 11.58%  bazil.org/fuse/fs.(*Server).handleRequest
       1MB 0.061% 91.53%    15.50MB  0.94%  github.com/aws/aws-sdk-go-v2/aws/middleware.setRegion (inline)
       1MB 0.061% 91.60%       15MB  0.91%  github.com/aws/aws-sdk-go-v2/service/s3.setS3ResolvedURI (inline)
    0.50MB  0.03% 91.63%   509.10MB 30.92%  github.com/aws/aws-sdk-go-v2/aws/retry.MetricsHeader.HandleFinalize
         0     0% 91.63%     8.83MB  0.54%  bazil.org/fuse/fs.(*Server).Serve
         0     0% 91.63%   185.62MB 11.27%  bazil.org/fuse/fs.(*Server).Serve.func1
         0     0% 91.63%    79.52MB  4.83%  bazil.org/fuse/fs.(*Server).saveLookup
         0     0% 91.63%   190.62MB 11.58%  bazil.org/fuse/fs.(*Server).serve
         0     0% 91.63%    78.01MB  4.74%  bazil.org/fuse/fs.nodeAttr
         0     0% 91.63%       10MB  0.61%  context.WithCancel
         0     0% 91.63%    22.50MB  1.37%  encoding/json.(*Decoder).Decode
         0     0% 91.63%    22.50MB  1.37%  encoding/json.(*decodeState).object
         0     0% 91.63%    22.50MB  1.37%  encoding/json.(*decodeState).unmarshal
         0     0% 91.63%    22.50MB  1.37%  encoding/json.(*decodeState).value
         0     0% 91.63%    17.50MB  1.06%  fmt.Fprintf
         0     0% 91.63%   827.64MB 50.26%  github.com/aws/aws-sdk-go-v2/aws/middleware.(*RecursionDetection).HandleBuild
         0     0% 91.63%       16MB  0.97%  github.com/aws/aws-sdk-go-v2/aws/middleware.(*RequestUserAgent).AddSDKAgentKeyValue
         0     0% 91.63%   840.14MB 51.02%  github.com/aws/aws-sdk-go-v2/aws/middleware.(*RequestUserAgent).HandleBuild
         0     0% 91.63%   459.09MB 27.88%  github.com/aws/aws-sdk-go-v2/aws/middleware.AddRawResponse.HandleDeserialize
         0     0% 91.63%   847.64MB 51.47%  github.com/aws/aws-sdk-go-v2/aws/middleware.ClientRequestID.HandleBuild
         0     0% 91.63%       16MB  0.97%  github.com/aws/aws-sdk-go-v2/aws/middleware.NewRequestUserAgent
         0     0% 91.63%   323.56MB 19.65%  github.com/aws/aws-sdk-go-v2/aws/middleware.RecordResponseTiming.HandleDeserialize
         0     0% 91.63%   936.14MB 56.85%  github.com/aws/aws-sdk-go-v2/aws/middleware.RegisterServiceMetadata.HandleInitialize
         0     0% 91.63%       16MB  0.97%  github.com/aws/aws-sdk-go-v2/aws/middleware.addSDKMetadata
         0     0% 91.63%   531.10MB 32.25%  github.com/aws/aws-sdk-go-v2/aws/retry.(*Attempt).handleAttempt
         0     0% 91.63%   622.12MB 37.78%  github.com/aws/aws-sdk-go-v2/aws/signer/v4.(*ComputePayloadSHA256).HandleFinalize
         0     0% 91.63%   613.62MB 37.26%  github.com/aws/aws-sdk-go-v2/aws/signer/v4.(*ContentSHA256Header).HandleFinalize
         0     0% 91.63%       24MB  1.46%  github.com/aws/aws-sdk-go-v2/aws/signer/v4.(*UnsignedPayload).HandleFinalize
         0     0% 91.63%    45.01MB  2.73%  github.com/aws/aws-sdk-go-v2/aws/signer/v4.(*httpSigner).Build
         0     0% 91.63%    45.01MB  2.73%  github.com/aws/aws-sdk-go-v2/aws/signer/v4.Signer.SignHTTP
         0     0% 91.63%    42.01MB  2.55%  github.com/aws/aws-sdk-go-v2/aws/signer/v4.buildAuthorizationHeader
         0     0% 91.63%    45.01MB  2.73%  github.com/aws/aws-sdk-go-v2/internal/auth/smithy.(*V4SignerAdapter).SignRequest
         0     0% 91.63%    12.50MB  0.76%  github.com/aws/aws-sdk-go-v2/internal/context.SetAttemptSkewContext (inline)
         0     0% 91.63%    13.50MB  0.82%  github.com/aws/aws-sdk-go-v2/internal/context.SetS3Backend (inline)
         0     0% 91.63%   323.56MB 19.65%  github.com/aws/aws-sdk-go-v2/internal/middleware.(*AddTimeOffsetMiddleware).HandleDeserialize
         0     0% 91.63%   840.14MB 51.02%  github.com/aws/aws-sdk-go-v2/internal/middleware.AddTimeOffsetMiddleware.HandleBuild
         0     0% 91.63%   827.14MB 50.23%  github.com/aws/aws-sdk-go-v2/service/internal/accept-encoding.(*DisableGzip).HandleFinalize
         0     0% 91.63%       24MB  1.46%  github.com/aws/aws-sdk-go-v2/service/internal/checksum.(*ComputeInputPayloadChecksum).HandleFinalize
         0     0% 91.63%       26MB  1.58%  github.com/aws/aws-sdk-go-v2/service/internal/checksum.(*SetupInputContext).HandleInitialize
         0     0% 91.63%   886.14MB 53.81%  github.com/aws/aws-sdk-go-v2/service/internal/s3shared.(*ARNLookup).HandleInitialize
         0     0% 91.63%   459.09MB 27.88%  github.com/aws/aws-sdk-go-v2/service/internal/s3shared.(*errorWrapper).HandleDeserialize
         0     0% 91.63%   459.09MB 27.88%  github.com/aws/aws-sdk-go-v2/service/internal/s3shared.(*metadataRetriever).HandleDeserialize
         0     0% 91.63%       25MB  1.52%  github.com/aws/aws-sdk-go-v2/service/internal/s3shared.(*s3100Continue).HandleBuild
         0     0% 91.63%   987.15MB 59.95%  github.com/aws/aws-sdk-go-v2/service/s3.(*Client).HeadObject
         0     0% 91.63%    26.50MB  1.61%  github.com/aws/aws-sdk-go-v2/service/s3.(*Client).PutObject
         0     0% 91.63%       16MB  0.97%  github.com/aws/aws-sdk-go-v2/service/s3.(*Client).addOperationHeadObjectMiddlewares
         0     0% 91.63%  1020.65MB 61.98%  github.com/aws/aws-sdk-go-v2/service/s3.(*Client).invokeOperation
         0     0% 91.63%   848.14MB 51.51%  github.com/aws/aws-sdk-go-v2/service/s3.(*ResolveEndpoint).HandleSerialize
         0     0% 91.63%   815.64MB 49.53%  github.com/aws/aws-sdk-go-v2/service/s3.(*awsRestxml_serializeOpHeadObject).HandleSerialize
         0     0% 91.63%    25.50MB  1.55%  github.com/aws/aws-sdk-go-v2/service/s3.(*awsRestxml_serializeOpPutObject).HandleSerialize
         0     0% 91.63%    50.51MB  3.07%  github.com/aws/aws-sdk-go-v2/service/s3.(*defaultAuthSchemeResolver).ResolveAuthSchemes
         0     0% 91.63%   646.12MB 39.24%  github.com/aws/aws-sdk-go-v2/service/s3.(*disableHTTPSMiddleware).HandleFinalize
         0     0% 91.63%    51.01MB  3.10%  github.com/aws/aws-sdk-go-v2/service/s3.(*endpointAuthResolver).ResolveAuthSchemes
         0     0% 91.63%    51.01MB  3.10%  github.com/aws/aws-sdk-go-v2/service/s3.(*endpointAuthResolver).resolveAuthSchemes
         0     0% 91.63%   754.63MB 45.83%  github.com/aws/aws-sdk-go-v2/service/s3.(*getIdentityMiddleware).HandleFinalize
         0     0% 91.63%       14MB  0.85%  github.com/aws/aws-sdk-go-v2/service/s3.(*getIdentityMiddleware).HandleFinalize.func1
         0     0% 91.63%   847.64MB 51.47%  github.com/aws/aws-sdk-go-v2/service/s3.(*isExpressUserAgent).HandleSerialize
         0     0% 91.63%   886.14MB 53.81%  github.com/aws/aws-sdk-go-v2/service/s3.(*legacyEndpointContextSetter).HandleInitialize
         0     0% 91.63%   880.14MB 53.45%  github.com/aws/aws-sdk-go-v2/service/s3.(*putBucketContextMiddleware).HandleSerialize
         0     0% 91.63%   827.14MB 50.23%  github.com/aws/aws-sdk-go-v2/service/s3.(*resolveAuthSchemeMiddleware).HandleFinalize
         0     0% 91.63%   725.12MB 44.03%  github.com/aws/aws-sdk-go-v2/service/s3.(*resolveEndpointV2Middleware).HandleFinalize
         0     0% 91.63%       17MB  1.03%  github.com/aws/aws-sdk-go-v2/service/s3.(*resolveEndpointV2Middleware).HandleFinalize.func1
         0     0% 91.63%    17.50MB  1.06%  github.com/aws/aws-sdk-go-v2/service/s3.(*resolver).ResolveEndpoint
         0     0% 91.63%        9MB  0.55%  github.com/aws/aws-sdk-go-v2/service/s3.(*resolver).ResolveEndpoint.(*resolver).ResolveEndpoint.func195.func335 (inline)
         0     0% 91.63%        9MB  0.55%  github.com/aws/aws-sdk-go-v2/service/s3.(*resolver).ResolveEndpoint.func195 (inline)
         0     0% 91.63%   848.14MB 51.51%  github.com/aws/aws-sdk-go-v2/service/s3.(*serializeImmutableHostnameBucketMiddleware).HandleSerialize
         0     0% 91.63%   504.10MB 30.61%  github.com/aws/aws-sdk-go-v2/service/s3.(*setLegacyContextSigningOptionsMiddleware).HandleFinalize
         0     0% 91.63%   862.14MB 52.36%  github.com/aws/aws-sdk-go-v2/service/s3.(*setOperationInputMiddleware).HandleSerialize
         0     0% 91.63%   504.10MB 30.61%  github.com/aws/aws-sdk-go-v2/service/s3.(*signRequestMiddleware).HandleFinalize
         0     0% 91.63%    45.01MB  2.73%  github.com/aws/aws-sdk-go-v2/service/s3.(*signRequestMiddleware).HandleFinalize.func1
         0     0% 91.63%   827.64MB 50.26%  github.com/aws/aws-sdk-go-v2/service/s3.(*spanBuildRequestEnd).HandleBuild
         0     0% 91.63%   880.14MB 53.45%  github.com/aws/aws-sdk-go-v2/service/s3.(*spanBuildRequestStart).HandleSerialize
         0     0% 91.63%   880.14MB 53.45%  github.com/aws/aws-sdk-go-v2/service/s3.(*spanInitializeEnd).HandleInitialize
         0     0% 91.63%   936.14MB 56.85%  github.com/aws/aws-sdk-go-v2/service/s3.(*spanInitializeStart).HandleInitialize
         0     0% 91.63%   613.62MB 37.26%  github.com/aws/aws-sdk-go-v2/service/s3.(*spanRetryLoop).HandleFinalize
         0     0% 91.63%   847.14MB 51.44%  github.com/aws/aws-sdk-go-v2/service/s3.(*validateOpHeadObject).HandleInitialize
         0     0% 91.63%       26MB  1.58%  github.com/aws/aws-sdk-go-v2/service/s3.(*validateOpPutObject).HandleInitialize
         0     0% 91.63%       16MB  0.97%  github.com/aws/aws-sdk-go-v2/service/s3.addClientUserAgent
         0     0% 91.63%       16MB  0.97%  github.com/aws/aws-sdk-go-v2/service/s3.getOrAddRequestUserAgent
         0     0% 91.63%    50.51MB  3.07%  github.com/aws/aws-sdk-go-v2/service/s3.serviceAuthOptions
         0     0% 91.63%    50.51MB  3.07%  github.com/aws/aws-sdk-go-v2/service/s3.serviceAuthOptions.func1 (inline)
         0     0% 91.63%    15.50MB  0.94%  github.com/aws/aws-sdk-go-v2/service/s3.setIdentity (inline)
         0     0% 91.63%       14MB  0.85%  github.com/aws/aws-sdk-go-v2/service/s3.setOperationInput (inline)
         0     0% 91.63%    14.50MB  0.88%  github.com/aws/aws-sdk-go-v2/service/s3.setResolvedAuthScheme (inline)
         0     0% 91.63%       14MB  0.85%  github.com/aws/aws-sdk-go-v2/service/s3.timeOperationMetric[go.shape.interface { Expiration time.Time }]
         0     0% 91.63%    45.01MB  2.73%  github.com/aws/aws-sdk-go-v2/service/s3.timeOperationMetric[go.shape.interface {}]
         0     0% 91.63%       17MB  1.03%  github.com/aws/aws-sdk-go-v2/service/s3.timeOperationMetric[go.shape.struct { URI net/url.URL; Headers net/http.Header; Properties github.com/aws/smithy-go.Properties }]
         0     0% 91.63%   848.14MB 51.51%  github.com/aws/aws-sdk-go-v2/service/s3/internal/customizations.(*processARNResource).HandleSerialize
         0     0% 91.63%   847.64MB 51.47%  github.com/aws/aws-sdk-go-v2/service/s3/internal/customizations.(*removeBucketFromPathMiddleware).HandleSerialize
         0     0% 91.63%   848.14MB 51.51%  github.com/aws/aws-sdk-go-v2/service/s3/internal/customizations.(*s3ObjectLambdaEndpoint).HandleSerialize
         0     0% 91.63%   847.64MB 51.47%  github.com/aws/aws-sdk-go-v2/service/s3/internal/customizations.(*updateEndpoint).HandleSerialize
         0     0% 91.63%   847.64MB 51.47%  github.com/aws/smithy-go/middleware.(*BuildStep).HandleMiddleware
         0     0% 91.63%   459.09MB 27.88%  github.com/aws/smithy-go/middleware.(*DeserializeStep).HandleMiddleware
         0     0% 91.63%   827.64MB 50.26%  github.com/aws/smithy-go/middleware.(*FinalizeStep).HandleMiddleware
         0     0% 91.63%   936.14MB 56.85%  github.com/aws/smithy-go/middleware.(*InitializeStep).HandleMiddleware
         0     0% 91.63%   880.14MB 53.45%  github.com/aws/smithy-go/middleware.(*SerializeStep).HandleMiddleware
         0     0% 91.63%   936.14MB 56.85%  github.com/aws/smithy-go/middleware.(*Stack).HandleMiddleware
         0     0% 91.63%   886.14MB 53.81%  github.com/aws/smithy-go/middleware.(*setLogger).HandleInitialize
         0     0% 91.63%   198.51MB 12.05%  github.com/aws/smithy-go/middleware.WithStackValue
         0     0% 91.63%   827.64MB 50.26%  github.com/aws/smithy-go/middleware.buildWrapHandler.HandleBuild
         0     0% 91.63%   847.64MB 51.47%  github.com/aws/smithy-go/middleware.decoratedBuildHandler.HandleBuild
         0     0% 91.63%   459.09MB 27.88%  github.com/aws/smithy-go/middleware.decoratedDeserializeHandler.HandleDeserialize
         0     0% 91.63%   827.14MB 50.23%  github.com/aws/smithy-go/middleware.decoratedFinalizeHandler.HandleFinalize
         0     0% 91.63%   936.14MB 56.85%  github.com/aws/smithy-go/middleware.decoratedHandler.Handle
         0     0% 91.63%   936.14MB 56.85%  github.com/aws/smithy-go/middleware.decoratedInitializeHandler.HandleInitialize
         0     0% 91.63%   880.14MB 53.45%  github.com/aws/smithy-go/middleware.decoratedSerializeHandler.HandleSerialize
         0     0% 91.63%   271.05MB 16.46%  github.com/aws/smithy-go/middleware.deserializeWrapHandler.HandleDeserialize
         0     0% 91.63%   459.09MB 27.88%  github.com/aws/smithy-go/middleware.finalizeWrapHandler.HandleFinalize
         0     0% 91.63%   880.14MB 53.45%  github.com/aws/smithy-go/middleware.initializeWrapHandler.HandleInitialize
         0     0% 91.63%   847.64MB 51.47%  github.com/aws/smithy-go/middleware.serializeWrapHandler.HandleSerialize
         0     0% 91.63%   840.14MB 51.02%  github.com/aws/smithy-go/transport/http.(*ComputeContentLength).HandleBuild
         0     0% 91.63%   158.54MB  9.63%  github.com/aws/smithy-go/transport/http.(*Request).Build
         0     0% 91.63%   271.05MB 16.46%  github.com/aws/smithy-go/transport/http.(*RequestResponseLogger).HandleDeserialize
         0     0% 91.63%       16MB  0.97%  github.com/aws/smithy-go/transport/http.(*UserAgentBuilder).AddKeyValue (inline)
         0     0% 91.63%       16MB  0.97%  github.com/aws/smithy-go/transport/http.(*UserAgentBuilder).appendTo
         0     0% 91.63%   459.09MB 27.88%  github.com/aws/smithy-go/transport/http.(*closeResponseBody).HandleDeserialize
         0     0% 91.63%   459.09MB 27.88%  github.com/aws/smithy-go/transport/http.(*errorCloseResponseBodyMiddleware).HandleDeserialize
         0     0% 91.63%     8.50MB  0.52%  github.com/aws/smithy-go/transport/http.(*timedClientDo).Do
         0     0% 91.63%       17MB  1.03%  github.com/rclone/rclone/backend/s3.(*Fs).List
         0     0% 91.63%       17MB  1.03%  github.com/rclone/rclone/backend/s3.(*Fs).ListP
         0     0% 91.63%   987.15MB 59.95%  github.com/rclone/rclone/backend/s3.(*Fs).headObject
         0     0% 91.63%   987.15MB 59.95%  github.com/rclone/rclone/backend/s3.(*Fs).headObject.func1
         0     0% 91.63%       17MB  1.03%  github.com/rclone/rclone/backend/s3.(*Fs).list
         0     0% 91.63%       17MB  1.03%  github.com/rclone/rclone/backend/s3.(*Fs).listDir
         0     0% 91.63%       16MB  0.97%  github.com/rclone/rclone/backend/s3.(*Fs).split
         0     0% 91.63%    83.51MB  5.07%  github.com/rclone/rclone/backend/s3.(*Object).ModTime
         0     0% 91.63%  1035.78MB 62.90%  github.com/rclone/rclone/backend/s3.(*Object).Update
         0     0% 91.63%    83.51MB  5.07%  github.com/rclone/rclone/backend/s3.(*Object).readMetaData
         0     0% 91.63%    56.01MB  3.40%  github.com/rclone/rclone/backend/s3.(*Object).setMetaData
         0     0% 91.63%       16MB  0.97%  github.com/rclone/rclone/backend/s3.(*Object).split
         0     0% 91.63%       26MB  1.58%  github.com/rclone/rclone/backend/s3.(*Object).uploadSinglepartPutObject
         0     0% 91.63%       26MB  1.58%  github.com/rclone/rclone/backend/s3.(*Object).uploadSinglepartPutObject.func2
         0     0% 91.63%   124.45MB  7.56%  github.com/rclone/rclone/cmd.Main
         0     0% 91.63%       17MB  1.03%  github.com/rclone/rclone/cmd/mount.(*Dir).Lookup
         0     0% 91.63%     9.50MB  0.58%  github.com/rclone/rclone/cmd/mount.(*Dir).ReadDirAll
         0     0% 91.63%    83.51MB  5.07%  github.com/rclone/rclone/cmd/mount.(*File).Attr
         0     0% 91.63%     8.83MB  0.54%  github.com/rclone/rclone/cmd/mount.mount.func2
         0     0% 91.63%   123.94MB  7.53%  github.com/rclone/rclone/cmd/mountlib.(*MountPoint).Mount
         0     0% 91.63%   123.94MB  7.53%  github.com/rclone/rclone/cmd/mountlib.NewMountCommand.func1
         0     0% 91.63%    17.50MB  1.06%  github.com/rclone/rclone/fs.Fingerprint
         0     0% 91.63%  1020.15MB 61.95%  github.com/rclone/rclone/fs.pacerInvoker
         0     0% 91.63%       17MB  1.03%  github.com/rclone/rclone/fs/list.DirSorted
         0     0% 91.63%       17MB  1.03%  github.com/rclone/rclone/fs/list.WithListP
         0     0% 91.63%   996.27MB 60.50%  github.com/rclone/rclone/fs/operations.(*copy).copy
         0     0% 91.63%  1049.78MB 63.75%  github.com/rclone/rclone/fs/operations.(*copy).manualCopy
         0     0% 91.63%  1052.28MB 63.90%  github.com/rclone/rclone/fs/operations.(*copy).updateOrPut
         0     0% 91.63%   996.27MB 60.50%  github.com/rclone/rclone/fs/operations.Copy
         0     0% 91.63%   994.15MB 60.37%  github.com/rclone/rclone/lib/pacer.(*Pacer).Call
         0     0% 91.63%       26MB  1.58%  github.com/rclone/rclone/lib/pacer.(*Pacer).CallNoRetry (inline)
         0     0% 91.63%  1020.15MB 61.95%  github.com/rclone/rclone/lib/pacer.(*Pacer).call
         0     0% 91.63%    20.50MB  1.25%  github.com/rclone/rclone/vfs.(*Dir).Create
         0     0% 91.63%     9.50MB  0.58%  github.com/rclone/rclone/vfs.(*Dir).ReadDirAll
         0     0% 91.63%       17MB  1.03%  github.com/rclone/rclone/vfs.(*Dir).Stat
         0     0% 91.63%       17MB  1.03%  github.com/rclone/rclone/vfs.(*Dir)._readDir
         0     0% 91.63%       17MB  1.03%  github.com/rclone/rclone/vfs.(*Dir).stat
         0     0% 91.63%     8.50MB  0.52%  github.com/rclone/rclone/vfs.(*File).CachePath
         0     0% 91.63%    83.51MB  5.07%  github.com/rclone/rclone/vfs.(*File).ModTime
         0     0% 91.63%    52.58MB  3.19%  github.com/rclone/rclone/vfs.(*File).Open
         0     0% 91.63%     9.50MB  0.58%  github.com/rclone/rclone/vfs.(*File).Path
         0     0% 91.63%     8.50MB  0.52%  github.com/rclone/rclone/vfs.(*File)._cachePath
         0     0% 91.63%     9.07MB  0.55%  github.com/rclone/rclone/vfs.(*File).openRW
         0     0% 91.63%     8.57MB  0.52%  github.com/rclone/rclone/vfs.(*RWFileHandle).Truncate
         0     0% 91.63%     8.57MB  0.52%  github.com/rclone/rclone/vfs.(*RWFileHandle).openPending
         0     0% 91.63%   123.94MB  7.53%  github.com/rclone/rclone/vfs.(*VFS).SetCacheMode
         0     0% 91.63%   123.94MB  7.53%  github.com/rclone/rclone/vfs.New
         0     0% 91.63%     9.50MB  0.58%  github.com/rclone/rclone/vfs.Nodes.Less
         0     0% 91.63%     9.07MB  0.55%  github.com/rclone/rclone/vfs.newRWFileHandle
         0     0% 91.63%    35.01MB  2.13%  github.com/rclone/rclone/vfs/vfscache.(*Cache).Exists
         0     0% 91.63%   129.94MB  7.89%  github.com/rclone/rclone/vfs/vfscache.(*Cache).get
         0     0% 91.63%   123.94MB  7.53%  github.com/rclone/rclone/vfs/vfscache.(*Cache).reload
         0     0% 91.63%    95.43MB  5.80%  github.com/rclone/rclone/vfs/vfscache.(*Cache).reload.(*Cache).walk.func2
         0     0% 91.63%    95.43MB  5.80%  github.com/rclone/rclone/vfs/vfscache.(*Cache).reload.func1
         0     0% 91.63%   123.94MB  7.53%  github.com/rclone/rclone/vfs/vfscache.(*Cache).walk (inline)
         0     0% 91.63%   788.23MB 47.87%  github.com/rclone/rclone/vfs/vfscache.(*Item).Close.func2
         0     0% 91.63%   953.26MB 57.89%  github.com/rclone/rclone/vfs/vfscache.(*Item)._store
         0     0% 91.63%   988.27MB 60.01%  github.com/rclone/rclone/vfs/vfscache.(*Item)._store.func1
         0     0% 91.63%    17.50MB  1.06%  github.com/rclone/rclone/vfs/vfscache.(*Item)._updateFingerprint
         0     0% 91.63%    22.50MB  1.37%  github.com/rclone/rclone/vfs/vfscache.(*Item).load
         0     0% 91.63%   811.24MB 49.26%  github.com/rclone/rclone/vfs/vfscache.(*Item).store
         0     0% 91.63%   123.94MB  7.53%  github.com/rclone/rclone/vfs/vfscache.New
         0     0% 91.63%   988.27MB 60.01%  github.com/rclone/rclone/vfs/vfscache.unlockMutexForCall
         0     0% 91.63%       10MB  0.61%  github.com/rclone/rclone/vfs/vfscache/writeback.(*WriteBack)._resetTimer.func1
         0     0% 91.63%       10MB  0.61%  github.com/rclone/rclone/vfs/vfscache/writeback.(*WriteBack).processItems
         0     0% 91.63%   779.73MB 47.35%  github.com/rclone/rclone/vfs/vfscache/writeback.(*WriteBack).upload
         0     0% 91.63%   124.45MB  7.56%  github.com/spf13/cobra.(*Command).Execute (inline)
         0     0% 91.63%   124.45MB  7.56%  github.com/spf13/cobra.(*Command).ExecuteC
         0     0% 91.63%   123.94MB  7.53%  github.com/spf13/cobra.(*Command).execute
         0     0% 91.63%    17.02MB  1.03%  io.Copy (inline)
         0     0% 91.63%    12.89MB  0.78%  io.CopyBuffer
         0     0% 91.63%   124.45MB  7.56%  main.main
         0     0% 91.63%    13.41MB  0.81%  net/http.(*Request).write
         0     0% 91.63%   218.08MB 13.24%  net/http.(*persistConn).readLoop
         0     0% 91.63%   218.08MB 13.24%  net/http.(*persistConn).readResponse
         0     0% 91.63%    13.41MB  0.81%  net/http.(*persistConn).writeLoop
         0     0% 91.63%    13.41MB  0.81%  net/http.(*transferWriter).doBodyCopy
         0     0% 91.63%    13.41MB  0.81%  net/http.(*transferWriter).writeBody
         0     0% 91.63%   196.58MB 11.94%  net/textproto.(*Reader).ReadMIMEHeader (inline)
         0     0% 91.63%    28.50MB  1.73%  path/filepath.Join (inline)
         0     0% 91.63%   123.94MB  7.53%  path/filepath.Walk
         0     0% 91.63%    28.50MB  1.73%  path/filepath.join
         0     0% 91.63%   123.94MB  7.53%  path/filepath.walk
         0     0% 91.63%   127.47MB  7.74%  runtime.main
         0     0% 91.63%     9.50MB  0.58%  sort.Sort
         0     0% 91.63%     9.50MB  0.58%  sort.pdqsort
         0     0% 91.63%    83.02MB  5.04%  strings.(*Builder).Grow
         0     0% 91.63%    33.50MB  2.03%  strings.Join

top

9989 root      20   0 4934732   3.5g  18432 S  12.5  46.6  15:35.99 rclone

pmap

[root@lbr-rclone ~]# pmap `pidof rclone`
9989:   /usr/bin/rclone mount zos:lbr-rclone-test /mnt/rc --vfs-cache-mode full --cache-dir /cache --log-file /var/log/rc.log --log-level info --uid 1000 --gid 1000 --allow-other --rc --rc-addr=127.0.0.1:5572
0000000000400000  30416K r-x-- rclone
00000000021b4000  33552K r---- rclone
0000000004278000   2172K rw--- rclone
0000000004497000    332K rw---   [ anon ]
000000c000000000 4169728K rw---   [ anon ]
000000c0fe800000  24576K -----   [ anon ]
00007f3fec684000  67176K rw---   [ anon ]
00007f3ff0828000  28280K rw---   [ anon ]
00007f3ff23cc000  18604K rw---   [ anon ]
00007f3ff3601000  12508K rw---   [ anon ]
00007f3ff423a000   8272K rw---   [ anon ]
00007f3ff4a54000   5968K rw---   [ anon ]
00007f3ff5032000   4100K rw---   [ anon ]
00007f3ff5434000   2308K rw---   [ anon ]
00007f3ff567a000   1544K rw---   [ anon ]
00007f3ff5800000   1024K rw---   [ anon ]
00007f3ff5908000   6020K rw---   [ anon ]
00007f3ff5ee9000   1024K rw---   [ anon ]
00007f3ff5fe9000     68K rw---   [ anon ]
00007f3ff5ffa000     24K rw---   [ anon ]
00007f3ff6000000  30720K rw---   [ anon ]
00007f3ff7e00000   2024K rw---   [ anon ]
00007f3ff7ffa000 263680K -----   [ anon ]
00007f400817a000      8K rw---   [ anon ]
00007f400817c000 524280K -----   [ anon ]
00007f402817a000      8K rw---   [ anon ]
00007f402817c000 293560K -----   [ anon ]
00007f403a02a000      4K rw---   [ anon ]
00007f403a02b000  36692K -----   [ anon ]
00007f403c400000      4K rw---   [ anon ]
00007f403c401000   4580K -----   [ anon ]
00007f403c87a000      4K rw---   [ anon ]
00007f403c87b000    508K -----   [ anon ]
00007f403c8fa000    384K rw---   [ anon ]
00007ffd75a9f000    132K rw---   [ stack ]
00007ffd75b76000     16K r----   [ anon ]
00007ffd75b7a000      8K r-x--   [ anon ]
ffffffffff600000      4K --x--   [ anon ]
 total          5574312K
3

Can you please create a Github Issue for this?

And also please attach the full heap profile there, rather than just a snapshot of a single metric. You can create it like so:

curl "http://127.0.0.1:5572/debug/pprof/heap" > rclone.heap
1 Like
4

here is the pprof heap file
rclone.heap.log (144.1 KB)

profile001
profile0011920×1475 163 KB

I ran my test script again, and this time the memory usage grew to 2.1G. Due to the limited Ceph testing space on my local setup, about 230,000 files of 512KB each were created.

top

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND                                                                                   
 172065 root      20   0 4199140   2.0g  58752 S   0.0   4.3 165:53.97 rclone

pmap

172065:   rclone mount s3:rclone-mem mp --vfs-cache-mode full --cache-dir /cache --log-file rc.log --log-level info --uid 1000 --gid 1000 --allow-other --vfs-cache-max-size 10G --rc --rc-addr=127.0.0.1:5572
0000000000400000  30416K r-x-- rclone
00000000021b4000  33552K r---- rclone
0000000004278000   2172K rw--- rclone
0000000004497000    332K rw---   [ anon ]
000000c000000000 2846720K rw---   [ anon ]
000000c0adc00000  36864K -----   [ anon ]
00007f1ed1583000  27360K rw---   [ anon ]
00007f1ed3042000  19304K rw---   [ anon ]
00007f1ed4326000  12884K rw---   [ anon ]
00007f1ed4fbc000   7512K rw---   [ anon ]
00007f1ed5718000   7436K rw---   [ anon ]
00007f1ed5e65000   5644K rw---   [ anon ]
00007f1ed63ed000   1604K rw---   [ anon ]
00007f1ed6582000    512K rw---   [ anon ]
00007f1ed6609000   9096K rw---   [ anon ]
00007f1ed6eeb000   1024K rw---   [ anon ]
00007f1ed6feb000     68K rw---   [ anon ]
00007f1ed6ffc000     16K rw---   [ anon ]
00007f1ed7000000  30720K rw---   [ anon ]
00007f1ed8e00000   2032K rw---   [ anon ]
00007f1ed8ffc000 263680K -----   [ anon ]
00007f1ee917c000      8K rw---   [ anon ]
00007f1ee917e000 524280K -----   [ anon ]
00007f1f0917c000      8K rw---   [ anon ]
00007f1f0917e000 293560K -----   [ anon ]
00007f1f1b02c000      4K rw---   [ anon ]
00007f1f1b02d000  36692K -----   [ anon ]
00007f1f1d402000      4K rw---   [ anon ]
00007f1f1d403000   4580K -----   [ anon ]
00007f1f1d87c000      4K rw---   [ anon ]
00007f1f1d87d000    508K -----   [ anon ]
00007f1f1d8fc000    384K rw---   [ anon ]
00007ffd2000a000    136K rw---   [ stack ]
00007ffd20048000     16K r----   [ anon ]
00007ffd2004c000      8K r-x--   [ anon ]
ffffffffff600000      4K --x--   [ anon ]
 total          4199144K
5

Performed another set of tests on v1.70.3, this time exporting the mounted directory to a Windows host using Samba for writing. After writing approximately 100,000 files, memory usage reached 3.5GB. After waiting for a while and executing rclone rc core/gc, memory usage still remained at 3.5GB.

Then I tried to delete all the files I had written before. However, after that, memory usage still remained high. vfs/stats shows that the file system actually only has a few files and directories.

pprof file:
rclone-after-delete-files.heap.log (130.8 KB)

top

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND                                                                                                 
  24008 root      20   0 4869896   3.3g  19712 S   4.0  44.4  24:45.94 rclone

The output of rc core/memstats is as follows:
HeapAlloc is only ~100MB but HeapSys is ~3GB

{
        "Alloc": 68330528,
        "BuckHashSys": 4169929,
        "Frees": 1316197175,
        "GCSys": 36076088,
        "HeapAlloc": 68330528,
        "HeapIdle": 3460227072,
        "HeapInuse": 140681216,
        "HeapObjects": 379111,
        "HeapReleased": 3427344384,
        "HeapSys": 3600908288,
        "MCacheInuse": 4832,
        "MCacheSys": 15704,
        "MSpanInuse": 2415360,
        "MSpanSys": 63452160,
        "Mallocs": 1316576286,
        "OtherSys": 7082559,
        "StackInuse": 1998848,
        "StackSys": 1998848,
        "Sys": 3713703576,
        "TotalAlloc": 115601328536
}

{
        "diskCache": {
                "bytesUsed": 0,
                "erroredFiles": 0,
                "files": 148964,
                "hashType": 1,
                "outOfSpace": false,
                "path": "/cache/vfs/xxx/xxx",
                "pathMeta": "/cache/vfsMeta/xxx/xxx",
                "uploadsInProgress": 0,
                "uploadsQueued": 0
        },
        "fs": "xxx:xxx",
        "inUse": 1,
        "metadataCache": {
                "dirs": 9,
                "files": 13
        },
        "opt": {
                "BlockNormDupes": false,
                "CacheMaxAge": 3600000000000,
                "CacheMaxSize": 161061273600,
                "CacheMinFreeSpace": -1,
                "CacheMode": 3,
                "CachePollInterval": 60000000000,
                "CaseInsensitive": false,
                "ChunkSize": 134217728,
                "ChunkSizeLimit": -1,
                "ChunkStreams": 0,
                "DirCacheTime": 300000000000,
                "DirPerms": 2147484141,
                "DiskSpaceTotalSize": -1,
                "FastFingerprint": false,
                "FilePerms": 420,
                "GID": 1000,
                "LinkPerms": 134218148,
                "Links": false,
                "MetadataExtension": "",
                "NoChecksum": false,
                "NoModTime": false,
                "NoSeek": false,
                "PollInterval": 60000000000,
                "ReadAhead": 0,
                "ReadOnly": false,
                "ReadWait": 20000000,
                "Refresh": false,
                "UID": 1000,
                "Umask": 18,
                "UsedIsSize": false,
                "WriteBack": 5000000000,
                "WriteWait": 1000000000
        }
}
6

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