diff --git a/lib/model/model.go b/lib/model/model.go index fec754de8..ff098b506 100644 --- a/lib/model/model.go +++ b/lib/model/model.go @@ -173,8 +173,8 @@ func NewModel(cfg *config.Wrapper, id protocol.DeviceID, deviceName, clientName, // period. func (m *Model) StartDeadlockDetector(timeout time.Duration) { l.Infof("Starting deadlock detector with %v timeout", timeout) - deadlockDetect(m.fmut, timeout) - deadlockDetect(m.pmut, timeout) + deadlockDetect(m.fmut, timeout, "fmut") + deadlockDetect(m.pmut, timeout, "pmut") } // StartFolder constructs the folder service and starts it. diff --git a/lib/model/util.go b/lib/model/util.go index a7648eacf..46386ae0f 100644 --- a/lib/model/util.go +++ b/lib/model/util.go @@ -7,11 +7,16 @@ package model import ( + "fmt" "sync" "time" ) -func deadlockDetect(mut sync.Locker, timeout time.Duration) { +type Holder interface { + Holder() (string, int) +} + +func deadlockDetect(mut sync.Locker, timeout time.Duration, name string) { go func() { for { time.Sleep(timeout / 4) @@ -29,7 +34,12 @@ func deadlockDetect(mut sync.Locker, timeout time.Duration) { }() if r := <-ok; !r { - panic("deadlock detected") + msg := fmt.Sprintf("deadlock detected at %s", name) + if hmut, ok := mut.(Holder); ok { + holder, goid := hmut.Holder() + msg = fmt.Sprintf("deadlock detected at %s, current holder: %s at routine %d", name, holder, goid) + } + panic(msg) } } }() diff --git a/lib/sync/sync.go b/lib/sync/sync.go index aeb0e30f5..89a042bd4 100644 --- a/lib/sync/sync.go +++ b/lib/sync/sync.go @@ -10,6 +10,7 @@ import ( "fmt" "path/filepath" "runtime" + "strconv" "strings" "sync" "sync/atomic" @@ -60,12 +61,14 @@ type loggedMutex struct { sync.Mutex start time.Time lockedAt string + goid int } func (m *loggedMutex) Lock() { m.Mutex.Lock() m.start = time.Now() m.lockedAt = getCaller() + m.goid = goid() } func (m *loggedMutex) Unlock() { @@ -76,10 +79,15 @@ func (m *loggedMutex) Unlock() { m.Mutex.Unlock() } +func (m *loggedMutex) Holder() (string, int) { + return m.lockedAt, m.goid +} + type loggedRWMutex struct { sync.RWMutex start time.Time lockedAt string + goid int logUnlockers uint32 @@ -98,6 +106,7 @@ func (m *loggedRWMutex) Lock() { duration := m.start.Sub(start) m.lockedAt = getCaller() + m.goid = goid() if duration > threshold { l.Debugf("RWMutex took %v to lock. Locked at %s. RUnlockers while locking: %s", duration, m.lockedAt, strings.Join(m.unlockers, ", ")) } @@ -139,3 +148,14 @@ func getCaller() string { file = filepath.Join(filepath.Base(filepath.Dir(file)), filepath.Base(file)) return fmt.Sprintf("%s:%d", file, line) } + +func goid() int { + var buf [64]byte + n := runtime.Stack(buf[:], false) + idField := strings.Fields(strings.TrimPrefix(string(buf[:n]), "goroutine "))[0] + id, err := strconv.Atoi(idField) + if err != nil { + return -1 + } + return id +}