Improve the frontend slow query logs. (#2520)

* Improve the frontend slow query logs. This will help for the log to be more readable, parsable. Signed-off-by: Cyril Tovena <cyril.tovena@gmail.com> * Fixed query string in slow query logging Signed-off-by: Marco Pracucci <marco@pracucci.com> * Added CHANGELOG.md Signed-off-by: Peter Štibraný <peter.stibrany@grafana.com> * Use f.log instead of util.Logger Signed-off-by: Peter Štibraný <peter.stibrany@grafana.com> Co-authored-by: Marco Pracucci <marco@pracucci.com> Co-authored-by: Peter Štibraný <peter.stibrany@grafana.com>
cortexproject · Apr 24, 2020 · 06c4920 · 06c4920
1 parent 4ef3853
commit 06c4920
Show file tree

Hide file tree

Showing 2 changed files with 12 additions and 9 deletions.
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -19,6 +19,7 @@
 * [CHANGE] Experimental TSDB: Modified default values for `compactor.deletion-delay` option from 48h to 12h and `-experimental.tsdb.bucket-store.ignore-deletion-marks-delay` from 24h to 6h. #2414
 * [CHANGE] Experimental WAL: Default value of `-ingester.checkpoint-enabled` changed to `true`. #2416
 * [CHANGE] `trace_id` field in log files has been renamed to `traceID`. #2518
+* [CHANGE] Slow query log has a different output now. Previously used `url` field has been replaced with `host` and `path`, and query parameters are logged as individual log fields with `qs_` prefix. #2520
 * [FEATURE] Ruler: The `-ruler.evaluation-delay` flag was added to allow users to configure a default evaluation delay for all rules in cortex. The default value is 0 which is the current behavior. #2423
 * [ENHANCEMENT] Experimental TSDB: sample ingestion errors are now reported via existing `cortex_discarded_samples_total` metric. #2370
 * [ENHANCEMENT] Failures on samples at distributors and ingesters return the first validation error as opposed to the last. #2383

diff --git a/pkg/querier/frontend/frontend.go b/pkg/querier/frontend/frontend.go
@@ -11,6 +11,7 @@ import (
 	"net/http"
 	"net/url"
 	"path"
+	"strings"
 	"sync"
 	"time"
 
@@ -23,6 +24,8 @@ import (
 	"github.com/weaveworks/common/httpgrpc"
 	"github.com/weaveworks/common/httpgrpc/server"
 	"github.com/weaveworks/common/user"
+
+	"github.com/cortexproject/cortex/pkg/util"
 )
 
 const (
@@ -152,27 +155,26 @@ func (f *Frontend) Handler() http.Handler {
 }
 
 func (f *Frontend) handle(w http.ResponseWriter, r *http.Request) {
-	userID, err := user.ExtractOrgID(r.Context())
-	if err != nil {
-		server.WriteError(w, err)
-		return
-	}
 
 	startTime := time.Now()
 	resp, err := f.roundTripper.RoundTrip(r)
 	queryResponseTime := time.Since(startTime)
 
 	if f.cfg.LogQueriesLongerThan > 0 && queryResponseTime > f.cfg.LogQueriesLongerThan {
-		logMessage := []interface{}{"msg", "slow query",
-			"org_id", userID,
-			"url", fmt.Sprintf("http://%s", r.Host+r.RequestURI),
+		logMessage := []interface{}{
+			"msg", "slow query",
+			"host", r.Host,
+			"path", r.URL.Path,
 			"time_taken", queryResponseTime.String(),
 		}
+		for k, v := range r.URL.Query() {
+			logMessage = append(logMessage, fmt.Sprintf("qs_%s", k), strings.Join(v, ","))
+		}
 		pf := r.PostForm.Encode()
 		if pf != "" {
 			logMessage = append(logMessage, "body", pf)
 		}
-		level.Info(f.log).Log(logMessage...)
+		level.Info(util.WithContext(r.Context(), f.log)).Log(logMessage...)
 	}
 
 	if err != nil {