From da04e1e07a76487fc9e19334a04a1cb9414f1de3 Mon Sep 17 00:00:00 2001 From: fatedier Date: Wed, 12 Aug 2026 23:56:00 +0800 Subject: [PATCH] log: improve prefix handling (#5489) --- go.mod | 2 +- go.sum | 4 +- pkg/config/v1/validation/name.go | 48 +++++++++++++++++ pkg/config/v1/validation/name_test.go | 48 +++++++++++++++++ pkg/util/xlog/xlog.go | 10 ++-- pkg/util/xlog/xlog_test.go | 76 +++++++++++++++++++++++++++ server/service.go | 4 ++ server/service_test.go | 19 +++++++ 8 files changed, 203 insertions(+), 8 deletions(-) create mode 100644 pkg/config/v1/validation/name.go create mode 100644 pkg/config/v1/validation/name_test.go create mode 100644 pkg/util/xlog/xlog_test.go diff --git a/go.mod b/go.mod index 30c106d5..9e02c333 100644 --- a/go.mod +++ b/go.mod @@ -5,7 +5,7 @@ go 1.25.0 require ( github.com/armon/go-socks5 v0.0.0-20160902184237-e75332964ef5 github.com/coreos/go-oidc/v3 v3.18.0 - github.com/fatedier/golib v0.8.1 + github.com/fatedier/golib v0.8.2 github.com/google/uuid v1.6.0 github.com/gorilla/mux v1.8.1 github.com/gorilla/websocket v1.5.0 diff --git a/go.sum b/go.sum index 238c5ae2..30641d78 100644 --- a/go.sum +++ b/go.sum @@ -20,8 +20,8 @@ github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSs github.com/envoyproxy/go-control-plane v0.9.0/go.mod h1:YTl/9mNaCwkRvm6d1a2C3ymFceY/DCBVvsKhRF0iEA4= github.com/envoyproxy/go-control-plane v0.9.4/go.mod h1:6rpuAdCZL397s3pYoYcLgu1mIlRU8Am5FuJP05cCM98= github.com/envoyproxy/protoc-gen-validate v0.1.0/go.mod h1:iSmxcyjqTsJpI2R4NaDN7+kN2VEUnK/pcBlmesArF7c= -github.com/fatedier/golib v0.8.1 h1:pHcIu0zAcZ6VTkO1dW/meelCGN5nem52DKCBY7cUvyA= -github.com/fatedier/golib v0.8.1/go.mod h1:ArUGvPg2cOw/py2RAuBt46nNZH2VQ5Z70p109MAZpJw= +github.com/fatedier/golib v0.8.2 h1:02n2Dg7KJ7rR7p7n4/6hBUjaLQf2J7EiHYZQsgGTvww= +github.com/fatedier/golib v0.8.2/go.mod h1:ArUGvPg2cOw/py2RAuBt46nNZH2VQ5Z70p109MAZpJw= github.com/fatedier/yamux v0.0.0-20250825093530-d0154be01cd6 h1:u92UUy6FURPmNsMBUuongRWC0rBqN6gd01Dzu+D21NE= github.com/fatedier/yamux v0.0.0-20250825093530-d0154be01cd6/go.mod h1:c5/tk6G0dSpXGzJN7Wk1OEie8grdSJAmeawId9Zvd34= github.com/go-jose/go-jose/v4 v4.1.4 h1:moDMcTHmvE6Groj34emNPLs/qtYXRVcd6S7NHbHz3kA= diff --git a/pkg/config/v1/validation/name.go b/pkg/config/v1/validation/name.go new file mode 100644 index 00000000..ce03de88 --- /dev/null +++ b/pkg/config/v1/validation/name.go @@ -0,0 +1,48 @@ +// Copyright 2026 The frp Authors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package validation + +import ( + "fmt" + "unicode" + "unicode/utf8" +) + +const ( + // MaxRunIDLength is the maximum number of bytes accepted for a control run ID. + MaxRunIDLength = 64 +) + +func validateIdentifier(value, kind string, maxLength int) error { + if value == "" { + return fmt.Errorf("%s cannot be empty", kind) + } + if len(value) > maxLength { + return fmt.Errorf("%s is too long: length %d exceeds maximum %d", kind, len(value), maxLength) + } + if !utf8.ValidString(value) { + return fmt.Errorf("%s must be valid UTF-8", kind) + } + for _, r := range value { + if !unicode.IsPrint(r) { + return fmt.Errorf("%s contains non-printable character", kind) + } + } + return nil +} + +func ValidateRunID(runID string) error { + return validateIdentifier(runID, "run id", MaxRunIDLength) +} diff --git a/pkg/config/v1/validation/name_test.go b/pkg/config/v1/validation/name_test.go new file mode 100644 index 00000000..1095e78f --- /dev/null +++ b/pkg/config/v1/validation/name_test.go @@ -0,0 +1,48 @@ +// Copyright 2026 The frp Authors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package validation + +import ( + "strings" + "testing" + + "github.com/stretchr/testify/require" +) + +func TestValidateIdentifiers(t *testing.T) { + tests := []struct { + name string + validate func(string) error + value string + wantError string + }{ + {name: "run id accepts printable values", validate: ValidateRunID, value: "run-%1000s-中文"}, + {name: "run id rejects empty", validate: ValidateRunID, wantError: "cannot be empty"}, + {name: "run id rejects control character", validate: ValidateRunID, value: "run\nforged", wantError: "non-printable"}, + {name: "run id rejects invalid utf8", validate: ValidateRunID, value: string([]byte{0xff}), wantError: "valid UTF-8"}, + {name: "run id rejects excessive length", validate: ValidateRunID, value: strings.Repeat("a", MaxRunIDLength+1), wantError: "too long"}, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + err := tt.validate(tt.value) + if tt.wantError == "" { + require.NoError(t, err) + return + } + require.ErrorContains(t, err, tt.wantError) + }) + } +} diff --git a/pkg/util/xlog/xlog.go b/pkg/util/xlog/xlog.go index f8f4116a..1021d44a 100644 --- a/pkg/util/xlog/xlog.go +++ b/pkg/util/xlog/xlog.go @@ -96,21 +96,21 @@ func (l *Logger) Spawn() *Logger { } func (l *Logger) Errorf(format string, v ...any) { - log.Logger.Errorf(l.prefixString+format, v...) + log.Logger.WithPrefix(l.prefixString).Errorf(format, v...) } func (l *Logger) Warnf(format string, v ...any) { - log.Logger.Warnf(l.prefixString+format, v...) + log.Logger.WithPrefix(l.prefixString).Warnf(format, v...) } func (l *Logger) Infof(format string, v ...any) { - log.Logger.Infof(l.prefixString+format, v...) + log.Logger.WithPrefix(l.prefixString).Infof(format, v...) } func (l *Logger) Debugf(format string, v ...any) { - log.Logger.Debugf(l.prefixString+format, v...) + log.Logger.WithPrefix(l.prefixString).Debugf(format, v...) } func (l *Logger) Tracef(format string, v ...any) { - log.Logger.Tracef(l.prefixString+format, v...) + log.Logger.WithPrefix(l.prefixString).Tracef(format, v...) } diff --git a/pkg/util/xlog/xlog_test.go b/pkg/util/xlog/xlog_test.go new file mode 100644 index 00000000..13d006ef --- /dev/null +++ b/pkg/util/xlog/xlog_test.go @@ -0,0 +1,76 @@ +// Copyright 2026 The frp Authors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package xlog + +import ( + "bytes" + "testing" + + goliblog "github.com/fatedier/golib/log" + "github.com/stretchr/testify/require" + + frplog "github.com/fatedier/frp/pkg/util/log" +) + +func TestPrefixIsNotPartOfFormatString(t *testing.T) { + tests := []struct { + name string + log func(*Logger) + }{ + {name: "error", log: func(xl *Logger) { xl.Errorf("value [%s]", "ok") }}, + {name: "warn", log: func(xl *Logger) { xl.Warnf("value [%s]", "ok") }}, + {name: "info", log: func(xl *Logger) { xl.Infof("value [%s]", "ok") }}, + {name: "debug", log: func(xl *Logger) { xl.Debugf("value [%s]", "ok") }}, + {name: "trace", log: func(xl *Logger) { xl.Tracef("value [%s]", "ok") }}, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + output := captureLogs(t) + + tt.log(New().AppendPrefix("%1000000s")) + + require.Contains(t, output.String(), "[%1000000s] value [ok]") + require.Less(t, output.Len(), 1024) + }) + } +} + +func TestFormattingSemanticsArePreserved(t *testing.T) { + output := captureLogs(t) + xl := New().AppendPrefix("run") + + xl.Infof("%[2]s %[1]s", "first", "second") + xl.Infof("100% complete") + + require.Contains(t, output.String(), "[run] second first") + require.Contains(t, output.String(), "[run] 100% complete") +} + +func captureLogs(t *testing.T) *bytes.Buffer { + t.Helper() + + output := bytes.NewBuffer(nil) + oldLogger := frplog.Logger + frplog.Logger = goliblog.New( + goliblog.WithOutput(output), + goliblog.WithLevel(goliblog.TraceLevel), + goliblog.WithCaller(false), + ) + t.Cleanup(func() { + frplog.Logger = oldLogger + }) + return output +} diff --git a/server/service.go b/server/service.go index 7aba085e..82883bb2 100644 --- a/server/service.go +++ b/server/service.go @@ -35,6 +35,7 @@ import ( "github.com/fatedier/frp/pkg/auth" v1 "github.com/fatedier/frp/pkg/config/v1" + "github.com/fatedier/frp/pkg/config/v1/validation" modelmetrics "github.com/fatedier/frp/pkg/metrics" "github.com/fatedier/frp/pkg/msg" "github.com/fatedier/frp/pkg/nathole" @@ -791,6 +792,9 @@ func (svr *Service) RegisterControl( return nil, err } } + if err := validation.ValidateRunID(loginMsg.RunID); err != nil { + return nil, fmt.Errorf("invalid run id: %w", err) + } ctx := netpkg.NewContextFromConn(ctlConn) xl := xlog.FromContextSafe(ctx) diff --git a/server/service_test.go b/server/service_test.go index e35f11b9..d4fcbe77 100644 --- a/server/service_test.go +++ b/server/service_test.go @@ -17,10 +17,12 @@ package server import ( "context" "errors" + "fmt" "math" "net" "net/http" "runtime" + "strings" "sync" "sync/atomic" "testing" @@ -31,6 +33,7 @@ import ( "github.com/fatedier/frp/pkg/auth" v1 "github.com/fatedier/frp/pkg/config/v1" + "github.com/fatedier/frp/pkg/config/v1/validation" "github.com/fatedier/frp/pkg/msg" plugin "github.com/fatedier/frp/pkg/plugin/server" "github.com/fatedier/frp/pkg/proto/wire" @@ -638,6 +641,22 @@ func TestServiceRegisterControlRejectsInvalidCodecSelection(t *testing.T) { } } +func TestServiceRegisterControlRejectsInvalidRunID(t *testing.T) { + for _, runID := range []string{ + "run\nforged", + strings.Repeat("a", validation.MaxRunIDLength+1), + } { + t.Run(fmt.Sprintf("run_id_%d", len(runID)), func(t *testing.T) { + svr := newControlTestService(t) + conn := newDeadlineReadConn() + msgConn := msg.NewConn(conn, msg.NewV1ReadWriter(conn)) + ctl, err := svr.RegisterControl(msgConn, &msg.Login{RunID: runID}, true, wire.ProtocolV1, "") + require.Nil(t, ctl) + require.ErrorContains(t, err, "invalid run id") + }) + } +} + func TestServiceRegisterControlPoolCountBoundaries(t *testing.T) { for _, tc := range []struct { name string