Skip to content

Commit 89fa268

Browse files
committed
transport: rate-limit [ts] write-error log spam
A socket that is broken but still open keeps accepting writes that immediately fail, so the writer goroutine retries in a tight loop and floods the log during an outage. Added shouldLogWriteErr() using the same package-level atomic CAS pattern as the auth/oob/drop paths: at most one line per minute with a suppressed count. Note: the [net][s]select error line is V(2) (silent by default) upstream, so it does not flood at default verbosity and is left untouched.
1 parent 75a5f31 commit 89fa268

1 file changed

Lines changed: 34 additions & 1 deletion

File tree

transport.go

Lines changed: 34 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -397,6 +397,14 @@ func isBetterMode(current TransportMode, other TransportMode) bool {
397397
var lastAuthErrLogNano atomic.Int64
398398
var suppressedAuthErrCount atomic.Int64
399399

400+
// lastWriteErrLogNano and suppressedWriteErrCount rate-limit [ts] write-error
401+
// log lines. A socket that is broken but still open keeps accepting writes that
402+
// immediately fail, so the writer goroutine retries in a tight loop and every
403+
// failed write logs a line. During an outage this floods the log just like the
404+
// auth path, so the same once-per-minute throttle is applied here.
405+
var lastWriteErrLogNano atomic.Int64
406+
var suppressedWriteErrCount atomic.Int64
407+
400408
// shouldLogAuthErr returns (true, suppressedCount) if a log line should be emitted,
401409
// resetting the suppressed counter. Returns (false, 0) if the error is suppressed.
402410
func shouldLogAuthErr() (bool, int64) {
@@ -414,6 +422,25 @@ func shouldLogAuthErr() (bool, int64) {
414422
return true, suppressed
415423
}
416424

425+
// shouldLogWriteErr returns (true, suppressedCount) if a [ts] write-error line
426+
// should be emitted, resetting the suppressed counter. Returns (false, 0) if
427+
// suppressed. A broken-but-open socket retries writes in a tight loop; this
428+
// throttles that flood to one line per minute with a suppressed count.
429+
func shouldLogWriteErr() (bool, int64) {
430+
now := time.Now().UnixNano()
431+
last := lastWriteErrLogNano.Load()
432+
if now-last < int64(time.Minute) {
433+
suppressedWriteErrCount.Add(1)
434+
return false, 0
435+
}
436+
if !lastWriteErrLogNano.CompareAndSwap(last, now) {
437+
suppressedWriteErrCount.Add(1)
438+
return false, 0
439+
}
440+
suppressed := suppressedWriteErrCount.Swap(0)
441+
return true, suppressed
442+
}
443+
417444
func (self *PlatformTransport) runH1(initialTimeout time.Duration) {
418445
// connect and update route manager for this transport
419446
defer self.cancel()
@@ -682,7 +709,13 @@ func (self *PlatformTransport) runH1(initialTimeout time.Duration) {
682709
MessagePoolReturn(message)
683710
if err != nil {
684711
// note that for websocket a dealine timeout cannot be recovered
685-
self.log.Infof("[ts]%s-> error = %s\n", clientId, err)
712+
if ok, suppressed := shouldLogWriteErr(); ok {
713+
if suppressed > 0 {
714+
self.log.Infof("[ts]%s-> error = %s (%d suppressed)\n", clientId, err, suppressed)
715+
} else {
716+
self.log.Infof("[ts]%s-> error = %s\n", clientId, err)
717+
}
718+
}
686719
return err
687720
}
688721
self.log.V(2).Infof("[ts]%s->\n", clientId)

0 commit comments

Comments
 (0)