From 5cbd4cfca949a3c85354e2408e7ce1a7f9a683bc Mon Sep 17 00:00:00 2001 From: Aliaksandr Valialkin Date: Fri, 24 May 2019 16:12:31 +0300 Subject: [PATCH] app/vmselect: log slow queries if their execution time exceeds `-search.logSlowQueryDuration` --- app/vmselect/promql/exec.go | 15 +++++++++++++++ 1 file changed, 15 insertions(+) diff --git a/app/vmselect/promql/exec.go b/app/vmselect/promql/exec.go index d686f9008..696ee8038 100644 --- a/app/vmselect/promql/exec.go +++ b/app/vmselect/promql/exec.go @@ -1,16 +1,21 @@ package promql import ( + "flag" "fmt" "math" "sort" "sync" "sync/atomic" + "time" "github.com/VictoriaMetrics/VictoriaMetrics/app/vmselect/netstorage" + "github.com/VictoriaMetrics/VictoriaMetrics/lib/logger" "github.com/VictoriaMetrics/metrics" ) +var logSlowQueryDuration = flag.Duration("search.logSlowQueryDuration", 5*time.Second, "Log queries with execution time exceeding this value. Zero disables slow query logging") + // ExpandWithExprs expands WITH expressions inside q and returns the resulting // PromQL without WITH expressions. func ExpandWithExprs(q string) (string, error) { @@ -24,6 +29,16 @@ func ExpandWithExprs(q string) (string, error) { // Exec executes q for the given ec until the deadline. func Exec(ec *EvalConfig, q string) ([]netstorage.Result, error) { + if *logSlowQueryDuration > 0 { + startTime := time.Now() + defer func() { + d := time.Since(startTime) + if d >= *logSlowQueryDuration { + logger.Infof("slow query: duration=%s, start=%d, end=%d, step=%d, query=%q", d, ec.Start/1000, ec.End/1000, ec.Step/1000, q) + } + }() + } + ec.validate() e, err := parsePromQLWithCache(q)