lib/logger: prevent from blocking when log output isn't consumed in timely manner

Drop log messages instead of blocking and increment `vm_log_messages_dropped_total` metric.
This commit is contained in:
Aliaksandr Valialkin 2019-12-20 11:47:54 +02:00
parent bea5a8700a
commit e3c462f08a

View file

@ -8,7 +8,6 @@ import (
"os" "os"
"runtime" "runtime"
"strings" "strings"
"sync"
"sync/atomic" "sync/atomic"
"time" "time"
@ -30,6 +29,7 @@ func Init() {
validateLoggerLevel() validateLoggerLevel()
validateLoggerFormat() validateLoggerFormat()
go errorsLoggedCleaner() go errorsLoggedCleaner()
go logMessageWriter()
logAllFlags() logAllFlags()
} }
@ -137,10 +137,13 @@ func logMessage(level, msg string, skipframes int) {
logMsg = fmt.Sprintf("%s\t%s\t%s:%d\t%s\n", timestamp, levelLowercase, file, line, msg) logMsg = fmt.Sprintf("%s\t%s\t%s:%d\t%s\n", timestamp, levelLowercase, file, line, msg)
} }
// Serialize writes to log. select {
mu.Lock() case logMessageCh <- logMsg:
fmt.Fprint(os.Stderr, logMsg) default:
mu.Unlock() // Writing to log can stuck if the log output isn't consumed in timely manner.
// Handle this case via `vm_log_messages_dropped_total`
logMessagesDropped.Inc()
}
// Increment vm_log_messages_total // Increment vm_log_messages_total
location := fmt.Sprintf("%s:%d", file, line) location := fmt.Sprintf("%s:%d", file, line)
@ -155,7 +158,15 @@ func logMessage(level, msg string, skipframes int) {
} }
} }
var mu sync.Mutex var logMessagesDropped = metrics.NewCounter(`vm_log_messages_dropped_total`)
func logMessageWriter() {
for msg := range logMessageCh {
fmt.Fprint(os.Stderr, msg)
}
}
var logMessageCh = make(chan string, 100)
func shouldSkipLog(level string) bool { func shouldSkipLog(level string) bool {
switch *loggerLevel { switch *loggerLevel {