From 4d6992982d99a542f1e99af18b691830b71469e0 Mon Sep 17 00:00:00 2001 From: Callum Styan Date: Mon, 30 Sep 2024 13:22:58 -0700 Subject: [PATCH] feat: add query user and query source to "executing query" log lines (#14320) Signed-off-by: Callum Styan --- pkg/logql/engine.go | 15 +++++++++++++-- pkg/logql/engine_test.go | 26 ++++++++------------------ 2 files changed, 21 insertions(+), 20 deletions(-) diff --git a/pkg/logql/engine.go b/pkg/logql/engine.go index c44ee06c16..17e90520e7 100644 --- a/pkg/logql/engine.go +++ b/pkg/logql/engine.go @@ -241,11 +241,21 @@ func (q *query) Exec(ctx context.Context) (logqlmodel.Result, error) { if q.logExecQuery { queryHash := util.HashedQuery(q.params.QueryString()) + + logValues := []interface{}{ + "msg", "executing query", + "query", q.params.QueryString(), + "query_hash", queryHash, + } + tags := httpreq.ExtractQueryTagsFromContext(ctx) + tagValues := tagsToKeyValues(tags) if GetRangeType(q.params) == InstantType { - level.Info(logutil.WithContext(ctx, q.logger)).Log("msg", "executing query", "type", "instant", "query", q.params.QueryString(), "query_hash", queryHash) + logValues = append(logValues, "type", "instant") } else { - level.Info(logutil.WithContext(ctx, q.logger)).Log("msg", "executing query", "type", "range", "query", q.params.QueryString(), "length", q.params.End().Sub(q.params.Start()), "step", q.params.Step(), "query_hash", queryHash) + logValues = append(logValues, "type", "range", "length", q.params.End().Sub(q.params.Start()), "step", q.params.Step()) } + logValues = append(logValues, tagValues...) + level.Info(logutil.WithContext(ctx, q.logger)).Log(logValues...) } rangeType := GetRangeType(q.params) @@ -265,6 +275,7 @@ func (q *query) Exec(ctx context.Context) (logqlmodel.Result, error) { sp.LogKV(statResult.KVList()...) status, _ := server.ClientHTTPStatusAndError(err) + if q.record { RecordRangeAndInstantQueryMetrics(ctx, q.logger, q.params, strconv.Itoa(status), statResult, data) } diff --git a/pkg/logql/engine_test.go b/pkg/logql/engine_test.go index 23bcbac91e..fd534ac046 100644 --- a/pkg/logql/engine_test.go +++ b/pkg/logql/engine_test.go @@ -6,7 +6,6 @@ import ( "errors" "fmt" "math" - "regexp" "strings" "testing" "time" @@ -2618,23 +2617,14 @@ func TestHashingStability(t *testing.T) { expectedQueryHash := util.HashedQuery(test.qs) // check that both places will end up having the same query hash, even though they're emitting different log lines. - require.Regexp(t, - regexp.MustCompile( - fmt.Sprintf( - `level=info org_id=fake msg="executing query" type=range query=.* length=5s step=1m0s query_hash=%d.*`, expectedQueryHash, - ), - ), - queryWithEngine(), - ) - - require.Regexp(t, - regexp.MustCompile( - fmt.Sprintf( - `level=info org_id=fake latency=slow query=".*" query_hash=%d query_type=metric range_type=range.*\n`, expectedQueryHash, - ), - ), - queryDirectly(), - ) + withEngine := queryWithEngine() + require.Contains(t, withEngine, fmt.Sprintf("query_hash=%d", expectedQueryHash)) + require.Contains(t, withEngine, "step=1m0s") + + directly := queryDirectly() + require.Contains(t, directly, fmt.Sprintf("query_hash=%d", expectedQueryHash)) + require.Contains(t, directly, "length=5s") + require.Contains(t, directly, "latency=slow") } }