集成gorm日志

jukylin · Jan 8, 2021 · 7c71f96 · 7c71f96
1 parent f64f687
commit 7c71f96
Show file tree

Hide file tree

Showing 7 changed files with 100 additions and 31 deletions.
diff --git a/grpc/grpc_server.go b/grpc/grpc_server.go
@@ -111,6 +111,8 @@ func NewServer(target string, options ...ServerOption) *Server {
 			otgrpc.OpenTracingServerInterceptor(Server.tracer))
 	}
 
+	unaryServerInterceptors = append(unaryServerInterceptors, Server.tracerID())
+
 	if Server.conf.GetBool("grpc_server_metrics") {
 		ggp.EnableHandlingTimeHistogram()
 		serverMetrics := ggp.DefaultServerMetrics
@@ -127,8 +129,6 @@ func NewServer(target string, options ...ServerOption) *Server {
 		unaryServerInterceptors = append(unaryServerInterceptors, Server.serverDebug())
 	}
 
-	unaryServerInterceptors = append(unaryServerInterceptors, Server.tracerID())
-
 	// handle panic
 	opts := []grpc_recovery.Option{
 		grpc_recovery.WithRecoveryHandlerContext(Server.handelPanic()),

diff --git a/log/gorm_logger.go b/log/gorm_logger.go
@@ -46,28 +46,37 @@ func (gl *gormLogger) LogMode(logLevel glogger.LogLevel) glogger.Interface {
 }
 
 func (gl *gormLogger) Info(ctx context.Context, template string, args ...interface{}) {
-	gl.sugar.With(gl.ez.getGormArgs(ctx)...).Infof(template, args...)
+	gl.sugar.With(gl.ez.getArgs(ctx)...).Debugf(template, args...)
 }
 
 func (gl *gormLogger) Warn(ctx context.Context, template string, args ...interface{}) {
-	gl.sugar.With(gl.ez.getGormArgs(ctx)...).Warnf(template, args...)
+	gl.sugar.With(gl.ez.getArgs(ctx)...).Warnf(template, args...)
 }
 
 func (gl *gormLogger) Error(ctx context.Context, template string, args ...interface{}) {
-	gl.sugar.With(gl.ez.getGormArgs(ctx)...).Errorf(template, args...)
+	gl.sugar.With(gl.ez.getArgs(ctx)...).Errorf(template, args...)
 }
 
 func (gl *gormLogger) Trace(ctx context.Context, begin time.Time,
 	fc func() (string, int64), err error) {
-	if gl.logLevel > 0 {
+	if gl.logLevel > 0 && fc != nil {
 		elapsed := time.Since(begin)
-		sql, rows := fc()
 		switch {
-		case err != nil && err != gorm.ErrRecordNotFound && gl.logLevel >= glogger.Error:
-			gl.sugar.With(gl.ez.getGormArgs(ctx)...).Errorf("%.2fms [%d] %s : %s",
+		case err != nil && err != gorm.ErrRecordNotFound && gl.logLevel == glogger.Error:
+			sql, rows := fc()
+			gl.Error(ctx, "%.2fms [%d] %s : %s",
 				float64(elapsed.Nanoseconds())/1e6, rows, sql, err.Error())
-		case gl.logLevel >= glogger.Info:
-			gl.sugar.With(gl.ez.getGormArgs(ctx)...).Debugf("%.2fms [%d] %s",
+		case gl.logLevel == glogger.Warn:
+			sql, rows := fc()
+			gl.Warn(ctx,"%.2fms [%d] %s",
+				float64(elapsed.Nanoseconds())/1e6, rows, sql)
+		case gl.logLevel == glogger.Info:
+			sql, rows := fc()
+			gl.Info(ctx, "%.2fms [%d] %s",
+				float64(elapsed.Nanoseconds())/1e6, rows, sql)
+		default:
+			sql, rows := fc()
+			gl.Info(ctx, "%.2fms [%d] %s",
 				float64(elapsed.Nanoseconds())/1e6, rows, sql)
 		}
 	}

diff --git a/log/gorm_logger_test.go b/log/gorm_logger_test.go
@@ -0,0 +1,70 @@
+package log
+
+import (
+	"context"
+	"testing"
+	"time"
+
+	glogger "gorm.io/gorm/logger"
+	"errors"
+	"gorm.io/gorm"
+)
+
+func Test_gormLogger_Trace(t *testing.T) {
+	type fields struct {
+		logLevel glogger.LogLevel
+		ez       *EsimZap
+	}
+	type args struct {
+		ctx   context.Context
+		begin time.Time
+		fc    func() (string, int64)
+		err   error
+	}
+
+	z := NewEsimZap(
+		WithEsimZapJSON(true),
+		WithEsimZapDebug(true),
+	)
+	ctx := context.Background()
+
+	tests := []struct {
+		name   string
+		fields fields
+		args   args
+	}{
+		{"Error",
+		fields{ez:z, logLevel : glogger.Error},
+		args{ctx, time.Now(), func() (string, int64) {
+			return "select * from Error;", 10
+		}, errors.New("error")}},
+		{"Error ErrRecordNotFound",
+			fields{ez:z, logLevel : glogger.Error},
+			args{ctx, time.Now(), func() (string, int64) {
+				return "select * from ErrRecordNotFound;", 0
+			}, gorm.ErrRecordNotFound}},
+		{"Warn",
+			fields{ez:z, logLevel : glogger.Warn},
+			args{ctx, time.Now(), func() (string, int64) {
+				return "select * from Warn;", 0
+			}, nil}},
+
+		{"Info",
+			fields{ez:z, logLevel : glogger.Info},
+			args{ctx, time.Now(), func() (string, int64) {
+				return "select * from Info;", 0
+			}, nil}},
+		{"fc 为 nil",
+			fields{ez:z, logLevel : glogger.Info},
+			args{ctx, time.Now(), nil, nil}},
+	}
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			gl := NewGormLogger(
+				WithGLogEsimZap(tt.fields.ez),
+			)
+			gl.LogMode(tt.fields.logLevel)
+			gl.Trace(tt.args.ctx, tt.args.begin, tt.args.fc, tt.args.err)
+		})
+	}
+}
diff --git a/log/logger_test.go b/log/logger_test.go
@@ -9,7 +9,6 @@ import (
 )
 
 func TestLog(t *testing.T) {
-
 	ez := NewEsimZap(
 		WithEsimZapDebug(true),
 		WithEsimZapJSON(true),

diff --git a/log/zap.go b/log/zap.go
@@ -91,7 +91,7 @@ func (ez *EsimZap) standardTimeEncoder(t time.Time, enc zapcore.PrimitiveArrayEn
 func (ez *EsimZap) getArgs(ctx context.Context) []interface{} {
 	args := make([]interface{}, 0)
 
-	args = append(args, "caller", ez.getCaller(runtime.Caller(2)))
+	args = append(args, "caller", ez.getCaller())
 	tracerID := tracerid.ExtractTracerID(ctx)
 	if tracerID != "" {
 		args = append(args, "tracer_id", tracerID)
@@ -100,14 +100,14 @@ func (ez *EsimZap) getArgs(ctx context.Context) []interface{} {
 	return args
 }
 
-func (ez *EsimZap) getGormArgs(ctx context.Context) []interface{} {
-	args := make([]interface{}, 0)
+func (ez *EsimZap) getCaller() string {
 	var fullPath string
 	var offidx int
 
 	for i := 0; i < 15; i++ {
 		_, file, line, ok := runtime.Caller(i)
-		if ok && (strings.Index(file, "esim") == -1) {
+		if ok && (strings.Index(file, "esim") == -1 && strings.Index(file, "gorm") == -1 &&
+		strings.Index(file, "redigo") == -1) {
 			fullPath = file + ":" + strconv.FormatInt(int64(line), 10)
 			break
 		}
@@ -124,15 +124,5 @@ func (ez *EsimZap) getGormArgs(ctx context.Context) []interface{} {
 		offidx = idx
 	}
 
-	args = append(args, "caller", fullPath[offidx+1:])
-	tracerID := tracerid.ExtractTracerID(ctx)
-	if tracerID != "" {
-		args = append(args, "tracer_id", tracerID)
-	}
-
-	return args
-}
-
-func (ez *EsimZap) getCaller(pc uintptr, file string, line int, ok bool) string {
-	return zapcore.NewEntryCaller(pc, file, line, ok).TrimmedPath()
+	return fullPath[offidx+1:]
 }
diff --git a/log/zap_test.go b/log/zap_test.go
@@ -6,7 +6,7 @@ import (
 	"testing"
 )
 
-func Test_esimZap_getGormArgs(t *testing.T) {
+func Test_esimZap_getArgs(t *testing.T) {
 	type args struct {
 		ctx context.Context
 	}
@@ -23,9 +23,9 @@ func Test_esimZap_getGormArgs(t *testing.T) {
 	for _, tt := range tests {
 		t.Run(tt.name, func(t *testing.T) {
 			ez := NewEsimZap()
-			if got := ez.getGormArgs(tt.args.ctx); !reflect.DeepEqual(got, tt.want) {
-				t.Errorf("esimZap.getGormArgs() = %v, want %v", got, tt.want)
+			if got := ez.getArgs(tt.args.ctx); !reflect.DeepEqual(got, tt.want) {
+				t.Errorf("esimZap.getArgs() = %v, want %v", got, tt.want)
 			}
 		})
 	}
-}
+}
diff --git a/tool/new/infra_fc.go b/tool/new/infra_fc.go
@@ -8,6 +8,7 @@ var (
 
 import (
 	"sync"
+	"gorm.io/gorm"
 	"github.com/google/wire"
 	"github.com/jukylin/esim/container"
 	"github.com/jukylin/esim/mysql"