From de959153a857ba9394cc5841a716da8abbe24a59 Mon Sep 17 00:00:00 2001 From: Ross Jones Date: Wed, 3 May 2023 09:24:56 +0100 Subject: [PATCH] Allow disabling of violation logging When some tasks take too long, a violation is logged using the default logging package. We don't want to add more dependencies to this package, but we also don't want to log these violations in every circumstance (e.g. when used in a CLI). Allows the caller enabled a tracing mutex to specify they want to Disable violation logging. --- lock.go | 15 ++++++++------- lock_rw.go | 15 ++++++++------- opts.go | 11 +++++++---- tracers.go | 3 +++ 4 files changed, 26 insertions(+), 18 deletions(-) diff --git a/lock.go b/lock.go index 10493d7..f8b9546 100644 --- a/lock.go +++ b/lock.go @@ -9,11 +9,12 @@ type Mutex struct { lock sync.Mutex // internal trace fields - threshold atomic.Uint64 // 0 when disabled, else threshold in nanoseconds - beginAwaitLock atomic.Uint64 // start time in unix nanoseconds from start waiting for lock - beginAwaitUnlock atomic.Uint64 // start time in unix nanoseconds from start waiting for unlock - lockObtained atomic.Uint64 // once we've entered the lock in unix nanoseconds - id []byte // if set this will be printed as string + threshold atomic.Uint64 // 0 when disabled, else threshold in nanoseconds + beginAwaitLock atomic.Uint64 // start time in unix nanoseconds from start waiting for lock + beginAwaitUnlock atomic.Uint64 // start time in unix nanoseconds from start waiting for unlock + lockObtained atomic.Uint64 // once we've entered the lock in unix nanoseconds + id []byte // if set this will be printed as string + DisableViolationLog bool } func (m *Mutex) Lock() { @@ -66,7 +67,7 @@ func (m *Mutex) traceEndAwaitLock(threshold Threshold) { // check for no overflow took = ts - start } - if took >= uint64(threshold) { + if took >= uint64(threshold) && !m.DisableViolationLog { logViolation(Id(m.id), threshold, Actual(took), Now(ts), ViolationLock) } } @@ -86,7 +87,7 @@ func (m *Mutex) traceEndAwaitUnlock(threshold Threshold) { took = ts - lockObtained } - if took >= uint64(threshold) && lockObtained > 0 { + if took >= uint64(threshold) && lockObtained > 0 && !m.DisableViolationLog { // lockObtained = 0 when the tracer is enabled half way logViolation(Id(m.id), threshold, Actual(took), Now(ts), ViolationCritical) } diff --git a/lock_rw.go b/lock_rw.go index cfa32af..9c1d69b 100644 --- a/lock_rw.go +++ b/lock_rw.go @@ -9,11 +9,12 @@ type RWMutex struct { lock sync.RWMutex // internal trace fields - threshold atomic.Uint64 // 0 when disabled, else threshold in nanoseconds - beginAwaitLock atomic.Uint64 // start time in unix nanoseconds from start waiting for lock - beginAwaitUnlock atomic.Uint64 // start time in unix nanoseconds from start waiting for unlock - lockObtained atomic.Uint64 // once we've entered the lock in unix nanoseconds - id []byte // if set this will be printed as string + threshold atomic.Uint64 // 0 when disabled, else threshold in nanoseconds + beginAwaitLock atomic.Uint64 // start time in unix nanoseconds from start waiting for lock + beginAwaitUnlock atomic.Uint64 // start time in unix nanoseconds from start waiting for unlock + lockObtained atomic.Uint64 // once we've entered the lock in unix nanoseconds + id []byte // if set this will be printed as string + DisableViolationLog bool } func (m *RWMutex) Lock() { @@ -94,7 +95,7 @@ func (m *RWMutex) traceEndAwaitLock(threshold Threshold) { // check for no overflow took = ts - start } - if took >= uint64(threshold) { + if took >= uint64(threshold) && !m.DisableViolationLog { logViolation(Id(m.id), threshold, Actual(took), Now(ts), ViolationLock) } } @@ -114,7 +115,7 @@ func (m *RWMutex) traceEndAwaitUnlock(threshold Threshold) { took = ts - lockObtained } - if took >= uint64(threshold) && lockObtained > 0 { + if took >= uint64(threshold) && lockObtained > 0 && !m.DisableViolationLog { // lockObtained = 0 when the tracer is enabled half way logViolation(Id(m.id), threshold, Actual(took), Now(ts), ViolationCritical) } diff --git a/opts.go b/opts.go index 7ec2e08..905a025 100644 --- a/opts.go +++ b/opts.go @@ -1,9 +1,12 @@ package muxtracer -import "time" +import ( + "time" +) type Opts struct { - Threshold time.Duration - Enabled bool - Id string // use with + Threshold time.Duration + Enabled bool + Id string // use with + DisableViolationLog bool } diff --git a/tracers.go b/tracers.go index 00e3230..0476a16 100644 --- a/tracers.go +++ b/tracers.go @@ -10,6 +10,7 @@ func logViolation(id Id, threshold Threshold, actual Actual, now Now, violationT if id != nil { idStr = string(id) + " " } + log.Printf("%sviolation %s section took %s %d (threshold %s)", idStr, violationType.String(), time.Duration(actual).String(), actual, time.Duration(threshold).String()) } @@ -32,6 +33,7 @@ func (m *Mutex) EnableTracerWithOpts(o Opts) { m.id = []byte(o.Id) } m.threshold.Store(uint64(o.Threshold.Nanoseconds())) + m.DisableViolationLog = o.DisableViolationLog } func (m *Mutex) DisableTracer() { @@ -47,6 +49,7 @@ func (m *RWMutex) EnableTracerWithOpts(o Opts) { m.id = []byte(o.Id) } m.threshold.Store(uint64(o.Threshold.Nanoseconds())) + m.DisableViolationLog = o.DisableViolationLog } func (m *RWMutex) DisableTracer() {