accounting: fix deadlock in stats printing

The deadlock was caused in transfermap.go by calling mu.RLock() in one
function then calling it again in a sub function. Normally this is
fine, however this leaves a window where mu.Lock() can be called. When
mu.Lock() is called it doesn't allow the second mu.RLock() and
deadlocks.

    Thead 1                    Thread 2
    String():mu.RLock()
                               del():mu.Lock()
    sortedSlice():mu.RLock()                     - DEADLOCK

Lesson learnt: don't try using locks recursively ever!

This patch fixes the problem by removing the second mu.RLock(). This
was done by factoring the code that was calling it into the
transfermap.go file so all the locking can be seen at once which was
ultimately the cause of the problem - the code which used the locks
was too far away from the rest of the code using the lock.

This problem was introduced in:

bfa5715017 fs/accounting: sort transfers by start time

Which hasn't been released in a stable version yet

fs/accounting/accounting.go

@@ -487,8 +487,8 @@ func (acc *Account) String() string {
 	)
 }
 
-// RemoteStats produces stats for this file
+// rcStats produces remote control stats for this file
-func (acc *Account) RemoteStats() (out rc.Params) {
+func (acc *Account) rcStats() (out rc.Params) {
 	out = make(rc.Params)
 	a, b := acc.progress()
 	out["bytes"] = a

fs/accounting/stats.go

@@ -72,27 +72,10 @@ func (s *StatsInfo) RemoteStats() (out rc.Params, err error) {
 	out["elapsedTime"] = time.Since(startTime).Seconds()
 	s.mu.RUnlock()
 	if !s.checking.empty() {
-		var c []string
+		out["checking"] = s.checking.remotes()
-		s.checking.mu.RLock()
-		defer s.checking.mu.RUnlock()
-		for _, tr := range s.checking.sortedSlice() {
-			c = append(c, tr.remote)
-		}
-		out["checking"] = c
 	}
 	if !s.transferring.empty() {
-		s.transferring.mu.RLock()
+		out["transferring"] = s.transferring.rcStats(s.inProgress)
-
-		var t []rc.Params
-		for _, tr := range s.transferring.sortedSlice() {
-			if acc := s.inProgress.get(tr.remote); acc != nil {
-				t = append(t, acc.RemoteStats())
-			} else {
-				t = append(t, s.transferRemoteStats(tr))
-			}
-		}
-		out["transferring"] = t
-		s.transferring.mu.RUnlock()
 	}
 	if s.errors > 0 {
 		out["lastError"] = s.lastError.Error()
@@ -111,13 +94,6 @@ func (s *StatsInfo) Speed() float64 {
 	return speed
 }
 
-func (s *StatsInfo) transferRemoteStats(tr *Transfer) rc.Params {
-	return rc.Params{
-		"name": tr.remote,
-		"size": tr.size,
-	}
-}
-
 // timeRange is a start and end time of a transfer
 type timeRange struct {
 	start time.Time

fs/accounting/transfer.go

@@ -8,6 +8,7 @@ import (
 	"time"
 
 	"github.com/rclone/rclone/fs"
+	"github.com/rclone/rclone/fs/rc"
 )
 
 // TransferSnapshot represents state of an account at point in time.
@@ -182,3 +183,11 @@ func (tr *Transfer) Snapshot() TransferSnapshot {
 		Group:       tr.stats.group,
 	}
 }
+
+// rcStats returns stats for the transfer suitable for the rc
+func (tr *Transfer) rcStats() rc.Params {
+	return rc.Params{
+		"name": tr.remote, // no locking needed to access thess
+		"size": tr.size,
+	}
+}

fs/accounting/transfermap.go

@@ -7,6 +7,7 @@ import (
 	"sync"
 
 	"github.com/rclone/rclone/fs"
+	"github.com/rclone/rclone/fs/rc"
 )
 
 // transferMap holds name to transfer map
@@ -63,10 +64,10 @@ func (tm *transferMap) count() int {
 	return len(tm.items)
 }
 
-// sortedSlice returns all transfers sorted by start time
+// _sortedSlice returns all transfers sorted by start time
-func (tm *transferMap) sortedSlice() []*Transfer {
+//
-	tm.mu.RLock()
+// Call with mu.Rlock held
-	defer tm.mu.RUnlock()
+func (tm *transferMap) _sortedSlice() []*Transfer {
 	s := make([]*Transfer, 0, len(tm.items))
 	for _, tr := range tm.items {
 		s = append(s, tr)
@@ -83,7 +84,7 @@ func (tm *transferMap) String(progress *inProgress, exclude *transferMap) string
 	tm.mu.RLock()
 	defer tm.mu.RUnlock()
 	strngs := make([]string, 0, len(tm.items))
-	for _, tr := range tm.sortedSlice() {
+	for _, tr := range tm._sortedSlice() {
 		if exclude != nil {
 			exclude.mu.RLock()
 			_, found := exclude.items[tr.remote]
@@ -122,3 +123,27 @@ func (tm *transferMap) progress(stats *StatsInfo) (totalBytes, totalSize int64)
 	}
 	return totalBytes, totalSize
 }
+
+// remotes returns a []string of the remote names for the transferMap
+func (tm *transferMap) remotes() (c []string) {
+	tm.mu.RLock()
+	defer tm.mu.RUnlock()
+	for _, tr := range tm._sortedSlice() {
+		c = append(c, tr.remote)
+	}
+	return c
+}
+
+// rcStats returns a []rc.Params of the stats for the transferMap
+func (tm *transferMap) rcStats(progress *inProgress) (t []rc.Params) {
+	tm.mu.RLock()
+	defer tm.mu.RUnlock()
+	for _, tr := range tm._sortedSlice() {
+		if acc := progress.get(tr.remote); acc != nil {
+			t = append(t, acc.rcStats())
+		} else {
+			t = append(t, tr.rcStats())
+		}
+	}
+	return t
+}