Add extra details to query spans. (#2636)

* Log min/max time, matchers.

Signed-off-by: Peter Štibraný <[email protected]>

* Add tracing to series set to see how until when series set is iterated.

Signed-off-by: Peter Štibraný <[email protected]>

* Log labels of iterated series, and current series and samples counts.

Signed-off-by: Peter Štibraný <[email protected]>

* Don't log all series, only every 100th, to avoid creating too many logs.

Signed-off-by: Peter Štibraný <[email protected]>

* Removed tracing_set, as it proved to be useless.

Signed-off-by: Peter Štibraný <[email protected]>

* Move matchers logging to querier.go.

Signed-off-by: Peter Štibraný <[email protected]>

Author: pstibrany

pkg/querier/block.go

@@ -5,6 +5,7 @@ import (
 	"math"
 	"sort"
 
+	"github.com/go-kit/kit/log/level"
 	"github.com/pkg/errors"
 	"github.com/prometheus/client_golang/prometheus"
 	"github.com/prometheus/prometheus/pkg/labels"
@@ -108,9 +109,9 @@ func (b *blocksQuerier) Select(_ bool, sp *storage.SelectHints, matchers ...*lab
 		return nil, nil, promql.ErrStorage{Err: err}
 	}
 
-	return &blockQuerierSeriesSet{
-		series: series,
-	}, warnings, nil
+	level.Debug(log).Log("series", len(series), "warnings", len(warnings))
+
+	return &blockQuerierSeriesSet{series: series}, warnings, nil
 }
 
 func convertMatchersToLabelMatcher(matchers []*labels.Matcher) []storepb.LabelMatcher {

pkg/querier/querier.go

@@ -247,7 +247,7 @@ func (q querier) Select(_ bool, sp *storage.SelectHints, matchers ...*labels.Mat
 	defer log.Span.Finish()
 
 	if sp != nil {
-		level.Debug(log).Log("start", util.TimeFromMillis(sp.Start).UTC().String(), "end", util.TimeFromMillis(sp.End).UTC().String(), "step", sp.Step)
+		level.Debug(log).Log("start", util.TimeFromMillis(sp.Start).UTC().String(), "end", util.TimeFromMillis(sp.End).UTC().String(), "step", sp.Step, "matchers", matchers)
 	}
 
 	// Kludge: Prometheus passes nil SelectHints if it is doing a 'series' operation,