Add "response_size_bytes" field to "query stats" log (#5196)

Signed-off-by: Marco Pracucci <marco@pracucci.com>

CHANGELOG.md

@@ -7,6 +7,7 @@
 * [CHANGE] Store-gateway: skip verifying index header integrity upon loading. To enable verification set `blocks_storage.bucket_store.index_header.verify_on_load: true`.
 * [ENHANCEMENT] Cardinality API: When zone aware replication is enabled, the label values cardinality API can now tolerate single zone failure #5178
 * [ENHANCEMENT] Distributor: optimize sending requests to ingesters when incoming requests don't need to be modified. For now this feature can be disabled by setting `-timeseries-unmarshal-caching-optimization-enabled=false`. #5137
+* [ENHANCEMENT] Query-frontend: added "response_size_bytes" field to "query stats" log. #5196
 
 ### Mixin
 * [CHANGE] Dashboards: show all workloads in selected namespace on "rollout progress" dashboard. #5113

pkg/frontend/transport/handler.go

@@ -208,7 +208,7 @@ func (f *Handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 
 	if err != nil {
 		writeError(w, err)
-		f.reportQueryStats(r, params, queryResponseTime, stats, err)
+		f.reportQueryStats(r, params, queryResponseTime, 0, stats, err)
 		return
 	}
 
@@ -223,13 +223,13 @@ func (f *Handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 
 	w.WriteHeader(resp.StatusCode)
 	// we don't check for copy error as there is no much we can do at this point
-	_, _ = io.Copy(w, resp.Body)
+	queryResponseSize, _ := io.Copy(w, resp.Body)
 
 	if f.cfg.LogQueriesLongerThan > 0 && queryResponseTime > f.cfg.LogQueriesLongerThan {
 		f.reportSlowQuery(r, params, queryResponseTime)
 	}
 	if f.cfg.QueryStatsEnabled {
-		f.reportQueryStats(r, params, queryResponseTime, stats, nil)
+		f.reportQueryStats(r, params, queryResponseTime, queryResponseSize, stats, nil)
 	}
 }
 
@@ -250,7 +250,7 @@ func (f *Handler) reportSlowQuery(r *http.Request, queryString url.Values, query
 	level.Info(util_log.WithContext(r.Context(), f.log)).Log(logMessage...)
 }
 
-func (f *Handler) reportQueryStats(r *http.Request, queryString url.Values, queryResponseTime time.Duration, stats *querier_stats.Stats, queryErr error) {
+func (f *Handler) reportQueryStats(r *http.Request, queryString url.Values, queryResponseTime time.Duration, queryResponseSizeBytes int64, stats *querier_stats.Stats, queryErr error) {
 	tenantIDs, err := tenant.TenantIDs(r.Context())
 	if err != nil {
 		return
@@ -281,6 +281,7 @@ func (f *Handler) reportQueryStats(r *http.Request, queryString url.Values, quer
 		"path", r.URL.Path,
 		"user_agent", r.UserAgent(),
 		"response_time", queryResponseTime,
+		"response_size_bytes", queryResponseSizeBytes,
 		"query_wall_time_seconds", wallTime.Seconds(),
 		"fetched_series_count", numSeries,
 		"fetched_chunk_bytes", numBytes,

pkg/frontend/transport/handler_test.go

@@ -155,7 +155,7 @@ func TestHandler_ServeHTTP(t *testing.T) {
 			resp := httptest.NewRecorder()
 
 			handler.ServeHTTP(resp, req)
-			_, _ = io.ReadAll(resp.Body)
+			responseData, _ := io.ReadAll(resp.Body)
 			require.Equal(t, resp.Code, http.StatusOK)
 
 			count, err := promtest.GatherAndCount(
@@ -178,7 +178,7 @@ func TestHandler_ServeHTTP(t *testing.T) {
 				require.Len(t, logger.logMessages, 1)
 
 				msg := logger.logMessages[0]
-				require.Len(t, msg, 17+len(tt.expectedParams))
+				require.Len(t, msg, 18+len(tt.expectedParams))
 				require.Equal(t, level.InfoValue(), msg["level"])
 				require.Equal(t, "query stats", msg["msg"])
 				require.Equal(t, "query-frontend", msg["component"])
@@ -188,6 +188,7 @@ func TestHandler_ServeHTTP(t *testing.T) {
 				require.Equal(t, req.URL.Path, msg["path"])
 				require.Equal(t, req.UserAgent(), msg["user_agent"])
 				require.Contains(t, msg, "response_time")
+				require.Equal(t, int64(len(responseData)), msg["response_size_bytes"])
 				require.Contains(t, msg, "query_wall_time_seconds")
 				require.EqualValues(t, 0, msg["fetched_series_count"])
 				require.EqualValues(t, 0, msg["fetched_chunk_bytes"])