Adds execution timer stats to the range query

API consumers should be able to get insight into the query run times.
The UI currently measures total roundtrip times. This PR allows for more
fine grained metrics to be exposed.

* adds new timer for total execution time (queue + eval)

* expose new timer, queue timer, and eval timer in stats field of the
 range query response:
```json
{
  "status": "success",
  "data": {
    "resultType": "matrix",
    "result": [],
    "stats": {
      "execQueueTimeNs": 4683,
      "execTotalTimeNs": 2086587,
      "totalEvalTimeNs": 2077851
    }
  }
}
```

* stats field is optional, only set when query parameter `stats` is not
empty

Try it via
```sh
curl 'http://localhost:9090/api/v1/query_range?query=up&start=1486480279&end=1486483879&step=14000&stats=true'
```

Review feedback

* moved query stats json generation to query_stats.go
* use seconds for all query timers
* expose all timers available
* Changed ExecTotalTime string representation from Exec queue total time to Exec total time
This commit is contained in:
David Kaltschmidt 2017-02-08 12:58:40 +01:00
parent a51c500e30
commit c93e54d240
4 changed files with 57 additions and 0 deletions

View file

@ -314,6 +314,8 @@ func (ng *Engine) exec(ctx context.Context, q *query) (Value, error) {
ctx, cancel := context.WithTimeout(ctx, ng.options.Timeout) ctx, cancel := context.WithTimeout(ctx, ng.options.Timeout)
q.cancel = cancel q.cancel = cancel
execTimer := q.stats.GetTimer(stats.ExecTotalTime).Start()
defer execTimer.Stop()
queueTimer := q.stats.GetTimer(stats.ExecQueueTime).Start() queueTimer := q.stats.GetTimer(stats.ExecQueueTime).Start()
if err := ng.gate.Start(ctx); err != nil { if err := ng.gate.Start(ctx); err != nil {

View file

@ -25,6 +25,7 @@ const (
InnerEvalTime InnerEvalTime
ResultAppendTime ResultAppendTime
ExecQueueTime ExecQueueTime
ExecTotalTime
) )
// Return a string representation of a QueryTiming identifier. // Return a string representation of a QueryTiming identifier.
@ -42,7 +43,47 @@ func (s QueryTiming) String() string {
return "Result append time" return "Result append time"
case ExecQueueTime: case ExecQueueTime:
return "Exec queue wait time" return "Exec queue wait time"
case ExecTotalTime:
return "Exec total time"
default: default:
return "Unknown query timing" return "Unknown query timing"
} }
} }
// QueryStats with all query timers mapped to durations.
type QueryStats struct {
TotalEvalTime float64 `json:"totalEvalTime"`
ResultSortTime float64 `json:"resultSortTime"`
QueryPreparationTime float64 `json:"queryPreparationTime"`
InnerEvalTime float64 `json:"innerEvalTime"`
ResultAppendTime float64 `json:"resultAppendTime"`
ExecQueueTime float64 `json:"execQueueTime"`
ExecTotalTime float64 `json:"execTotalTime"`
}
// MakeQueryStats makes a QueryStats struct with all QueryTimings found in the
// given TimerGroup.
func MakeQueryStats(tg *TimerGroup) *QueryStats {
var qs QueryStats
for s, timer := range tg.timers {
switch s {
case TotalEvalTime:
qs.TotalEvalTime = timer.Duration()
case ResultSortTime:
qs.ResultSortTime = timer.Duration()
case QueryPreparationTime:
qs.QueryPreparationTime = timer.Duration()
case InnerEvalTime:
qs.InnerEvalTime = timer.Duration()
case ResultAppendTime:
qs.ResultAppendTime = timer.Duration()
case ExecQueueTime:
qs.ExecQueueTime = timer.Duration()
case ExecTotalTime:
qs.ExecTotalTime = timer.Duration()
}
}
return &qs
}

View file

@ -45,6 +45,11 @@ func (t *Timer) ElapsedTime() time.Duration {
return time.Since(t.start) return time.Since(t.start)
} }
// Duration returns the duration value of the timer in seconds.
func (t *Timer) Duration() float64 {
return t.duration.Seconds()
}
// Return a string representation of the Timer. // Return a string representation of the Timer.
func (t *Timer) String() string { func (t *Timer) String() string {
return fmt.Sprintf("%s: %s", t.name, t.duration) return fmt.Sprintf("%s: %s", t.name, t.duration)

View file

@ -38,6 +38,7 @@ import (
"github.com/prometheus/prometheus/storage" "github.com/prometheus/prometheus/storage"
"github.com/prometheus/prometheus/storage/remote" "github.com/prometheus/prometheus/storage/remote"
"github.com/prometheus/prometheus/util/httputil" "github.com/prometheus/prometheus/util/httputil"
"github.com/prometheus/prometheus/util/stats"
) )
type status string type status string
@ -172,6 +173,7 @@ func (api *API) Register(r *route.Router) {
type queryData struct { type queryData struct {
ResultType promql.ValueType `json:"resultType"` ResultType promql.ValueType `json:"resultType"`
Result promql.Value `json:"result"` Result promql.Value `json:"result"`
Stats *stats.QueryStats `json:"stats,omitempty"`
} }
func (api *API) options(r *http.Request) (interface{}, *apiError) { func (api *API) options(r *http.Request) (interface{}, *apiError) {
@ -284,9 +286,16 @@ func (api *API) queryRange(r *http.Request) (interface{}, *apiError) {
return nil, &apiError{errorExec, res.Err} return nil, &apiError{errorExec, res.Err}
} }
// Optional stats field in response if parameter "stats" is not empty.
var qs *stats.QueryStats
if r.FormValue("stats") != "" {
qs = stats.MakeQueryStats(qry.Stats())
}
return &queryData{ return &queryData{
ResultType: res.Value.Type(), ResultType: res.Value.Type(),
Result: res.Value, Result: res.Value,
Stats: qs,
}, nil }, nil
} }