From 15d48fb0ad034ce328dba11e76a2d8596ff25388 Mon Sep 17 00:00:00 2001 From: wangchuxiao Date: Wed, 15 Mar 2023 15:26:37 +0800 Subject: [PATCH] Merge branch 'errcode' of github.com:OpenIMSDK/Open-IM-Server into errcode # Conflicts: # pkg/common/mw/rpc_server_interceptor.go --- config/config.yaml | 2 +- pkg/common/db/relation/mysql_init.go | 85 +++++++++++++++++++++++++--- pkg/common/log/zap.go | 27 +++------ pkg/statistics/statistics.go | 3 +- 4 files changed, 87 insertions(+), 30 deletions(-) diff --git a/config/config.yaml b/config/config.yaml index 8c7d47067..d83df8d34 100644 --- a/config/config.yaml +++ b/config/config.yaml @@ -159,7 +159,7 @@ log: rotationTime: 24 remainRotationCount: 2 #日志数量 #日志级别 6表示全都打印，测试阶段建议设置为6 - remainLogLevel: 6 + remainLogLevel: -1 stderr: true elasticSearchSwitch: false diff --git a/pkg/common/db/relation/mysql_init.go b/pkg/common/db/relation/mysql_init.go index 6fa697537..7acc8247b 100644 --- a/pkg/common/db/relation/mysql_init.go +++ b/pkg/common/db/relation/mysql_init.go @@ -6,9 +6,11 @@ import ( "OpenIM/pkg/common/mw/specialerror" "OpenIM/pkg/errs" "context" + "errors" "fmt" mysqlDriver "github.com/go-sql-driver/mysql" "gorm.io/driver/mysql" + "gorm.io/gorm/utils" "strings" "time" @@ -39,16 +41,17 @@ func newMysqlGormDB() (*gorm.DB, error) { } dsn = fmt.Sprintf("%s:%s@tcp(%s)/%s?charset=utf8mb4&parseTime=true&loc=Local", config.Config.Mysql.DBUserName, config.Config.Mysql.DBPassword, config.Config.Mysql.DBAddress[0], config.Config.Mysql.DBDatabaseName) - newLogger := logger.New( - Writer{}, - logger.Config{ - SlowThreshold: time.Duration(config.Config.Mysql.SlowThreshold) * time.Millisecond, // Slow SQL threshold - LogLevel: logger.LogLevel(config.Config.Mysql.LogLevel), // Log level - IgnoreRecordNotFoundError: true, // Ignore ErrRecordNotFound error for logger - }, - ) + //newLogger := logger.New( + // Writer{}, + // logger.Config{ + // SlowThreshold: time.Duration(config.Config.Mysql.SlowThreshold) * time.Millisecond, // Slow SQL threshold + // LogLevel: logger.LogLevel(config.Config.Mysql.LogLevel), // Log level + // IgnoreRecordNotFoundError: true, // Ignore ErrRecordNotFound error for logger + // }, + //) + sqlLogger := NewSqlLogger(logger.LogLevel(config.Config.Mysql.LogLevel), true, time.Duration(config.Config.Mysql.SlowThreshold)*time.Millisecond) db, err = gorm.Open(mysql.Open(dsn), &gorm.Config{ - Logger: newLogger, + Logger: sqlLogger, }) if err != nil { return nil, err @@ -84,6 +87,70 @@ func IsMysqlDuplicateKey(err error) bool { return false } +type SqlLogger struct { + LogLevel logger.LogLevel + IgnoreRecordNotFoundError bool + SlowThreshold time.Duration +} + +func NewSqlLogger(logLevel logger.LogLevel, ignoreRecordNotFoundError bool, slowThreshold time.Duration) *SqlLogger { + return &SqlLogger{ + LogLevel: logLevel, + IgnoreRecordNotFoundError: ignoreRecordNotFoundError, + SlowThreshold: slowThreshold, + } +} + +func (l *SqlLogger) LogMode(logLevel logger.LogLevel) logger.Interface { + newLogger := *l + newLogger.LogLevel = logLevel + return &newLogger +} + +func (SqlLogger) Info(ctx context.Context, msg string, args ...interface{}) { + log.ZInfo(ctx, msg, args) +} + +func (SqlLogger) Warn(ctx context.Context, msg string, args ...interface{}) { + log.ZWarn(ctx, msg, nil, args) +} + +func (SqlLogger) Error(ctx context.Context, msg string, args ...interface{}) { + log.ZError(ctx, msg, nil, args) +} + +func (l SqlLogger) Trace(ctx context.Context, begin time.Time, fc func() (sql string, rowsAffected int64), err error) { + if l.LogLevel <= logger.Silent { + return + } + elapsed := time.Since(begin) + switch { + case err != nil && l.LogLevel >= logger.Error && (!errors.Is(err, gorm.ErrRecordNotFound) || !l.IgnoreRecordNotFoundError): + sql, rows := fc() + if rows == -1 { + log.ZError(ctx, utils.FileWithLineNum(), err, "time", float64(elapsed.Nanoseconds())/1e6, "sql", sql) + } else { + log.ZError(ctx, utils.FileWithLineNum(), err, "time", float64(elapsed.Nanoseconds())/1e6, "rows", rows, "sql", sql) + } + case elapsed > l.SlowThreshold && l.SlowThreshold != 0 && l.LogLevel >= logger.Warn: + sql, rows := fc() + slowLog := fmt.Sprintf("SLOW SQL >= %v", l.SlowThreshold) + if rows == -1 { + log.ZWarn(ctx, utils.FileWithLineNum(), nil, "slow sql", slowLog, "time", float64(elapsed.Nanoseconds())/1e6, "sql", sql) + } else { + log.ZWarn(ctx, utils.FileWithLineNum(), nil, "slow sql", slowLog, "time", float64(elapsed.Nanoseconds())/1e6, "rows", rows, "sql", sql) + } + case l.LogLevel == logger.Info: + sql, rows := fc() + if rows == -1 { + log.ZDebug(ctx, utils.FileWithLineNum(), "time", float64(elapsed.Nanoseconds())/1e6, "sql", sql) + } else { + log.ZDebug(ctx, utils.FileWithLineNum(), "time", float64(elapsed.Nanoseconds())/1e6, "rows", rows, "sql", sql) + + } + } +} + type Writer struct{} func (w Writer) Printf(format string, args ...interface{}) { diff --git a/pkg/common/log/zap.go b/pkg/common/log/zap.go index 18a11b7c2..d3872aaaf 100644 --- a/pkg/common/log/zap.go +++ b/pkg/common/log/zap.go @@ -51,11 +51,10 @@ type ZapLogger struct { func NewZapLogger() (*ZapLogger, error) { zapConfig := zap.Config{ - Level: zap.NewAtomicLevelAt(zapcore.DebugLevel), - Encoding: "json", - EncoderConfig: zap.NewProductionEncoderConfig(), - DisableStacktrace: true, - InitialFields: map[string]interface{}{"PID": os.Getegid()}, + Level: zap.NewAtomicLevelAt(zapcore.Level(config.Config.Log.RemainLogLevel)), + Encoding: "json", + EncoderConfig: zap.NewProductionEncoderConfig(), + InitialFields: map[string]interface{}{"PID": os.Getegid()}, } if config.Config.Log.Stderr { zapConfig.OutputPaths = append(zapConfig.OutputPaths, "stderr") @@ -70,7 +69,6 @@ func NewZapLogger() (*ZapLogger, error) { return nil, err } zl.zap = l.Sugar() - zl.zap.WithOptions(zap.AddStacktrace(zap.DPanicLevel)) return zl, nil } @@ -82,7 +80,6 @@ func (l *ZapLogger) cores() (zap.Option, error) { c.LevelKey = "level" c.TimeKey = "time" c.CallerKey = "caller" - //c.EncodeLevel = zapcore.LowercaseColorLevelEncoder fileEncoder := zapcore.NewJSONEncoder(c) fileEncoder.AddInt("PID", os.Getpid()) writer, err := l.getWriter() @@ -92,25 +89,17 @@ func (l *ZapLogger) cores() (zap.Option, error) { var cores []zapcore.Core if config.Config.Log.StorageLocation != "" { cores = []zapcore.Core{ - zapcore.NewCore(fileEncoder, writer, zapcore.DebugLevel), + zapcore.NewCore(fileEncoder, writer, zap.NewAtomicLevelAt(zapcore.Level(config.Config.Log.RemainLogLevel))), } } if config.Config.Log.Stderr { - cores = append(cores, zapcore.NewCore(fileEncoder, zapcore.Lock(os.Stdout), zapcore.DebugLevel)) + cores = append(cores, zapcore.NewCore(fileEncoder, zapcore.Lock(os.Stdout), zap.NewAtomicLevelAt(zapcore.Level(config.Config.Log.RemainLogLevel)))) } return zap.WrapCore(func(c zapcore.Core) zapcore.Core { return zapcore.NewTee(cores...) }), nil } -func NewErrStackCore(c zapcore.Core) zapcore.Core { - return &errStackCore{c} -} - -type errStackCore struct { - zapcore.Core -} - func (l *ZapLogger) getWriter() (zapcore.WriteSyncer, error) { logf, err := rotatelogs.New(config.Config.Log.StorageLocation+sp+"OpenIM.log.all"+".%Y-%m-%d", rotatelogs.WithRotationCount(config.Config.Log.RemainRotationCount), @@ -138,7 +127,7 @@ func (l *ZapLogger) Info(ctx context.Context, msg string, keysAndValues ...inter func (l *ZapLogger) Warn(ctx context.Context, msg string, err error, keysAndValues ...interface{}) { if err != nil { - keysAndValues = append(keysAndValues, "error", err) + keysAndValues = append(keysAndValues, "error", err.Error()) } keysAndValues = l.kvAppend(ctx, keysAndValues) l.zap.Warnw(msg, keysAndValues...) @@ -146,7 +135,7 @@ func (l *ZapLogger) Warn(ctx context.Context, msg string, err error, keysAndValu func (l *ZapLogger) Error(ctx context.Context, msg string, err error, keysAndValues ...interface{}) { if err != nil { - keysAndValues = append(keysAndValues, "error", err) + keysAndValues = append(keysAndValues, "error", err.Error()) } keysAndValues = append([]interface{}{constant.OperationID, tracelog.GetOperationID(ctx)}, keysAndValues...) l.zap.Errorw(msg, keysAndValues...) diff --git a/pkg/statistics/statistics.go b/pkg/statistics/statistics.go index d61c6098b..55a80bcb7 100644 --- a/pkg/statistics/statistics.go +++ b/pkg/statistics/statistics.go @@ -2,6 +2,7 @@ package statistics import ( "OpenIM/pkg/common/log" + "context" "time" ) @@ -29,7 +30,7 @@ func (s *Statistics) output() { intervalCount = *s.AllCount - sum } timeIntervalNum++ - log.NewWarn("", " system stat ", s.ModuleName, s.PrintArgs, intervalCount, "total:", *s.AllCount, "intervalNum", timeIntervalNum, "avg", (*s.AllCount)/(timeIntervalNum)/s.SleepTime) + log.ZWarn(context.Background(), " system stat ", nil, "args", s.PrintArgs, "intervalCount", intervalCount, "total:", *s.AllCount, "intervalNum", timeIntervalNum, "avg", (*s.AllCount)/(timeIntervalNum)/s.SleepTime) } }