Mirroristas/etcd
2
0
Fork 0
mirror of https://github.com/etcd-io/etcd.git synced 2024-09-27 06:25:44 +00:00
Code Issues Packages Projects Releases Wiki Activity

v3rpc: print expensive request info in UnaryInterceptor

Browse Source
This commit is contained in:
tangcong 2020-06-25 13:43:18 +08:00
parent e94dc39edc
commit 644d09edb5
1 changed files with 33 additions and 3 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

36
etcdserver/api/v3rpc/interceptor.go
View File

@ -33,7 +33,8 @@ import (
)
const (
maxNoLeaderCnt = 3
maxNoLeaderCnt = 3
warnUnaryRequestLatency = 300 * time.Millisecond
)
type streamsMap struct {
@ -75,7 +76,7 @@ func newLogUnaryInterceptor(s *etcdserver.EtcdServer) grpc.UnaryServerIntercepto
startTime := time.Now()
resp, err := handler(ctx, req)
lg := s.Logger()
if lg != nil && lg.Core().Enabled(zap.DebugLevel) { // only acquire stats if debug level is enabled
if lg != nil { // acquire stats if debug level is enabled or request is expensive
defer logUnaryRequestStats(ctx, lg, info, startTime, req, resp)
}
return resp, err
@ -84,6 +85,16 @@ func newLogUnaryInterceptor(s *etcdserver.EtcdServer) grpc.UnaryServerIntercepto
func logUnaryRequestStats(ctx context.Context, lg *zap.Logger, info *grpc.UnaryServerInfo, startTime time.Time, req interface{}, resp interface{}) {
duration := time.Since(startTime)
var enabledDebugLevel, expensiveRequest bool
if lg.Core().Enabled(zap.DebugLevel) {
enabledDebugLevel = true
}
if duration > warnUnaryRequestLatency {
expensiveRequest = true
}
if !enabledDebugLevel && !expensiveRequest {
return
}
remote := "No remote client info."
peerInfo, ok := peer.FromContext(ctx)
if ok {
@ -158,7 +169,11 @@ func logUnaryRequestStats(ctx context.Context, lg *zap.Logger, info *grpc.UnaryS
respSize = -1
}
logGenericRequestStats(lg, startTime, duration, remote, responseType, reqCount, reqSize, respCount, respSize, reqContent)
if enabledDebugLevel {
logGenericRequestStats(lg, startTime, duration, remote, responseType, reqCount, reqSize, respCount, respSize, reqContent)
} else if expensiveRequest {
logExpensiveRequestStats(lg, startTime, duration, remote, responseType, reqCount, reqSize, respCount, respSize, reqContent)
}
}
func logGenericRequestStats(lg *zap.Logger, startTime time.Time, duration time.Duration, remote string, responseType string,
@ -176,6 +191,21 @@ func logGenericRequestStats(lg *zap.Logger, startTime time.Time, duration time.D
)
}
func logExpensiveRequestStats(lg *zap.Logger, startTime time.Time, duration time.Duration, remote string, responseType string,
reqCount int64, reqSize int, respCount int64, respSize int, reqContent string) {
lg.Warn("request stats",
zap.Time("start time", startTime),
zap.Duration("time spent", duration),
zap.String("remote", remote),
zap.String("response type", responseType),
zap.Int64("request count", reqCount),
zap.Int("request size", reqSize),
zap.Int64("response count", respCount),
zap.Int("response size", respSize),
zap.String("request content", reqContent),
)
}
func newStreamInterceptor(s *etcdserver.EtcdServer) grpc.StreamServerInterceptor {
smap := monitorLeader(s)