From f5439ddc54ae63f55ce9f23a743c18fc9d7dbd4a Mon Sep 17 00:00:00 2001 From: Nick Craig-Wood Date: Wed, 5 Aug 2020 16:59:44 +0100 Subject: [PATCH] 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: bfa57150179f512f fs/accounting: sort transfers by start time Which hasn't been released in a stable version yet --- fs/accounting/accounting.go | 4 ++-- fs/accounting/stats.go | 28 ++-------------------------- fs/accounting/transfer.go | 9 +++++++++ fs/accounting/transfermap.go | 35 ++++++++++++++++++++++++++++++----- 4 files changed, 43 insertions(+), 33 deletions(-) diff --git a/fs/accounting/accounting.go b/fs/accounting/accounting.go index eeef4715a..83745adb2 100644 --- a/fs/accounting/accounting.go +++ b/fs/accounting/accounting.go @@ -487,8 +487,8 @@ func (acc *Account) String() string { ) } -// RemoteStats produces stats for this file -func (acc *Account) RemoteStats() (out rc.Params) { +// rcStats produces remote control stats for this file +func (acc *Account) rcStats() (out rc.Params) { out = make(rc.Params) a, b := acc.progress() out["bytes"] = a diff --git a/fs/accounting/stats.go b/fs/accounting/stats.go index 84eaafc63..357dced2c 100644 --- a/fs/accounting/stats.go +++ b/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 - s.checking.mu.RLock() - defer s.checking.mu.RUnlock() - for _, tr := range s.checking.sortedSlice() { - c = append(c, tr.remote) - } - out["checking"] = c + out["checking"] = s.checking.remotes() } if !s.transferring.empty() { - s.transferring.mu.RLock() - - 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() + out["transferring"] = s.transferring.rcStats(s.inProgress) } 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 diff --git a/fs/accounting/transfer.go b/fs/accounting/transfer.go index 8365a4a0a..e51d97c2d 100644 --- a/fs/accounting/transfer.go +++ b/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, + } +} diff --git a/fs/accounting/transfermap.go b/fs/accounting/transfermap.go index c391313db..ce145ae38 100644 --- a/fs/accounting/transfermap.go +++ b/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 -func (tm *transferMap) sortedSlice() []*Transfer { - tm.mu.RLock() - defer tm.mu.RUnlock() +// _sortedSlice returns all transfers sorted by start time +// +// Call with mu.Rlock held +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 +}