mirror of
https://github.com/syncthing/syncthing.git
synced 2024-11-16 10:28:49 -07:00
326 lines
6.6 KiB
Go
326 lines
6.6 KiB
Go
// 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/syncthing/syncthing/lib/logger"
|
|
)
|
|
|
|
const (
|
|
logThreshold = 100 * time.Millisecond
|
|
shortWait = 5 * time.Millisecond
|
|
longWait = 125 * time.Millisecond
|
|
)
|
|
|
|
var skipTimingTests = false
|
|
|
|
func init() {
|
|
// Check a few times that a short sleep does not in fact overrun the log
|
|
// threshold. If it does, the timer accuracy is crap or the host is
|
|
// overloaded and we can't reliably run the tests in here. In the normal
|
|
// case this takes just 25*5 = 125 ms.
|
|
for i := 0; i < 25; i++ {
|
|
t0 := time.Now()
|
|
time.Sleep(shortWait)
|
|
if time.Since(t0) > logThreshold {
|
|
skipTimingTests = true
|
|
return
|
|
}
|
|
}
|
|
}
|
|
|
|
func TestTypes(t *testing.T) {
|
|
debug = false
|
|
l.SetDebug("sync", 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
|
|
l.SetDebug("sync", 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
|
|
l.SetDebug("sync", false)
|
|
}
|
|
|
|
func TestMutex(t *testing.T) {
|
|
if skipTimingTests {
|
|
t.Skip("insufficient timer accuracy")
|
|
return
|
|
}
|
|
|
|
debug = true
|
|
l.SetDebug("sync", 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
|
|
l.SetDebug("sync", false)
|
|
}
|
|
|
|
func TestRWMutex(t *testing.T) {
|
|
if skipTimingTests {
|
|
t.Skip("insufficient timer accuracy")
|
|
return
|
|
}
|
|
|
|
debug = true
|
|
l.SetDebug("sync", 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()
|
|
_ = 1 // skip empty critical section check
|
|
mut.Unlock()
|
|
|
|
if len(messages) != 2 {
|
|
t.Errorf("Unexpected message count")
|
|
}
|
|
if !strings.Contains(messages[1], "RUnlockers while locking:\nat sync") || !strings.Contains(messages[1], "sync_test.go:") {
|
|
t.Error("Unexpected message")
|
|
}
|
|
|
|
// Testing multiple rlockers
|
|
mut.RLock()
|
|
mut.RLock()
|
|
mut.RLock()
|
|
_ = 1 // skip empty critical section check
|
|
mut.RUnlock()
|
|
mut.RUnlock()
|
|
mut.RUnlock()
|
|
|
|
debug = false
|
|
l.SetDebug("sync", false)
|
|
}
|
|
|
|
func TestWaitGroup(t *testing.T) {
|
|
if skipTimingTests {
|
|
t.Skip("insufficient timer accuracy")
|
|
return
|
|
}
|
|
|
|
debug = true
|
|
l.SetDebug("sync", 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
|
|
l.SetDebug("sync", false)
|
|
}
|
|
|
|
func TestTimeoutCond(t *testing.T) {
|
|
// WARNING this test relies heavily on threads not being stalled at particular points.
|
|
// As such, it's pretty unstable on the build server. It has been left in as it still
|
|
// exercises the deadlock detector, and one of the two things it tests is still functional.
|
|
// See the comments in runLocks
|
|
|
|
const (
|
|
// Low values to avoid being intrusive in continuous testing. Can be
|
|
// increased significantly for stress testing.
|
|
iterations = 100
|
|
routines = 10
|
|
|
|
timeMult = 2
|
|
)
|
|
|
|
c := NewTimeoutCond(NewMutex())
|
|
|
|
// Start a routine to periodically broadcast on the cond.
|
|
|
|
go func() {
|
|
d := time.Duration(routines) * timeMult * time.Millisecond / 2
|
|
t.Log("Broadcasting every", d)
|
|
for i := 0; i < iterations; i++ {
|
|
time.Sleep(d)
|
|
|
|
c.L.Lock()
|
|
c.Broadcast()
|
|
c.L.Unlock()
|
|
}
|
|
}()
|
|
|
|
// Start several routines that wait on it with different timeouts.
|
|
|
|
var results [routines][2]int
|
|
var wg sync.WaitGroup
|
|
for i := 0; i < routines; i++ {
|
|
i := i
|
|
wg.Add(1)
|
|
go func() {
|
|
d := time.Duration(i) * timeMult * time.Millisecond
|
|
t.Logf("Routine %d waits for %v\n", i, d)
|
|
succ, fail := runLocks(t, iterations, c, d)
|
|
results[i][0] = succ
|
|
results[i][1] = fail
|
|
wg.Done()
|
|
}()
|
|
}
|
|
|
|
wg.Wait()
|
|
|
|
// Print a table of routine number: successes, failures.
|
|
|
|
for i, v := range results {
|
|
t.Logf("%4d: %4d %4d\n", i, v[0], v[1])
|
|
}
|
|
}
|
|
|
|
func runLocks(t *testing.T, iterations int, c *TimeoutCond, d time.Duration) (succ, fail int) {
|
|
for i := 0; i < iterations; i++ {
|
|
c.L.Lock()
|
|
|
|
// The thread may be stalled, so we can't test the 'succeeded late' case reliably.
|
|
// Therefore make sure that we start t0 before starting the timeout, and only test
|
|
// the 'failed early' case.
|
|
|
|
t0 := time.Now()
|
|
w := c.SetupWait(d)
|
|
|
|
res := w.Wait()
|
|
waited := time.Since(t0)
|
|
|
|
// Allow 20% slide in either direction, and a five milliseconds of
|
|
// scheduling delay... In tweaking these it was clear that things
|
|
// worked like the should, so if this becomes a spurious failure
|
|
// kind of thing feel free to remove or give significantly more
|
|
// slack.
|
|
|
|
if !res && waited < d*8/10 {
|
|
t.Errorf("Wait failed early, %v < %v", waited, d)
|
|
}
|
|
if res && waited > d*11/10+5*time.Millisecond {
|
|
// Ideally this would be t.Errorf
|
|
t.Logf("WARNING: Wait succeeded late, %v > %v. This is probably a thread scheduling issue", waited, d)
|
|
}
|
|
|
|
w.Stop()
|
|
|
|
if res {
|
|
succ++
|
|
} else {
|
|
fail++
|
|
}
|
|
c.L.Unlock()
|
|
}
|
|
return
|
|
}
|