perf(logging): aggregate disabled-client logs in Xray config generation (#7055)

GetXrayConfig logged one INFO line for every client whose traffic row is
disabled, on every config generation: each reconcile, restart and node
traffic sync, changed or not. With a few thousand expired clients that
flooded the journal and pushed everything else out of the panel's in-memory
log buffer. The line also said "Remove Inbound User", although nothing is
removed there; the client is only left out of the config being built.

A successful generation now writes one summary with the number of excluded
client entries and affected inbounds, and a failed one writes none. The
filter and the generated config are unchanged.

Closes #7054
This commit is contained in:
Hamed
2026-11-13 22:25:21 +03:30
committed by GitHub
parent 2fab6c3d50
commit 5297fd3c84
3 changed files with 210 additions and 1 deletions
+9 -1
View File
@@ -204,6 +204,7 @@ func (s *XrayService) GetXrayConfig() (*xray.Config, error) {
if err != nil {
return nil, err
}
excludedClients, excludedInbounds := 0, 0
for _, inbound := range inbounds {
if !inbound.Enable {
continue
@@ -248,10 +249,11 @@ func (s *XrayService) GetXrayConfig() (*xray.Config, error) {
finalClients := make([]any, 0, len(dbClients))
var wgPeers []any
excludedBefore := excludedClients
for i := range dbClients {
c := dbClients[i]
if enable, exists := enableMap[c.Email]; exists && !enable {
logger.Infof("Remove Inbound User %s due to expiration or traffic limit", c.Email)
excludedClients++
continue
}
if !c.Enable {
@@ -320,6 +322,9 @@ func (s *XrayService) GetXrayConfig() (*xray.Config, error) {
}
finalClients = append(finalClients, entry)
}
if excludedClients > excludedBefore {
excludedInbounds++
}
var mutated bool
if inbound.Protocol == model.WireGuard {
@@ -491,6 +496,9 @@ func (s *XrayService) GetXrayConfig() (*xray.Config, error) {
xrayConfig.RouterConfig = dropRefusedScript(xrayConfig.RouterConfig, "routing", routingScriptRefused)
xrayConfig.DNSConfig = dropRefusedScript(xrayConfig.DNSConfig, "dns", dnsScriptRefused)
if excludedClients > 0 {
logger.Infof("Xray config generated: excluded %d disabled client entries across %d inbounds", excludedClients, excludedInbounds)
}
return xrayConfig, nil
}
@@ -2,13 +2,167 @@ package service
import (
"encoding/json"
"fmt"
"strings"
"testing"
"github.com/mhsanaei/3x-ui/v3/internal/database"
"github.com/mhsanaei/3x-ui/v3/internal/database/model"
"github.com/mhsanaei/3x-ui/v3/internal/logger"
"github.com/mhsanaei/3x-ui/v3/internal/xray"
)
func TestGetXrayConfig_AggregatesExcludedClientLogs(t *testing.T) {
for _, tc := range []struct {
name string
clients int
inbounds int
excluded int
affected int
shared bool
}{
{"2000 excluded entries", 2000, 5, 2000, 5, false},
{"mixed clients and inbounds", 8, 4, 3, 2, false},
{"no excluded entries", 8, 4, 0, 0, false},
{"shared client counts as two entries", 4, 2, 1, 2, true},
} {
t.Run(tc.name, func(t *testing.T) {
setupSettingTestDB(t)
ds := seedScaleDataset(t, tc.clients, tc.inbounds)
excluded := make(map[string]bool, tc.excluded)
for _, email := range ds.emails[:tc.excluded] {
excluded[email] = true
}
if tc.shared {
var record model.ClientRecord
if err := database.GetDB().Where("email = ?", ds.emails[0]).First(&record).Error; err != nil {
t.Fatal(err)
}
if err := database.GetDB().Create(&model.ClientInbound{ClientId: record.Id, InboundId: ds.inboundIds[1]}).Error; err != nil {
t.Fatal(err)
}
}
// Manual disablement is a separate filter and must not inflate the summary.
if tc.excluded < tc.clients {
disableClients(t, ds.emails[tc.clients-1])
}
svc := &XrayService{}
want, err := svc.GetXrayConfig()
if err != nil {
t.Fatal(err)
}
for i, tag := range ds.tags {
clients := make([]map[string]string, 0)
for _, client := range ds.perInbound[i] {
if !excluded[client.Email] && client.Email != ds.emails[tc.clients-1] {
clients = append(clients, map[string]string{"email": client.Email, "id": client.ID})
}
}
for k := range want.InboundConfigs {
if want.InboundConfigs[k].Tag == tag {
settings, err := json.MarshalIndent(map[string]any{"clients": clients}, "", " ")
if err != nil {
t.Fatal(err)
}
want.InboundConfigs[k].Settings = settings
}
}
}
wantJSON, err := json.Marshal(want)
if err != nil {
t.Fatal(err)
}
if tc.excluded > 0 {
if err := database.GetDB().Model(&xray.ClientTraffic{}).
Where("email IN ?", ds.emails[:tc.excluded]).Update("enable", false).Error; err != nil {
t.Fatal(err)
}
}
for generation := range 2 {
marker := fmt.Sprintf("%s generation %d", t.Name(), generation)
logger.Info(marker)
got, err := svc.GetXrayConfig()
if err != nil {
t.Fatal(err)
}
gotJSON, err := json.Marshal(got)
if err != nil {
t.Fatal(err)
}
if string(gotJSON) != string(wantJSON) {
t.Fatal("generated config changed beyond the expected client exclusions")
}
infoCount := 0
foundMarker := false
for _, line := range logger.GetLogs(10000, "DEBUG") {
if strings.HasSuffix(line, " INFO - "+marker) {
foundMarker = true
break
}
if strings.Contains(line, "Remove Inbound User") || strings.Contains(line, "@scale") {
t.Fatalf("per-client log emitted: %s", line)
}
for _, clients := range ds.perInbound {
for _, client := range clients {
if strings.Contains(line, client.ID) || strings.Contains(line, client.SubID) {
t.Error("client credential or subscription ID leaked into logs")
}
}
}
if strings.Contains(line, " INFO - ") {
infoCount++
entries := tc.excluded
if tc.shared {
entries++
}
message := fmt.Sprintf(" INFO - Xray config generated: excluded %d disabled client entries across %d inbounds", entries, tc.affected)
if !strings.HasSuffix(line, message) {
t.Errorf("unexpected INFO entry: %s", line)
}
}
}
wantCount := 0
if tc.excluded > 0 {
wantCount = 1
}
if !foundMarker || infoCount != wantCount {
t.Errorf("generation %d: marker found = %v, INFO entries = %d, want %d", generation, foundMarker, infoCount, wantCount)
}
}
})
}
}
func TestGetXrayConfig_FailureDoesNotLogExclusionSummary(t *testing.T) {
setupSettingTestDB(t)
ds := seedScaleDataset(t, 1, 1)
db := database.GetDB()
if err := db.Model(&xray.ClientTraffic{}).Where("email = ?", ds.emails[0]).Update("enable", false).Error; err != nil {
t.Fatal(err)
}
if err := db.Model(&model.Inbound{}).Where("id = ?", ds.inboundIds[0]).
Update("stream_settings", `{"network":"tcp","security":"tls","tlsSettings":{}}`).Error; err != nil {
t.Fatal(err)
}
if err := db.Migrator().DropTable(&model.InboundFallback{}); err != nil {
t.Fatal(err)
}
logger.Info(t.Name())
cfg, err := (&XrayService{}).GetXrayConfig()
if cfg != nil || err == nil || err.Error() != "no such table: inbound_fallbacks" {
t.Fatalf("GetXrayConfig = %v, %v; want missing fallback table failure", cfg, err)
}
for _, line := range logger.GetLogs(100, "DEBUG") {
if strings.HasSuffix(line, " INFO - "+t.Name()) {
return
}
if strings.Contains(line, "Xray config generated:") || strings.Contains(line, "Remove Inbound User") {
t.Fatalf("failed generation logged a successful summary or per-client removal: %s", line)
}
}
t.Fatal("log boundary not found")
}
func seedVlessInbound(t *testing.T, tag string, port int, clients []model.Client) {
t.Helper()
setupSettingTestDB(t)
@@ -3,13 +3,60 @@ package service
import (
"encoding/json"
"fmt"
"strings"
"testing"
"time"
"github.com/mhsanaei/3x-ui/v3/internal/database"
"github.com/mhsanaei/3x-ui/v3/internal/database/model"
"github.com/mhsanaei/3x-ui/v3/internal/logger"
"github.com/mhsanaei/3x-ui/v3/internal/xray"
)
func BenchmarkGetXrayConfigDisabledClients(b *testing.B) {
b.Setenv("XUI_LOG_FOLDER", b.TempDir())
setupScaleDB(b)
b.Cleanup(logger.CloseLogger)
seedScaleDataset(b, 2000, 5)
db := database.GetDB()
// Fix the generated credentials and lifecycle values for before/after comparisons.
if err := db.Model(&model.ClientRecord{}).Where("id > 0").
Updates(map[string]any{"uuid": "11111111-1111-1111-1111-111111111111", "expiry_time": 0}).Error; err != nil {
b.Fatal(err)
}
if err := db.Model(&model.Inbound{}).Where("id > 0").Update("settings", `{"clients":[]}`).Error; err != nil {
b.Fatal(err)
}
if err := db.Model(&xray.ClientTraffic{}).Where("id > 0").
Updates(map[string]any{"enable": false, "expiry_time": 0}).Error; err != nil {
b.Fatal(err)
}
svc := &XrayService{}
b.ReportAllocs()
b.ResetTimer()
for range b.N {
if _, err := svc.GetXrayConfig(); err != nil {
b.Fatal(err)
}
}
b.StopTimer()
const marker = "disabled-client benchmark log boundary"
logger.Info(marker)
if _, err := svc.GetXrayConfig(); err != nil {
b.Fatal(err)
}
entries, bytes := 0, 0
for _, line := range logger.GetLogs(10000, "DEBUG") {
if strings.HasSuffix(line, " INFO - "+marker) {
break
}
entries++
bytes += len(line) + 1
}
b.ReportMetric(float64(entries), "logs/op")
b.ReportMetric(float64(bytes), "buffered-log-bytes/op")
}
// TestGetXrayConfigScale measures building the full Xray config (the path
// every restart/reconcile takes) and, separately, how much of the per-inbound
// settings rebuild is spent on indented vs plain JSON marshaling.