enhance: [2.5] Add an extra parameter for slow log (#40759)

Cherry-pick from master
pr: #40758
Related to #40756

Signed-off-by: Congqi Xia <congqi.xia@zilliz.com>
This commit is contained in:
congqixia 2025-03-19 18:10:13 +08:00 committed by GitHub
parent d1359010d0
commit cd8d7efc96
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
2 changed files with 35 additions and 15 deletions

View File

@ -3127,13 +3127,10 @@ func (node *Proxy) search(ctx context.Context, request *milvuspb.SearchRequest,
defer func() {
span := tr.ElapseSpan()
if span >= paramtable.Get().ProxyCfg.SlowQuerySpanInSeconds.GetAsDuration(time.Second) {
if span >= paramtable.Get().ProxyCfg.SlowLogSpanInSeconds.GetAsDuration(time.Second) {
log.Info(rpcSlow(method), zap.Uint64("guarantee_timestamp", qt.GetGuaranteeTimestamp()),
zap.Int64("nq", qt.SearchRequest.GetNq()), zap.Duration("duration", span))
metrics.ProxySlowQueryCount.WithLabelValues(
strconv.FormatInt(paramtable.GetNodeID(), 10),
metrics.SearchLabel,
).Inc()
// WebUI slow query shall use slow log as well.
user, _ := GetCurUserFromContext(ctx)
traceID := ""
if sp != nil {
@ -3143,6 +3140,12 @@ func (node *Proxy) search(ctx context.Context, request *milvuspb.SearchRequest,
node.slowQueries.Add(qt.BeginTs(), metricsinfo.NewSlowQueryWithSearchRequest(request, user, span, traceID))
}
}
if span >= paramtable.Get().ProxyCfg.SlowQuerySpanInSeconds.GetAsDuration(time.Second) {
metrics.ProxySlowQueryCount.WithLabelValues(
strconv.FormatInt(paramtable.GetNodeID(), 10),
metrics.SearchLabel,
).Inc()
}
}()
log.Debug(rpcReceived(method))
@ -3360,12 +3363,9 @@ func (node *Proxy) hybridSearch(ctx context.Context, request *milvuspb.HybridSea
defer func() {
span := tr.ElapseSpan()
if span >= paramtable.Get().ProxyCfg.SlowQuerySpanInSeconds.GetAsDuration(time.Second) {
if span >= paramtable.Get().ProxyCfg.SlowLogSpanInSeconds.GetAsDuration(time.Second) {
log.Info(rpcSlow(method), zap.Uint64("guarantee_timestamp", qt.GetGuaranteeTimestamp()), zap.Duration("duration", span))
metrics.ProxySlowQueryCount.WithLabelValues(
strconv.FormatInt(paramtable.GetNodeID(), 10),
metrics.HybridSearchLabel,
).Inc()
// WebUI slow query shall use slow log as well.
user, _ := GetCurUserFromContext(ctx)
traceID := ""
if sp != nil {
@ -3375,6 +3375,12 @@ func (node *Proxy) hybridSearch(ctx context.Context, request *milvuspb.HybridSea
node.slowQueries.Add(qt.BeginTs(), metricsinfo.NewSlowQueryWithSearchRequest(newSearchReq, user, span, traceID))
}
}
if span >= paramtable.Get().ProxyCfg.SlowQuerySpanInSeconds.GetAsDuration(time.Second) {
metrics.ProxySlowQueryCount.WithLabelValues(
strconv.FormatInt(paramtable.GetNodeID(), 10),
metrics.HybridSearchLabel,
).Inc()
}
}()
log.Debug(rpcReceived(method))
@ -3645,7 +3651,7 @@ func (node *Proxy) query(ctx context.Context, qt *queryTask, sp trace.Span) (*mi
defer func() {
span := tr.ElapseSpan()
if span >= paramtable.Get().ProxyCfg.SlowQuerySpanInSeconds.GetAsDuration(time.Second) {
if span >= paramtable.Get().ProxyCfg.SlowLogSpanInSeconds.GetAsDuration(time.Second) {
log.Info(
rpcSlow(method),
zap.String("expr", request.Expr),
@ -3653,10 +3659,7 @@ func (node *Proxy) query(ctx context.Context, qt *queryTask, sp trace.Span) (*mi
zap.Uint64("travel_timestamp", request.TravelTimestamp),
zap.Uint64("guarantee_timestamp", qt.GetGuaranteeTimestamp()),
zap.Duration("duration", span))
metrics.ProxySlowQueryCount.WithLabelValues(
strconv.FormatInt(paramtable.GetNodeID(), 10),
metrics.QueryLabel,
).Inc()
// WebUI slow query shall use slow log as well.
user, _ := GetCurUserFromContext(ctx)
traceID := ""
if sp != nil {
@ -3667,6 +3670,12 @@ func (node *Proxy) query(ctx context.Context, qt *queryTask, sp trace.Span) (*mi
node.slowQueries.Add(qt.BeginTs(), metricsinfo.NewSlowQueryWithQueryRequest(request, user, span, traceID))
}
}
if span >= paramtable.Get().ProxyCfg.SlowQuerySpanInSeconds.GetAsDuration(time.Second) {
metrics.ProxySlowQueryCount.WithLabelValues(
strconv.FormatInt(paramtable.GetNodeID(), 10),
metrics.QueryLabel,
).Inc()
}
}()
if err := node.sched.dqQueue.Enqueue(qt); err != nil {

View File

@ -1387,6 +1387,7 @@ type proxyConfig struct {
GracefulStopTimeout ParamItem `refreshable:"true"`
SlowQuerySpanInSeconds ParamItem `refreshable:"true"`
SlowLogSpanInSeconds ParamItem `refreshable:"true"`
QueryNodePoolingSize ParamItem `refreshable:"false"`
}
@ -1833,6 +1834,16 @@ please adjust in embedded Milvus: false`,
}
p.SlowQuerySpanInSeconds.Init(base.mgr)
p.SlowLogSpanInSeconds = ParamItem{
Key: "proxy.slowLogSpanInSeconds",
Version: "2.5.8",
Doc: "query whose executed time exceeds the `slowLogSpanInSeconds` will have slow log, in seconds.",
DefaultValue: "1",
FallbackKeys: []string{"proxy.slowQuerySpanInSeconds"},
Export: false,
}
p.SlowLogSpanInSeconds.Init(base.mgr)
p.QueryNodePoolingSize = ParamItem{
Key: "proxy.queryNodePooling.size",
Version: "2.4.7",