trace: fix races on concurrent Trace method calls
This change protects fields mutated by Trace methods with a mutex.
In particular it fixes races caused by concurrent calls to IsError,
and viewing active traces in /debug/requests.
Includes changes from CL/67730.
Updates golang/go#24231
Change-Id: I07db54c2642efe0ea0e3ffeb54ec796ae51e70ef
Reviewed-on: https://go-review.googlesource.com/98535
Run-TryBot: Hyang-Ah Hana Kim <hyangah@gmail.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Hyang-Ah Hana Kim <hyangah@gmail.com>
diff --git a/trace/trace.go b/trace/trace.go
index bb72a52..a46ee0e 100644
--- a/trace/trace.go
+++ b/trace/trace.go
@@ -368,7 +368,11 @@
}
func (tr *trace) Finish() {
- tr.Elapsed = time.Now().Sub(tr.Start)
+ elapsed := time.Now().Sub(tr.Start)
+ tr.mu.Lock()
+ tr.Elapsed = elapsed
+ tr.mu.Unlock()
+
if DebugUseAfterFinish {
buf := make([]byte, 4<<10) // 4 KB should be enough
n := runtime.Stack(buf, false)
@@ -381,14 +385,17 @@
m.Remove(tr)
f := getFamily(tr.Family, true)
+ tr.mu.RLock() // protects tr fields in Cond.match calls
for _, b := range f.Buckets {
if b.Cond.match(tr) {
b.Add(tr)
}
}
+ tr.mu.RUnlock()
+
// Add a sample of elapsed time as microseconds to the family's timeseries
h := new(histogram)
- h.addMeasurement(tr.Elapsed.Nanoseconds() / 1e3)
+ h.addMeasurement(elapsed.Nanoseconds() / 1e3)
f.LatencyMu.Lock()
f.Latency.Add(h)
f.LatencyMu.Unlock()
@@ -684,25 +691,20 @@
// Title is the title of this trace.
Title string
- // Timing information.
- Start time.Time
- Elapsed time.Duration // zero while active
+ // Start time of the this trace.
+ Start time.Time
- // Trace information if non-zero.
- traceID uint64
- spanID uint64
-
- // Whether this trace resulted in an error.
- IsError bool
-
- // Append-only sequence of events (modulo discards).
mu sync.RWMutex
- events []event
+ events []event // Append-only sequence of events (modulo discards).
maxEvents int
+ recycler func(interface{})
+ IsError bool // Whether this trace resulted in an error.
+ Elapsed time.Duration // Elapsed time for this trace, zero while active.
+ traceID uint64 // Trace information if non-zero.
+ spanID uint64
- refs int32 // how many buckets this is in
- recycler func(interface{})
- disc discarded // scratch space to avoid allocation
+ refs int32 // how many buckets this is in
+ disc discarded // scratch space to avoid allocation
finishStack []byte // where finish was called, if DebugUseAfterFinish is set
@@ -714,14 +716,18 @@
tr.Family = ""
tr.Title = ""
tr.Start = time.Time{}
+
+ tr.mu.Lock()
tr.Elapsed = 0
tr.traceID = 0
tr.spanID = 0
tr.IsError = false
tr.maxEvents = 0
tr.events = nil
- tr.refs = 0
tr.recycler = nil
+ tr.mu.Unlock()
+
+ tr.refs = 0
tr.disc = 0
tr.finishStack = nil
for i := range tr.eventsBuf {
@@ -801,21 +807,31 @@
tr.addEvent(&lazySprintf{format, a}, false, false)
}
-func (tr *trace) SetError() { tr.IsError = true }
+func (tr *trace) SetError() {
+ tr.mu.Lock()
+ tr.IsError = true
+ tr.mu.Unlock()
+}
func (tr *trace) SetRecycler(f func(interface{})) {
+ tr.mu.Lock()
tr.recycler = f
+ tr.mu.Unlock()
}
func (tr *trace) SetTraceInfo(traceID, spanID uint64) {
+ tr.mu.Lock()
tr.traceID, tr.spanID = traceID, spanID
+ tr.mu.Unlock()
}
func (tr *trace) SetMaxEvents(m int) {
+ tr.mu.Lock()
// Always keep at least three events: first, discarded count, last.
if len(tr.events) == 0 && m > 3 {
tr.maxEvents = m
}
+ tr.mu.Unlock()
}
func (tr *trace) ref() {
@@ -824,6 +840,7 @@
func (tr *trace) unref() {
if atomic.AddInt32(&tr.refs, -1) == 0 {
+ tr.mu.RLock()
if tr.recycler != nil {
// freeTrace clears tr, so we hold tr.recycler and tr.events here.
go func(f func(interface{}), es []event) {
@@ -834,6 +851,7 @@
}
}(tr.recycler, tr.events)
}
+ tr.mu.RUnlock()
freeTrace(tr)
}
@@ -844,7 +862,10 @@
}
func (tr *trace) ElapsedTime() string {
+ tr.mu.RLock()
t := tr.Elapsed
+ tr.mu.RUnlock()
+
if t == 0 {
// Active trace.
t = time.Since(tr.Start)
