From a8aab0d56a167b4a64956a81b1a614bcb83f2ced Mon Sep 17 00:00:00 2001 From: Ben Ye Date: Tue, 14 Nov 2023 19:56:43 -0800 Subject: [PATCH] Fix param_query omitted in query frontend query stats log (#5655) * fix param_query not logged in query stats log Signed-off-by: Ben Ye * fix lint Signed-off-by: Ben Ye * fix unit test of user agent Signed-off-by: Ben Ye --------- Signed-off-by: Ben Ye --- CHANGELOG.md | 1 + pkg/frontend/transport/handler.go | 8 ++--- pkg/frontend/transport/handler_test.go | 43 +++++++++++++++++++++++++- 3 files changed, 47 insertions(+), 5 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index c3b8626b32..1876323f60 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -102,6 +102,7 @@ * [BUGFIX] DDBKV: When no change detected in ring, retry the CAS until there is change. #5502 * [BUGFIX] Fix bug on objstore when configured to use S3 fips endpoints. #5540 * [BUGFIX] Ruler: Fix bug on ruler where a failure to load a single RuleGroup would prevent rulers to sync all RuleGroup. #5563 +* [BUGFIX] Query Frontend: Fix query string being omitted in query stats log. #5655 ## 1.15.3 2023-06-22 diff --git a/pkg/frontend/transport/handler.go b/pkg/frontend/transport/handler.go index 080712056e..36263c2c5d 100644 --- a/pkg/frontend/transport/handler.go +++ b/pkg/frontend/transport/handler.go @@ -98,7 +98,7 @@ type Handler struct { } // NewHandler creates a new frontend handler. -func NewHandler(cfg HandlerConfig, roundTripper http.RoundTripper, log log.Logger, reg prometheus.Registerer) http.Handler { +func NewHandler(cfg HandlerConfig, roundTripper http.RoundTripper, log log.Logger, reg prometheus.Registerer) *Handler { h := &Handler{ cfg: cfg, log: log, @@ -407,17 +407,17 @@ func (f *Handler) parseRequestQueryString(r *http.Request, bodyBuf bytes.Buffer) } func formatQueryString(queryString url.Values) (fields []interface{}) { - var queryFields []string + var queryFields []interface{} for k, v := range queryString { // If `query` or `match[]` field exists, we always put it as the last field. if k == "query" || k == "match[]" { - queryFields = []string{fmt.Sprintf("param_%s", k), strings.Join(v, ",")} + queryFields = []interface{}{fmt.Sprintf("param_%s", k), strings.Join(v, ",")} continue } fields = append(fields, fmt.Sprintf("param_%s", k), strings.Join(v, ",")) } if len(queryFields) > 0 { - fields = append(fields, queryFields) + fields = append(fields, queryFields...) } return fields } diff --git a/pkg/frontend/transport/handler_test.go b/pkg/frontend/transport/handler_test.go index d075f5ec4c..7cf4a4bd34 100644 --- a/pkg/frontend/transport/handler_test.go +++ b/pkg/frontend/transport/handler_test.go @@ -1,12 +1,15 @@ package transport import ( + "bytes" "context" "io" "net/http" "net/http/httptest" + "net/url" "strings" "testing" + "time" "github.com/go-kit/log" "github.com/pkg/errors" @@ -16,6 +19,8 @@ import ( "github.com/stretchr/testify/require" "github.com/weaveworks/common/httpgrpc" "github.com/weaveworks/common/user" + + querier_stats "github.com/cortexproject/cortex/pkg/querier/stats" ) type roundTripperFunc func(*http.Request) (*http.Response, error) @@ -274,8 +279,44 @@ func TestHandler_ServeHTTP(t *testing.T) { assert.Equal(t, tt.expectedMetrics, count) if tt.additionalMetricsCheckFunc != nil { - tt.additionalMetricsCheckFunc(handler.(*Handler)) + tt.additionalMetricsCheckFunc(handler) } }) } } + +func TestReportQueryStatsFormat(t *testing.T) { + outputBuf := bytes.NewBuffer(nil) + logger := log.NewSyncLogger(log.NewLogfmtLogger(outputBuf)) + handler := NewHandler(HandlerConfig{QueryStatsEnabled: true}, http.DefaultTransport, logger, nil) + + userID := "fake" + queryString := url.Values(map[string][]string{"query": {"up"}}) + req, err := http.NewRequest(http.MethodGet, "http://localhost:8080/prometheus/api/v1/query", nil) + require.NoError(t, err) + req.Header = http.Header{ + "User-Agent": []string{"Grafana"}, + } + resp := &http.Response{ + ContentLength: 1000, + } + stats := &querier_stats.QueryStats{ + Stats: querier_stats.Stats{ + WallTime: 3 * time.Second, + FetchedSeriesCount: 100, + FetchedChunksCount: 200, + FetchedSamplesCount: 300, + FetchedChunkBytes: 1024, + FetchedDataBytes: 2048, + }, + } + responseErr := errors.New("foo_err") + handler.reportQueryStats(req, userID, queryString, time.Second, stats, responseErr, http.StatusOK, resp) + + data, err := io.ReadAll(outputBuf) + require.NoError(t, err) + + expectedLog := `level=error msg="query stats" component=query-frontend method=GET path=/prometheus/api/v1/query response_time=1s query_wall_time_seconds=3 fetched_series_count=100 fetched_chunks_count=200 fetched_samples_count=300 fetched_chunks_bytes=1024 fetched_data_bytes=2048 status_code=200 response_size=1000 query_length=2 user_agent=Grafana error=foo_err param_query=up +` + require.Equal(t, expectedLog, string(data)) +}