log: improve prefix handling (#5489)

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

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=

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)
+}

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)
+		})
+	}
+}

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...)
 }

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
+}

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)

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