2014-11-16 21:13:20 +01:00
|
|
|
// Copyright (C) 2014 The Syncthing Authors.
|
2014-09-29 21:43:32 +02:00
|
|
|
//
|
2015-03-07 21:36:35 +01:00
|
|
|
// 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/.
|
2014-07-25 14:50:14 +02:00
|
|
|
|
2016-08-08 20:09:40 +02:00
|
|
|
package events
|
2014-07-13 21:07:24 +02:00
|
|
|
|
|
|
|
import (
|
|
|
|
"fmt"
|
|
|
|
"testing"
|
|
|
|
"time"
|
|
|
|
)
|
|
|
|
|
2015-08-24 09:38:39 +02:00
|
|
|
const timeout = 100 * time.Millisecond
|
2014-07-13 21:07:24 +02:00
|
|
|
|
2016-08-08 20:09:40 +02:00
|
|
|
func init() {
|
|
|
|
runningTests = true
|
|
|
|
}
|
|
|
|
|
2014-07-13 21:07:24 +02:00
|
|
|
func TestNewLogger(t *testing.T) {
|
2016-08-08 20:09:40 +02:00
|
|
|
l := NewLogger()
|
2014-07-13 21:07:24 +02:00
|
|
|
if l == nil {
|
|
|
|
t.Fatal("Unexpected nil Logger")
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
func TestSubscriber(t *testing.T) {
|
2016-08-08 20:09:40 +02:00
|
|
|
l := NewLogger()
|
2014-07-13 21:07:24 +02:00
|
|
|
s := l.Subscribe(0)
|
2015-08-24 09:38:39 +02:00
|
|
|
defer l.Unsubscribe(s)
|
2014-07-13 21:07:24 +02:00
|
|
|
if s == nil {
|
|
|
|
t.Fatal("Unexpected nil Subscription")
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
func TestTimeout(t *testing.T) {
|
2016-08-08 20:09:40 +02:00
|
|
|
l := NewLogger()
|
2014-07-13 21:07:24 +02:00
|
|
|
s := l.Subscribe(0)
|
2015-08-24 09:38:39 +02:00
|
|
|
defer l.Unsubscribe(s)
|
2014-07-13 21:07:24 +02:00
|
|
|
_, err := s.Poll(timeout)
|
2016-08-08 20:09:40 +02:00
|
|
|
if err != ErrTimeout {
|
2014-07-13 21:07:24 +02:00
|
|
|
t.Fatal("Unexpected non-Timeout error:", err)
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
func TestEventBeforeSubscribe(t *testing.T) {
|
2016-08-08 20:09:40 +02:00
|
|
|
l := NewLogger()
|
2014-07-13 21:07:24 +02:00
|
|
|
|
2016-08-08 20:09:40 +02:00
|
|
|
l.Log(DeviceConnected, "foo")
|
2014-07-13 21:07:24 +02:00
|
|
|
s := l.Subscribe(0)
|
2015-08-24 09:38:39 +02:00
|
|
|
defer l.Unsubscribe(s)
|
2014-07-13 21:07:24 +02:00
|
|
|
|
|
|
|
_, err := s.Poll(timeout)
|
2016-08-08 20:09:40 +02:00
|
|
|
if err != ErrTimeout {
|
2014-07-13 21:07:24 +02:00
|
|
|
t.Fatal("Unexpected non-Timeout error:", err)
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
func TestEventAfterSubscribe(t *testing.T) {
|
2016-08-08 20:09:40 +02:00
|
|
|
l := NewLogger()
|
2014-07-13 21:07:24 +02:00
|
|
|
|
2016-08-08 20:09:40 +02:00
|
|
|
s := l.Subscribe(AllEvents)
|
2015-08-24 09:38:39 +02:00
|
|
|
defer l.Unsubscribe(s)
|
2016-08-08 20:09:40 +02:00
|
|
|
l.Log(DeviceConnected, "foo")
|
2014-07-13 21:07:24 +02:00
|
|
|
|
|
|
|
ev, err := s.Poll(timeout)
|
|
|
|
|
|
|
|
if err != nil {
|
|
|
|
t.Fatal("Unexpected error:", err)
|
|
|
|
}
|
2016-08-08 20:09:40 +02:00
|
|
|
if ev.Type != DeviceConnected {
|
2014-07-13 21:07:24 +02:00
|
|
|
t.Error("Incorrect event type", ev.Type)
|
|
|
|
}
|
|
|
|
switch v := ev.Data.(type) {
|
|
|
|
case string:
|
|
|
|
if v != "foo" {
|
|
|
|
t.Error("Incorrect Data string", v)
|
|
|
|
}
|
|
|
|
default:
|
|
|
|
t.Errorf("Incorrect Data type %#v", v)
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
func TestEventAfterSubscribeIgnoreMask(t *testing.T) {
|
2016-08-08 20:09:40 +02:00
|
|
|
l := NewLogger()
|
2014-07-13 21:07:24 +02:00
|
|
|
|
2016-08-08 20:09:40 +02:00
|
|
|
s := l.Subscribe(DeviceDisconnected)
|
2015-08-24 09:38:39 +02:00
|
|
|
defer l.Unsubscribe(s)
|
2016-08-08 20:09:40 +02:00
|
|
|
l.Log(DeviceConnected, "foo")
|
2014-07-13 21:07:24 +02:00
|
|
|
|
|
|
|
_, err := s.Poll(timeout)
|
2016-08-08 20:09:40 +02:00
|
|
|
if err != ErrTimeout {
|
2014-07-13 21:07:24 +02:00
|
|
|
t.Fatal("Unexpected non-Timeout error:", err)
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
func TestBufferOverflow(t *testing.T) {
|
2016-08-08 20:09:40 +02:00
|
|
|
l := NewLogger()
|
2014-07-13 21:07:24 +02:00
|
|
|
|
2016-08-08 20:09:40 +02:00
|
|
|
s := l.Subscribe(AllEvents)
|
2015-08-24 09:38:39 +02:00
|
|
|
defer l.Unsubscribe(s)
|
2014-07-13 21:07:24 +02:00
|
|
|
|
|
|
|
t0 := time.Now()
|
2016-08-08 20:09:40 +02:00
|
|
|
for i := 0; i < BufferSize*2; i++ {
|
|
|
|
l.Log(DeviceConnected, "foo")
|
2014-07-13 21:07:24 +02:00
|
|
|
}
|
|
|
|
if time.Since(t0) > timeout {
|
|
|
|
t.Fatalf("Logging took too long")
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
func TestUnsubscribe(t *testing.T) {
|
2016-08-08 20:09:40 +02:00
|
|
|
l := NewLogger()
|
2014-07-13 21:07:24 +02:00
|
|
|
|
2016-08-08 20:09:40 +02:00
|
|
|
s := l.Subscribe(AllEvents)
|
|
|
|
l.Log(DeviceConnected, "foo")
|
2014-07-13 21:07:24 +02:00
|
|
|
|
|
|
|
_, err := s.Poll(timeout)
|
|
|
|
if err != nil {
|
|
|
|
t.Fatal("Unexpected error:", err)
|
|
|
|
}
|
|
|
|
|
|
|
|
l.Unsubscribe(s)
|
2016-08-08 20:09:40 +02:00
|
|
|
l.Log(DeviceConnected, "foo")
|
2014-07-13 21:07:24 +02:00
|
|
|
|
|
|
|
_, err = s.Poll(timeout)
|
2016-08-08 20:09:40 +02:00
|
|
|
if err != ErrClosed {
|
2014-07-13 21:07:24 +02:00
|
|
|
t.Fatal("Unexpected non-Closed error:", err)
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2016-06-27 23:18:58 +02:00
|
|
|
func TestGlobalIDs(t *testing.T) {
|
2016-08-08 20:09:40 +02:00
|
|
|
l := NewLogger()
|
2014-07-13 21:07:24 +02:00
|
|
|
|
2016-08-08 20:09:40 +02:00
|
|
|
s := l.Subscribe(AllEvents)
|
2015-08-24 09:38:39 +02:00
|
|
|
defer l.Unsubscribe(s)
|
2016-08-08 20:09:40 +02:00
|
|
|
l.Log(DeviceConnected, "foo")
|
|
|
|
_ = l.Subscribe(AllEvents)
|
|
|
|
l.Log(DeviceConnected, "bar")
|
2014-07-13 21:07:24 +02:00
|
|
|
|
|
|
|
ev, err := s.Poll(timeout)
|
|
|
|
if err != nil {
|
|
|
|
t.Fatal("Unexpected error:", err)
|
|
|
|
}
|
|
|
|
if ev.Data.(string) != "foo" {
|
|
|
|
t.Fatal("Incorrect event:", ev)
|
|
|
|
}
|
2016-06-27 23:18:58 +02:00
|
|
|
id := ev.GlobalID
|
2014-07-13 21:07:24 +02:00
|
|
|
|
|
|
|
ev, err = s.Poll(timeout)
|
|
|
|
if err != nil {
|
|
|
|
t.Fatal("Unexpected error:", err)
|
|
|
|
}
|
|
|
|
if ev.Data.(string) != "bar" {
|
|
|
|
t.Fatal("Incorrect event:", ev)
|
|
|
|
}
|
2016-06-27 23:18:58 +02:00
|
|
|
if ev.GlobalID != id+1 {
|
|
|
|
t.Fatalf("ID not incremented (%d != %d)", ev.GlobalID, id+1)
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
func TestSubscriptionIDs(t *testing.T) {
|
2016-08-08 20:09:40 +02:00
|
|
|
l := NewLogger()
|
2016-06-27 23:18:58 +02:00
|
|
|
|
2016-08-08 20:09:40 +02:00
|
|
|
s := l.Subscribe(DeviceConnected)
|
2016-06-27 23:18:58 +02:00
|
|
|
defer l.Unsubscribe(s)
|
|
|
|
|
2016-08-08 20:09:40 +02:00
|
|
|
l.Log(DeviceDisconnected, "a")
|
|
|
|
l.Log(DeviceConnected, "b")
|
|
|
|
l.Log(DeviceConnected, "c")
|
|
|
|
l.Log(DeviceDisconnected, "d")
|
2016-06-27 23:18:58 +02:00
|
|
|
|
|
|
|
ev, err := s.Poll(timeout)
|
|
|
|
if err != nil {
|
|
|
|
t.Fatal("Unexpected error:", err)
|
|
|
|
}
|
|
|
|
|
|
|
|
if ev.GlobalID != 2 {
|
|
|
|
t.Fatal("Incorrect GlobalID:", ev.GlobalID)
|
|
|
|
}
|
|
|
|
if ev.SubscriptionID != 1 {
|
|
|
|
t.Fatal("Incorrect SubscriptionID:", ev.SubscriptionID)
|
|
|
|
}
|
|
|
|
|
|
|
|
ev, err = s.Poll(timeout)
|
|
|
|
if err != nil {
|
|
|
|
t.Fatal("Unexpected error:", err)
|
|
|
|
}
|
|
|
|
if ev.GlobalID != 3 {
|
|
|
|
t.Fatal("Incorrect GlobalID:", ev.GlobalID)
|
|
|
|
}
|
|
|
|
if ev.SubscriptionID != 2 {
|
|
|
|
t.Fatal("Incorrect SubscriptionID:", ev.SubscriptionID)
|
|
|
|
}
|
|
|
|
|
|
|
|
ev, err = s.Poll(timeout)
|
2016-08-08 20:09:40 +02:00
|
|
|
if err != ErrTimeout {
|
2016-06-27 23:18:58 +02:00
|
|
|
t.Fatal("Unexpected error:", err)
|
2014-07-13 21:07:24 +02:00
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
func TestBufferedSub(t *testing.T) {
|
2016-08-08 20:09:40 +02:00
|
|
|
l := NewLogger()
|
2014-07-13 21:07:24 +02:00
|
|
|
|
2016-08-08 20:09:40 +02:00
|
|
|
s := l.Subscribe(AllEvents)
|
2015-08-24 09:38:39 +02:00
|
|
|
defer l.Unsubscribe(s)
|
2016-08-08 20:09:40 +02:00
|
|
|
bs := NewBufferedSubscription(s, 10*BufferSize)
|
2014-07-13 21:07:24 +02:00
|
|
|
|
|
|
|
go func() {
|
2016-08-08 20:09:40 +02:00
|
|
|
for i := 0; i < 10*BufferSize; i++ {
|
|
|
|
l.Log(DeviceConnected, fmt.Sprintf("event-%d", i))
|
2014-07-13 21:07:24 +02:00
|
|
|
if i%30 == 0 {
|
|
|
|
// Give the buffer routine time to pick up the events
|
|
|
|
time.Sleep(20 * time.Millisecond)
|
|
|
|
}
|
|
|
|
}
|
|
|
|
}()
|
|
|
|
|
|
|
|
recv := 0
|
2016-08-08 20:09:40 +02:00
|
|
|
for recv < 10*BufferSize {
|
2017-01-31 13:04:29 +01:00
|
|
|
evs := bs.Since(recv, nil, time.Minute)
|
2014-07-13 21:07:24 +02:00
|
|
|
for _, ev := range evs {
|
2016-06-27 23:18:58 +02:00
|
|
|
if ev.GlobalID != recv+1 {
|
|
|
|
t.Fatalf("Incorrect ID; %d != %d", ev.GlobalID, recv+1)
|
2014-07-13 21:07:24 +02:00
|
|
|
}
|
2016-06-27 23:18:58 +02:00
|
|
|
recv = ev.GlobalID
|
2014-07-13 21:07:24 +02:00
|
|
|
}
|
|
|
|
}
|
2016-06-27 10:26:43 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
func BenchmarkBufferedSub(b *testing.B) {
|
2016-08-08 20:09:40 +02:00
|
|
|
l := NewLogger()
|
2016-06-27 10:26:43 +02:00
|
|
|
|
2016-08-08 20:09:40 +02:00
|
|
|
s := l.Subscribe(AllEvents)
|
2016-06-27 10:26:43 +02:00
|
|
|
defer l.Unsubscribe(s)
|
2016-08-08 20:09:40 +02:00
|
|
|
bufferSize := BufferSize
|
|
|
|
bs := NewBufferedSubscription(s, bufferSize)
|
2016-06-27 10:26:43 +02:00
|
|
|
|
|
|
|
// The coord channel paces the sender according to the receiver,
|
|
|
|
// ensuring that no events are dropped. The benchmark measures sending +
|
|
|
|
// receiving + synchronization overhead.
|
|
|
|
|
|
|
|
coord := make(chan struct{}, bufferSize)
|
|
|
|
for i := 0; i < bufferSize-1; i++ {
|
|
|
|
coord <- struct{}{}
|
|
|
|
}
|
|
|
|
|
|
|
|
// Receive the events
|
2016-12-18 19:57:41 +01:00
|
|
|
done := make(chan error)
|
2016-06-27 10:26:43 +02:00
|
|
|
go func() {
|
|
|
|
recv := 0
|
2016-08-08 20:09:40 +02:00
|
|
|
var evs []Event
|
2016-06-27 10:26:43 +02:00
|
|
|
for i := 0; i < b.N; {
|
2017-01-31 13:04:29 +01:00
|
|
|
evs = bs.Since(recv, evs[:0], time.Minute)
|
2016-06-27 10:26:43 +02:00
|
|
|
for _, ev := range evs {
|
2016-06-27 23:18:58 +02:00
|
|
|
if ev.GlobalID != recv+1 {
|
2016-12-18 19:57:41 +01:00
|
|
|
done <- fmt.Errorf("skipped event %v %v", ev.GlobalID, recv)
|
|
|
|
return
|
2016-06-27 10:26:43 +02:00
|
|
|
}
|
2016-06-27 23:18:58 +02:00
|
|
|
recv = ev.GlobalID
|
2016-06-27 10:26:43 +02:00
|
|
|
coord <- struct{}{}
|
|
|
|
}
|
|
|
|
i += len(evs)
|
|
|
|
}
|
2016-12-18 19:57:41 +01:00
|
|
|
done <- nil
|
2016-06-27 10:26:43 +02:00
|
|
|
}()
|
|
|
|
|
|
|
|
// Send the events
|
|
|
|
eventData := map[string]string{
|
|
|
|
"foo": "bar",
|
|
|
|
"other": "data",
|
|
|
|
"and": "something else",
|
|
|
|
}
|
|
|
|
for i := 0; i < b.N; i++ {
|
2016-08-08 20:09:40 +02:00
|
|
|
l.Log(DeviceConnected, eventData)
|
2016-06-27 10:26:43 +02:00
|
|
|
<-coord
|
|
|
|
}
|
2014-07-13 21:07:24 +02:00
|
|
|
|
2016-12-18 19:57:41 +01:00
|
|
|
if err := <-done; err != nil {
|
|
|
|
b.Error(err)
|
|
|
|
}
|
2016-06-27 10:26:43 +02:00
|
|
|
b.ReportAllocs()
|
2014-07-13 21:07:24 +02:00
|
|
|
}
|
2016-06-27 23:18:58 +02:00
|
|
|
|
|
|
|
func TestSinceUsesSubscriptionId(t *testing.T) {
|
2016-08-08 20:09:40 +02:00
|
|
|
l := NewLogger()
|
2016-06-27 23:18:58 +02:00
|
|
|
|
2016-08-08 20:09:40 +02:00
|
|
|
s := l.Subscribe(DeviceConnected)
|
2016-06-27 23:18:58 +02:00
|
|
|
defer l.Unsubscribe(s)
|
2016-08-08 20:09:40 +02:00
|
|
|
bs := NewBufferedSubscription(s, 10*BufferSize)
|
2016-06-27 23:18:58 +02:00
|
|
|
|
2016-08-08 20:09:40 +02:00
|
|
|
l.Log(DeviceConnected, "a") // SubscriptionID = 1
|
|
|
|
l.Log(DeviceDisconnected, "b")
|
|
|
|
l.Log(DeviceDisconnected, "c")
|
|
|
|
l.Log(DeviceConnected, "d") // SubscriptionID = 2
|
2016-06-27 23:18:58 +02:00
|
|
|
|
2016-06-28 08:29:49 +02:00
|
|
|
// We need to loop for the events, as they may not all have been
|
|
|
|
// delivered to the buffered subscription when we get here.
|
|
|
|
t0 := time.Now()
|
|
|
|
for time.Since(t0) < time.Second {
|
2017-01-31 13:04:29 +01:00
|
|
|
events := bs.Since(0, nil, time.Minute)
|
2016-06-28 08:29:49 +02:00
|
|
|
if len(events) == 2 {
|
|
|
|
break
|
|
|
|
}
|
|
|
|
if len(events) > 2 {
|
|
|
|
t.Fatal("Incorrect number of events:", len(events))
|
|
|
|
}
|
2016-06-27 23:18:58 +02:00
|
|
|
}
|
|
|
|
|
2017-01-31 13:04:29 +01:00
|
|
|
events := bs.Since(1, nil, time.Minute)
|
2016-06-27 23:18:58 +02:00
|
|
|
if len(events) != 1 {
|
|
|
|
t.Fatal("Incorrect number of events:", len(events))
|
|
|
|
}
|
|
|
|
}
|