github.com/xhghs/rclone@v1.51.1-0.20200430155106-e186a28cced8/fs/accounting/stats.go (about)

     1  package accounting
     2  
     3  import (
     4  	"bytes"
     5  	"fmt"
     6  	"sort"
     7  	"strings"
     8  	"sync"
     9  	"time"
    10  
    11  	"github.com/rclone/rclone/fs"
    12  	"github.com/rclone/rclone/fs/fserrors"
    13  	"github.com/rclone/rclone/fs/rc"
    14  )
    15  
    16  // MaxCompletedTransfers specifies maximum number of completed transfers in startedTransfers list
    17  var MaxCompletedTransfers = 100
    18  
    19  // StatsInfo accounts all transfers
    20  type StatsInfo struct {
    21  	mu                sync.RWMutex
    22  	bytes             int64
    23  	errors            int64
    24  	lastError         error
    25  	fatalError        bool
    26  	retryError        bool
    27  	retryAfter        time.Time
    28  	checks            int64
    29  	checking          *stringSet
    30  	checkQueue        int
    31  	checkQueueSize    int64
    32  	transfers         int64
    33  	transferring      *stringSet
    34  	transferQueue     int
    35  	transferQueueSize int64
    36  	renameQueue       int
    37  	renameQueueSize   int64
    38  	deletes           int64
    39  	inProgress        *inProgress
    40  	startedTransfers  []*Transfer   // currently active transfers
    41  	oldTimeRanges     timeRanges    // a merged list of time ranges for the transfers
    42  	oldDuration       time.Duration // duration of transfers we have culled
    43  	group             string
    44  }
    45  
    46  // NewStats creates an initialised StatsInfo
    47  func NewStats() *StatsInfo {
    48  	return &StatsInfo{
    49  		checking:     newStringSet(fs.Config.Checkers, "checking"),
    50  		transferring: newStringSet(fs.Config.Transfers, "transferring"),
    51  		inProgress:   newInProgress(),
    52  	}
    53  }
    54  
    55  // RemoteStats returns stats for rc
    56  func (s *StatsInfo) RemoteStats() (out rc.Params, err error) {
    57  	out = make(rc.Params)
    58  	s.mu.RLock()
    59  	dt := s.totalDuration()
    60  	dtSeconds := dt.Seconds()
    61  	speed := 0.0
    62  	if dt > 0 {
    63  		speed = float64(s.bytes) / dtSeconds
    64  	}
    65  	out["speed"] = speed
    66  	out["bytes"] = s.bytes
    67  	out["errors"] = s.errors
    68  	out["fatalError"] = s.fatalError
    69  	out["retryError"] = s.retryError
    70  	out["checks"] = s.checks
    71  	out["transfers"] = s.transfers
    72  	out["deletes"] = s.deletes
    73  	out["elapsedTime"] = dtSeconds
    74  	s.mu.RUnlock()
    75  	if !s.checking.empty() {
    76  		var c []string
    77  		s.checking.mu.RLock()
    78  		defer s.checking.mu.RUnlock()
    79  		for name := range s.checking.items {
    80  			c = append(c, name)
    81  		}
    82  		out["checking"] = c
    83  	}
    84  	if !s.transferring.empty() {
    85  		s.transferring.mu.RLock()
    86  
    87  		var t []rc.Params
    88  		for name := range s.transferring.items {
    89  			if acc := s.inProgress.get(name); acc != nil {
    90  				t = append(t, acc.RemoteStats())
    91  			} else {
    92  				t = append(t, s.transferRemoteStats(name))
    93  			}
    94  		}
    95  		out["transferring"] = t
    96  		s.transferring.mu.RUnlock()
    97  	}
    98  	if s.errors > 0 {
    99  		out["lastError"] = s.lastError.Error()
   100  	}
   101  	return out, nil
   102  }
   103  
   104  func (s *StatsInfo) transferRemoteStats(name string) rc.Params {
   105  	s.mu.RLock()
   106  	defer s.mu.RUnlock()
   107  	for _, tr := range s.startedTransfers {
   108  		if tr.remote == name {
   109  			return rc.Params{
   110  				"name": name,
   111  				"size": tr.size,
   112  			}
   113  		}
   114  	}
   115  	return rc.Params{"name": name}
   116  }
   117  
   118  // timeRange is a start and end time of a transfer
   119  type timeRange struct {
   120  	start time.Time
   121  	end   time.Time
   122  }
   123  
   124  // timeRanges is a list of non-overlapping start and end times for
   125  // transfers
   126  type timeRanges []timeRange
   127  
   128  // merge all the overlapping time ranges
   129  func (trs *timeRanges) merge() {
   130  	Trs := *trs
   131  
   132  	// Sort by the starting time.
   133  	sort.Slice(Trs, func(i, j int) bool {
   134  		return Trs[i].start.Before(Trs[j].start)
   135  	})
   136  
   137  	// Merge overlaps and add distinctive ranges together
   138  	var (
   139  		newTrs = Trs[:0]
   140  		i, j   = 0, 1
   141  	)
   142  	for i < len(Trs) {
   143  		if j < len(Trs) {
   144  			if !Trs[i].end.Before(Trs[j].start) {
   145  				if Trs[i].end.Before(Trs[j].end) {
   146  					Trs[i].end = Trs[j].end
   147  				}
   148  				j++
   149  				continue
   150  			}
   151  		}
   152  		newTrs = append(newTrs, Trs[i])
   153  		i = j
   154  		j++
   155  	}
   156  
   157  	*trs = newTrs
   158  }
   159  
   160  // cull remove any ranges whose start and end are before cutoff
   161  // returning their duration sum
   162  func (trs *timeRanges) cull(cutoff time.Time) (d time.Duration) {
   163  	var newTrs = (*trs)[:0]
   164  	for _, tr := range *trs {
   165  		if cutoff.Before(tr.start) || cutoff.Before(tr.end) {
   166  			newTrs = append(newTrs, tr)
   167  		} else {
   168  			d += tr.end.Sub(tr.start)
   169  		}
   170  	}
   171  	*trs = newTrs
   172  	return d
   173  }
   174  
   175  // total the time out of the time ranges
   176  func (trs timeRanges) total() (total time.Duration) {
   177  	for _, tr := range trs {
   178  		total += tr.end.Sub(tr.start)
   179  	}
   180  	return total
   181  }
   182  
   183  // Total duration is union of durations of all transfers belonging to this
   184  // object.
   185  // Needs to be protected by mutex.
   186  func (s *StatsInfo) totalDuration() time.Duration {
   187  	// copy of s.oldTimeRanges with extra room for the current transfers
   188  	timeRanges := make(timeRanges, len(s.oldTimeRanges), len(s.oldTimeRanges)+len(s.startedTransfers))
   189  	copy(timeRanges, s.oldTimeRanges)
   190  
   191  	// Extract time ranges of all transfers.
   192  	now := time.Now()
   193  	for i := range s.startedTransfers {
   194  		start, end := s.startedTransfers[i].TimeRange()
   195  		if end.IsZero() {
   196  			end = now
   197  		}
   198  		timeRanges = append(timeRanges, timeRange{start, end})
   199  	}
   200  
   201  	timeRanges.merge()
   202  	return s.oldDuration + timeRanges.total()
   203  }
   204  
   205  // eta returns the ETA of the current operation,
   206  // rounded to full seconds.
   207  // If the ETA cannot be determined 'ok' returns false.
   208  func eta(size, total int64, rate float64) (eta time.Duration, ok bool) {
   209  	if total <= 0 || size < 0 || rate <= 0 {
   210  		return 0, false
   211  	}
   212  	remaining := total - size
   213  	if remaining < 0 {
   214  		return 0, false
   215  	}
   216  	seconds := float64(remaining) / rate
   217  	return time.Second * time.Duration(seconds), true
   218  }
   219  
   220  // etaString returns the ETA of the current operation,
   221  // rounded to full seconds.
   222  // If the ETA cannot be determined it returns "-"
   223  func etaString(done, total int64, rate float64) string {
   224  	d, ok := eta(done, total, rate)
   225  	if !ok {
   226  		return "-"
   227  	}
   228  	return fs.Duration(d).ReadableString()
   229  }
   230  
   231  // percent returns a/b as a percentage rounded to the nearest integer
   232  // as a string
   233  //
   234  // if the percentage is invalid it returns "-"
   235  func percent(a int64, b int64) string {
   236  	if a < 0 || b <= 0 {
   237  		return "-"
   238  	}
   239  	return fmt.Sprintf("%d%%", int(float64(a)*100/float64(b)+0.5))
   240  }
   241  
   242  // String convert the StatsInfo to a string for printing
   243  func (s *StatsInfo) String() string {
   244  	// checking and transferring have their own locking so read
   245  	// here before lock to prevent deadlock on GetBytes
   246  	transferring, checking := s.transferring.count(), s.checking.count()
   247  	transferringBytesDone, transferringBytesTotal := s.transferring.progress(s)
   248  
   249  	s.mu.RLock()
   250  
   251  	dt := s.totalDuration()
   252  	dtSeconds := dt.Seconds()
   253  	dtSecondsOnly := dt.Truncate(time.Second/10) % time.Minute
   254  	speed := 0.0
   255  	if dt > 0 {
   256  		speed = float64(s.bytes) / dtSeconds
   257  	}
   258  
   259  	displaySpeed := speed
   260  	if fs.Config.DataRateUnit == "bits" {
   261  		displaySpeed *= 8
   262  	}
   263  
   264  	var (
   265  		totalChecks   = int64(s.checkQueue) + s.checks + int64(checking)
   266  		totalTransfer = int64(s.transferQueue) + s.transfers + int64(transferring)
   267  		// note that s.bytes already includes transferringBytesDone so
   268  		// we take it off here to avoid double counting
   269  		totalSize    = s.transferQueueSize + s.bytes + transferringBytesTotal - transferringBytesDone
   270  		currentSize  = s.bytes
   271  		buf          = &bytes.Buffer{}
   272  		xfrchkString = ""
   273  		dateString   = ""
   274  	)
   275  
   276  	if !fs.Config.StatsOneLine {
   277  		_, _ = fmt.Fprintf(buf, "\nTransferred:   	")
   278  	} else {
   279  		xfrchk := []string{}
   280  		if totalTransfer > 0 && s.transferQueue > 0 {
   281  			xfrchk = append(xfrchk, fmt.Sprintf("xfr#%d/%d", s.transfers, totalTransfer))
   282  		}
   283  		if totalChecks > 0 && s.checkQueue > 0 {
   284  			xfrchk = append(xfrchk, fmt.Sprintf("chk#%d/%d", s.checks, totalChecks))
   285  		}
   286  		if len(xfrchk) > 0 {
   287  			xfrchkString = fmt.Sprintf(" (%s)", strings.Join(xfrchk, ", "))
   288  		}
   289  		if fs.Config.StatsOneLineDate {
   290  			t := time.Now()
   291  			dateString = t.Format(fs.Config.StatsOneLineDateFormat) // Including the separator so people can customize it
   292  		}
   293  	}
   294  
   295  	_, _ = fmt.Fprintf(buf, "%s%10s / %s, %s, %s, ETA %s%s\n",
   296  		dateString,
   297  		fs.SizeSuffix(s.bytes),
   298  		fs.SizeSuffix(totalSize).Unit("Bytes"),
   299  		percent(s.bytes, totalSize),
   300  		fs.SizeSuffix(displaySpeed).Unit(strings.Title(fs.Config.DataRateUnit)+"/s"),
   301  		etaString(currentSize, totalSize, speed),
   302  		xfrchkString,
   303  	)
   304  
   305  	if !fs.Config.StatsOneLine {
   306  		errorDetails := ""
   307  		switch {
   308  		case s.fatalError:
   309  			errorDetails = " (fatal error encountered)"
   310  		case s.retryError:
   311  			errorDetails = " (retrying may help)"
   312  		case s.errors != 0:
   313  			errorDetails = " (no need to retry)"
   314  		}
   315  
   316  		// Add only non zero stats
   317  		if s.errors != 0 {
   318  			_, _ = fmt.Fprintf(buf, "Errors:        %10d%s\n",
   319  				s.errors, errorDetails)
   320  		}
   321  		if s.checks != 0 || totalChecks != 0 {
   322  			_, _ = fmt.Fprintf(buf, "Checks:        %10d / %d, %s\n",
   323  				s.checks, totalChecks, percent(s.checks, totalChecks))
   324  		}
   325  		if s.deletes != 0 {
   326  			_, _ = fmt.Fprintf(buf, "Deleted:       %10d\n", s.deletes)
   327  		}
   328  		if s.transfers != 0 || totalTransfer != 0 {
   329  			_, _ = fmt.Fprintf(buf, "Transferred:   %10d / %d, %s\n",
   330  				s.transfers, totalTransfer, percent(s.transfers, totalTransfer))
   331  		}
   332  		_, _ = fmt.Fprintf(buf, "Elapsed time:  %10ss\n", strings.TrimRight(dt.Truncate(time.Minute).String(), "0s")+fmt.Sprintf("%.1f", dtSecondsOnly.Seconds()))
   333  	}
   334  
   335  	// checking and transferring have their own locking so unlock
   336  	// here to prevent deadlock on GetBytes
   337  	s.mu.RUnlock()
   338  
   339  	// Add per transfer stats if required
   340  	if !fs.Config.StatsOneLine {
   341  		if !s.checking.empty() {
   342  			_, _ = fmt.Fprintf(buf, "Checking:\n%s\n", s.checking.String(s.inProgress, s.transferring))
   343  		}
   344  		if !s.transferring.empty() {
   345  			_, _ = fmt.Fprintf(buf, "Transferring:\n%s\n", s.transferring.String(s.inProgress, nil))
   346  		}
   347  	}
   348  
   349  	return buf.String()
   350  }
   351  
   352  // Transferred returns list of all completed transfers including checked and
   353  // failed ones.
   354  func (s *StatsInfo) Transferred() []TransferSnapshot {
   355  	ts := make([]TransferSnapshot, 0, len(s.startedTransfers))
   356  
   357  	for _, tr := range s.startedTransfers {
   358  		if tr.IsDone() {
   359  			ts = append(ts, tr.Snapshot())
   360  		}
   361  	}
   362  
   363  	return ts
   364  }
   365  
   366  // Log outputs the StatsInfo to the log
   367  func (s *StatsInfo) Log() {
   368  	fs.LogLevelPrintf(fs.Config.StatsLogLevel, nil, "%v\n", s)
   369  }
   370  
   371  // Bytes updates the stats for bytes bytes
   372  func (s *StatsInfo) Bytes(bytes int64) {
   373  	s.mu.Lock()
   374  	defer s.mu.Unlock()
   375  	s.bytes += bytes
   376  }
   377  
   378  // GetBytes returns the number of bytes transferred so far
   379  func (s *StatsInfo) GetBytes() int64 {
   380  	s.mu.RLock()
   381  	defer s.mu.RUnlock()
   382  	return s.bytes
   383  }
   384  
   385  // Errors updates the stats for errors
   386  func (s *StatsInfo) Errors(errors int64) {
   387  	s.mu.Lock()
   388  	defer s.mu.Unlock()
   389  	s.errors += errors
   390  }
   391  
   392  // GetErrors reads the number of errors
   393  func (s *StatsInfo) GetErrors() int64 {
   394  	s.mu.RLock()
   395  	defer s.mu.RUnlock()
   396  	return s.errors
   397  }
   398  
   399  // GetLastError returns the lastError
   400  func (s *StatsInfo) GetLastError() error {
   401  	s.mu.RLock()
   402  	defer s.mu.RUnlock()
   403  	return s.lastError
   404  }
   405  
   406  // GetChecks returns the number of checks
   407  func (s *StatsInfo) GetChecks() int64 {
   408  	s.mu.RLock()
   409  	defer s.mu.RUnlock()
   410  	return s.checks
   411  }
   412  
   413  // FatalError sets the fatalError flag
   414  func (s *StatsInfo) FatalError() {
   415  	s.mu.Lock()
   416  	defer s.mu.Unlock()
   417  	s.fatalError = true
   418  }
   419  
   420  // HadFatalError returns whether there has been at least one FatalError
   421  func (s *StatsInfo) HadFatalError() bool {
   422  	s.mu.RLock()
   423  	defer s.mu.RUnlock()
   424  	return s.fatalError
   425  }
   426  
   427  // RetryError sets the retryError flag
   428  func (s *StatsInfo) RetryError() {
   429  	s.mu.Lock()
   430  	defer s.mu.Unlock()
   431  	s.retryError = true
   432  }
   433  
   434  // HadRetryError returns whether there has been at least one non-NoRetryError
   435  func (s *StatsInfo) HadRetryError() bool {
   436  	s.mu.RLock()
   437  	defer s.mu.RUnlock()
   438  	return s.retryError
   439  }
   440  
   441  // Deletes updates the stats for deletes
   442  func (s *StatsInfo) Deletes(deletes int64) int64 {
   443  	s.mu.Lock()
   444  	defer s.mu.Unlock()
   445  	s.deletes += deletes
   446  	return s.deletes
   447  }
   448  
   449  // ResetCounters sets the counters (bytes, checks, errors, transfers, deletes) to 0 and resets lastError, fatalError and retryError
   450  func (s *StatsInfo) ResetCounters() {
   451  	s.mu.Lock()
   452  	defer s.mu.Unlock()
   453  	s.bytes = 0
   454  	s.errors = 0
   455  	s.lastError = nil
   456  	s.fatalError = false
   457  	s.retryError = false
   458  	s.retryAfter = time.Time{}
   459  	s.checks = 0
   460  	s.transfers = 0
   461  	s.deletes = 0
   462  	s.startedTransfers = nil
   463  	s.oldDuration = 0
   464  }
   465  
   466  // ResetErrors sets the errors count to 0 and resets lastError, fatalError and retryError
   467  func (s *StatsInfo) ResetErrors() {
   468  	s.mu.Lock()
   469  	defer s.mu.Unlock()
   470  	s.errors = 0
   471  	s.lastError = nil
   472  	s.fatalError = false
   473  	s.retryError = false
   474  	s.retryAfter = time.Time{}
   475  }
   476  
   477  // Errored returns whether there have been any errors
   478  func (s *StatsInfo) Errored() bool {
   479  	s.mu.RLock()
   480  	defer s.mu.RUnlock()
   481  	return s.errors != 0
   482  }
   483  
   484  // Error adds a single error into the stats, assigns lastError and eventually sets fatalError or retryError
   485  func (s *StatsInfo) Error(err error) error {
   486  	if err == nil || fserrors.IsCounted(err) {
   487  		return err
   488  	}
   489  	s.mu.Lock()
   490  	defer s.mu.Unlock()
   491  	s.errors++
   492  	s.lastError = err
   493  	err = fserrors.FsError(err)
   494  	fserrors.Count(err)
   495  	switch {
   496  	case fserrors.IsFatalError(err):
   497  		s.fatalError = true
   498  	case fserrors.IsRetryAfterError(err):
   499  		retryAfter := fserrors.RetryAfterErrorTime(err)
   500  		if s.retryAfter.IsZero() || retryAfter.Sub(s.retryAfter) > 0 {
   501  			s.retryAfter = retryAfter
   502  		}
   503  		s.retryError = true
   504  	case !fserrors.IsNoRetryError(err):
   505  		s.retryError = true
   506  	}
   507  	return err
   508  }
   509  
   510  // RetryAfter returns the time to retry after if it is set.  It will
   511  // be Zero if it isn't set.
   512  func (s *StatsInfo) RetryAfter() time.Time {
   513  	s.mu.Lock()
   514  	defer s.mu.Unlock()
   515  	return s.retryAfter
   516  }
   517  
   518  // NewCheckingTransfer adds a checking transfer to the stats, from the object.
   519  func (s *StatsInfo) NewCheckingTransfer(obj fs.Object) *Transfer {
   520  	s.checking.add(obj.Remote())
   521  	return newCheckingTransfer(s, obj)
   522  }
   523  
   524  // DoneChecking removes a check from the stats
   525  func (s *StatsInfo) DoneChecking(remote string) {
   526  	s.checking.del(remote)
   527  	s.mu.Lock()
   528  	s.checks++
   529  	s.mu.Unlock()
   530  }
   531  
   532  // GetTransfers reads the number of transfers
   533  func (s *StatsInfo) GetTransfers() int64 {
   534  	s.mu.RLock()
   535  	defer s.mu.RUnlock()
   536  	return s.transfers
   537  }
   538  
   539  // NewTransfer adds a transfer to the stats from the object.
   540  func (s *StatsInfo) NewTransfer(obj fs.Object) *Transfer {
   541  	s.transferring.add(obj.Remote())
   542  	return newTransfer(s, obj)
   543  }
   544  
   545  // NewTransferRemoteSize adds a transfer to the stats based on remote and size.
   546  func (s *StatsInfo) NewTransferRemoteSize(remote string, size int64) *Transfer {
   547  	s.transferring.add(remote)
   548  	return newTransferRemoteSize(s, remote, size, false)
   549  }
   550  
   551  // DoneTransferring removes a transfer from the stats
   552  //
   553  // if ok is true then it increments the transfers count
   554  func (s *StatsInfo) DoneTransferring(remote string, ok bool) {
   555  	s.transferring.del(remote)
   556  	if ok {
   557  		s.mu.Lock()
   558  		s.transfers++
   559  		s.mu.Unlock()
   560  	}
   561  }
   562  
   563  // SetCheckQueue sets the number of queued checks
   564  func (s *StatsInfo) SetCheckQueue(n int, size int64) {
   565  	s.mu.Lock()
   566  	s.checkQueue = n
   567  	s.checkQueueSize = size
   568  	s.mu.Unlock()
   569  }
   570  
   571  // SetTransferQueue sets the number of queued transfers
   572  func (s *StatsInfo) SetTransferQueue(n int, size int64) {
   573  	s.mu.Lock()
   574  	s.transferQueue = n
   575  	s.transferQueueSize = size
   576  	s.mu.Unlock()
   577  }
   578  
   579  // SetRenameQueue sets the number of queued transfers
   580  func (s *StatsInfo) SetRenameQueue(n int, size int64) {
   581  	s.mu.Lock()
   582  	s.renameQueue = n
   583  	s.renameQueueSize = size
   584  	s.mu.Unlock()
   585  }
   586  
   587  // AddTransfer adds reference to the started transfer.
   588  func (s *StatsInfo) AddTransfer(transfer *Transfer) {
   589  	s.mu.Lock()
   590  	s.startedTransfers = append(s.startedTransfers, transfer)
   591  	s.mu.Unlock()
   592  }
   593  
   594  // removeTransfer removes a reference to the started transfer in
   595  // position i.
   596  //
   597  // Must be called with the lock held
   598  func (s *StatsInfo) removeTransfer(transfer *Transfer, i int) {
   599  	now := time.Now()
   600  
   601  	// add finished transfer onto old time ranges
   602  	start, end := transfer.TimeRange()
   603  	if end.IsZero() {
   604  		end = now
   605  	}
   606  	s.oldTimeRanges = append(s.oldTimeRanges, timeRange{start, end})
   607  	s.oldTimeRanges.merge()
   608  
   609  	// remove the found entry
   610  	s.startedTransfers = append(s.startedTransfers[:i], s.startedTransfers[i+1:]...)
   611  
   612  	// Find youngest active transfer
   613  	oldestStart := now
   614  	for i := range s.startedTransfers {
   615  		start, _ := s.startedTransfers[i].TimeRange()
   616  		if start.Before(oldestStart) {
   617  			oldestStart = start
   618  		}
   619  	}
   620  
   621  	// remove old entries older than that
   622  	s.oldDuration += s.oldTimeRanges.cull(oldestStart)
   623  }
   624  
   625  // RemoveTransfer removes a reference to the started transfer.
   626  func (s *StatsInfo) RemoveTransfer(transfer *Transfer) {
   627  	s.mu.Lock()
   628  	for i, tr := range s.startedTransfers {
   629  		if tr == transfer {
   630  			s.removeTransfer(tr, i)
   631  			break
   632  		}
   633  	}
   634  	s.mu.Unlock()
   635  }
   636  
   637  // PruneTransfers makes sure there aren't too many old transfers by removing
   638  // single finished transfer.
   639  func (s *StatsInfo) PruneTransfers() {
   640  	if MaxCompletedTransfers < 0 {
   641  		return
   642  	}
   643  	s.mu.Lock()
   644  	// remove a transfer from the start if we are over quota
   645  	if len(s.startedTransfers) > MaxCompletedTransfers+fs.Config.Transfers {
   646  		for i, tr := range s.startedTransfers {
   647  			if tr.IsDone() {
   648  				s.removeTransfer(tr, i)
   649  				break
   650  			}
   651  		}
   652  	}
   653  	s.mu.Unlock()
   654  }