From d4add219b1af337ad9f3766b9d4e23675513e2f8 Mon Sep 17 00:00:00 2001 From: Moroka8 Date: Fri, 8 May 2026 01:23:57 +0700 Subject: [PATCH] fix: gate noisy logs behind debug --- README.md | 1 + client/main.go | 40 ++++++++++++++++++++++-------------- server/main.go | 56 +++++++++++++++++++++++++++++++------------------- 3 files changed, 61 insertions(+), 36 deletions(-) diff --git a/README.md b/README.md index 18be0ae..5d3eb13 100644 --- a/README.md +++ b/README.md @@ -317,6 +317,7 @@ docker build -t vk-turn-proxy . | `-wrap` | `false` | включить WRAP-обфускацию | | `-wrap-key` | пусто | 32-байтный ключ в hex, 64 символа | | `-gen-wrap-key` | `false` | напечатать новый WRAP-ключ и выйти | +| `-debug` | `false` | подробные логи | ## Captcha diff --git a/client/main.go b/client/main.go index 93147a3..09628ec 100644 --- a/client/main.go +++ b/client/main.go @@ -72,6 +72,12 @@ var ( captchaSolverVersion string ) +func debugf(format string, v ...any) { + if isDebug { + log.Printf(format, v...) + } +} + type captchaSolveMode int const ( @@ -142,6 +148,10 @@ func (s *throughputStats) addRx(n int) { } func (s *throughputStats) logEvery(ctx context.Context, label, txName, rxName string) { + if !isDebug { + return + } + ticker := time.NewTicker(5 * time.Second) defer ticker.Stop() @@ -162,7 +172,7 @@ func (s *throughputStats) logEvery(ctx context.Context, label, txName, rxName st continue } - log.Printf( + debugf( "%s throughput: %s=%s %s=%s total_%s=%s total_%s=%s", label, txName, @@ -1775,7 +1785,7 @@ func oneTurnConnection(ctx context.Context, turnParams *turnParams, peer *net.UD return } turnServerAddr = turnServerUDPAddr.String() - fmt.Println(turnServerUDPAddr.IP) + debugf("[STREAM %d] TURN server IP: %s", streamID, turnServerUDPAddr.IP) var cfg *turn.ClientConfig var turnConn net.PacketConn var d net.Dialer @@ -2468,13 +2478,13 @@ func handleBondedTCP(ctx context.Context, tcpConn net.Conn, connID uint64, candi } }) - log.Printf("[bond %d] TCP accept from=%s lanes=%d [%s]", connID, tcpConn.RemoteAddr(), len(lanes), strings.Join(laneIDs, ",")) + debugf("[bond %d] TCP accept from=%s lanes=%d [%s]", connID, tcpConn.RemoteAddr(), len(lanes), strings.Join(laneIDs, ",")) defer func() { for _, lane := range lanes { _ = lane.stream.Close() active := lane.ps.active.Add(-1) closed := lane.ps.closed.Add(1) - log.Printf("[bond %d] lane session %d close active=%d closed=%d totals: to-session=%s from-session=%s", + debugf("[bond %d] lane session %d close active=%d closed=%d totals: to-session=%s from-session=%s", connID, lane.ps.id, active, closed, formatByteCount(lane.ps.toSession.Load()), formatByteCount(lane.ps.fromSession.Load())) } @@ -2494,7 +2504,7 @@ func handleBondedTCP(ctx context.Context, tcpConn net.Conn, connID uint64, candi case <-ctx.Done(): default: if err != io.EOF { - log.Printf("[bond %d] session %d read frame error: %v", connID, l.ps.id, err) + debugf("[bond %d] session %d read frame error: %v", connID, l.ps.id, err) } } return @@ -2561,7 +2571,7 @@ func copyTCPToBond(ctx context.Context, connID uint64, tcpConn net.Conn, lanes [ log.Printf("[bond %d] session %d write FIN error: %v", connID, lane.ps.id, writeErr) } } - log.Printf("[bond %d] upload finished chunks=%d", connID, seq) + debugf("[bond %d] upload finished chunks=%d", connID, seq) return } select { @@ -2605,7 +2615,7 @@ func copyBondToTCP(ctx context.Context, connID uint64, tcpConn net.Conn, recvCh for { if finSeq != nil && expect == *finSeq { closeWrite(tcpConn) - log.Printf("[bond %d] download finished chunks=%d", connID, expect) + debugf("[bond %d] download finished chunks=%d", connID, expect) return } @@ -2740,7 +2750,7 @@ func runVLESSMode(ctx context.Context, tp *turnParams, peer *net.UDPAddr, listen connID := pool.nextConnID() opened := ps.opened.Add(1) active := ps.active.Add(1) - log.Printf("[session %d] TCP accept #%d from=%s active=%d opened=%d pool=%d", + debugf("[session %d] TCP accept #%d from=%s active=%d opened=%d pool=%d", ps.id, connID, tcpConn.RemoteAddr(), active, opened, pool.count()) wgConn.Add(1) @@ -2750,7 +2760,7 @@ func runVLESSMode(ctx context.Context, tp *turnParams, peer *net.UDPAddr, listen defer func() { active := ps.active.Add(-1) closed := ps.closed.Add(1) - log.Printf("[session %d] TCP close #%d active=%d closed=%d totals: to-session=%s from-session=%s", + debugf("[session %d] TCP close #%d active=%d closed=%d totals: to-session=%s from-session=%s", ps.id, connID, active, closed, formatByteCount(ps.toSession.Load()), formatByteCount(ps.fromSession.Load())) }() @@ -2764,7 +2774,7 @@ func runVLESSMode(ctx context.Context, tp *turnParams, peer *net.UDPAddr, listen fromSession, toSession := pipe(ctx, tc, stream) ps.fromSession.Add(uint64(fromSession)) ps.toSession.Add(uint64(toSession)) - log.Printf("[session %d] TCP done #%d local<-session=%s local->session=%s", + debugf("[session %d] TCP done #%d local<-session=%s local->session=%s", ps.id, connID, formatByteCount(uint64(fromSession)), formatByteCount(uint64(toSession))) }(tcpConn, ps, connID) } @@ -2846,7 +2856,7 @@ func createSmuxSession(ctx context.Context, tp *turnParams, peer *net.UDPAddr, i return nil, nil, fmt.Errorf("resolve TURN addr: %w", err) } turnServerAddr = turnServerUDPAddr.String() - fmt.Println(turnServerUDPAddr.IP) + debugf("[session %d] TURN server IP: %s", id, turnServerUDPAddr.IP) // 2. Connect to TURN server var turnConn net.PacketConn @@ -2902,7 +2912,7 @@ func createSmuxSession(ctx context.Context, tp *turnParams, peer *net.UDPAddr, i return nil, nil, fmt.Errorf("TURN allocate: %w", err) } cleanupFns = append(cleanupFns, func() { _ = relayConn.Close() }) - log.Printf("relayed-address=%s", relayConn.LocalAddr().String()) + debugf("relayed-address=%s", relayConn.LocalAddr().String()) // 4. Establish DTLS over TURN relay certificate, err := selfsign.GenerateSelfSigned() @@ -2930,7 +2940,7 @@ func createSmuxSession(ctx context.Context, tp *turnParams, peer *net.UDPAddr, i return nil, nil, fmt.Errorf("DTLS handshake: %w", err) } cleanupFns = append(cleanupFns, func() { _ = dtlsConn.Close() }) - log.Printf("DTLS connection established") + debugf("DTLS connection established") // 5. Create KCP session over DTLS statsCtx, statsCancel := context.WithCancel(ctx) @@ -2944,7 +2954,7 @@ func createSmuxSession(ctx context.Context, tp *turnParams, peer *net.UDPAddr, i return nil, nil, fmt.Errorf("KCP session: %w", err) } cleanupFns = append(cleanupFns, func() { _ = kcpSess.Close() }) - log.Printf("KCP session established") + debugf("KCP session established") // 6. Create smux client session over KCP smuxSess, err := smux.Client(kcpSess, tcputil.DefaultSmuxConfig()) @@ -2953,7 +2963,7 @@ func createSmuxSession(ctx context.Context, tp *turnParams, peer *net.UDPAddr, i return nil, nil, fmt.Errorf("smux client: %w", err) } cleanupFns = append(cleanupFns, func() { _ = smuxSess.Close() }) - log.Printf("smux session established") + debugf("smux session established") return smuxSess, cleanup, nil } diff --git a/server/main.go b/server/main.go index 432802c..1ff83f4 100644 --- a/server/main.go +++ b/server/main.go @@ -23,6 +23,14 @@ import ( "github.com/xtaci/smux" ) +var isDebug bool + +func debugf(format string, v ...any) { + if isDebug { + log.Printf(format, v...) + } +} + func main() { listen := flag.String("listen", "0.0.0.0:56000", "listen on ip:port") connect := flag.String("connect", "", "connect to ip:port") @@ -31,7 +39,9 @@ func main() { wrapMode := flag.Bool("wrap", false, "WRAP mode: ChaCha20-XOR obfuscate DTLS packets before they reach TURN ChannelData") wrapKeyHex := flag.String("wrap-key", "", "32-byte hex-encoded shared key for -wrap (64 hex chars)") genWrapKey := flag.Bool("gen-wrap-key", false, "print a fresh 64-character hex key for -wrap-key and exit") + debugFlag := flag.Bool("debug", false, "enable debug logging") flag.Parse() + isDebug = *debugFlag if *genWrapKey { key := make([]byte, wrapKeyLen) @@ -135,7 +145,7 @@ func main() { log.Printf("failed to close incoming connection: %s", closeErr) } }() - log.Printf("Connection from %s\n", conn.RemoteAddr()) + debugf("Connection from %s\n", conn.RemoteAddr()) // Perform the handshake with a 30-second timeout ctx1, cancel1 := context.WithTimeout(ctx, 30*time.Second) @@ -146,12 +156,12 @@ func main() { log.Println("Type error: expected *dtls.Conn") return } - log.Println("Start handshake") + debugf("Start handshake") if err := dtlsConn.HandshakeContext(ctx1); err != nil { log.Printf("Handshake failed: %v", err) return } - log.Println("Handshake done") + debugf("Handshake done") if *vlessMode { handleVLESSConnection(ctx, dtlsConn, *connect, *vlessBond) @@ -159,7 +169,7 @@ func main() { handleUDPConnection(ctx, conn, *connect) } - log.Printf("Connection closed: %s\n", conn.RemoteAddr()) + debugf("Connection closed: %s\n", conn.RemoteAddr()) }(conn) } } @@ -182,6 +192,10 @@ func (s *throughputStats) addRx(n int) { } func (s *throughputStats) logEvery(ctx context.Context, label, txName, rxName string) { + if !isDebug { + return + } + ticker := time.NewTicker(5 * time.Second) defer ticker.Stop() @@ -202,7 +216,7 @@ func (s *throughputStats) logEvery(ctx context.Context, label, txName, rxName st continue } - log.Printf( + debugf( "%s throughput: %s=%s %s=%s total_%s=%s total_%s=%s", label, txName, @@ -353,7 +367,7 @@ func closeWrite(conn net.Conn) { } if cw, ok := conn.(closeWriter); ok { if err := cw.CloseWrite(); err != nil { - log.Printf("CloseWrite failed: %v", err) + debugf("CloseWrite failed: %v", err) } } } @@ -423,7 +437,7 @@ func (c *bondServerConn) addLane(l *bondServerLane, laneCount uint16) { c.lanes = append(c.lanes, l) count := len(c.lanes) c.lanesMu.Unlock() - log.Printf("[bond %d] lane %d attached (lanes=%d)", c.id, l.index, count) + debugf("[bond %d] lane %d attached (lanes=%d)", c.id, l.index, count) select { case c.ready <- struct{}{}: default: @@ -471,7 +485,7 @@ func (c *bondServerConn) waitForInitialLanes() { return case <-c.ready: case <-timer.C: - log.Printf("[bond %d] starting with %d/%d lanes after attach timeout", c.id, count, want) + debugf("[bond %d] starting with %d/%d lanes after attach timeout", c.id, count, want) return } } @@ -486,7 +500,7 @@ func (c *bondServerConn) readLane(l *bondServerLane) { case <-c.ctx.Done(): default: if err != io.EOF { - log.Printf("[bond %d] lane %d read error: %v (lanes=%d)", c.id, l.index, err, left) + debugf("[bond %d] lane %d read error: %v (lanes=%d)", c.id, l.index, err, left) } if left == 0 { c.cancel() @@ -529,7 +543,7 @@ func (c *bondServerConn) run() { } } }) - log.Printf("[bond %d] backend connected", c.id) + debugf("[bond %d] backend connected", c.id) var wg sync.WaitGroup wg.Add(2) @@ -553,7 +567,7 @@ func (c *bondServerConn) copyBondToBackend(backendConn net.Conn) { for { if finSeq != nil && expect == *finSeq { closeWrite(backendConn) - log.Printf("[bond %d] upload to backend finished chunks=%d", c.id, expect) + debugf("[bond %d] upload to backend finished chunks=%d", c.id, expect) return } @@ -617,7 +631,7 @@ func (c *bondServerConn) copyBackendToBond(backendConn net.Conn) { log.Printf("[bond %d] lane %d write FIN error: %v", c.id, lane.index, writeErr) } } - log.Printf("[bond %d] download from backend finished chunks=%d", c.id, seq) + debugf("[bond %d] download from backend finished chunks=%d", c.id, seq) return } select { @@ -822,7 +836,7 @@ func handleVLESSConnection(ctx context.Context, dtlsConn net.Conn, connectAddr s log.Printf("failed to close KCP session: %v", closeErr) } }() - log.Printf("KCP session established (server)") + debugf("KCP session established (server)") // 2. Create smux server session over KCP smuxSess, err := smux.Server(kcpSess, tcputil.DefaultSmuxConfig()) @@ -835,7 +849,7 @@ func handleVLESSConnection(ctx context.Context, dtlsConn net.Conn, connectAddr s log.Printf("failed to close smux session: %v", err) } }() - log.Printf("smux session established (server)") + debugf("smux session established (server)") // 3. Accept smux streams and forward to backend via TCP var wg sync.WaitGroup @@ -863,7 +877,7 @@ func handleVLESSConnection(ctx context.Context, dtlsConn net.Conn, connectAddr s return } if string(prefix[:]) == bondMagic { - log.Printf("auto-detected bond smux stream") + debugf("auto-detected bond smux stream") handleBondServerStreamAfterMagic(ctx, s, connectAddr, prefix) return } @@ -903,10 +917,10 @@ func pipeConn(ctx context.Context, c1, c2 net.Conn) { context.AfterFunc(ctx2, func() { if err := c1.SetDeadline(time.Now()); err != nil { - log.Printf("pipeConn: failed to set deadline c1: %v", err) + debugf("pipeConn: failed to set deadline c1: %v", err) } if err := c2.SetDeadline(time.Now()); err != nil { - log.Printf("pipeConn: failed to set deadline c2: %v", err) + debugf("pipeConn: failed to set deadline c2: %v", err) } }) @@ -916,14 +930,14 @@ func pipeConn(ctx context.Context, c1, c2 net.Conn) { go func() { defer wg.Done() if _, err := io.Copy(c1, c2); err != nil { - log.Printf("pipeConn: c1<-c2 copy error: %v", err) + debugf("pipeConn: c1<-c2 copy error: %v", err) } }() go func() { defer wg.Done() if _, err := io.Copy(c2, c1); err != nil { - log.Printf("pipeConn: c2<-c1 copy error: %v", err) + debugf("pipeConn: c2<-c1 copy error: %v", err) } }() @@ -931,9 +945,9 @@ func pipeConn(ctx context.Context, c1, c2 net.Conn) { // Reset deadlines (best-effort; connection may already be closed) if err := c1.SetDeadline(time.Time{}); err != nil { - log.Printf("pipeConn: failed to reset deadline c1: %v", err) + debugf("pipeConn: failed to reset deadline c1: %v", err) } if err := c2.SetDeadline(time.Time{}); err != nil { - log.Printf("pipeConn: failed to reset deadline c2: %v", err) + debugf("pipeConn: failed to reset deadline c2: %v", err) } }