chore: fix elapsed time formatting (#5238)

ee/query-service/app/db/metrics.go

@@ -21,7 +21,7 @@ import (
 // GetMetricResultEE runs the query and returns list of time series
 func (r *ClickhouseReader) GetMetricResultEE(ctx context.Context, query string) ([]*basemodel.Series, string, error) {
 
-	defer utils.Elapsed("GetMetricResult")()
+	defer utils.Elapsed("GetMetricResult", nil)()
 	zap.L().Info("Executing metric result query: ", zap.String("query", query))
 
 	var hash string

pkg/query-service/app/clickhouseReader/reader.go

@@ -3081,7 +3081,7 @@ func (r *ClickHouseReader) GetMetricResultEE(ctx context.Context, query string)
 // GetMetricResult runs the query and returns list of time series
 func (r *ClickHouseReader) GetMetricResult(ctx context.Context, query string) ([]*model.Series, error) {
 
-	defer utils.Elapsed("GetMetricResult")()
+	defer utils.Elapsed("GetMetricResult", nil)()
 
 	zap.L().Info("Executing metric result query: ", zap.String("query", query))
 
@@ -4594,26 +4594,27 @@ func readRowsForTimeSeriesResult(rows driver.Rows, vars []interface{}, columnNam
 	return seriesList, getPersonalisedError(rows.Err())
 }
 
-func logComment(ctx context.Context) string {
+func logCommentKVs(ctx context.Context) map[string]string {
-	// Get the key-value pairs from context for log comment
 	kv := ctx.Value(common.LogCommentKey)
 	if kv == nil {
-		return ""
+		return nil
 	}
-
 	logCommentKVs, ok := kv.(map[string]string)
 	if !ok {
-		return ""
+		return nil
 	}
-
+	return logCommentKVs
-	x, _ := json.Marshal(logCommentKVs)
-	return string(x)
 }
 
 // GetTimeSeriesResultV3 runs the query and returns list of time series
 func (r *ClickHouseReader) GetTimeSeriesResultV3(ctx context.Context, query string) ([]*v3.Series, error) {
 
-	defer utils.Elapsed("GetTimeSeriesResultV3", query, fmt.Sprintf("logComment: %s", logComment(ctx)))()
+	ctxArgs := map[string]interface{}{"query": query}
+	for k, v := range logCommentKVs(ctx) {
+		ctxArgs[k] = v
+	}
+
+	defer utils.Elapsed("GetTimeSeriesResultV3", ctxArgs)()
 
 	rows, err := r.db.Query(ctx, query)
 
@@ -4655,7 +4656,12 @@ func (r *ClickHouseReader) GetTimeSeriesResultV3(ctx context.Context, query stri
 // GetListResultV3 runs the query and returns list of rows
 func (r *ClickHouseReader) GetListResultV3(ctx context.Context, query string) ([]*v3.Row, error) {
 
-	defer utils.Elapsed("GetListResultV3", query, fmt.Sprintf("logComment: %s", logComment(ctx)))()
+	ctxArgs := map[string]interface{}{"query": query}
+	for k, v := range logCommentKVs(ctx) {
+		ctxArgs[k] = v
+	}
+
+	defer utils.Elapsed("GetListResultV3", ctxArgs)()
 
 	rows, err := r.db.Query(ctx, query)
 

pkg/query-service/utils/time.go

@@ -1,20 +1,19 @@
 package utils
 
 import (
-	"fmt"
 	"time"
 
 	"go.uber.org/zap"
 )
 
-func Elapsed(funcName string, args ...interface{}) func() {
+func Elapsed(funcName string, args map[string]interface{}) func() {
 	start := time.Now()
-	argsStr := ""
-	for _, v := range args {
-		argsStr += fmt.Sprintf("%v, ", v)
-	}
-	argsStr = argsStr[:len(argsStr)-2]
 	return func() {
-		zap.L().Info("Elapsed time", zap.String("func_name", funcName), zap.Duration("duration", time.Since(start)), zap.String("args", argsStr))
+		var zapFields []zap.Field
+		zapFields = append(zapFields, zap.String("func_name", funcName), zap.Duration("duration", time.Since(start)))
+		for k, v := range args {
+			zapFields = append(zapFields, zap.Any(k, v))
+		}
+		zap.L().Info("Elapsed time", zapFields...)
 	}
 }