enhance: optimize access log formatter and add bench test (#30829)

relate: https://github.com/milvus-io/milvus/issues/28948
https://github.com/milvus-io/milvus/issues/30806

---------

Signed-off-by: aoiasd <zhicheng.yue@zilliz.com>

internal/proxy/accesslog/benchmark_test.go

@@ -0,0 +1,89 @@
+package accesslog
+
+import (
+	"context"
+	"fmt"
+	"testing"
+
+	"google.golang.org/grpc"
+	"google.golang.org/grpc/metadata"
+
+	"github.com/milvus-io/milvus-proto/go-api/v2/commonpb"
+	"github.com/milvus-io/milvus-proto/go-api/v2/milvuspb"
+	"github.com/milvus-io/milvus/internal/proxy/connection"
+	"github.com/milvus-io/milvus/pkg/util"
+	"github.com/milvus-io/milvus/pkg/util/paramtable"
+)
+
+type TestData struct {
+	req, resp interface{}
+	err       error
+}
+
+func genTestData(clientInfo *commonpb.ClientInfo, identifier int64) []*TestData {
+	ret := []*TestData{}
+
+	ret = append(ret, &TestData{
+		req: &milvuspb.QueryRequest{
+			CollectionName: "test1",
+			Expr:           "pk >= 100",
+		},
+		resp: &milvuspb.QueryResults{
+			CollectionName: "test1",
+		},
+		err: nil,
+	})
+
+	ret = append(ret, &TestData{
+		req: &milvuspb.SearchRequest{
+			CollectionName: "test2",
+			Dsl:            "pk <= 100",
+		},
+		resp: &milvuspb.SearchResults{
+			CollectionName: "test2",
+		},
+		err: nil,
+	})
+
+	ret = append(ret, &TestData{
+		req: &milvuspb.ConnectRequest{
+			ClientInfo: clientInfo,
+		},
+		resp: &milvuspb.ConnectResponse{
+			Identifier: identifier,
+		},
+		err: nil,
+	})
+
+	return ret
+}
+
+func BenchmarkAccesslog(b *testing.B) {
+	paramtable.Init()
+	Params := paramtable.Get()
+	Params.Save(Params.ProxyCfg.AccessLog.Enable.Key, "true")
+	Params.Save(Params.ProxyCfg.AccessLog.Filename.Key, "")
+	Params.Save(Params.CommonCfg.ClusterPrefix.Key, "in-test")
+	initAccessLogger(&Params.ProxyCfg.AccessLog, &Params.MinioCfg)
+	paramtable.Get().CommonCfg.ClusterPrefix.GetValue()
+
+	clientInfo := &commonpb.ClientInfo{
+		SdkType:    "gotest",
+		SdkVersion: "testversion",
+	}
+	identifier := int64(11111)
+	md := metadata.MD{util.IdentifierKey: []string{fmt.Sprint(identifier)}}
+	ctx := metadata.NewIncomingContext(context.TODO(), md)
+	connection.GetManager().Register(ctx, identifier, clientInfo)
+	rpcInfo := &grpc.UnaryServerInfo{Server: nil, FullMethod: "testMethod"}
+	datas := genTestData(clientInfo, identifier)
+
+	b.ResetTimer()
+	for i := 0; i < b.N; i++ {
+		data := datas[i%len(datas)]
+		accessInfo := NewGrpcAccessInfo(ctx, rpcInfo, data.req)
+		accessInfo.UpdateCtx(ctx)
+		accessInfo.SetResult(data.resp, data.err)
+		accessInfo.Write()
+	}
+}

internal/proxy/accesslog/formatter.go

@@ -17,6 +17,7 @@
 package accesslog
 
 import (
+	"fmt"
 	"strings"
 
 	"github.com/milvus-io/milvus/pkg/util/merr"
@@ -92,23 +93,23 @@ func (m *FormatterManger) GetByMethod(method string) (*Formatter, bool) {
 }
 
 type Formatter struct {
+	base   string
 	fmt    string
 	fields []string
-	prefixs []string
 }
 
 func NewFormatter(base string) *Formatter {
 	formatter := &Formatter{
-		fmt: base,
+		base: base,
 	}
 	formatter.build()
 	return formatter
 }
 
-func (f *Formatter) buildMetric(metric string) ([]string, []string) {
+func (f *Formatter) buildMetric(metric string, prefixs []string) ([]string, []string) {
 	newFields := []string{}
 	newPrefixs := []string{}
-	for id, prefix := range f.prefixs {
+	for id, prefix := range prefixs {
 		prefixs := strings.Split(prefix, metric)
 		newPrefixs = append(newPrefixs, prefixs...)
 
@@ -124,27 +125,27 @@ func (f *Formatter) buildMetric(metric string) ([]string, []string) {
 }
 
 func (f *Formatter) build() {
-	f.prefixs = []string{f.fmt}
+	prefixs := []string{f.base}
 	f.fields = []string{}
-	for mertric := range metricFuncMap {
-		if strings.Contains(f.fmt, mertric) {
-			f.fields, f.prefixs = f.buildMetric(mertric)
+	for metric := range metricFuncMap {
+		if strings.Contains(f.base, metric) {
+			f.fields, prefixs = f.buildMetric(metric, prefixs)
 		}
 	}
+
+	f.fmt = ""
+	for id, prefix := range prefixs {
+		f.fmt += prefix
+		if id < len(f.fields) {
+			f.fmt += "%s"
+		}
+	}
+	f.fmt += "\n"
 }
 
-func (f *Formatter) Format(info AccessInfo) string {
-	fieldValues := info.Get(f.fields...)
-
-	result := ""
-	for id, prefix := range f.prefixs {
-		result += prefix
-		if id < len(fieldValues) {
-			result += fieldValues[id]
-		}
-	}
-	result += "\n"
-	return result
+func (f *Formatter) Format(i AccessInfo) string {
+	fieldValues := i.Get(f.fields...)
+	return fmt.Sprintf(f.fmt, fieldValues...)
 }
 
 func parseConfigKey(k string) (string, string, error) {

internal/proxy/accesslog/info.go

@@ -39,7 +39,7 @@ import (
 )
 
 type AccessInfo interface {
-	Get(keys ...string) []string
+	Get(keys ...string) []any
 }
 
 type GrpcAccessInfo struct {
@@ -89,8 +89,8 @@ func (i *GrpcAccessInfo) SetResult(resp interface{}, err error) {
 	}
 }
 
-func (i *GrpcAccessInfo) Get(keys ...string) []string {
-	result := []string{}
+func (i *GrpcAccessInfo) Get(keys ...string) []any {
+	result := []any{}
 	for _, key := range keys {
 		if getFunc, ok := metricFuncMap[key]; ok {
 			result = append(result, getFunc(i))