VictoriaMetrics/lib/logger/logger.go

208 lines
4.9 KiB
Go
Raw Normal View History

2019-05-22 23:16:55 +02:00
package logger
import (
"errors"
"flag"
"fmt"
"io"
2019-05-22 23:16:55 +02:00
"log"
"os"
"runtime"
"strings"
"sync"
2019-05-22 23:16:55 +02:00
"sync/atomic"
"time"
"github.com/VictoriaMetrics/VictoriaMetrics/lib/buildinfo"
"github.com/VictoriaMetrics/metrics"
2019-05-22 23:16:55 +02:00
)
var (
loggerLevel = flag.String("loggerLevel", "INFO", "Minimum level of errors to log. Possible values: INFO, ERROR, FATAL, PANIC")
loggerFormat = flag.String("loggerFormat", "default", "Format for logs. Possible values: default, json")
loggerOutput = flag.String("loggerOutput", "stderr", "Output for the logs. Supported values: stderr, stdout")
)
2019-05-22 23:16:55 +02:00
// Init initializes the logger.
//
// Init must be called after flag.Parse()
//
// There is no need in calling Init from tests.
func Init() {
setLoggerOutput()
2019-05-22 23:16:55 +02:00
validateLoggerLevel()
validateLoggerFormat()
2019-05-22 23:16:55 +02:00
go errorsLoggedCleaner()
logAllFlags()
}
func setLoggerOutput() {
switch *loggerOutput {
case "stderr":
output = os.Stderr
case "stdout":
output = os.Stdout
default:
panic(fmt.Errorf("FATAL: unsupported `loggerOutput` value: %q; supported values are: stderr, stdout", *loggerOutput))
}
}
var output io.Writer
2019-05-22 23:16:55 +02:00
func validateLoggerLevel() {
switch *loggerLevel {
case "INFO", "ERROR", "FATAL", "PANIC":
default:
// We cannot use logger.Panicf here, since the logger isn't initialized yet.
panic(fmt.Errorf("FATAL: unsupported `-loggerLevel` value: %q; supported values are: INFO, ERROR, FATAL, PANIC", *loggerLevel))
}
}
func validateLoggerFormat() {
switch *loggerFormat {
case "default", "json":
default:
// We cannot use logger.Pancif here, since the logger isn't initialized yet.
panic(fmt.Errorf("FATAL: unsupported `-loggerFormat` value: %q; supported values are: default, json", *loggerFormat))
}
}
2019-05-22 23:16:55 +02:00
var stdErrorLogger = log.New(&logWriter{}, "", 0)
// StdErrorLogger returns standard error logger.
func StdErrorLogger() *log.Logger {
return stdErrorLogger
}
// Infof logs info message.
func Infof(format string, args ...interface{}) {
logLevel("INFO", format, args...)
}
// Errorf logs error message.
func Errorf(format string, args ...interface{}) {
logLevel("ERROR", format, args...)
}
// ErrorfSkipframes logs error message and skips the given number of frames for the caller.
func ErrorfSkipframes(skipframes int, format string, args ...interface{}) {
logLevelSkipframes(skipframes, "ERROR", format, args...)
}
2019-05-22 23:16:55 +02:00
// Fatalf logs fatal message and terminates the app.
func Fatalf(format string, args ...interface{}) {
logLevel("FATAL", format, args...)
}
// Panicf logs panic message and panics.
func Panicf(format string, args ...interface{}) {
logLevel("PANIC", format, args...)
}
func logLevel(level, format string, args ...interface{}) {
logLevelSkipframes(1, level, format, args...)
}
func logLevelSkipframes(skipframes int, level, format string, args ...interface{}) {
2019-05-22 23:16:55 +02:00
if shouldSkipLog(level) {
return
}
msg := fmt.Sprintf(format, args...)
logMessage(level, msg, 3+skipframes)
2019-05-22 23:16:55 +02:00
}
func errorsLoggedCleaner() {
for {
time.Sleep(5 * time.Second)
atomic.StoreUint64(&errorsLogged, 0)
}
}
var errorsLogged uint64
type logWriter struct {
}
func (lw *logWriter) Write(p []byte) (int, error) {
logLevelSkipframes(2, "ERROR", "%s", p)
2019-05-22 23:16:55 +02:00
return len(p), nil
}
func logMessage(level, msg string, skipframes int) {
// rate limit ERROR log messages
if level == "ERROR" {
if n := atomic.AddUint64(&errorsLogged, 1); n > 10 {
return
}
}
timestamp := time.Now().UTC().Format("2006-01-02T15:04:05.000Z")
2019-05-22 23:16:55 +02:00
levelLowercase := strings.ToLower(level)
_, file, line, ok := runtime.Caller(skipframes)
if !ok {
file = "???"
line = 0
}
if n := strings.Index(file, "/VictoriaMetrics/"); n >= 0 {
// Strip /VictoriaMetrics/ prefix
file = file[n+len("/VictoriaMetrics/"):]
}
for len(msg) > 0 && msg[len(msg)-1] == '\n' {
msg = msg[:len(msg)-1]
}
var logMsg string
switch *loggerFormat {
case "json":
caller := fmt.Sprintf("%s:%d", file, line)
logMsg = fmt.Sprintf(`{"ts":%q,"level":%q,"caller":%q,"msg":%q}`+"\n", timestamp, levelLowercase, caller, msg)
default:
logMsg = fmt.Sprintf("%s\t%s\t%s:%d\t%s\n", timestamp, levelLowercase, file, line, msg)
}
2019-05-22 23:16:55 +02:00
// Serialize writes to log.
mu.Lock()
fmt.Fprint(output, logMsg)
mu.Unlock()
2019-05-22 23:16:55 +02:00
// Increment vm_log_messages_total
location := fmt.Sprintf("%s:%d", file, line)
counterName := fmt.Sprintf(`vm_log_messages_total{app_version=%q, level=%q, location=%q}`, buildinfo.Version, levelLowercase, location)
metrics.GetOrCreateCounter(counterName).Inc()
2019-05-22 23:16:55 +02:00
switch level {
case "PANIC":
if *loggerFormat == "json" {
// Do not clutter `json` output with panic stack trace
os.Exit(-1)
}
2019-05-22 23:16:55 +02:00
panic(errors.New(msg))
case "FATAL":
os.Exit(-1)
}
}
var mu sync.Mutex
2019-05-22 23:16:55 +02:00
func shouldSkipLog(level string) bool {
switch *loggerLevel {
case "ERROR":
switch level {
case "ERROR", "FATAL", "PANIC":
return false
default:
return true
}
case "FATAL":
switch level {
case "FATAL", "PANIC":
return false
default:
return true
}
case "PANIC":
return level != "PANIC"
default:
return false
}
}