.

go/internal/xtracing/tracetest/example_test.go

@@ -32,6 +32,7 @@ import (
 	"strings"
 	"sync"
 	"testing"
+	"time"
 
 	"lab.nexedi.com/kirr/go123/tracing"
 	"lab.nexedi.com/kirr/neo/go/internal/xtracing/tracetest"
@@ -138,7 +139,7 @@ func Test2ThreadsOK(t *testing.T) {
 	})
 }
 
-// TestDeadlock demonstrates deadlock scenario.
+// TestDeadlock demonstrates deadlock detection.
 func TestDeadlock(t *testing.T) {
 	verify(t, func(t *tracetest.T) {
 		var wg sync.WaitGroup
@@ -156,6 +157,33 @@ func TestDeadlock(t *testing.T) {
 	}, "-tracetest.deadtime=0.5s")
 }
 
+// TestRace demonstrates detection of logical race.
+func TestRace(t *testing.T) {
+	verify(t, func(t *tracetest.T) {
+		var wg sync.WaitGroup
+		defer wg.Wait()
+		wg.Add(2)
+
+		// 2 threads should synchronize with each other and do step A before B.
+		// They do not properly synchronize though, and just happen to
+		// usually emit events in expected order due to sleep in T2.
+		// Tracetest detects that.
+		go func() { // thread1
+			defer wg.Done()
+			hi("x·A")
+		}()
+
+		go func() { // thread2
+			defer wg.Done()
+			time.Sleep(100*time.Millisecond)
+			hi("x·B")
+		}()
+
+		t.Expect("x", eventHi("x·A"))
+		t.Expect("x", eventHi("x·B"))
+	})
+}
+
 
 // XXX race bug with sleep caught only by delay injection
 
@@ -271,18 +299,22 @@ var testExpectMap = map[string]testExpect{
 
 	"TestDeadlock":   {1,
 `--- FAIL: TestDeadlock (<TIME>)
-    example_test.go:155: t2: recv: deadlock waiting for *tracetest_test.eventHi
-    example_test.go:155: test shutdown: #streams: 2,  #(pending events): 1
+    example_test.go:156: t2: recv: deadlock waiting for *tracetest_test.eventHi
+    example_test.go:156: test shutdown: #streams: 2,  #(pending events): 1
         t1	<- tracetest_test.eventHi T1·A
         # t2
 
     tracetest.go:<LINE>: t1: send: canceled (test failed)
 `},
 
+	"TestRace":       {1,
+`xxx
+`},
+
 	"TestExpectType": {1,
 `--- FAIL: TestExpectType (<TIME>)
-    example_test.go:177: t1: expect: tracetest_test.eventHello:  got tracetest_test.eventHi T1·A
-    example_test.go:177: test shutdown: #streams: 1,  #(pending events): 0
+    example_test.go:205: t1: expect: tracetest_test.eventHello:  got tracetest_test.eventHi T1·A
+    example_test.go:205: test shutdown: #streams: 1,  #(pending events): 0
         # t1
 
     tracetest.go:<LINE>: t1: send: unexpected event type
@@ -290,14 +322,14 @@ var testExpectMap = map[string]testExpect{
 
 	"TestExpectValue": {1,
 `--- FAIL: TestExpectValue (<TIME>)
-    example_test.go:193: t1: expect: tracetest_test.eventHi:
+    example_test.go:221: t1: expect: tracetest_test.eventHi:
         want: T1·B
         have: T1·A
         diff:
         -"T1·B"
         +"T1·A"
 
-    example_test.go:193: test shutdown: #streams: 1,  #(pending events): 0
+    example_test.go:221: test shutdown: #streams: 1,  #(pending events): 0
         # t1
 
     tracetest.go:<LINE>: t1: send: unexpected event data