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 <[email protected]> * fix lint Signed-off-by: Ben Ye <[email protected]> * fix unit test of user agent Signed-off-by: Ben Ye <[email protected]> --------- Signed-off-by: Ben Ye <[email protected]>
cortexproject · Nov 15, 2023 · b601141 · b601141
1 parent 470027e
commit b601141
Show file tree

Hide file tree

Showing 3 changed files with 47 additions and 5 deletions.
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -4,6 +4,7 @@
 * [CHANGE] Azure Storage: Upgraded objstore dependency and support Azure Workload Identity Authentication. Added `connection_string` to support authenticating via SAS token. Marked `msi_resource` config as deprecating. #5645
 * [FEATURE] Ingester: Add per-tenant new metric `cortex_ingester_tsdb_data_replay_duration_seconds`. #5477
 * [ENHANCEMENT] Store Gateway: Added `-store-gateway.enabled-tenants` and `-store-gateway.disabled-tenants` to explicitly enable or disable store-gateway for specific tenants. #5638
+* [BUGFIX] Query Frontend: Fix query string being omitted in query stats log. #5655
 
 ## 1.16.0 in progress
 

diff --git 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
@@ -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))
+}