Speeding the queries up.

This commit is contained in:
2024-05-04 21:17:14 +01:00
parent 4e60a90ce4
commit 9a58df7a54
8 changed files with 496 additions and 165 deletions
+48 -86
View File
@@ -1,9 +1,8 @@
package libpack_logging
import (
"io"
"os"
"strings"
"sync"
"time"
"github.com/gookit/goutil/envutil"
@@ -11,83 +10,40 @@ import (
)
type LogConfig struct {
baseLogger zerolog.Logger
errorLogger zerolog.Logger
nopLogger zerolog.Logger
mu sync.Mutex
minLevel zerolog.Level
logger zerolog.Logger
}
var baseLogger zerolog.Logger
func init() {
zerolog.TimeFieldFormat = time.RFC3339
zerolog.MessageFieldName = "msg"
zerolog.TimestampFieldName = "ts"
zerolog.MessageFieldName = "short_message"
zerolog.TimestampFieldName = "timestamp"
zerolog.LevelFieldName = "level"
zerolog.LevelFatalValue = "critical"
}
func getMinLogLevel() zerolog.Level {
levelStr := strings.ToLower(envutil.Getenv("LOG_LEVEL", "info"))
return matchLogLevel(levelStr)
}
// Add function set the minimum log level instead of using environment variable
func (lc *LogConfig) SetLogLevel(level string) {
lc.mu.Lock()
defer lc.mu.Unlock()
lc.minLevel = matchLogLevel(level)
}
// Match the log level provided as string with the log level provided as zerolog.Level
func matchLogLevel(level string) zerolog.Level {
switch level {
case "debug":
return zerolog.DebugLevel
case "warn":
return zerolog.WarnLevel
case "error":
return zerolog.ErrorLevel
case "critical":
return zerolog.FatalLevel
default:
return zerolog.InfoLevel
}
baseLogger = zerolog.New(os.Stdout).With().Timestamp().Logger()
}
func NewLogger() *LogConfig {
zl := zerolog.New(os.Stdout).With().Timestamp().Logger()
// Determine the minimum log level from environment variable
return &LogConfig{
baseLogger: zl,
errorLogger: zl.Output(os.Stderr),
nopLogger: zerolog.Nop(),
minLevel: getMinLogLevel(),
switch logLevel := envutil.Getenv("LOG_LEVEL", "info"); logLevel {
case "debug":
baseLogger = baseLogger.Level(zerolog.DebugLevel)
case "warn":
baseLogger = baseLogger.Level(zerolog.WarnLevel)
case "error":
baseLogger = baseLogger.Level(zerolog.ErrorLevel)
default:
baseLogger = baseLogger.Level(zerolog.InfoLevel)
}
return &LogConfig{logger: baseLogger}
}
func (lc *LogConfig) getLogger(level zerolog.Level) zerolog.Logger {
if level >= zerolog.ErrorLevel {
return lc.errorLogger
}
if level < lc.minLevel {
return lc.nopLogger
}
return lc.baseLogger
}
func (lc *LogConfig) Log(level zerolog.Level, message string, fields []map[string]interface{}) {
if level < lc.minLevel {
return
}
logger := lc.getLogger(level)
event := logger.WithLevel(level).CallerSkipFrame(3)
if len(fields) == 0 {
event.Msg(message)
return
}
field := fields[0]
for k, val := range field {
func (lw *LogConfig) log(w io.Writer, level zerolog.Level, message string, v map[string]interface{}) {
e := lw.logger.With().Logger()
e = e.Output(w)
event := e.WithLevel(level).CallerSkipFrame(3)
for k, val := range v {
switch v := val.(type) {
case string:
event.Str(k, v)
@@ -96,39 +52,45 @@ func (lc *LogConfig) Log(level zerolog.Level, message string, fields []map[strin
case float64:
event.Float64(k, v)
default:
event.Interface(k, v)
event.Interface(k, val)
}
}
event.Msg(message)
}
func (lc *LogConfig) Info(message string, fields ...map[string]interface{}) {
lc.Log(zerolog.InfoLevel, message, fields)
func (lw *LogConfig) Debug(message string, v ...map[string]interface{}) {
if !lw.logger.Debug().Enabled() {
return
}
lw.log(os.Stdout, zerolog.DebugLevel, message, mergeMaps(v))
}
func (lc *LogConfig) Debug(message string, fields ...map[string]interface{}) {
lc.Log(zerolog.DebugLevel, message, fields)
func (lw *LogConfig) Info(message string, v ...map[string]interface{}) {
if !lw.logger.Info().Enabled() {
return
}
lw.log(os.Stdout, zerolog.InfoLevel, message, mergeMaps(v))
}
func (lc *LogConfig) Warn(message string, fields ...map[string]interface{}) {
lc.Log(zerolog.WarnLevel, message, fields)
func (lw *LogConfig) Warning(message string, v ...map[string]interface{}) {
lw.log(os.Stdout, zerolog.WarnLevel, message, mergeMaps(v))
}
// alias Warning to Warn
func (lc *LogConfig) Warning(message string, fields ...map[string]interface{}) {
lc.Warn(message, fields...)
func (lw *LogConfig) Error(message string, v ...map[string]interface{}) {
lw.log(os.Stderr, zerolog.ErrorLevel, message, mergeMaps(v))
}
func (lc *LogConfig) Error(message string, fields ...map[string]interface{}) {
lc.Log(zerolog.ErrorLevel, message, fields)
}
func (lc *LogConfig) Critical(message string, fields ...map[string]interface{}) {
lc.Log(zerolog.FatalLevel, message, fields)
func (lw *LogConfig) Critical(message string, v ...map[string]interface{}) {
lw.log(os.Stderr, zerolog.FatalLevel, message, mergeMaps(v))
os.Exit(1)
}
// alias Fatal to Critical
func (lc *LogConfig) Fatal(message string, fields ...map[string]interface{}) {
lc.Critical(message, fields...)
func mergeMaps(maps []map[string]interface{}) map[string]interface{} {
result := make(map[string]interface{})
for _, m := range maps {
for k, v := range m {
result[k] = v
}
}
return result
}
-1
View File
@@ -25,7 +25,6 @@ func BenchmarkInfoLog(b *testing.B) {
}()
testsLogger := NewLogger()
b.ResetTimer()
for i := 0; i < b.N; i++ {
testsLogger.Info("test", map[string]interface{}{"test": "test"})
}
+373
View File
@@ -0,0 +1,373 @@
package libpack_logging
import (
"errors"
"io"
"os"
"reflect"
"testing"
"github.com/buger/jsonparser"
"github.com/stretchr/testify/suite"
)
type LoggingTestSuite struct {
suite.Suite
}
var (
testsLogger *LogConfig
)
type stdoutCapture struct {
oldStdout *os.File
readPipe *os.File
}
func (sc *stdoutCapture) StartCapture() {
sc.oldStdout = os.Stdout
sc.readPipe, os.Stdout, _ = os.Pipe()
}
func (sc *stdoutCapture) StopCapture() (string, error) {
if sc.oldStdout == nil || sc.readPipe == nil {
return "", errors.New("StartCapture not called before StopCapture on Stdout")
}
os.Stdout.Close()
os.Stdout = sc.oldStdout
bytes, err := io.ReadAll(sc.readPipe)
if err != nil {
return "", err
}
return string(bytes), nil
}
type stderrCapture struct {
oldStderr *os.File
readPipe *os.File
}
func (sc *stderrCapture) StartCapture() {
sc.oldStderr = os.Stderr
sc.readPipe, os.Stderr, _ = os.Pipe()
}
func (sc *stderrCapture) StopCapture() (string, error) {
if sc.oldStderr == nil || sc.readPipe == nil {
return "", errors.New("StartCapture not called before StopCapture on Stderr")
}
os.Stderr.Close()
os.Stderr = sc.oldStderr
bytes, err := io.ReadAll(sc.readPipe)
if err != nil {
return "", err
}
return string(bytes), nil
}
func (suite *LoggingTestSuite) SetupTest() {
}
func TestLoggingTestSuite(t *testing.T) {
suite.Run(t, new(LoggingTestSuite))
}
func (suite *LoggingTestSuite) TestLogConfig_AllHandlers() {
type args struct {
message string
}
tests := []struct {
name string
args args
wantLevel string
wantMessage string
envMinLogLevel string
loggerType string
stdOutExpect bool
stdErrExpect bool
}{
{
name: "Test log: Error",
loggerType: "Error",
args: args{
message: "This is a error message",
},
wantLevel: "error",
wantMessage: "This is a error message",
stdErrExpect: true,
stdOutExpect: false,
},
{
name: "Test log: Warning",
loggerType: "Warning",
args: args{
message: "This is a warning message",
},
wantLevel: "warn",
wantMessage: "This is a warning message",
stdErrExpect: false,
stdOutExpect: true,
envMinLogLevel: "info",
},
{
name: "Test log: Warning | Min level: Debug",
loggerType: "Warning",
args: args{
message: "This is a warning message",
},
wantLevel: "warn",
wantMessage: "This is a warning message",
stdErrExpect: false,
stdOutExpect: true,
envMinLogLevel: "debug",
},
{
name: "Test log: Info",
loggerType: "Info",
args: args{
message: "This is a info message",
},
wantLevel: "info",
wantMessage: "This is a info message",
stdErrExpect: false,
stdOutExpect: true,
},
{
name: "Test log: Info | Min level: Warn",
loggerType: "Info",
args: args{
message: "This is a info message",
},
wantLevel: "",
wantMessage: "",
stdErrExpect: false,
stdOutExpect: false,
envMinLogLevel: "warn",
},
{
name: "Test log: Warning | Min level: Warn",
loggerType: "Warning",
args: args{
message: "This is a warning message",
},
wantLevel: "warn",
wantMessage: "This is a warning message",
stdErrExpect: false,
stdOutExpect: true,
envMinLogLevel: "warn",
},
{
name: "Test log: Warning | Min level: Error",
loggerType: "Warning",
args: args{
message: "This is an error message",
},
wantLevel: "",
wantMessage: "",
stdErrExpect: false,
stdOutExpect: false,
envMinLogLevel: "error",
},
{
name: "Test log: Debug | Min level: Debug",
loggerType: "Debug",
args: args{
message: "This is a debug message",
},
wantLevel: "debug",
wantMessage: "This is a debug message",
stdErrExpect: false,
stdOutExpect: true,
envMinLogLevel: "debug",
},
}
for _, tt := range tests {
suite.Run(tt.name, func() {
if tt.envMinLogLevel != "" {
os.Setenv("LOG_LEVEL", tt.envMinLogLevel)
defer os.Unsetenv("LOG_LEVEL")
}
testsLogger = NewLogger()
captureStdout := stdoutCapture{}
captureStdout.StartCapture()
captureStderr := stderrCapture{}
captureStderr.StartCapture()
reflect.ValueOf(testsLogger).MethodByName(tt.loggerType).Call([]reflect.Value{reflect.ValueOf(tt.args.message)})
stdoutOut, err := captureStdout.StopCapture()
if err != nil {
suite.T().Fatal(err)
}
stderrOut, err := captureStderr.StopCapture()
if err != nil {
suite.T().Fatal(err)
}
if tt.stdErrExpect && !tt.stdOutExpect {
gotLvl, gotMsg, err := getResponseValues(stderrOut, "short_message")
suite.NoError(err, "Failed in [STDERR]: "+tt.name)
suite.Equal(tt.wantLevel, gotLvl, "Failed in [STDERR]: "+tt.name)
suite.Equal(tt.wantMessage, gotMsg, "Failed in [STDERR]: "+tt.name)
suite.Equal("", stdoutOut, "Failed in [STDERR]: "+tt.name)
}
if tt.stdOutExpect && !tt.stdErrExpect {
gotLvl, gotMsg, err := getResponseValues(stdoutOut, "short_message")
suite.NoError(err, "Failed in [STDOUT]: "+tt.name)
suite.Equal(tt.wantLevel, gotLvl, "Failed in [STDOUT]: "+tt.name)
suite.Equal(tt.wantMessage, gotMsg, "Failed in [STDOUT]: "+tt.name)
suite.Equal("", stderrOut, "Failed in [STDOUT]: "+tt.name)
}
if !tt.stdErrExpect && !tt.stdOutExpect {
suite.Equal("", stderrOut, "Failed in [NEITHER]: "+tt.name)
suite.Equal("", stdoutOut, "Failed in [NEITHER]: "+tt.name)
}
os.Unsetenv("LOG_LEVEL")
})
}
}
func (suite *LoggingTestSuite) TestFullMessage() {
type args struct {
extraFields map[string]interface{}
message string
}
extraFields := make(map[string]interface{})
extraFields["_full_message"] = "full message"
tests := []struct {
args args
name string
wantLevel string
wantMessage string
envMinLogLevel string
loggerType string
stdOutExpect bool
stdErrExpect bool
}{
{
name: "Test log: Error",
loggerType: "Error",
args: args{
message: "This is a error message",
extraFields: extraFields,
},
wantLevel: "error",
wantMessage: extraFields["_full_message"].(string),
stdErrExpect: true,
stdOutExpect: false,
},
{
name: "Test log: Info",
loggerType: "Info",
args: args{
message: "This is a info message",
extraFields: extraFields,
},
wantMessage: extraFields["_full_message"].(string),
stdErrExpect: false,
stdOutExpect: true,
},
}
for _, tt := range tests {
suite.Run(tt.name, func() {
if tt.envMinLogLevel != "" {
os.Setenv("LOG_LEVEL", tt.envMinLogLevel)
defer os.Unsetenv("LOG_LEVEL")
}
testsLogger = NewLogger()
captureStdout := stdoutCapture{}
captureStdout.StartCapture()
captureStderr := stderrCapture{}
captureStderr.StartCapture()
reflect.ValueOf(testsLogger).MethodByName(tt.loggerType).Call([]reflect.Value{
reflect.ValueOf(tt.args.message),
reflect.ValueOf(tt.args.extraFields),
})
stdoutOut, err := captureStdout.StopCapture()
if err != nil {
suite.T().Fatal(err)
}
stderrOut, err := captureStderr.StopCapture()
if err != nil {
suite.T().Fatal(err)
}
if tt.stdErrExpect && !tt.stdOutExpect {
_, gotMsg, err := getResponseValues(stderrOut, "_full_message")
suite.NoError(err, "Failed in [STDERR]: "+tt.name)
suite.Equal(tt.wantMessage, gotMsg, "Failed in [STDERR]: "+tt.name)
}
if tt.stdOutExpect && !tt.stdErrExpect {
_, gotMsg, err := getResponseValues(stdoutOut, "_full_message")
suite.NoError(err, "Failed in [STDOUT]: "+tt.name)
suite.Equal(tt.wantMessage, gotMsg, "Failed in [STDOUT]: "+tt.name)
}
os.Unsetenv("LOG_LEVEL")
})
}
}
func Test_getResponseValues(t *testing.T) {
type args struct {
sourceJson string
}
tests := []struct {
name string
args args
wantGotLvl string
wantGotMsg string
wantErr bool
}{
{
name: "Test with json",
args: args{
sourceJson: `{"level": "debug", "short_message": "hello world"`,
},
wantGotLvl: "debug",
wantGotMsg: "hello world",
wantErr: false,
},
{
name: "Test with json, wrong message field",
args: args{
sourceJson: `{"level": "debug", "message": "hello world"`,
},
wantGotLvl: "debug",
wantGotMsg: "",
wantErr: true,
},
}
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
gotGotLvl, gotGotMsg, err := getResponseValues(tt.args.sourceJson, "short_message")
if (err != nil) != tt.wantErr {
t.Errorf("getResponseValues() error = %v, wantErr %v", err, tt.wantErr)
return
}
if gotGotLvl != tt.wantGotLvl {
t.Errorf("getResponseValues() gotGotLvl = %v, want %v", gotGotLvl, tt.wantGotLvl)
}
if gotGotMsg != tt.wantGotMsg {
t.Errorf("getResponseValues() gotGotMsg = %v, want %v", gotGotMsg, tt.wantGotMsg)
}
})
}
}
func getResponseValues(sourceJson string, key string) (gotLvl, gotMsg string, err error) {
gotLvl, err = jsonparser.GetString([]byte(sourceJson), "level")
if err != nil {
return
}
gotMsg, err = jsonparser.GetString([]byte(sourceJson), key)
return
}