github.com/lingyao2333/mo-zero@v1.4.1/core/stores/redis/hook.go (about)

     1  package redis
     2  
     3  import (
     4  	"context"
     5  	"io"
     6  	"net"
     7  	"strings"
     8  	"time"
     9  
    10  	red "github.com/go-redis/redis/v8"
    11  	"github.com/lingyao2333/mo-zero/core/breaker"
    12  	"github.com/lingyao2333/mo-zero/core/errorx"
    13  	"github.com/lingyao2333/mo-zero/core/logx"
    14  	"github.com/lingyao2333/mo-zero/core/mapping"
    15  	"github.com/lingyao2333/mo-zero/core/timex"
    16  	"github.com/lingyao2333/mo-zero/core/trace"
    17  	"go.opentelemetry.io/otel"
    18  	"go.opentelemetry.io/otel/attribute"
    19  	"go.opentelemetry.io/otel/codes"
    20  	oteltrace "go.opentelemetry.io/otel/trace"
    21  )
    22  
    23  // spanName is the span name of the redis calls.
    24  const spanName = "redis"
    25  
    26  var (
    27  	startTimeKey          = contextKey("startTime")
    28  	durationHook          = hook{tracer: otel.GetTracerProvider().Tracer(trace.TraceName)}
    29  	redisCmdsAttributeKey = attribute.Key("redis.cmds")
    30  )
    31  
    32  type (
    33  	contextKey string
    34  	hook       struct {
    35  		tracer oteltrace.Tracer
    36  	}
    37  )
    38  
    39  func (h hook) BeforeProcess(ctx context.Context, cmd red.Cmder) (context.Context, error) {
    40  	return h.startSpan(context.WithValue(ctx, startTimeKey, timex.Now()), cmd), nil
    41  }
    42  
    43  func (h hook) AfterProcess(ctx context.Context, cmd red.Cmder) error {
    44  	err := cmd.Err()
    45  	h.endSpan(ctx, err)
    46  
    47  	val := ctx.Value(startTimeKey)
    48  	if val == nil {
    49  		return nil
    50  	}
    51  
    52  	start, ok := val.(time.Duration)
    53  	if !ok {
    54  		return nil
    55  	}
    56  
    57  	duration := timex.Since(start)
    58  	if duration > slowThreshold.Load() {
    59  		logDuration(ctx, []red.Cmder{cmd}, duration)
    60  	}
    61  
    62  	metricReqDur.Observe(int64(duration/time.Millisecond), cmd.Name())
    63  	if msg := formatError(err); len(msg) > 0 {
    64  		metricReqErr.Inc(cmd.Name(), msg)
    65  	}
    66  
    67  	return nil
    68  }
    69  
    70  func (h hook) BeforeProcessPipeline(ctx context.Context, cmds []red.Cmder) (context.Context, error) {
    71  	if len(cmds) == 0 {
    72  		return ctx, nil
    73  	}
    74  
    75  	return h.startSpan(context.WithValue(ctx, startTimeKey, timex.Now()), cmds...), nil
    76  }
    77  
    78  func (h hook) AfterProcessPipeline(ctx context.Context, cmds []red.Cmder) error {
    79  	if len(cmds) == 0 {
    80  		return nil
    81  	}
    82  
    83  	batchError := errorx.BatchError{}
    84  	for _, cmd := range cmds {
    85  		err := cmd.Err()
    86  		if err == nil {
    87  			continue
    88  		}
    89  
    90  		batchError.Add(err)
    91  	}
    92  	h.endSpan(ctx, batchError.Err())
    93  
    94  	val := ctx.Value(startTimeKey)
    95  	if val == nil {
    96  		return nil
    97  	}
    98  
    99  	start, ok := val.(time.Duration)
   100  	if !ok {
   101  		return nil
   102  	}
   103  
   104  	duration := timex.Since(start)
   105  	if duration > slowThreshold.Load()*time.Duration(len(cmds)) {
   106  		logDuration(ctx, cmds, duration)
   107  	}
   108  
   109  	metricReqDur.Observe(int64(duration/time.Millisecond), "Pipeline")
   110  	if msg := formatError(batchError.Err()); len(msg) > 0 {
   111  		metricReqErr.Inc("Pipeline", msg)
   112  	}
   113  
   114  	return nil
   115  }
   116  
   117  func formatError(err error) string {
   118  	if err == nil || err == red.Nil {
   119  		return ""
   120  	}
   121  
   122  	opErr, ok := err.(*net.OpError)
   123  	if ok && opErr.Timeout() {
   124  		return "timeout"
   125  	}
   126  
   127  	switch err {
   128  	case io.EOF:
   129  		return "eof"
   130  	case context.DeadlineExceeded:
   131  		return "context deadline"
   132  	case breaker.ErrServiceUnavailable:
   133  		return "breaker"
   134  	default:
   135  		return "unexpected error"
   136  	}
   137  }
   138  
   139  func logDuration(ctx context.Context, cmds []red.Cmder, duration time.Duration) {
   140  	var buf strings.Builder
   141  	for k, cmd := range cmds {
   142  		if k > 0 {
   143  			buf.WriteByte('\n')
   144  		}
   145  		var build strings.Builder
   146  		for i, arg := range cmd.Args() {
   147  			if i > 0 {
   148  				build.WriteByte(' ')
   149  			}
   150  			build.WriteString(mapping.Repr(arg))
   151  		}
   152  		buf.WriteString(build.String())
   153  	}
   154  	logx.WithContext(ctx).WithDuration(duration).Slowf("[REDIS] slowcall on executing: %s", buf.String())
   155  }
   156  
   157  func (h hook) startSpan(ctx context.Context, cmds ...red.Cmder) context.Context {
   158  	ctx, span := h.tracer.Start(ctx,
   159  		spanName,
   160  		oteltrace.WithSpanKind(oteltrace.SpanKindClient),
   161  	)
   162  
   163  	cmdStrs := make([]string, 0, len(cmds))
   164  	for _, cmd := range cmds {
   165  		cmdStrs = append(cmdStrs, cmd.Name())
   166  	}
   167  	span.SetAttributes(redisCmdsAttributeKey.StringSlice(cmdStrs))
   168  
   169  	return ctx
   170  }
   171  
   172  func (h hook) endSpan(ctx context.Context, err error) {
   173  	span := oteltrace.SpanFromContext(ctx)
   174  	defer span.End()
   175  
   176  	if err == nil || err == red.Nil {
   177  		span.SetStatus(codes.Ok, "")
   178  		return
   179  	}
   180  
   181  	span.SetStatus(codes.Error, err.Error())
   182  	span.RecordError(err)
   183  }