From ba4976260c6a219f37f1e0726208596955310530 Mon Sep 17 00:00:00 2001 From: Cyril Tovena Date: Thu, 23 Apr 2020 18:24:05 -0400 Subject: [PATCH 1/4] Improve the frontend slow query logs. This will help for the log to be more readable, parsable. Signed-off-by: Cyril Tovena --- pkg/querier/frontend/frontend.go | 20 +++++++++++--------- 1 file changed, 11 insertions(+), 9 deletions(-) diff --git a/pkg/querier/frontend/frontend.go b/pkg/querier/frontend/frontend.go index 1c5fce638f1..67eb0f53fa1 100644 --- 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() { + 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(), util.Logger)).Log(logMessage...) } if err != nil { From 10924a96ff30cd7d74b257be02184aae245dba9f Mon Sep 17 00:00:00 2001 From: Marco Pracucci Date: Fri, 24 Apr 2020 07:42:16 +0200 Subject: [PATCH 2/4] Fixed query string in slow query logging Signed-off-by: Marco Pracucci --- pkg/querier/frontend/frontend.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pkg/querier/frontend/frontend.go b/pkg/querier/frontend/frontend.go index 67eb0f53fa1..5a08e4547fb 100644 --- a/pkg/querier/frontend/frontend.go +++ b/pkg/querier/frontend/frontend.go @@ -168,7 +168,7 @@ func (f *Frontend) handle(w http.ResponseWriter, r *http.Request) { "time_taken", queryResponseTime.String(), } for k, v := range r.URL.Query() { - append(logMessage, fmt.Sprintf("qs_%s", k), strings.Join(v, ",")) + logMessage = append(logMessage, fmt.Sprintf("qs_%s", k), strings.Join(v, ",")) } pf := r.PostForm.Encode() if pf != "" { From 151b3eea2ad25ae50cd3a6b730c0301728a1ca90 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Peter=20S=CC=8Ctibrany=CC=81?= Date: Fri, 24 Apr 2020 09:38:38 +0200 Subject: [PATCH 3/4] Added CHANGELOG.md MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Signed-off-by: Peter Štibraný --- CHANGELOG.md | 1 + 1 file changed, 1 insertion(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index a25f46b2f5d..e97c777c0ff 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -18,6 +18,7 @@ * `cortex_querier_bucket_store_blocks_meta_sync_consistency_delay_seconds` > `cortex_querier_blocks_meta_sync_consistency_delay_seconds` * [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] 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 From 09fe88b0db93a446eb00b48d5bb3d8ccb9ceaf1f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Peter=20=C5=A0tibran=C3=BD?= Date: Fri, 24 Apr 2020 09:42:48 +0200 Subject: [PATCH 4/4] Use f.log instead of util.Logger MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Signed-off-by: Peter Štibraný --- pkg/querier/frontend/frontend.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pkg/querier/frontend/frontend.go b/pkg/querier/frontend/frontend.go index 5a08e4547fb..a59443f8b04 100644 --- a/pkg/querier/frontend/frontend.go +++ b/pkg/querier/frontend/frontend.go @@ -174,7 +174,7 @@ func (f *Frontend) handle(w http.ResponseWriter, r *http.Request) { if pf != "" { logMessage = append(logMessage, "body", pf) } - level.Info(util.WithContext(r.Context(), util.Logger)).Log(logMessage...) + level.Info(util.WithContext(r.Context(), f.log)).Log(logMessage...) } if err != nil {