From de185de215c273e787cb770c287b087f5b484022 Mon Sep 17 00:00:00 2001 From: Nick Craig-Wood Date: Sun, 30 Jul 2023 05:39:01 +0100 Subject: [PATCH] accounting: show server side stats in own lines and not as bytes transferred Before this change we showed both server side moves and server side copies as bytes transferred. This made a nice easy to use stats display, but also caused confusion for users who saw unrealistic transfer times. It also caused a problem with --max-transfer and chunker which renames each chunk after uploading which was counted as a transfer byte. This patch instead accounts the server side move and copy statistics as a seperate lines in the stats display which will only appear if there are any server side moves / copies. This is also output in the rc. This gives users something to look at when transfers are running which was the point of the original change but it now means that transfer bytes represents data transfers through this rclone instance only. Fixes #7183 --- fs/accounting/accounting.go | 23 ++++++--- fs/accounting/stats.go | 94 ++++++++++++++++++++++++----------- fs/accounting/stats_groups.go | 4 ++ fs/operations/operations.go | 6 +-- 4 files changed, 88 insertions(+), 39 deletions(-) diff --git a/fs/accounting/accounting.go b/fs/accounting/accounting.go index a019232fb..5b1046e5b 100644 --- a/fs/accounting/accounting.go +++ b/fs/accounting/accounting.go @@ -272,10 +272,10 @@ func (acc *Account) checkReadAfter(bytesUntilLimit int64, n int, err error) (out return n, err } -// ServerSideCopyStart should be called at the start of a server-side copy +// ServerSideTransferStart should be called at the start of a server-side transfer // // This pretends a transfer has started -func (acc *Account) ServerSideCopyStart() { +func (acc *Account) ServerSideTransferStart() { acc.values.mu.Lock() // Set start time. if acc.values.start.IsZero() { @@ -284,8 +284,9 @@ func (acc *Account) ServerSideCopyStart() { acc.values.mu.Unlock() } -// ServerSideCopyEnd accounts for a read of n bytes in a sever side copy -func (acc *Account) ServerSideCopyEnd(n int64) { +// ServerSideTransferEnd accounts for a read of n bytes in a sever +// side transfer to be treated as a normal transfer. +func (acc *Account) ServerSideTransferEnd(n int64) { // Update Stats acc.values.mu.Lock() acc.values.bytes += n @@ -294,10 +295,20 @@ func (acc *Account) ServerSideCopyEnd(n int64) { acc.stats.Bytes(n) } +// ServerSideCopyEnd accounts for a read of n bytes in a sever side copy +func (acc *Account) ServerSideCopyEnd(n int64) { + acc.stats.AddServerSideCopy(n) +} + +// ServerSideMoveEnd accounts for a read of n bytes in a sever side move +func (acc *Account) ServerSideMoveEnd(n int64) { + acc.stats.AddServerSideMove(n) +} + // DryRun accounts for statistics without running the operation func (acc *Account) DryRun(n int64) { - acc.ServerSideCopyStart() - acc.ServerSideCopyEnd(n) + acc.ServerSideTransferStart() + acc.ServerSideTransferEnd(n) } // Account for n bytes from the current file bandwidth limit (if any) diff --git a/fs/accounting/stats.go b/fs/accounting/stats.go index 7e3a07225..2d7376ab6 100644 --- a/fs/accounting/stats.go +++ b/fs/accounting/stats.go @@ -28,36 +28,40 @@ var MaxCompletedTransfers = 100 // N.B.: if this struct is modified, please remember to also update sum() function in stats_groups // to correctly count the updated fields type StatsInfo struct { - mu sync.RWMutex - ctx context.Context - ci *fs.ConfigInfo - bytes int64 - errors int64 - lastError error - fatalError bool - retryError bool - retryAfter time.Time - checks int64 - checking *transferMap - checkQueue int - checkQueueSize int64 - transfers int64 - transferring *transferMap - transferQueue int - transferQueueSize int64 - renames int64 - renameQueue int - renameQueueSize int64 - deletes int64 - deletesSize int64 - deletedDirs int64 - inProgress *inProgress - startedTransfers []*Transfer // currently active transfers - oldTimeRanges timeRanges // a merged list of time ranges for the transfers - oldDuration time.Duration // duration of transfers we have culled - group string - startTime time.Time // the moment these stats were initialized or reset - average averageValues + mu sync.RWMutex + ctx context.Context + ci *fs.ConfigInfo + bytes int64 + errors int64 + lastError error + fatalError bool + retryError bool + retryAfter time.Time + checks int64 + checking *transferMap + checkQueue int + checkQueueSize int64 + transfers int64 + transferring *transferMap + transferQueue int + transferQueueSize int64 + renames int64 + renameQueue int + renameQueueSize int64 + deletes int64 + deletesSize int64 + deletedDirs int64 + inProgress *inProgress + startedTransfers []*Transfer // currently active transfers + oldTimeRanges timeRanges // a merged list of time ranges for the transfers + oldDuration time.Duration // duration of transfers we have culled + group string + startTime time.Time // the moment these stats were initialized or reset + average averageValues + serverSideCopies int64 + serverSideCopyBytes int64 + serverSideMoves int64 + serverSideMoveBytes int64 } type averageValues struct { @@ -110,6 +114,10 @@ func (s *StatsInfo) RemoteStats() (out rc.Params, err error) { out["deletedDirs"] = s.deletedDirs out["renames"] = s.renames out["elapsedTime"] = time.Since(s.startTime).Seconds() + out["serverSideCopies"] = s.serverSideCopies + out["serverSideCopyBytes"] = s.serverSideCopyBytes + out["serverSideMoves"] = s.serverSideMoves + out["serverSideMoveBytes"] = s.serverSideMoveBytes eta, etaOK := eta(s.bytes, ts.totalBytes, ts.speed) if etaOK { out["eta"] = eta.Seconds() @@ -449,6 +457,16 @@ func (s *StatsInfo) String() string { _, _ = fmt.Fprintf(buf, "Transferred: %10d / %d, %s\n", s.transfers, ts.totalTransfers, percent(s.transfers, ts.totalTransfers)) } + if s.serverSideCopies != 0 || s.serverSideCopyBytes != 0 { + _, _ = fmt.Fprintf(buf, "Server Side Copies:%6d @ %s\n", + s.serverSideCopies, fs.SizeSuffix(s.serverSideCopyBytes).ByteUnit(), + ) + } + if s.serverSideMoves != 0 || s.serverSideMoveBytes != 0 { + _, _ = fmt.Fprintf(buf, "Server Side Moves:%7d @ %s\n", + s.serverSideMoves, fs.SizeSuffix(s.serverSideMoveBytes).ByteUnit(), + ) + } _, _ = fmt.Fprintf(buf, "Elapsed time: %10ss\n", strings.TrimRight(fs.Duration(elapsedTime.Truncate(time.Minute)).ReadableString(), "0s")+fmt.Sprintf("%.1f", elapsedTimeSecondsOnly.Seconds())) } @@ -856,3 +874,19 @@ func (s *StatsInfo) PruneTransfers() { } s.mu.Unlock() } + +// AddServerSideMove counts a server side move +func (s *StatsInfo) AddServerSideMove(n int64) { + s.mu.Lock() + s.serverSideMoves += 1 + s.serverSideMoveBytes += n + s.mu.Unlock() +} + +// AddServerSideCopy counts a server side copy +func (s *StatsInfo) AddServerSideCopy(n int64) { + s.mu.Lock() + s.serverSideCopies += 1 + s.serverSideCopyBytes += n + s.mu.Unlock() +} diff --git a/fs/accounting/stats_groups.go b/fs/accounting/stats_groups.go index 7906df998..eaa3d2a2f 100644 --- a/fs/accounting/stats_groups.go +++ b/fs/accounting/stats_groups.go @@ -97,6 +97,10 @@ Returns the following values: "lastError": last error string, "renames" : number of files renamed, "retryError": boolean showing whether there has been at least one non-NoRetryError, + "serverSideCopies": number of server side copies done, + "serverSideCopyBytes": number bytes server side copied, + "serverSideMoves": number of server side moves done, + "serverSideMoveBytes": number bytes server side moved, "speed": average speed in bytes per second since start of the group, "totalBytes": total number of bytes in the group, "totalChecks": total number of checks in the group, diff --git a/fs/operations/operations.go b/fs/operations/operations.go index 2ab0dab54..4a42a33b0 100644 --- a/fs/operations/operations.go +++ b/fs/operations/operations.go @@ -392,7 +392,7 @@ func Copy(ctx context.Context, f fs.Fs, dst fs.Object, remote string, src fs.Obj } if doCopy := f.Features().Copy; doCopy != nil && (SameConfig(src.Fs(), f) || (SameRemoteType(src.Fs(), f) && (f.Features().ServerSideAcrossConfigs || ci.ServerSideAcrossConfigs))) { in := tr.Account(ctx, nil) // account the transfer - in.ServerSideCopyStart() + in.ServerSideTransferStart() newDst, err = doCopy(ctx, src, remote) if err == nil { dst = newDst @@ -639,7 +639,7 @@ func Move(ctx context.Context, fdst fs.Fs, dst fs.Object, remote string, src fs. } // Move dst <- src in := tr.Account(ctx, nil) // account the transfer - in.ServerSideCopyStart() + in.ServerSideTransferStart() newDst, err = doMove(ctx, src, remote) switch err { case nil: @@ -648,7 +648,7 @@ func Move(ctx context.Context, fdst fs.Fs, dst fs.Object, remote string, src fs. } else { fs.Infof(src, "Moved (server-side)") } - in.ServerSideCopyEnd(newDst.Size()) // account the bytes for the server-side transfer + in.ServerSideMoveEnd(newDst.Size()) // account the bytes for the server-side transfer _ = in.Close() return newDst, nil case fs.ErrorCantMove: