Skip to content

Improve the frontend slow query logs. #2520

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 5 commits into from
Apr 24, 2020
Merged

Improve the frontend slow query logs. #2520

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
ba49762
Improve the frontend slow query logs.
cyriltovena Apr 23, 2020
10924a9
Fixed query string in slow query logging
pracucci Apr 24, 2020
151b3ee
Added CHANGELOG.md
pstibrany Apr 24, 2020
3a3439b
Merge branch 'master' into improve-log-slow-request
pstibrany Apr 24, 2020
09fe88b
Use f.log instead of util.Logger
pstibrany Apr 24, 2020
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions CHANGELOG.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
20 changes: 11 additions & 9 deletions pkg/querier/frontend/frontend.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,7 @@ import (
"net/http"
"net/url"
"path"
"strings"
"sync"
"time"

Expand All @@ -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 (
Expand Down Expand Up @@ -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 {
Expand Down