mv internal lib
This commit is contained in:
31
lib/sync/debug.go
Normal file
31
lib/sync/debug.go
Normal file
@@ -0,0 +1,31 @@
|
||||
// Copyright (C) 2015 The Syncthing Authors.
|
||||
//
|
||||
// This Source Code Form is subject to the terms of the Mozilla Public
|
||||
// License, v. 2.0. If a copy of the MPL was not distributed with this file,
|
||||
// You can obtain one at http://mozilla.org/MPL/2.0/.
|
||||
|
||||
package sync
|
||||
|
||||
import (
|
||||
"os"
|
||||
"strconv"
|
||||
"strings"
|
||||
"time"
|
||||
|
||||
"github.com/calmh/logger"
|
||||
)
|
||||
|
||||
var (
|
||||
debug = strings.Contains(os.Getenv("STTRACE"), "locks") || os.Getenv("STTRACE") == "all"
|
||||
threshold = time.Duration(100 * time.Millisecond)
|
||||
l = logger.DefaultLogger
|
||||
)
|
||||
|
||||
func init() {
|
||||
if n, err := strconv.Atoi(os.Getenv("STLOCKTHRESHOLD")); debug && err == nil {
|
||||
threshold = time.Duration(n) * time.Millisecond
|
||||
}
|
||||
if debug {
|
||||
l.Debugf("Enabling lock logging at %v threshold", threshold)
|
||||
}
|
||||
}
|
||||
141
lib/sync/sync.go
Normal file
141
lib/sync/sync.go
Normal file
@@ -0,0 +1,141 @@
|
||||
// Copyright (C) 2015 The Syncthing Authors.
|
||||
//
|
||||
// This Source Code Form is subject to the terms of the Mozilla Public
|
||||
// License, v. 2.0. If a copy of the MPL was not distributed with this file,
|
||||
// You can obtain one at http://mozilla.org/MPL/2.0/.
|
||||
|
||||
package sync
|
||||
|
||||
import (
|
||||
"fmt"
|
||||
"path/filepath"
|
||||
"runtime"
|
||||
"strings"
|
||||
"sync"
|
||||
"sync/atomic"
|
||||
"time"
|
||||
)
|
||||
|
||||
type Mutex interface {
|
||||
Lock()
|
||||
Unlock()
|
||||
}
|
||||
|
||||
type RWMutex interface {
|
||||
Mutex
|
||||
RLock()
|
||||
RUnlock()
|
||||
}
|
||||
|
||||
type WaitGroup interface {
|
||||
Add(int)
|
||||
Done()
|
||||
Wait()
|
||||
}
|
||||
|
||||
func NewMutex() Mutex {
|
||||
if debug {
|
||||
return &loggedMutex{}
|
||||
}
|
||||
return &sync.Mutex{}
|
||||
}
|
||||
|
||||
func NewRWMutex() RWMutex {
|
||||
if debug {
|
||||
return &loggedRWMutex{
|
||||
unlockers: make([]string, 0),
|
||||
}
|
||||
}
|
||||
return &sync.RWMutex{}
|
||||
}
|
||||
|
||||
func NewWaitGroup() WaitGroup {
|
||||
if debug {
|
||||
return &loggedWaitGroup{}
|
||||
}
|
||||
return &sync.WaitGroup{}
|
||||
}
|
||||
|
||||
type loggedMutex struct {
|
||||
sync.Mutex
|
||||
start time.Time
|
||||
lockedAt string
|
||||
}
|
||||
|
||||
func (m *loggedMutex) Lock() {
|
||||
m.Mutex.Lock()
|
||||
m.start = time.Now()
|
||||
m.lockedAt = getCaller()
|
||||
}
|
||||
|
||||
func (m *loggedMutex) Unlock() {
|
||||
duration := time.Now().Sub(m.start)
|
||||
if duration >= threshold {
|
||||
l.Debugf("Mutex held for %v. Locked at %s unlocked at %s", duration, m.lockedAt, getCaller())
|
||||
}
|
||||
m.Mutex.Unlock()
|
||||
}
|
||||
|
||||
type loggedRWMutex struct {
|
||||
sync.RWMutex
|
||||
start time.Time
|
||||
lockedAt string
|
||||
|
||||
logUnlockers uint32
|
||||
|
||||
unlockers []string
|
||||
unlockersMut sync.Mutex
|
||||
}
|
||||
|
||||
func (m *loggedRWMutex) Lock() {
|
||||
start := time.Now()
|
||||
|
||||
atomic.StoreUint32(&m.logUnlockers, 1)
|
||||
m.RWMutex.Lock()
|
||||
m.logUnlockers = 0
|
||||
|
||||
m.start = time.Now()
|
||||
duration := m.start.Sub(start)
|
||||
|
||||
m.lockedAt = getCaller()
|
||||
if duration > threshold {
|
||||
l.Debugf("RWMutex took %v to lock. Locked at %s. RUnlockers while locking: %s", duration, m.lockedAt, strings.Join(m.unlockers, ", "))
|
||||
}
|
||||
m.unlockers = m.unlockers[0:]
|
||||
}
|
||||
|
||||
func (m *loggedRWMutex) Unlock() {
|
||||
duration := time.Now().Sub(m.start)
|
||||
if duration >= threshold {
|
||||
l.Debugf("RWMutex held for %v. Locked at %s: unlocked at %s", duration, m.lockedAt, getCaller())
|
||||
}
|
||||
m.RWMutex.Unlock()
|
||||
}
|
||||
|
||||
func (m *loggedRWMutex) RUnlock() {
|
||||
if atomic.LoadUint32(&m.logUnlockers) == 1 {
|
||||
m.unlockersMut.Lock()
|
||||
m.unlockers = append(m.unlockers, getCaller())
|
||||
m.unlockersMut.Unlock()
|
||||
}
|
||||
m.RWMutex.RUnlock()
|
||||
}
|
||||
|
||||
type loggedWaitGroup struct {
|
||||
sync.WaitGroup
|
||||
}
|
||||
|
||||
func (wg *loggedWaitGroup) Wait() {
|
||||
start := time.Now()
|
||||
wg.WaitGroup.Wait()
|
||||
duration := time.Now().Sub(start)
|
||||
if duration >= threshold {
|
||||
l.Debugf("WaitGroup took %v at %s", duration, getCaller())
|
||||
}
|
||||
}
|
||||
|
||||
func getCaller() string {
|
||||
_, file, line, _ := runtime.Caller(2)
|
||||
file = filepath.Join(filepath.Base(filepath.Dir(file)), filepath.Base(file))
|
||||
return fmt.Sprintf("%s:%d", file, line)
|
||||
}
|
||||
185
lib/sync/sync_test.go
Normal file
185
lib/sync/sync_test.go
Normal file
@@ -0,0 +1,185 @@
|
||||
// Copyright (C) 2015 The Syncthing Authors.
|
||||
//
|
||||
// This Source Code Form is subject to the terms of the Mozilla Public
|
||||
// License, v. 2.0. If a copy of the MPL was not distributed with this file,
|
||||
// You can obtain one at http://mozilla.org/MPL/2.0/.
|
||||
|
||||
package sync
|
||||
|
||||
import (
|
||||
"strings"
|
||||
"sync"
|
||||
"testing"
|
||||
"time"
|
||||
|
||||
"github.com/calmh/logger"
|
||||
)
|
||||
|
||||
const (
|
||||
logThreshold = 100 * time.Millisecond
|
||||
shortWait = 5 * time.Millisecond
|
||||
longWait = 125 * time.Millisecond
|
||||
)
|
||||
|
||||
func TestTypes(t *testing.T) {
|
||||
debug = false
|
||||
|
||||
if _, ok := NewMutex().(*sync.Mutex); !ok {
|
||||
t.Error("Wrong type")
|
||||
}
|
||||
|
||||
if _, ok := NewRWMutex().(*sync.RWMutex); !ok {
|
||||
t.Error("Wrong type")
|
||||
}
|
||||
|
||||
if _, ok := NewWaitGroup().(*sync.WaitGroup); !ok {
|
||||
t.Error("Wrong type")
|
||||
}
|
||||
|
||||
debug = true
|
||||
|
||||
if _, ok := NewMutex().(*loggedMutex); !ok {
|
||||
t.Error("Wrong type")
|
||||
}
|
||||
|
||||
if _, ok := NewRWMutex().(*loggedRWMutex); !ok {
|
||||
t.Error("Wrong type")
|
||||
}
|
||||
|
||||
if _, ok := NewWaitGroup().(*loggedWaitGroup); !ok {
|
||||
t.Error("Wrong type")
|
||||
}
|
||||
|
||||
debug = false
|
||||
}
|
||||
|
||||
func TestMutex(t *testing.T) {
|
||||
debug = true
|
||||
threshold = logThreshold
|
||||
|
||||
msgmut := sync.Mutex{}
|
||||
var messages []string
|
||||
|
||||
l.AddHandler(logger.LevelDebug, func(_ logger.LogLevel, message string) {
|
||||
msgmut.Lock()
|
||||
messages = append(messages, message)
|
||||
msgmut.Unlock()
|
||||
})
|
||||
|
||||
mut := NewMutex()
|
||||
mut.Lock()
|
||||
time.Sleep(shortWait)
|
||||
mut.Unlock()
|
||||
|
||||
if len(messages) > 0 {
|
||||
t.Errorf("Unexpected message count")
|
||||
}
|
||||
|
||||
mut.Lock()
|
||||
time.Sleep(longWait)
|
||||
mut.Unlock()
|
||||
|
||||
if len(messages) != 1 {
|
||||
t.Errorf("Unexpected message count")
|
||||
}
|
||||
|
||||
debug = false
|
||||
}
|
||||
|
||||
func TestRWMutex(t *testing.T) {
|
||||
debug = true
|
||||
threshold = logThreshold
|
||||
|
||||
msgmut := sync.Mutex{}
|
||||
var messages []string
|
||||
|
||||
l.AddHandler(logger.LevelDebug, func(_ logger.LogLevel, message string) {
|
||||
msgmut.Lock()
|
||||
messages = append(messages, message)
|
||||
msgmut.Unlock()
|
||||
})
|
||||
|
||||
mut := NewRWMutex()
|
||||
mut.Lock()
|
||||
time.Sleep(shortWait)
|
||||
mut.Unlock()
|
||||
|
||||
if len(messages) > 0 {
|
||||
t.Errorf("Unexpected message count")
|
||||
}
|
||||
|
||||
mut.Lock()
|
||||
time.Sleep(longWait)
|
||||
mut.Unlock()
|
||||
|
||||
if len(messages) != 1 {
|
||||
t.Errorf("Unexpected message count")
|
||||
}
|
||||
|
||||
// Testing rlocker logging
|
||||
mut.RLock()
|
||||
go func() {
|
||||
time.Sleep(longWait)
|
||||
mut.RUnlock()
|
||||
}()
|
||||
|
||||
mut.Lock()
|
||||
mut.Unlock()
|
||||
|
||||
if len(messages) != 2 {
|
||||
t.Errorf("Unexpected message count")
|
||||
}
|
||||
if !strings.Contains(messages[1], "RUnlockers while locking: sync") || !strings.Contains(messages[1], "sync_test.go:") {
|
||||
t.Error("Unexpected message")
|
||||
}
|
||||
|
||||
// Testing multiple rlockers
|
||||
mut.RLock()
|
||||
mut.RLock()
|
||||
mut.RLock()
|
||||
mut.RUnlock()
|
||||
mut.RUnlock()
|
||||
mut.RUnlock()
|
||||
|
||||
debug = false
|
||||
}
|
||||
|
||||
func TestWaitGroup(t *testing.T) {
|
||||
debug = true
|
||||
threshold = logThreshold
|
||||
|
||||
msgmut := sync.Mutex{}
|
||||
var messages []string
|
||||
|
||||
l.AddHandler(logger.LevelDebug, func(_ logger.LogLevel, message string) {
|
||||
msgmut.Lock()
|
||||
messages = append(messages, message)
|
||||
msgmut.Unlock()
|
||||
})
|
||||
|
||||
wg := NewWaitGroup()
|
||||
wg.Add(1)
|
||||
go func() {
|
||||
time.Sleep(shortWait)
|
||||
wg.Done()
|
||||
}()
|
||||
wg.Wait()
|
||||
|
||||
if len(messages) > 0 {
|
||||
t.Errorf("Unexpected message count")
|
||||
}
|
||||
|
||||
wg = NewWaitGroup()
|
||||
wg.Add(1)
|
||||
go func() {
|
||||
time.Sleep(longWait)
|
||||
wg.Done()
|
||||
}()
|
||||
wg.Wait()
|
||||
|
||||
if len(messages) != 1 {
|
||||
t.Errorf("Unexpected message count")
|
||||
}
|
||||
|
||||
debug = false
|
||||
}
|
||||
Reference in New Issue
Block a user